diff --git a/test/integration/node-specific/client_close.test.ts b/test/integration/node-specific/client_close.test.ts new file mode 100644 index 00000000000..7f9a3f11a3d --- /dev/null +++ b/test/integration/node-specific/client_close.test.ts @@ -0,0 +1,301 @@ +/* eslint-disable @typescript-eslint/no-empty-function */ +import { type TestConfiguration } from '../../tools/runner/config'; +import { runScriptAndGetProcessInfo } from './resource_tracking_script_builder'; + +describe.skip('MongoClient.close() Integration', () => { + // note: these tests are set-up in accordance of the resource ownership tree + + let config: TestConfiguration; + + beforeEach(function () { + config = this.configuration; + }); + + describe('Node.js resource: TLS File read', () => { + describe('when client is connecting and reads an infinite TLS file', () => { + it('the file read is interrupted by client.close()', async function () { + await runScriptAndGetProcessInfo( + 'tls-file-read', + config, + async function run({ MongoClient, uri, expect }) { + const infiniteFile = '/dev/zero'; + const client = new MongoClient(uri, { tls: true, tlsCertificateKeyFile: infiniteFile }); + const connectPromise = client.connect(); + expect(process.getActiveResourcesInfo()).to.include('FSReqPromise'); + await client.close(); + expect(process.getActiveResourcesInfo()).to.not.include('FSReqPromise'); + const err = await connectPromise.catch(e => e); + expect(err).to.exist; + } + ); + }); + }); + }); + + describe('MongoClientAuthProviders', () => { + describe('Node.js resource: Token file read', () => { + let tokenFileEnvCache; + + beforeEach(function () { + if (process.env.AUTH === 'auth') { + this.currentTest.skipReason = 'OIDC test environment requires auth disabled'; + return this.skip(); + } + tokenFileEnvCache = process.env.OIDC_TOKEN_FILE; + }); + + afterEach(function () { + process.env.OIDC_TOKEN_FILE = tokenFileEnvCache; + }); + + describe('when MongoClientAuthProviders is instantiated and token file read hangs', () => { + it('the file read is interrupted by client.close()', async () => { + await runScriptAndGetProcessInfo( + 'token-file-read', + config, + async function run({ MongoClient, uri, expect }) { + const infiniteFile = '/dev/zero'; + process.env.OIDC_TOKEN_FILE = infiniteFile; + const options = { + authMechanismProperties: { ENVIRONMENT: 'test' }, + authMechanism: 'MONGODB-OIDC' + }; + const client = new MongoClient(uri, options); + client.connect(); + expect(process.getActiveResourcesInfo()).to.include('FSReqPromise'); + await client.close(); + expect(process.getActiveResourcesInfo()).to.not.include('FSReqPromise'); + } + ); + }); + }); + }); + }); + + describe('Topology', () => { + describe('Node.js resource: Server Selection Timer', () => { + describe('after a Topology is created through client.connect()', () => { + it.skip('server selection timers are cleaned up by client.close()', async () => {}); + }); + }); + + describe('Server', () => { + describe('Monitor', () => { + // connection monitoring is by default turned on - with the exception of load-balanced mode + const metadata: MongoDBMetadataUI = { + requires: { + topology: ['single', 'replicaset', 'sharded'] + } + }; + + describe('MonitorInterval', () => { + describe('Node.js resource: Timer', () => { + describe('after a new monitor is made', () => { + it.skip('monitor interval timer is cleaned up by client.close()', async () => {}); + }); + + describe('after a heartbeat fails', () => { + it.skip('the new monitor interval timer is cleaned up by client.close()', async () => {}); + }); + }); + }); + + describe('Connection Monitoring', () => { + describe('Node.js resource: Socket', () => { + it.skip('no sockets remain after client.close()', metadata, async function () {}); + }); + }); + + describe('RTT Pinger', () => { + describe('Node.js resource: Timer', () => { + describe('after entering monitor streaming mode ', () => { + it.skip('the rtt pinger timer is cleaned up by client.close()', async () => { + // helloReply has a topologyVersion defined + }); + }); + }); + + describe('Connection', () => { + describe('Node.js resource: Socket', () => { + describe('when rtt monitoring is turned on', () => { + it.skip('no sockets remain after client.close()', async () => {}); + }); + }); + }); + }); + }); + + describe('ConnectionPool', () => { + describe('Node.js resource: minPoolSize timer', () => { + describe('after new connection pool is created', () => { + it.skip('the minPoolSize timer is cleaned up by client.close()', async () => {}); + }); + }); + + describe('Node.js resource: checkOut Timer', () => { + // waitQueueTimeoutMS + describe('after new connection pool is created', () => { + it.skip('the wait queue timer is cleaned up by client.close()', async () => {}); + }); + }); + + describe('Connection', () => { + describe('Node.js resource: Socket', () => { + describe('after a connection is checked out', () => { + it.skip('no sockets remain after client.close()', async () => {}); + }); + + describe('after a minPoolSize has been set on the ConnectionPool', () => { + it.skip('no sockets remain after client.close()', async () => {}); + }); + }); + }); + }); + }); + + describe('SrvPoller', () => { + describe('Node.js resource: Timer', () => { + describe('after SRVPoller is created', () => { + it.skip('timers are cleaned up by client.close()', async () => {}); + }); + }); + }); + }); + + describe('ClientSession (Implicit)', () => { + describe('Server resource: LSID/ServerSession', () => { + describe('after a clientSession is implicitly created and used', () => { + it.skip('the server-side ServerSession is cleaned up by client.close()', async function () {}); + }); + }); + + describe('Server resource: Transactions', () => { + describe('after a clientSession is implicitly created and used', () => { + it.skip('the server-side transaction is cleaned up by client.close()', async function () {}); + }); + }); + }); + + describe('ClientSession (Explicit)', () => { + describe('Server resource: LSID/ServerSession', () => { + describe('after a clientSession is created and used', () => { + it.skip('the server-side ServerSession is cleaned up by client.close()', async function () {}); + }); + }); + + describe('Server resource: Transactions', () => { + describe('after a clientSession is created and used', () => { + it.skip('the server-side transaction is cleaned up by client.close()', async function () {}); + }); + }); + }); + + describe('AutoEncrypter', () => { + const metadata: MongoDBMetadataUI = { + requires: { + mongodb: '>=4.2.0', + clientSideEncryption: true + } + }; + + describe('KMS Request', () => { + describe('Node.js resource: TLS file read', () => { + describe('when KMSRequest reads an infinite TLS file', () => { + it('the file read is interrupted by client.close()', async () => { + await runScriptAndGetProcessInfo( + 'tls-file-read-auto-encryption', + config, + async function run({ MongoClient, uri, expect, ClientEncryption, BSON }) { + const infiniteFile = '/dev/zero'; + + const kmsProviders = BSON.EJSON.parse(process.env.CSFLE_KMS_PROVIDERS); + const masterKey = { + region: 'us-east-1', + key: 'arn:aws:kms:us-east-1:579766882180:key/89fcc2c4-08b0-4bd9-9f25-e30687b580d0' + }; + const provider = 'aws'; + + const keyVaultClient = new MongoClient(uri); + await keyVaultClient.connect(); + await keyVaultClient.db('keyvault').collection('datakeys'); + + const clientEncryption = new ClientEncryption(keyVaultClient, { + keyVaultNamespace: 'keyvault.datakeys', + kmsProviders + }); + const dataKey = await clientEncryption.createDataKey(provider, { masterKey }); + + function getEncryptExtraOptions() { + if ( + typeof process.env.CRYPT_SHARED_LIB_PATH === 'string' && + process.env.CRYPT_SHARED_LIB_PATH.length > 0 + ) { + return { cryptSharedLibPath: process.env.CRYPT_SHARED_LIB_PATH }; + } + return {}; + } + const schemaMap = { + 'db.coll': { + bsonType: 'object', + encryptMetadata: { + keyId: [dataKey] + }, + properties: { + a: { + encrypt: { + bsonType: 'int', + algorithm: 'AEAD_AES_256_CBC_HMAC_SHA_512-Random', + keyId: [dataKey] + } + } + } + } + }; + const encryptionOptions = { + autoEncryption: { + keyVaultNamespace: 'keyvault.datakeys', + kmsProviders, + extraOptions: getEncryptExtraOptions(), + schemaMap, + tlsOptions: { aws: { tlsCAFile: infiniteFile } } + } + }; + + const encryptedClient = new MongoClient(uri, encryptionOptions); + await encryptedClient.connect(); + + expect(process.getActiveResourcesInfo()).to.not.include('FSReqPromise'); + + const insertPromise = encryptedClient + .db('db') + .collection('coll') + .insertOne({ a: 1 }); + + expect(process.getActiveResourcesInfo()).to.include('FSReqPromise'); + + await keyVaultClient.close(); + await encryptedClient.close(); + + expect(process.getActiveResourcesInfo()).to.not.include('FSReqPromise'); + + const err = await insertPromise.catch(e => e); + expect(err).to.exist; + expect(err.errmsg).to.contain('Error in KMS response'); + } + ); + }); + }); + }); + + describe('Node.js resource: Socket', () => { + it.skip('no sockets remain after client.close()', metadata, async () => {}); + }); + }); + }); + + describe('Server resource: Cursor', () => { + describe('after cursors are created', () => { + it.skip('all active server-side cursors are closed by client.close()', async function () {}); + }); + }); +}); diff --git a/test/integration/node-specific/resource_clean_up.test.ts b/test/integration/node-specific/resource_clean_up.test.ts index e370986a264..9e021b65790 100644 --- a/test/integration/node-specific/resource_clean_up.test.ts +++ b/test/integration/node-specific/resource_clean_up.test.ts @@ -3,7 +3,7 @@ import * as v8 from 'node:v8'; import { expect } from 'chai'; import { sleep } from '../../tools/utils'; -import { runScript } from './resource_tracking_script_builder'; +import { runScriptAndReturnHeapInfo } from './resource_tracking_script_builder'; /** * This 5MB range is selected arbitrarily and should likely be raised if failures are seen intermittently. @@ -38,7 +38,7 @@ describe('Driver Resources', () => { return; } try { - const res = await runScript( + const res = await runScriptAndReturnHeapInfo( 'no_resource_leak_connect_close', this.configuration, async function run({ MongoClient, uri }) { diff --git a/test/integration/node-specific/resource_tracking_script_builder.ts b/test/integration/node-specific/resource_tracking_script_builder.ts index f7cfb764230..69273c90c5b 100644 --- a/test/integration/node-specific/resource_tracking_script_builder.ts +++ b/test/integration/node-specific/resource_tracking_script_builder.ts @@ -1,34 +1,53 @@ -import { fork } from 'node:child_process'; +import { fork, spawn } from 'node:child_process'; import { on, once } from 'node:events'; import { readFile, unlink, writeFile } from 'node:fs/promises'; import * as path from 'node:path'; -import { expect } from 'chai'; +import { AssertionError, expect } from 'chai'; import { parseSnapshot } from 'v8-heapsnapshot'; -import { type MongoClient } from '../../mongodb'; +import { type BSON, type ClientEncryption, type MongoClient } from '../../mongodb'; import { type TestConfiguration } from '../../tools/runner/config'; -export type ResourceTestFunction = (options: { +export type ResourceTestFunction = HeapResourceTestFunction | ProcessResourceTestFunction; + +export type HeapResourceTestFunction = (options: { MongoClient: typeof MongoClient; uri: string; iteration: number; }) => Promise; -const RESOURCE_SCRIPT_PATH = path.resolve(__dirname, '../../tools/fixtures/resource_script.in.js'); +export type ProcessResourceTestFunction = (options: { + MongoClient: typeof MongoClient; + uri: string; + log?: (out: any) => void; + expect: typeof expect; + ClientEncryption?: typeof ClientEncryption; + BSON?: typeof BSON; +}) => Promise; + +const HEAP_RESOURCE_SCRIPT_PATH = path.resolve( + __dirname, + '../../tools/fixtures/resource_script.in.js' +); +const REPORT_RESOURCE_SCRIPT_PATH = path.resolve( + __dirname, + '../../tools/fixtures/process_resource_script.in.js' +); const DRIVER_SRC_PATH = JSON.stringify(path.resolve(__dirname, '../../../lib')); export async function testScriptFactory( name: string, uri: string, - iterations: number, - func: ResourceTestFunction + resourceScriptPath: string, + func: ResourceTestFunction, + iterations?: number ) { - let resourceScript = await readFile(RESOURCE_SCRIPT_PATH, { encoding: 'utf8' }); + let resourceScript = await readFile(resourceScriptPath, { encoding: 'utf8' }); resourceScript = resourceScript.replace('DRIVER_SOURCE_PATH', DRIVER_SRC_PATH); resourceScript = resourceScript.replace('FUNCTION_STRING', `(${func.toString()})`); - resourceScript = resourceScript.replace('NAME_STRING', JSON.stringify(name)); + resourceScript = resourceScript.replace('SCRIPT_NAME_STRING', JSON.stringify(name)); resourceScript = resourceScript.replace('URI_STRING', JSON.stringify(uri)); resourceScript = resourceScript.replace('ITERATIONS_STRING', `${iterations}`); @@ -36,7 +55,8 @@ export async function testScriptFactory( } /** - * A helper for running arbitrary MongoDB Driver scripting code in a resource information collecting script + * A helper for running arbitrary MongoDB Driver scripting code in a resource information collecting script. + * This script uses heap data to collect resource information. * * **The provided function is run in an isolated Node.js process** * @@ -57,16 +77,22 @@ export async function testScriptFactory( * @param options - settings for the script * @throws Error - if the process exits with failure */ -export async function runScript( +export async function runScriptAndReturnHeapInfo( name: string, config: TestConfiguration, - func: ResourceTestFunction, + func: HeapResourceTestFunction, { iterations = 100 } = {} ) { const scriptName = `${name}.cjs`; const heapsnapshotFile = `${name}.heapsnapshot.json`; - const scriptContent = await testScriptFactory(name, config.url(), iterations, func); + const scriptContent = await testScriptFactory( + name, + config.url(), + HEAP_RESOURCE_SCRIPT_PATH, + func, + iterations + ); await writeFile(scriptName, scriptContent, { encoding: 'utf8' }); const processDiedController = new AbortController(); @@ -106,3 +132,70 @@ export async function runScript( heap }; } + +/** + * A helper for running arbitrary MongoDB Driver scripting code in a resource information collecting script. + * This script uses info from node:process to collect resource information. + * + * **The provided function is run in an isolated Node.js process** + * + * A user of this function will likely need to familiarize themselves with the surrounding scripting, but briefly: + * - Many MongoClient operations (construction, connection, commands) can result in resources that keep the JS event loop running. + * - Timers + * - Active Sockets + * - File Read Hangs + * + * - This function performs assertions that at the end of the provided function, the js event loop has been exhausted + * + * @param name - the name of the script, this defines the name of the file, it will be cleaned up if the function returns successfully + * @param config - `this.configuration` from your mocha config + * @param func - your javascript function, you can write it inline! this will stringify the function, use the references on the `this` context to get typechecking + * @param options - settings for the script + * @throws Error - if the process exits with failure or if the process' resources are not cleaned up by the provided function. + */ +export async function runScriptAndGetProcessInfo( + name: string, + config: TestConfiguration, + func: ProcessResourceTestFunction +) { + const scriptName = `${name}.cjs`; + const scriptContent = await testScriptFactory( + name, + config.url(), + REPORT_RESOURCE_SCRIPT_PATH, + func + ); + await writeFile(scriptName, scriptContent, { encoding: 'utf8' }); + const logFile = name + '.logs.txt'; + + const script = spawn(process.execPath, [scriptName], { stdio: ['ignore', 'ignore', 'inherit'] }); + + const willClose = once(script, 'close'); + + // make sure the process ended + const [exitCode] = await willClose; + + // format messages from child process as an object + const messages = (await readFile(logFile, 'utf-8')) + .trim() + .split('\n') + .map(line => JSON.parse(line)) + .reduce((acc, curr) => ({ ...acc, ...curr }), {}); + + // delete temporary files + await unlink(scriptName); + await unlink(logFile); + + // assertions about exit status + if (exitCode) { + const assertionError = new AssertionError( + messages.error.message + '\n\t' + JSON.stringify(messages.error.resources, undefined, 2) + ); + assertionError.stack = messages.error.stack + new Error().stack.slice('Error'.length); + throw assertionError; + } + + // assertions about resource status + expect(messages.beforeExitHappened).to.be.true; + expect(messages.newResources).to.be.empty; +} diff --git a/test/tools/fixtures/resource_script.in.js b/test/tools/fixtures/heap_resource_script.in.js similarity index 100% rename from test/tools/fixtures/resource_script.in.js rename to test/tools/fixtures/heap_resource_script.in.js diff --git a/test/tools/fixtures/process_resource_script.in.js b/test/tools/fixtures/process_resource_script.in.js new file mode 100644 index 00000000000..2b5a3b40ac7 --- /dev/null +++ b/test/tools/fixtures/process_resource_script.in.js @@ -0,0 +1,117 @@ +'use strict'; + +/* eslint-disable no-undef */ +/* eslint-disable no-unused-vars */ +const driverPath = DRIVER_SOURCE_PATH; +const func = FUNCTION_STRING; +const scriptName = SCRIPT_NAME_STRING; +const uri = URI_STRING; + +const { MongoClient, ClientEncryption, BSON } = require(driverPath); +const process = require('node:process'); +const util = require('node:util'); +const timers = require('node:timers'); +const fs = require('node:fs'); +const { expect } = require('chai'); +const { setTimeout } = require('timers'); + +let originalReport; +const logFile = scriptName + '.logs.txt'; + +const run = func; + +/** + * + * Returns an array containing the new libuv resources created after script started. + * A new resource is something that will keep the event loop running. + * + * In order to be counted as a new resource, a resource MUST: + * - Must NOT share an address with a libuv resource that existed at the start of script + * - Must be referenced. See [here](https://nodejs.org/api/timers.html#timeoutref) for more context. + * - Must NOT be an inactive server + * + * We're using the following tool to track resources: `process.report.getReport().libuv` + * For more context, see documentation for [process.report.getReport()](https://nodejs.org/api/report.html), and [libuv](https://docs.libuv.org/en/v1.x/handle.html). + * + */ +function getNewLibuvResourceArray() { + let currReport = process.report.getReport().libuv; + const originalReportAddresses = originalReport.map(resource => resource.address); + + /** + * @typedef {Object} LibuvResource + * @property {boolean} is_active Is the resource active? For a socket, this means it is allowing I/O. For a timer, this means a timer is has not expired. + * @property {string} type What is the resource type? For example, 'tcp' | 'timer' | 'udp' | 'tty'... (See more in [docs](https://docs.libuv.org/en/v1.x/handle.html)). + * @property {boolean} is_referenced Is the resource keeping the JS event loop active? + * + * @param {LibuvResource} resource + */ + function isNewLibuvResource(resource) { + const serverType = ['tcp', 'udp']; + return ( + !originalReportAddresses.includes(resource.address) && + resource.is_referenced && // if a resource is unreferenced, it's not keeping the event loop open + (!serverType.includes(resource.type) || resource.is_active) + ); + } + + currReport = currReport.filter(resource => isNewLibuvResource(resource)); + return currReport; +} + +/** + * Returns an object of the new resources created after script started. + * + * + * In order to be counted as a new resource, a resource MUST either: + * - Meet the criteria to be returned by our helper utility `getNewLibuvResourceArray()` + * OR + * - Be returned by `process.getActiveResourcesInfo() + * + * The reason we are using both methods to detect active resources is: + * - `process.report.getReport().libuv` does not detect active requests (such as timers or file reads) accurately + * - `process.getActiveResourcesInfo()` does not contain enough server information we need for our assertions + * + */ +function getNewResources() { + return { + libuvResources: getNewLibuvResourceArray(), + activeResources: process.getActiveResourcesInfo() + }; +} + +// A log function for debugging +function log(message) { + // remove outer parentheses for easier parsing + const messageToLog = JSON.stringify(message) + ' \n'; + fs.writeFileSync(logFile, messageToLog, { flag: 'a' }); +} + +async function main() { + originalReport = process.report.getReport().libuv; + process.on('beforeExit', () => { + log({ beforeExitHappened: true }); + }); + await run({ MongoClient, uri, log, expect, ClientEncryption, BSON }); + log({ newResources: getNewResources() }); +} + +main() + .then(() => {}) + .catch(e => { + log({ error: { message: e.message, stack: e.stack, resources: getNewResources() } }); + process.exit(1); + }); + +setTimeout(() => { + // this means something was in the event loop such that it hung for more than 10 seconds + // so we kill the process + log({ + error: { + message: 'Process timed out: resources remain in the event loop', + resources: getNewResources() + } + }); + process.exit(99); + // using `unref` will ensure this setTimeout call is not a resource / does not keep the event loop running +}, 10000).unref();