From 68cb2a617be60e2ef09ba566f34bbc8d51ceec21 Mon Sep 17 00:00:00 2001 From: Leonardo Venturini Date: Wed, 16 Oct 2024 07:34:33 -0400 Subject: [PATCH 01/10] add github action --- .github/workflows/test.yml | 41 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 41 insertions(+) create mode 100644 .github/workflows/test.yml diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml new file mode 100644 index 0000000..61a87c3 --- /dev/null +++ b/.github/workflows/test.yml @@ -0,0 +1,41 @@ +name: Test Meteor Perf Package + +on: + push: + branches: + - main + pull_request: + +jobs: + test: + runs-on: ubuntu-latest + + env: + METEOR_VERSION: 3.0.4 + + steps: + - name: Checkout code + uses: actions/checkout@v2 + + - name: Set up Node.js + uses: actions/setup-node@v2 + with: + node-version: 20 + + - name: Cache Meteor Installation + id: meteor-cache + uses: actions/cache@v3 + with: + path: ~/.meteor + key: ${{ runner.os }}-meteor-${{ env.METEOR_VERSION }} + restore-keys: | + ${{ runner.os }}-meteor- + + - name: Install Meteor (if not cached) + if: steps.meteor-cache.outputs.cache-hit != 'true' + run: | + npx meteor@${{ env.METEOR_VERSION }} + + - name: Run Tests + run: | + TEST_CLIENT=0 meteor test-packages ./ --driver-package meteortesting:mocha --no-release-check --once \ No newline at end of file From a98ee415cc00ffc61baa130c50523aad37e2b463 Mon Sep 17 00:00:00 2001 From: Leonardo Venturini Date: Wed, 16 Oct 2024 07:38:01 -0400 Subject: [PATCH 02/10] ignore .npm --- .gitignore | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/.gitignore b/.gitignore index 7f32e4b..5a46b7b 100644 --- a/.gitignore +++ b/.gitignore @@ -1,2 +1,3 @@ .vscode -node_modules \ No newline at end of file +node_modules +.npm \ No newline at end of file From 38e12155b5ce427754d71eeb1e009efcc23550e3 Mon Sep 17 00:00:00 2001 From: Leonardo Venturini Date: Wed, 16 Oct 2024 07:38:23 -0400 Subject: [PATCH 03/10] adjust path --- .github/workflows/test.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 61a87c3..08d6559 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -38,4 +38,4 @@ jobs: - name: Run Tests run: | - TEST_CLIENT=0 meteor test-packages ./ --driver-package meteortesting:mocha --no-release-check --once \ No newline at end of file + TEST_CLIENT=0 ~/.meteor/meteor test-packages ./ --driver-package meteortesting:mocha --no-release-check --once \ No newline at end of file From e34304106968cb1339e6bd3458647ebcecb98aa9 Mon Sep 17 00:00:00 2001 From: Leonardo Venturini Date: Wed, 16 Oct 2024 07:41:43 -0400 Subject: [PATCH 04/10] export path --- .github/workflows/test.yml | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 08d6559..8d11a09 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -35,7 +35,8 @@ jobs: if: steps.meteor-cache.outputs.cache-hit != 'true' run: | npx meteor@${{ env.METEOR_VERSION }} + export PATH=/home/runner/.meteor:$PATH - name: Run Tests run: | - TEST_CLIENT=0 ~/.meteor/meteor test-packages ./ --driver-package meteortesting:mocha --no-release-check --once \ No newline at end of file + TEST_CLIENT=0 meteor test-packages ./ --driver-package meteortesting:mocha --no-release-check --once \ No newline at end of file From 893af9b75e195c602b841c9e013088a76e3841c2 Mon Sep 17 00:00:00 2001 From: Leonardo Venturini Date: Wed, 16 Oct 2024 07:43:15 -0400 Subject: [PATCH 05/10] export path --- .github/workflows/test.yml | 3 +++ 1 file changed, 3 insertions(+) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 8d11a09..9b03599 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -35,6 +35,9 @@ jobs: if: steps.meteor-cache.outputs.cache-hit != 'true' run: | npx meteor@${{ env.METEOR_VERSION }} + + - name: Export Path + run: | export PATH=/home/runner/.meteor:$PATH - name: Run Tests From 1f200cde4dbccf6cc27edd96b6c8558a62b4b0f0 Mon Sep 17 00:00:00 2001 From: Leonardo Venturini Date: Wed, 16 Oct 2024 07:45:29 -0400 Subject: [PATCH 06/10] export path --- .github/workflows/test.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 9b03599..d81d140 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -38,7 +38,7 @@ jobs: - name: Export Path run: | - export PATH=/home/runner/.meteor:$PATH + echo "$HOME/.meteor" >> $GITHUB_PATH - name: Run Tests run: | From bbfcdf21e507b91968f9fc72746e9fce2941a687 Mon Sep 17 00:00:00 2001 From: Leonardo Venturini Date: Wed, 16 Oct 2024 08:05:46 -0400 Subject: [PATCH 07/10] add garbage collection to async resource map --- async-interceptor.js | 30 ++++++++++++++++++++++-------- save-output.js | 4 ++-- 2 files changed, 24 insertions(+), 10 deletions(-) diff --git a/async-interceptor.js b/async-interceptor.js index 8f210ab..646ae87 100644 --- a/async-interceptor.js +++ b/async-interceptor.js @@ -1,25 +1,39 @@ import async_hooks from 'node:async_hooks'; -export const asyncResources = new Map(); +// 50% of map limit +export const GC_LIMIT = Math.pow(2, 23); + +export const AsyncResourceMap = new Map(); export const AsyncInterceptor = async_hooks.createHook({ - init(asyncId, type, triggerAsyncId, resource) { - logResourceCreation(asyncId, type, triggerAsyncId, resource); + init(asyncId, type) { + logResourceCreation(asyncId, type); }, }); -function logResourceCreation(asyncId, type, triggerAsyncId, resource) { +function logResourceCreation(asyncId, type) { const stack = (new Error()).stack.split('\n').slice(2).filter(line => { return !['AsyncHook.init', 'node:internal/async_hooks'].some(fn => line.includes(fn)); }).join('\n'); - if (!asyncResources.has(stack)) { - asyncResources.set(stack, { count: 0, types: new Set() }); + if (AsyncResourceMap.size > GC_LIMIT) { + console.log('Meteor Perf: Garbage collecting async resources'); + garbageCollectAsyncResources(); + } + + if (!AsyncResourceMap.has(stack)) { + AsyncResourceMap.set(stack, { count: 0, types: new Set() }); } - const resourceInfo = asyncResources.get(stack); + const resourceInfo = AsyncResourceMap.get(stack); resourceInfo.count++; resourceInfo.types.add(type); } - +function garbageCollectAsyncResources() { + AsyncResourceMap.forEach((info, stack) => { + if (info.count <= 1) { + AsyncResourceMap.delete(stack); + } + }); +} \ No newline at end of file diff --git a/save-output.js b/save-output.js index 793319d..14a20f6 100644 --- a/save-output.js +++ b/save-output.js @@ -1,4 +1,4 @@ -import { asyncResources } from './async-interceptor'; +import { AsyncResourceMap } from './async-interceptor'; import { StatDict } from './observer-monitor'; import path from 'node:path'; import fs from 'node:fs'; @@ -9,7 +9,7 @@ export function saveOutput() { performance.mark('saveOutput-start'); let async_traces = [] - asyncResources.forEach((info, stack) => { + AsyncResourceMap.forEach((info, stack) => { if (info.count <= 1) { return; } From 1012a496fddce171f9cecdbca278361dc56c3230 Mon Sep 17 00:00:00 2001 From: Leonardo Venturini Date: Wed, 16 Oct 2024 14:22:13 -0400 Subject: [PATCH 08/10] add basic tests --- async-interceptor.js | 25 ++++++++++++++-------- package.js | 3 ++- tests/async-interceptor.test.js | 38 +++++++++++++++++++++++++++++++++ tests/index.js | 3 ++- tests/observer.test.js | 15 ++----------- 5 files changed, 60 insertions(+), 24 deletions(-) create mode 100644 tests/async-interceptor.test.js diff --git a/async-interceptor.js b/async-interceptor.js index 646ae87..e507b6f 100644 --- a/async-interceptor.js +++ b/async-interceptor.js @@ -7,27 +7,26 @@ export const AsyncResourceMap = new Map(); export const AsyncInterceptor = async_hooks.createHook({ init(asyncId, type) { - logResourceCreation(asyncId, type); + captureResource(asyncId, type); }, }); -function logResourceCreation(asyncId, type) { - const stack = (new Error()).stack.split('\n').slice(2).filter(line => { - return !['AsyncHook.init', 'node:internal/async_hooks'].some(fn => line.includes(fn)); - }).join('\n'); +function captureResource(asyncId, type) { + let stack = stackTrace(); + + stack = `${type}\n${stack}`; if (AsyncResourceMap.size > GC_LIMIT) { - console.log('Meteor Perf: Garbage collecting async resources'); + console.log('Meteor Perf: Reached AsyncResourceMap limit, garbage collecting'); garbageCollectAsyncResources(); } if (!AsyncResourceMap.has(stack)) { - AsyncResourceMap.set(stack, { count: 0, types: new Set() }); + AsyncResourceMap.set(stack, { count: 0 }); } const resourceInfo = AsyncResourceMap.get(stack); resourceInfo.count++; - resourceInfo.types.add(type); } function garbageCollectAsyncResources() { @@ -36,4 +35,12 @@ function garbageCollectAsyncResources() { AsyncResourceMap.delete(stack); } }); -} \ No newline at end of file +} + +export function stackTrace () { + return (new Error()).stack.split('\n').slice(3).filter(line => { + return !['AsyncHook.init', 'node:internal/async_hooks'].some(fn => line.includes(fn)); + }).join('\n') +} + +setInterval(garbageCollectAsyncResources, 10000); \ No newline at end of file diff --git a/package.js b/package.js index 2645726..de5cea2 100644 --- a/package.js +++ b/package.js @@ -20,7 +20,8 @@ Package.onTest(function(api) { Npm.depends({ 'chai': '4.3.4', 'sinon': '10.0.0', - 'sinon-chai': '3.6.0' + 'sinon-chai': '3.6.0', + 'benchmarkify': '4.0.0' }); api.mainModule('tests/index.js', 'server'); diff --git a/tests/async-interceptor.test.js b/tests/async-interceptor.test.js new file mode 100644 index 0000000..366d5ee --- /dev/null +++ b/tests/async-interceptor.test.js @@ -0,0 +1,38 @@ +import { expect } from 'chai'; +import { AsyncInterceptor, AsyncResourceMap, stackTrace } from '../async-interceptor'; +import Benchmarkify from "benchmarkify"; + +const benchmark = new Benchmarkify("Meteor Perf", { chartImage: true }).printHeader(); + +benchmark.createSuite("Stack Trace", { time: 1000 }) + .add("default error stack trace", () => { + return new Error().stack; + }) + .ref("clean stack trace", () => { + return (new Error()).stack.split('\n').slice(2).filter(line => { + return !['AsyncHook.init', 'node:internal/async_hooks'].some(fn => line.includes(fn)); + }).join('\n'); + }); + + +await benchmark.run(); + +describe('Async Interceptor', () => { + it('get stack trace', async () => { + const stack = stackTrace(); + + expect(stack).to.be.a('string'); + }); + + it('should capture async operations', async () => { + AsyncInterceptor.enable(); + + await new Promise((resolve) => { + setTimeout(resolve, 100); + }); + + AsyncInterceptor.disable(); + + expect(AsyncResourceMap.size).to.be.greaterThan(0); + }) +}) \ No newline at end of file diff --git a/tests/index.js b/tests/index.js index 6d67538..1895563 100644 --- a/tests/index.js +++ b/tests/index.js @@ -1 +1,2 @@ -import './observer.test'; \ No newline at end of file +import './observer.test'; +import './async-interceptor.test'; \ No newline at end of file diff --git a/tests/observer.test.js b/tests/observer.test.js index 7c1c054..4b6d26e 100644 --- a/tests/observer.test.js +++ b/tests/observer.test.js @@ -1,5 +1,4 @@ import { StatDict } from '../observer-monitor'; -import { MeteorPerf } from '../index'; import { expect } from 'chai'; const coll = new Mongo.Collection('test') @@ -11,10 +10,7 @@ describe('Observer', () => { await coll.removeAsync({}, { multi: true }) observer = await coll.find({}).observeChanges({ - added: (...args) => { - console.trace() - console.log('added', args); - }, + added: (...args) => console.log('added', args), changed: (...args) => console.log('changed', args), removed: (...args) => console.log('removed', args), }) @@ -26,14 +22,7 @@ describe('Observer', () => { }); it('should detect observer creation', async () => { - console.log(await coll.insertAsync({ foo: 'bar' })) - console.log(await coll.insertAsync({ foo: 'bar' })) - console.log(await coll.insertAsync({ foo: 'bar' })) - console.log(await coll.insertAsync({ foo: 'bar' })) - - Meteor._sleepForMs(5000) - - console.log({ StatDict, MeteorPerf}) + await coll.insertAsync({ foo: 'bar' }) expect(StatDict.size).to.equal(1); expect(StatDict.get('test::{}')).to.have.property('key', 'test::{}'); From 0d95c67f4455c4cd1d94ea2e396e8cbfa0f09017 Mon Sep 17 00:00:00 2001 From: Leonardo Venturini Date: Wed, 16 Oct 2024 15:17:14 -0400 Subject: [PATCH 09/10] test garbage collector --- async-interceptor.js | 3 +- save-output.js | 1 - tests/async-interceptor.test.js | 55 +++++++++++++++++++++++++++++++-- 3 files changed, 53 insertions(+), 6 deletions(-) diff --git a/async-interceptor.js b/async-interceptor.js index e507b6f..ef1d6b8 100644 --- a/async-interceptor.js +++ b/async-interceptor.js @@ -1,7 +1,7 @@ import async_hooks from 'node:async_hooks'; // 50% of map limit -export const GC_LIMIT = Math.pow(2, 23); +export const GC_LIMIT = Meteor.isPackageTest ? 7 : Math.pow(2, 23); export const AsyncResourceMap = new Map(); @@ -17,7 +17,6 @@ function captureResource(asyncId, type) { stack = `${type}\n${stack}`; if (AsyncResourceMap.size > GC_LIMIT) { - console.log('Meteor Perf: Reached AsyncResourceMap limit, garbage collecting'); garbageCollectAsyncResources(); } diff --git a/save-output.js b/save-output.js index 14a20f6..84cefb2 100644 --- a/save-output.js +++ b/save-output.js @@ -16,7 +16,6 @@ export function saveOutput() { async_traces.push({ count: info.count, - types: [...info.types], stack, }); }); diff --git a/tests/async-interceptor.test.js b/tests/async-interceptor.test.js index 366d5ee..475fce5 100644 --- a/tests/async-interceptor.test.js +++ b/tests/async-interceptor.test.js @@ -1,5 +1,5 @@ import { expect } from 'chai'; -import { AsyncInterceptor, AsyncResourceMap, stackTrace } from '../async-interceptor'; +import { AsyncInterceptor, AsyncResourceMap, GC_LIMIT, stackTrace } from '../async-interceptor'; import Benchmarkify from "benchmarkify"; const benchmark = new Benchmarkify("Meteor Perf", { chartImage: true }).printHeader(); @@ -14,7 +14,6 @@ benchmark.createSuite("Stack Trace", { time: 1000 }) }).join('\n'); }); - await benchmark.run(); describe('Async Interceptor', () => { @@ -35,4 +34,54 @@ describe('Async Interceptor', () => { expect(AsyncResourceMap.size).to.be.greaterThan(0); }) -}) \ No newline at end of file + + it('should not capture async operations when disabled', async () => { + AsyncInterceptor.disable(); + + AsyncResourceMap.clear(); + + await new Promise((resolve) => { + setTimeout(resolve, 100); + }); + + expect(AsyncResourceMap.size).to.equal(0); + }); + + it('should garbage collect async resources', async () => { + AsyncInterceptor.enable(); + + for (let i = 0; i < GC_LIMIT + 1; i++) { + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + } + + AsyncInterceptor.disable(); + + expect(AsyncResourceMap.size).to.be.lessThanOrEqual(GC_LIMIT); + }) +}); \ No newline at end of file From d79698bd50710c5b6561acbf628cba1657f587a8 Mon Sep 17 00:00:00 2001 From: Leonardo Venturini Date: Wed, 16 Oct 2024 15:37:28 -0400 Subject: [PATCH 10/10] add benchmark --- async-interceptor.js | 2 +- tests/async-interceptor.test.js | 67 ++++++++++++++++++++++++++++++++- 2 files changed, 67 insertions(+), 2 deletions(-) diff --git a/async-interceptor.js b/async-interceptor.js index ef1d6b8..3fd7759 100644 --- a/async-interceptor.js +++ b/async-interceptor.js @@ -21,7 +21,7 @@ function captureResource(asyncId, type) { } if (!AsyncResourceMap.has(stack)) { - AsyncResourceMap.set(stack, { count: 0 }); + AsyncResourceMap.set(stack, { count: 0, ts: Date.now() }); } const resourceInfo = AsyncResourceMap.get(stack); diff --git a/tests/async-interceptor.test.js b/tests/async-interceptor.test.js index 475fce5..3ca7309 100644 --- a/tests/async-interceptor.test.js +++ b/tests/async-interceptor.test.js @@ -2,7 +2,7 @@ import { expect } from 'chai'; import { AsyncInterceptor, AsyncResourceMap, GC_LIMIT, stackTrace } from '../async-interceptor'; import Benchmarkify from "benchmarkify"; -const benchmark = new Benchmarkify("Meteor Perf", { chartImage: true }).printHeader(); +const benchmark = new Benchmarkify("Meteor Perf").printHeader(); benchmark.createSuite("Stack Trace", { time: 1000 }) .add("default error stack trace", () => { @@ -14,9 +14,39 @@ benchmark.createSuite("Stack Trace", { time: 1000 }) }).join('\n'); }); +benchmark.createSuite("Interceptor Overhead", { time: 3000 }) + .setup(() => { + AsyncInterceptor.enable(); + }) + .tearDown(() => { + AsyncInterceptor.disable(); + }) + .add("on", async (done) => { + await new Promise((resolve) => { + setTimeout(resolve, 0); + }) + + done() + }) + .ref("off", async (done) => { + AsyncInterceptor.disable(); + + await new Promise((resolve) => { + setTimeout(resolve, 0); + }) + + done() + }); + + + await benchmark.run(); describe('Async Interceptor', () => { + beforeEach(() => { + AsyncResourceMap.clear(); + }) + it('get stack trace', async () => { const stack = stackTrace(); @@ -78,10 +108,45 @@ describe('Async Interceptor', () => { await new Promise((resolve) => { setTimeout(resolve, 1); }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); + await new Promise((resolve) => { + setTimeout(resolve, 1); + }); } AsyncInterceptor.disable(); expect(AsyncResourceMap.size).to.be.lessThanOrEqual(GC_LIMIT); }) + + it('should have ts timestamp attribute for all trace entries', async () => { + AsyncInterceptor.enable(); + + await new Promise((resolve) => { + setTimeout(resolve, 100); + }); + + AsyncInterceptor.disable(); + + AsyncResourceMap.forEach((info) => { + expect(info).to.have.property('ts'); + }); + }); }); \ No newline at end of file