From bbc2113c11a65c594b7a13f5abe66e55848a1167 Mon Sep 17 00:00:00 2001 From: bailey Date: Mon, 21 Apr 2025 11:36:56 -0600 Subject: [PATCH 1/3] asdf --- .../resource_tracking_script_builder.ts | 27 ++++++++++++++++++- .../tools/fixtures/heap_resource_script.in.js | 17 ++++++++++++ 2 files changed, 43 insertions(+), 1 deletion(-) diff --git a/test/integration/node-specific/resource_tracking_script_builder.ts b/test/integration/node-specific/resource_tracking_script_builder.ts index 375613d6157..eaa2a914f28 100644 --- a/test/integration/node-specific/resource_tracking_script_builder.ts +++ b/test/integration/node-specific/resource_tracking_script_builder.ts @@ -3,6 +3,7 @@ import { on, once } from 'node:events'; import { openSync } from 'node:fs'; import { readFile, unlink, writeFile } from 'node:fs/promises'; import * as path from 'node:path'; +import { inspect } from 'node:util'; import { AssertionError, expect } from 'chai'; import type * as timers from 'timers'; @@ -50,6 +51,7 @@ export async function testScriptFactory( uri: string, resourceScriptPath: string, func: ResourceTestFunction, + logFn: string, iterations?: number ) { let resourceScript = await readFile(resourceScriptPath, { encoding: 'utf8' }); @@ -59,6 +61,7 @@ export async function testScriptFactory( resourceScript = resourceScript.replace('SCRIPT_NAME_STRING', JSON.stringify(name)); resourceScript = resourceScript.replace('URI_STRING', JSON.stringify(uri)); resourceScript = resourceScript.replace('ITERATIONS_STRING', `${iterations}`); + resourceScript = resourceScript.replace('LOG_FN', `${logFn.toString()}`); return resourceScript; } @@ -92,6 +95,9 @@ export async function runScriptAndReturnHeapInfo( func: HeapResourceTestFunction, { iterations = 100 } = {} ) { + const log = (...args) => process.stdout.write(`${args}\n`); + + log('starting'); const scriptName = `${name}.cjs`; const heapsnapshotFile = `${name}.heapsnapshot.json`; @@ -100,36 +106,55 @@ export async function runScriptAndReturnHeapInfo( config.url(), HEAP_RESOURCE_SCRIPT_PATH, func, + `(...args) => process.stdout.write('(subprocess): ' + args)`, iterations ); await writeFile(scriptName, scriptContent, { encoding: 'utf8' }); const processDiedController = new AbortController(); - const script = fork(scriptName, { execArgv: ['--expose-gc'] }); + const script = fork(scriptName, { execArgv: ['--expose-gc'], stdio: 'inherit' }); // Interrupt our awaiting of messages if the process crashed script.once('close', exitCode => { if (exitCode !== 0) { + log('process exited with non-zero: ', exitCode); processDiedController.abort(new Error(`process exited with: ${exitCode}`)); } }); + script.once('error', error => { + log(`processed errored: ${error}`); + processDiedController.abort(new Error(`process errored: `, { cause: error })); + }); + + script.once('spawn', () => log('script spawned successfully.')); + const messages = on(script, 'message', { signal: processDiedController.signal }); const willClose = once(script, 'close'); + log('fetching messages 1...'); const starting = await messages.next(); + log('fetching messages 2: ', inspect(starting, { depth: Infinity })); + const ending = await messages.next(); + log('fetching messages 3: ', inspect(ending, { depth: Infinity })); + const startingMemoryUsed = starting.value[0].startingMemoryUsed; const endingMemoryUsed = ending.value[0].endingMemoryUsed; // make sure the process ended const [exitCode] = await willClose; + + log('child process closed.'); + expect(exitCode, 'process should have exited with zero').to.equal(0); const heap = await readFile(heapsnapshotFile, { encoding: 'utf8' }).then(c => parseSnapshot(JSON.parse(c)) ); + log('done.'); + // If any of the above throws we won't reach these unlinks that clean up the created files. // This is intentional so that when debugging the file will still be present to check it for errors await unlink(scriptName); diff --git a/test/tools/fixtures/heap_resource_script.in.js b/test/tools/fixtures/heap_resource_script.in.js index 69083f8c5c4..2927a6cbb62 100644 --- a/test/tools/fixtures/heap_resource_script.in.js +++ b/test/tools/fixtures/heap_resource_script.in.js @@ -7,6 +7,7 @@ const func = FUNCTION_STRING; const name = SCRIPT_NAME_STRING; const uri = URI_STRING; const iterations = ITERATIONS_STRING; +const log = LOG_FN; const { MongoClient } = require(driverPath); const process = require('node:process'); @@ -14,6 +15,7 @@ const v8 = require('node:v8'); const util = require('node:util'); const timers = require('node:timers'); +const now = performance.now.bind(performance); const sleep = util.promisify(timers.setTimeout); const run = func; @@ -21,22 +23,37 @@ const run = func; const MB = (2 ** 10) ** 2; async function main() { + log('starting execution' + '\n'); const startingMemoryUsed = process.memoryUsage().heapUsed / MB; process.send({ startingMemoryUsed }); + log('sent first message' + '\n'); + for (let iteration = 0; iteration < iterations; iteration++) { await run({ MongoClient, uri, iteration }); + iteration % 20 === 0 && log(`iteration ${iteration} complete\n`); global.gc(); } + log('script executed' + '\n'); + global.gc(); // Sleep b/c maybe gc will run await sleep(100); global.gc(); const endingMemoryUsed = process.memoryUsage().heapUsed / MB; + + log('sending second message' + '\n'); + process.send({ endingMemoryUsed }); + log('second message sent.' + '\n'); + + const start = now(); v8.writeHeapSnapshot(`${name}.heapsnapshot.json`); + const end = now(); + + log(`heap snapshot written in ${end - start}ms. script exiting` + '\n'); } main() From fb23a84d1f5d12e52ea7cf4b3fc60398b69e8899 Mon Sep 17 00:00:00 2001 From: bailey Date: Mon, 21 Apr 2025 12:16:39 -0600 Subject: [PATCH 2/3] clean up logs per suggestions --- .../node-specific/resource_clean_up.test.ts | 2 +- .../resource_tracking_script_builder.ts | 20 +++++++++----- .../tools/fixtures/heap_resource_script.in.js | 26 +++++++++++++------ 3 files changed, 32 insertions(+), 16 deletions(-) diff --git a/test/integration/node-specific/resource_clean_up.test.ts b/test/integration/node-specific/resource_clean_up.test.ts index 1e1256f3d43..95f890f0e09 100644 --- a/test/integration/node-specific/resource_clean_up.test.ts +++ b/test/integration/node-specific/resource_clean_up.test.ts @@ -32,7 +32,7 @@ describe('Driver Resources', () => { } }); - context('on MongoClient.close()', () => { + context.only('on MongoClient.close()', () => { before('create leak reproduction script', async function () { if (globalThis.AbortController == null || typeof this.configuration.serverApi === 'string') { return; diff --git a/test/integration/node-specific/resource_tracking_script_builder.ts b/test/integration/node-specific/resource_tracking_script_builder.ts index eaa2a914f28..e166dfb6b4c 100644 --- a/test/integration/node-specific/resource_tracking_script_builder.ts +++ b/test/integration/node-specific/resource_tracking_script_builder.ts @@ -51,7 +51,6 @@ export async function testScriptFactory( uri: string, resourceScriptPath: string, func: ResourceTestFunction, - logFn: string, iterations?: number ) { let resourceScript = await readFile(resourceScriptPath, { encoding: 'utf8' }); @@ -61,7 +60,6 @@ export async function testScriptFactory( resourceScript = resourceScript.replace('SCRIPT_NAME_STRING', JSON.stringify(name)); resourceScript = resourceScript.replace('URI_STRING', JSON.stringify(uri)); resourceScript = resourceScript.replace('ITERATIONS_STRING', `${iterations}`); - resourceScript = resourceScript.replace('LOG_FN', `${logFn.toString()}`); return resourceScript; } @@ -95,8 +93,17 @@ export async function runScriptAndReturnHeapInfo( func: HeapResourceTestFunction, { iterations = 100 } = {} ) { - const log = (...args) => process.stdout.write(`${args}\n`); - + const log = (...args) => { + const payload = + args + .map(item => + typeof item === 'string' + ? item + : inspect(item, { depth: Infinity, breakLength: Infinity }) + ) + .join(', ') + '\n'; + process.stdout.write(payload); + }; log('starting'); const scriptName = `${name}.cjs`; const heapsnapshotFile = `${name}.heapsnapshot.json`; @@ -106,7 +113,6 @@ export async function runScriptAndReturnHeapInfo( config.url(), HEAP_RESOURCE_SCRIPT_PATH, func, - `(...args) => process.stdout.write('(subprocess): ' + args)`, iterations ); await writeFile(scriptName, scriptContent, { encoding: 'utf8' }); @@ -133,11 +139,11 @@ export async function runScriptAndReturnHeapInfo( log('fetching messages 1...'); const starting = await messages.next(); - log('fetching messages 2: ', inspect(starting, { depth: Infinity })); + log('fetching messages 2: ', starting); const ending = await messages.next(); - log('fetching messages 3: ', inspect(ending, { depth: Infinity })); + log('fetching messages 3: ', ending); const startingMemoryUsed = starting.value[0].startingMemoryUsed; const endingMemoryUsed = ending.value[0].endingMemoryUsed; diff --git a/test/tools/fixtures/heap_resource_script.in.js b/test/tools/fixtures/heap_resource_script.in.js index 2927a6cbb62..afe7407fcb0 100644 --- a/test/tools/fixtures/heap_resource_script.in.js +++ b/test/tools/fixtures/heap_resource_script.in.js @@ -7,7 +7,7 @@ const func = FUNCTION_STRING; const name = SCRIPT_NAME_STRING; const uri = URI_STRING; const iterations = ITERATIONS_STRING; -const log = LOG_FN; +const { inspect } = require('util'); const { MongoClient } = require(driverPath); const process = require('node:process'); @@ -22,20 +22,30 @@ const run = func; const MB = (2 ** 10) ** 2; +const log = (...args) => { + const payload = + args + .map(item => + typeof item === 'string' ? item : inspect(item, { depth: Infinity, breakLength: Infinity }) + ) + .join(', ') + '\n'; + process.stdout.write('(subprocess): ' + payload); +}; + async function main() { - log('starting execution' + '\n'); + log('starting execution'); const startingMemoryUsed = process.memoryUsage().heapUsed / MB; process.send({ startingMemoryUsed }); - log('sent first message' + '\n'); + log('sent first message'); for (let iteration = 0; iteration < iterations; iteration++) { await run({ MongoClient, uri, iteration }); - iteration % 20 === 0 && log(`iteration ${iteration} complete\n`); + iteration % 20 === 0 && log(`iteration ${iteration} complete`); global.gc(); } - log('script executed' + '\n'); + log('script executed'); global.gc(); // Sleep b/c maybe gc will run @@ -44,16 +54,16 @@ async function main() { const endingMemoryUsed = process.memoryUsage().heapUsed / MB; - log('sending second message' + '\n'); + log('sending second message'); process.send({ endingMemoryUsed }); - log('second message sent.' + '\n'); + log('second message sent.'); const start = now(); v8.writeHeapSnapshot(`${name}.heapsnapshot.json`); const end = now(); - log(`heap snapshot written in ${end - start}ms. script exiting` + '\n'); + log(`heap snapshot written in ${end - start}ms. script exiting`); } main() From 766c4751698bd8b078fbbd8d68d7cac056fe3716 Mon Sep 17 00:00:00 2001 From: Bailey Pearson Date: Mon, 21 Apr 2025 13:06:13 -0600 Subject: [PATCH 3/3] Update test/integration/node-specific/resource_clean_up.test.ts Co-authored-by: Neal Beeken --- test/integration/node-specific/resource_clean_up.test.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/integration/node-specific/resource_clean_up.test.ts b/test/integration/node-specific/resource_clean_up.test.ts index 95f890f0e09..1e1256f3d43 100644 --- a/test/integration/node-specific/resource_clean_up.test.ts +++ b/test/integration/node-specific/resource_clean_up.test.ts @@ -32,7 +32,7 @@ describe('Driver Resources', () => { } }); - context.only('on MongoClient.close()', () => { + context('on MongoClient.close()', () => { before('create leak reproduction script', async function () { if (globalThis.AbortController == null || typeof this.configuration.serverApi === 'string') { return;