From 2be5714ece168cdec112a02095ebe3fd8048f52e Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Wed, 2 Apr 2025 14:35:14 -0400 Subject: [PATCH 01/13] ci(NODE-6860): add logging for known flaky tests --- .../client_side_encryption.spec.test.ts | 8 --- ...ver_discovery_and_monitoring.prose.test.ts | 65 +++++++++---------- test/tools/runner/config.ts | 49 ++++++++++++++ test/tools/runner/hooks/configuration.ts | 14 +++- test/tools/unified-spec-runner/entities.ts | 58 ++++++++++------- .../entity_event_registry.test.ts | 4 +- 6 files changed, 130 insertions(+), 68 deletions(-) diff --git a/test/integration/client-side-encryption/client_side_encryption.spec.test.ts b/test/integration/client-side-encryption/client_side_encryption.spec.test.ts index 7d43268ef39..58fe5bb19bc 100644 --- a/test/integration/client-side-encryption/client_side_encryption.spec.test.ts +++ b/test/integration/client-side-encryption/client_side_encryption.spec.test.ts @@ -149,14 +149,6 @@ describe('Client Side Encryption (Unified)', function () { if (typeof shouldSkip === 'string') return shouldSkip; } - const flakyTests = { - 'rewrap to azure:name1': 'TODO(NODE-6860): fix flaky tests' - }; - - const skipReason = flakyTests[description]; - - if (skipReason) return skipReason; - return isServerless ? 'Unified CSFLE tests to not run on serverless' : false; } ); diff --git a/test/integration/server-discovery-and-monitoring/server_discovery_and_monitoring.prose.test.ts b/test/integration/server-discovery-and-monitoring/server_discovery_and_monitoring.prose.test.ts index 3549d580c69..ad8ade8c7dd 100644 --- a/test/integration/server-discovery-and-monitoring/server_discovery_and_monitoring.prose.test.ts +++ b/test/integration/server-discovery-and-monitoring/server_discovery_and_monitoring.prose.test.ts @@ -146,40 +146,37 @@ describe('Server Discovery and Monitoring Prose Tests', function () { await client.close(); }); - it.skip( - 'ensure monitors properly create and unpause connection pools when they discover servers', - { - metadata: { requires: { mongodb: '>=4.2.9', topology: '!load-balanced' } }, - test: async function () { - await client.connect(); - expect(events.shift()).to.equal(SERVER_HEARTBEAT_SUCCEEDED); - expect(events.shift()).to.equal(CONNECTION_POOL_READY); - - expect(events).to.be.empty; - - const heartBeatFailedEvent = once(client, SERVER_HEARTBEAT_FAILED); - await client.db('admin').command({ - configureFailPoint: 'failCommand', - mode: { times: 2 }, - data: { - failCommands: ['hello'], - errorCode: 1234, - appName: 'SDAMPoolManagementTest' - } - }); - await heartBeatFailedEvent; - expect(events.shift()).to.equal(SERVER_HEARTBEAT_FAILED); - expect(events.shift()).to.equal(CONNECTION_POOL_CLEARED); - - expect(events).to.be.empty; - - await once(client, SERVER_HEARTBEAT_SUCCEEDED); - expect(events.shift()).to.equal(SERVER_HEARTBEAT_SUCCEEDED); - expect(events.shift()).to.equal(CONNECTION_POOL_READY); - - expect(events).to.be.empty; - } + it('ensure monitors properly create and unpause connection pools when they discover servers', { + metadata: { requires: { mongodb: '>=4.2.9', topology: '!load-balanced' } }, + test: async function () { + await client.connect(); + expect(events.shift()).to.equal(SERVER_HEARTBEAT_SUCCEEDED); + expect(events.shift()).to.equal(CONNECTION_POOL_READY); + + expect(events).to.be.empty; + + const heartBeatFailedEvent = once(client, SERVER_HEARTBEAT_FAILED); + await client.db('admin').command({ + configureFailPoint: 'failCommand', + mode: { times: 2 }, + data: { + failCommands: ['hello'], + errorCode: 1234, + appName: 'SDAMPoolManagementTest' + } + }); + await heartBeatFailedEvent; + expect(events.shift()).to.equal(SERVER_HEARTBEAT_FAILED); + expect(events.shift()).to.equal(CONNECTION_POOL_CLEARED); + + expect(events).to.be.empty; + + await once(client, SERVER_HEARTBEAT_SUCCEEDED); + expect(events.shift()).to.equal(SERVER_HEARTBEAT_SUCCEEDED); + expect(events.shift()).to.equal(CONNECTION_POOL_READY); + + expect(events).to.be.empty; } - ).skipReason = 'TODO(NODE-5206): fix flaky test'; + }); }); }); diff --git a/test/tools/runner/config.ts b/test/tools/runner/config.ts index 5385ace8cc2..3a12a50ef6a 100644 --- a/test/tools/runner/config.ts +++ b/test/tools/runner/config.ts @@ -1,4 +1,7 @@ +import * as util from 'node:util'; + import { expect } from 'chai'; +import { type Context } from 'mocha'; import ConnectionString from 'mongodb-connection-string-url'; import * as qs from 'querystring'; import * as url from 'url'; @@ -205,6 +208,11 @@ export class TestConfiguration { newClient(urlOrQueryOptions?: string | Record, serverOptions?: MongoClientOptions) { serverOptions = Object.assign({}, getEnvironmentalOptions(), serverOptions); + + if (this.loggingEnabled && !Object.hasOwn(serverOptions, 'mongodbLogPath')) { + serverOptions = this.setupLogging(serverOptions); + } + // Support MongoClient constructor form (url, options) for `newClient`. if (typeof urlOrQueryOptions === 'string') { if (Reflect.has(serverOptions, 'host') || Reflect.has(serverOptions, 'port')) { @@ -427,6 +435,47 @@ export class TestConfiguration { makeAtlasTestConfiguration(): AtlasTestConfiguration { return new AtlasTestConfiguration(this.uri, this.context); } + + loggingEnabled = false; + logs = []; + /** + * Known flaky tests that we want to turn on logging for + * so that we can get a better idea of what is failing when it fails + */ + testsToEnableLogging = [ + 'Client Side Encryption (Unified) namedKMS-rewrapManyDataKey rewrap to azure:name1', + 'Server Discovery and Monitoring Prose Tests Connection Pool Management ensure monitors properly create and unpause connection pools when they discover servers', + 'CSOT spec tests legacy timeouts behave correctly for retryable operations operation succeeds after one socket timeout - aggregate on collection' + ]; + + setupLogging(options) { + this.logs = []; + const write = log => this.logs.push(log); + options.mongodbLogPath = { write }; + options.mongodbLogComponentSeverities = { default: 'trace' }; + options.mongodbLogMaxDocumentLength = 300; + return options; + } + + beforeEachLogging(ctx: Context) { + this.loggingEnabled = this.testsToEnableLogging.includes(ctx.currentTest.fullTitle()); + } + + afterEachLogging(ctx: Context) { + if (this.loggingEnabled && ctx.currentTest.state === 'failed') { + for (const log of this.logs) { + const logLine = util.inspect(log, { + compact: true, + breakLength: Infinity, + colors: true, + depth: 1000 + }); + console.error(logLine); + } + } + this.loggingEnabled = false; + this.logs = []; + } } /** diff --git a/test/tools/runner/hooks/configuration.ts b/test/tools/runner/hooks/configuration.ts index d6c4100f339..a2397eac139 100644 --- a/test/tools/runner/hooks/configuration.ts +++ b/test/tools/runner/hooks/configuration.ts @@ -22,6 +22,7 @@ import { NodeVersionFilter } from '../filters/node_version_filter'; import { OSFilter } from '../filters/os_filter'; import { ServerlessFilter } from '../filters/serverless_filter'; import { type Filter } from '../filters/filter'; +import { type Context } from 'mocha'; // Default our tests to have auth enabled // A better solution will be tackled in NODE-3714 @@ -211,8 +212,19 @@ const beforeAllPluginImports = () => { require('mocha-sinon'); }; +async function beforeEachLogging(this: Context) { + if (this.currentTest == null) return; + this.configuration.beforeEachLogging(this); +} + +async function afterEachLogging(this: Context) { + if (this.currentTest == null) return; + this.configuration.afterEachLogging(this); +} + export const mochaHooks = { beforeAll: [beforeAllPluginImports, testConfigBeforeHook], - beforeEach: [testSkipBeforeEachHook], + beforeEach: [testSkipBeforeEachHook, beforeEachLogging], + afterEach: [afterEachLogging], afterAll: [cleanUpMocksAfterHook] }; diff --git a/test/tools/unified-spec-runner/entities.ts b/test/tools/unified-spec-runner/entities.ts index 759d7fb8a17..af52c9aca63 100644 --- a/test/tools/unified-spec-runner/entities.ts +++ b/test/tools/unified-spec-runner/entities.ts @@ -28,7 +28,9 @@ import { type HostAddress, type Log, MongoClient, + type MongoClientOptions, type MongoCredentials, + type MongoDBLogWritable, ReadConcern, ReadPreference, SENSITIVE_COMMANDS, @@ -126,7 +128,6 @@ export class UnifiedMongoClient extends MongoClient { cmapEvents: CmapEvent[] = []; sdamEvents: SdamEvent[] = []; failPoints: Document[] = []; - logCollector: { buffer: LogMessage[]; write: (log: Log) => void }; ignoredEvents: string[]; observeSensitiveCommands: boolean; @@ -197,34 +198,44 @@ export class UnifiedMongoClient extends MongoClient { topology: 'MONGODB_LOG_TOPOLOGY' } as const; - constructor(uri: string, description: ClientEntity) { - const logCollector: { buffer: LogMessage[]; write: (log: Log) => void } = { - buffer: [], - write(log: Log): void { - const transformedLog = { - level: log.s, - component: log.c, - data: { ...log } - }; - - this.buffer.push(transformedLog); - } - }; - const mongodbLogComponentSeverities = description.observeLogMessages; - - super(uri, { + constructor( + uri: string, + description: ClientEntity, + config: { + loggingEnabled?: boolean; + setupLogging?: (options: Record) => Record; + } + ) { + const options: MongoClientOptions = { monitorCommands: true, __skipPingOnConnect: true, - mongodbLogComponentSeverities, ...getEnvironmentalOptions(), ...(description.serverApi ? { serverApi: description.serverApi } : {}), - mongodbLogPath: logCollector, // TODO(NODE-5785): We need to increase the truncation length because signature.hash is a Buffer making hellos too long mongodbLogMaxDocumentLength: 1250 - } as any); + }; + + if (description.observeLogMessages != null) { + options.mongodbLogComponentSeverities = description.observeLogMessages; + options.mongodbLogPath = { + buffer: [], + write(log: Log): void { + const transformedLog = { + level: log.s, + component: log.c, + data: { ...log } + }; + + this.buffer.push(transformedLog); + } + } as MongoDBLogWritable; + } else if (config.loggingEnabled) { + config.setupLogging?.(options); + } + + super(uri, options); this.observedEventEmitter.on('error', () => null); - this.logCollector = logCollector; this.observeSensitiveCommands = description.observeSensitiveCommands ?? false; this.ignoredEvents = [ @@ -337,7 +348,7 @@ export class UnifiedMongoClient extends MongoClient { } get collectedLogs(): LogMessage[] { - return this.logCollector.buffer; + return (this.options.mongodbLogPath as unknown as { buffer: any[] })?.buffer ?? []; } } @@ -578,7 +589,8 @@ export class EntitiesMap extends Map { } else { uri = makeConnectionString(config.url({ useMultipleMongoses }), entity.client.uriOptions); } - const client = new UnifiedMongoClient(uri, entity.client); + + const client = new UnifiedMongoClient(uri, entity.client, config); try { new EntityEventRegistry(client, entity.client, map).register(); await client.connect(); diff --git a/test/unit/tools/unified_spec_runner/entity_event_registry.test.ts b/test/unit/tools/unified_spec_runner/entity_event_registry.test.ts index f807ab5b9c0..8457ff4026b 100644 --- a/test/unit/tools/unified_spec_runner/entity_event_registry.test.ts +++ b/test/unit/tools/unified_spec_runner/entity_event_registry.test.ts @@ -48,7 +48,7 @@ describe('EntityEventRegistry', function () { }; const entitesMap = new EntitiesMap(); const uri = 'mongodb://127.0.0.1:27017'; - const client = new UnifiedMongoClient(uri, clientEntity); + const client = new UnifiedMongoClient(uri, clientEntity, {}); const registry = new EntityEventRegistry(client, clientEntity, entitesMap); before(function () { @@ -120,7 +120,7 @@ describe('EntityEventRegistry', function () { const clientEntity = { id: 'client0' }; const entitesMap = new EntitiesMap(); const uri = 'mongodb://127.0.0.1:27017'; - const client = new UnifiedMongoClient(uri, clientEntity); + const client = new UnifiedMongoClient(uri, clientEntity, {}); const registry = new EntityEventRegistry(client, clientEntity, entitesMap); before(function () { From c3b8b52e443094800c59fb2c881a5404770acf9c Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Thu, 3 Apr 2025 17:29:55 -0400 Subject: [PATCH 02/13] chore: add name --- test/tools/runner/config.ts | 4 ++-- test/tools/unified-spec-runner/entities.ts | 4 ++-- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/test/tools/runner/config.ts b/test/tools/runner/config.ts index 3a12a50ef6a..4dbb31a9573 100644 --- a/test/tools/runner/config.ts +++ b/test/tools/runner/config.ts @@ -448,9 +448,9 @@ export class TestConfiguration { 'CSOT spec tests legacy timeouts behave correctly for retryable operations operation succeeds after one socket timeout - aggregate on collection' ]; - setupLogging(options) { + setupLogging(options: MongoClientOptions, s: string = '') { this.logs = []; - const write = log => this.logs.push(log); + const write = log => this.logs.push({ t: log.t, s, ...log }); options.mongodbLogPath = { write }; options.mongodbLogComponentSeverities = { default: 'trace' }; options.mongodbLogMaxDocumentLength = 300; diff --git a/test/tools/unified-spec-runner/entities.ts b/test/tools/unified-spec-runner/entities.ts index af52c9aca63..5151d0d0ad7 100644 --- a/test/tools/unified-spec-runner/entities.ts +++ b/test/tools/unified-spec-runner/entities.ts @@ -203,7 +203,7 @@ export class UnifiedMongoClient extends MongoClient { description: ClientEntity, config: { loggingEnabled?: boolean; - setupLogging?: (options: Record) => Record; + setupLogging?: (options: Record, id: string) => Record; } ) { const options: MongoClientOptions = { @@ -230,7 +230,7 @@ export class UnifiedMongoClient extends MongoClient { } } as MongoDBLogWritable; } else if (config.loggingEnabled) { - config.setupLogging?.(options); + config.setupLogging?.(options, description.id); } super(uri, options); From ab9cd6c0da6d1c99c10debe02d9fa50a018a92cf Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Fri, 4 Apr 2025 10:13:52 -0400 Subject: [PATCH 03/13] refactor: update log handling in UnifiedMongoClient for improved log collection --- test/tools/unified-spec-runner/entities.ts | 13 ++++++++----- 1 file changed, 8 insertions(+), 5 deletions(-) diff --git a/test/tools/unified-spec-runner/entities.ts b/test/tools/unified-spec-runner/entities.ts index 5151d0d0ad7..2aaaf8205e1 100644 --- a/test/tools/unified-spec-runner/entities.ts +++ b/test/tools/unified-spec-runner/entities.ts @@ -30,7 +30,6 @@ import { MongoClient, type MongoClientOptions, type MongoCredentials, - type MongoDBLogWritable, ReadConcern, ReadPreference, SENSITIVE_COMMANDS, @@ -128,6 +127,7 @@ export class UnifiedMongoClient extends MongoClient { cmapEvents: CmapEvent[] = []; sdamEvents: SdamEvent[] = []; failPoints: Document[] = []; + logCollector?: { buffer: LogMessage[]; write: (log: Log) => void }; ignoredEvents: string[]; observeSensitiveCommands: boolean; @@ -215,9 +215,11 @@ export class UnifiedMongoClient extends MongoClient { mongodbLogMaxDocumentLength: 1250 }; + let logCollector: { buffer: LogMessage[]; write: (log: Log) => void } | undefined; + if (description.observeLogMessages != null) { options.mongodbLogComponentSeverities = description.observeLogMessages; - options.mongodbLogPath = { + logCollector = { buffer: [], write(log: Log): void { const transformedLog = { @@ -228,13 +230,14 @@ export class UnifiedMongoClient extends MongoClient { this.buffer.push(transformedLog); } - } as MongoDBLogWritable; + }; + options.mongodbLogPath = logCollector; } else if (config.loggingEnabled) { config.setupLogging?.(options, description.id); } super(uri, options); - + this.logCollector = logCollector; this.observedEventEmitter.on('error', () => null); this.observeSensitiveCommands = description.observeSensitiveCommands ?? false; @@ -348,7 +351,7 @@ export class UnifiedMongoClient extends MongoClient { } get collectedLogs(): LogMessage[] { - return (this.options.mongodbLogPath as unknown as { buffer: any[] })?.buffer ?? []; + return this.logCollector?.buffer ?? []; } } From d0100f78ccbbd926f35e901414c399fbbaa57027 Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Fri, 4 Apr 2025 10:45:20 -0400 Subject: [PATCH 04/13] chore: add a unique id per logger --- test/tools/runner/config.ts | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/test/tools/runner/config.ts b/test/tools/runner/config.ts index 4dbb31a9573..5edb6b542fa 100644 --- a/test/tools/runner/config.ts +++ b/test/tools/runner/config.ts @@ -11,6 +11,7 @@ import { HostAddress, MongoClient, type MongoClientOptions, + ObjectId, type ServerApi, TopologyType, type WriteConcernSettings @@ -448,7 +449,8 @@ export class TestConfiguration { 'CSOT spec tests legacy timeouts behave correctly for retryable operations operation succeeds after one socket timeout - aggregate on collection' ]; - setupLogging(options: MongoClientOptions, s: string = '') { + setupLogging(options: MongoClientOptions, s?: string) { + s ??= new ObjectId().toString(); this.logs = []; const write = log => this.logs.push({ t: log.t, s, ...log }); options.mongodbLogPath = { write }; From a770fb3fc468214cf72360868bae5c3c039cd78e Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Fri, 4 Apr 2025 10:57:03 -0400 Subject: [PATCH 05/13] chore: use json --- test/tools/runner/config.ts | 26 +++++++++++++++++++------- 1 file changed, 19 insertions(+), 7 deletions(-) diff --git a/test/tools/runner/config.ts b/test/tools/runner/config.ts index 5edb6b542fa..d3b33ea1812 100644 --- a/test/tools/runner/config.ts +++ b/test/tools/runner/config.ts @@ -1,4 +1,5 @@ import * as util from 'node:util'; +import * as types from 'node:util/types'; import { expect } from 'chai'; import { type Context } from 'mocha'; @@ -9,6 +10,7 @@ import * as url from 'url'; import { type AuthMechanism, HostAddress, + Long, MongoClient, type MongoClientOptions, ObjectId, @@ -466,13 +468,23 @@ export class TestConfiguration { afterEachLogging(ctx: Context) { if (this.loggingEnabled && ctx.currentTest.state === 'failed') { for (const log of this.logs) { - const logLine = util.inspect(log, { - compact: true, - breakLength: Infinity, - colors: true, - depth: 1000 - }); - console.error(logLine); + console.error( + JSON.stringify( + log, + function (_, value) { + if (types.isMap(value)) return { Map: Array.from(value.entries()) }; + if (types.isSet(value)) return { Set: Array.from(value.values()) }; + if (types.isNativeError(value)) return { [value.name]: util.inspect(value) }; + if (typeof value === 'bigint') return new Long(value).toExtendedJSON(); + if (typeof value === 'symbol') return `Symbol(${value.description})`; + if (Buffer.isBuffer(value)) + return { [value.constructor.name]: Buffer.prototype.base64Slice.call(value) }; + if (value === undefined) return { undefined: 'key was set but equal to undefined' }; + return value; + }, + 0 + ) + ); } } this.loggingEnabled = false; From 06464c90d339f731d4efd0dbea8db1cfe01f1930 Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Fri, 4 Apr 2025 11:02:50 -0400 Subject: [PATCH 06/13] improve json --- test/tools/runner/config.ts | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/test/tools/runner/config.ts b/test/tools/runner/config.ts index d3b33ea1812..1d5dc5124ca 100644 --- a/test/tools/runner/config.ts +++ b/test/tools/runner/config.ts @@ -9,6 +9,7 @@ import * as url from 'url'; import { type AuthMechanism, + Double, HostAddress, Long, MongoClient, @@ -475,8 +476,13 @@ export class TestConfiguration { if (types.isMap(value)) return { Map: Array.from(value.entries()) }; if (types.isSet(value)) return { Set: Array.from(value.values()) }; if (types.isNativeError(value)) return { [value.name]: util.inspect(value) }; - if (typeof value === 'bigint') return new Long(value).toExtendedJSON(); + if (typeof value === 'bigint') return { bigint: new Long(value).toExtendedJSON() }; if (typeof value === 'symbol') return `Symbol(${value.description})`; + if (typeof value === 'number') { + if (Number.isNaN(value) || !Number.isFinite(value) || Object.is(value, -0)) + // @ts-expect-error: toExtendedJSON internal on double but not on long + return { number: new Double(value).toExtendedJSON() }; + } if (Buffer.isBuffer(value)) return { [value.constructor.name]: Buffer.prototype.base64Slice.call(value) }; if (value === undefined) return { undefined: 'key was set but equal to undefined' }; From 46f2e0dd95b94de6e4f5103abdb5f7851561deb3 Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Fri, 4 Apr 2025 12:33:07 -0400 Subject: [PATCH 07/13] reduce diff --- test/tools/unified-spec-runner/entities.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/tools/unified-spec-runner/entities.ts b/test/tools/unified-spec-runner/entities.ts index 2aaaf8205e1..b228c0669a0 100644 --- a/test/tools/unified-spec-runner/entities.ts +++ b/test/tools/unified-spec-runner/entities.ts @@ -237,8 +237,8 @@ export class UnifiedMongoClient extends MongoClient { } super(uri, options); - this.logCollector = logCollector; this.observedEventEmitter.on('error', () => null); + this.logCollector = logCollector; this.observeSensitiveCommands = description.observeSensitiveCommands ?? false; this.ignoredEvents = [ From 7dd6053a0b3057c178f49c29a8afab2e438bcba7 Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Fri, 4 Apr 2025 12:36:15 -0400 Subject: [PATCH 08/13] chore: switch to id --- test/tools/runner/config.ts | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/test/tools/runner/config.ts b/test/tools/runner/config.ts index 1d5dc5124ca..df62552aaf2 100644 --- a/test/tools/runner/config.ts +++ b/test/tools/runner/config.ts @@ -452,10 +452,10 @@ export class TestConfiguration { 'CSOT spec tests legacy timeouts behave correctly for retryable operations operation succeeds after one socket timeout - aggregate on collection' ]; - setupLogging(options: MongoClientOptions, s?: string) { - s ??= new ObjectId().toString(); + setupLogging(options: MongoClientOptions, id?: string) { + id ??= new ObjectId().toString(); this.logs = []; - const write = log => this.logs.push({ t: log.t, s, ...log }); + const write = log => this.logs.push({ t: log.t, id, ...log }); options.mongodbLogPath = { write }; options.mongodbLogComponentSeverities = { default: 'trace' }; options.mongodbLogMaxDocumentLength = 300; From 29ca86019773e721d37948237c2a7486248c9cda Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Fri, 4 Apr 2025 13:08:14 -0400 Subject: [PATCH 09/13] chore: more tests --- test/tools/runner/config.ts | 28 +++++++++++++++++++++++++++- 1 file changed, 27 insertions(+), 1 deletion(-) diff --git a/test/tools/runner/config.ts b/test/tools/runner/config.ts index df62552aaf2..e85694ea010 100644 --- a/test/tools/runner/config.ts +++ b/test/tools/runner/config.ts @@ -449,7 +449,33 @@ export class TestConfiguration { testsToEnableLogging = [ 'Client Side Encryption (Unified) namedKMS-rewrapManyDataKey rewrap to azure:name1', 'Server Discovery and Monitoring Prose Tests Connection Pool Management ensure monitors properly create and unpause connection pools when they discover servers', - 'CSOT spec tests legacy timeouts behave correctly for retryable operations operation succeeds after one socket timeout - aggregate on collection' + 'CSOT spec tests legacy timeouts behave correctly for retryable operations operation succeeds after one socket timeout - aggregate on collection', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to aws', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to azure', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to gcp', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to kmip', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to local', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to aws', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to azure', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to gcp', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to kmip', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to local', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to aws', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to azure', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to gcp', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to kmip', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to local', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to aws', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to azure', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to gcp', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to kmip', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to local', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to aws', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to azure', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to gcp', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to kmip', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to local', + 'Client Side Encryption Prose Tests 16. Rewrap Case 2: RewrapManyDataKeyOpts.provider is not optional when provider field is missing raises an error' ]; setupLogging(options: MongoClientOptions, id?: string) { From 68707d2f928adb490fa229f00a6793f56c26b932 Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Fri, 4 Apr 2025 13:50:54 -0400 Subject: [PATCH 10/13] chore: move flaky tests list to their own file --- test/tools/runner/config.ts | 33 ++------------------------------- test/tools/runner/flaky.ts | 31 +++++++++++++++++++++++++++++++ 2 files changed, 33 insertions(+), 31 deletions(-) create mode 100644 test/tools/runner/flaky.ts diff --git a/test/tools/runner/config.ts b/test/tools/runner/config.ts index e85694ea010..477e758f620 100644 --- a/test/tools/runner/config.ts +++ b/test/tools/runner/config.ts @@ -21,6 +21,7 @@ import { } from '../../mongodb'; import { getEnvironmentalOptions } from '../utils'; import { type Filter } from './filters/filter'; +import { flakyTests } from './flaky'; interface ProxyParams { proxyHost?: string; @@ -446,37 +447,7 @@ export class TestConfiguration { * Known flaky tests that we want to turn on logging for * so that we can get a better idea of what is failing when it fails */ - testsToEnableLogging = [ - 'Client Side Encryption (Unified) namedKMS-rewrapManyDataKey rewrap to azure:name1', - 'Server Discovery and Monitoring Prose Tests Connection Pool Management ensure monitors properly create and unpause connection pools when they discover servers', - 'CSOT spec tests legacy timeouts behave correctly for retryable operations operation succeeds after one socket timeout - aggregate on collection', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to aws', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to azure', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to gcp', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to kmip', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to local', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to aws', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to azure', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to gcp', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to kmip', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to local', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to aws', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to azure', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to gcp', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to kmip', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to local', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to aws', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to azure', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to gcp', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to kmip', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to local', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to aws', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to azure', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to gcp', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to kmip', - 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to local', - 'Client Side Encryption Prose Tests 16. Rewrap Case 2: RewrapManyDataKeyOpts.provider is not optional when provider field is missing raises an error' - ]; + testsToEnableLogging = flakyTests; setupLogging(options: MongoClientOptions, id?: string) { id ??= new ObjectId().toString(); diff --git a/test/tools/runner/flaky.ts b/test/tools/runner/flaky.ts new file mode 100644 index 00000000000..32f299559ed --- /dev/null +++ b/test/tools/runner/flaky.ts @@ -0,0 +1,31 @@ +export const flakyTests = [ + 'Client Side Encryption (Unified) namedKMS-rewrapManyDataKey rewrap to azure:name1', + 'Server Discovery and Monitoring Prose Tests Connection Pool Management ensure monitors properly create and unpause connection pools when they discover servers', + 'CSOT spec tests legacy timeouts behave correctly for retryable operations operation succeeds after one socket timeout - aggregate on collection', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to aws', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to azure', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to gcp', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to kmip', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from aws to local', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to aws', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to azure', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to gcp', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to kmip', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from azure to local', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to aws', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to azure', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to gcp', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to kmip', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from gcp to local', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to aws', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to azure', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to gcp', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to kmip', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from kmip to local', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to aws', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to azure', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to gcp', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to kmip', + 'Client Side Encryption Prose Tests 16. Rewrap Case 1: Rewrap with separate ClientEncryption should rewrap data key from local to local', + 'Client Side Encryption Prose Tests 16. Rewrap Case 2: RewrapManyDataKeyOpts.provider is not optional when provider field is missing raises an error' +]; From 4bd24ecc0f7fcbef0b39f85041e344e54954edfe Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Mon, 7 Apr 2025 14:11:38 -0400 Subject: [PATCH 11/13] chore: logs and check list --- .../client_side_encryption.prose.test.js | 27 ++++++++++++++++++- test/tools/runner/hooks/configuration.ts | 21 ++++++++++++++- 2 files changed, 46 insertions(+), 2 deletions(-) diff --git a/test/integration/client-side-encryption/client_side_encryption.prose.test.js b/test/integration/client-side-encryption/client_side_encryption.prose.test.js index 9009bc94aff..a937c542a0d 100644 --- a/test/integration/client-side-encryption/client_side_encryption.prose.test.js +++ b/test/integration/client-side-encryption/client_side_encryption.prose.test.js @@ -2310,7 +2310,10 @@ describe('Client Side Encryption Prose Tests', metadata, function () { kmip: {}, local: undefined }; - let client1, client2; + /** @type {import('../../mongodb').MongoClient} */ + let client1; + /** @type {import('../../mongodb').MongoClient} */ + let client2; describe('Case 1: Rewrap with separate ClientEncryption', function () { /** @@ -2341,12 +2344,16 @@ describe('Client Side Encryption Prose Tests', metadata, function () { `should rewrap data key from ${srcProvider} to ${dstProvider}`, metadata, async function () { + client1.mongoLogger?.trace('client', 'dropping datakeys collection'); + // Step 1. Drop the collection ``keyvault.datakeys`` await client1 .db('keyvault') .dropCollection('datakeys') .catch(() => null); + client1.mongoLogger?.trace('client', 'dropped datakeys collection'); + // Step 2. Create a ``ClientEncryption`` object named ``clientEncryption1`` const clientEncryption1 = new ClientEncryption(client1, { keyVaultNamespace: 'keyvault.datakeys', @@ -2361,17 +2368,24 @@ describe('Client Side Encryption Prose Tests', metadata, function () { bson: BSON }); + client1.mongoLogger?.trace('client', 'clientEncryption1.createDataKey started'); + // Step 3. Call ``clientEncryption1.createDataKey`` with ``srcProvider`` const keyId = await clientEncryption1.createDataKey(srcProvider, { masterKey: masterKeys[srcProvider] }); + client1.mongoLogger?.trace('client', 'clientEncryption1.createDataKey finished'); + client1.mongoLogger?.trace('client', 'clientEncryption1.encrypt started'); + // Step 4. Call ``clientEncryption1.encrypt`` with the value "test" const cipherText = await clientEncryption1.encrypt('test', { keyId, algorithm: 'AEAD_AES_256_CBC_HMAC_SHA_512-Deterministic' }); + client1.mongoLogger?.trace('client', 'clientEncryption1.encrypt finished'); + // Step 5. Create a ``ClientEncryption`` object named ``clientEncryption2`` const clientEncryption2 = new ClientEncryption(client2, { keyVaultNamespace: 'keyvault.datakeys', @@ -2386,6 +2400,8 @@ describe('Client Side Encryption Prose Tests', metadata, function () { bson: BSON }); + client2.mongoLogger?.trace('client', 'clientEncryption2.rewrapManyDataKey started'); + // Step 6. Call ``clientEncryption2.rewrapManyDataKey`` with an empty ``filter`` const rewrapManyDataKeyResult = await clientEncryption2.rewrapManyDataKey( {}, @@ -2395,16 +2411,25 @@ describe('Client Side Encryption Prose Tests', metadata, function () { } ); + client2.mongoLogger?.trace('client', 'clientEncryption2.rewrapManyDataKey finished'); + expect(rewrapManyDataKeyResult).to.have.property('bulkWriteResult'); expect(rewrapManyDataKeyResult.bulkWriteResult).to.have.property('modifiedCount', 1); + client1.mongoLogger?.trace('client', 'clientEncryption1.decrypt started'); + // 7. Call ``clientEncryption1.decrypt`` with the ``ciphertext``. Assert the return value is "test". const decryptResult1 = await clientEncryption1.decrypt(cipherText); expect(decryptResult1).to.equal('test'); + client1.mongoLogger?.trace('client', 'clientEncryption1.decrypt finished'); + client2.mongoLogger?.trace('client', 'clientEncryption2.decrypt started'); + // 8. Call ``clientEncryption2.decrypt`` with the ``ciphertext``. Assert the return value is "test". const decryptResult2 = await clientEncryption2.decrypt(cipherText); expect(decryptResult2).to.equal('test'); + + client2.mongoLogger?.trace('client', 'clientEncryption2.decrypt finished'); } ); } diff --git a/test/tools/runner/hooks/configuration.ts b/test/tools/runner/hooks/configuration.ts index a2397eac139..92361eb6f9c 100644 --- a/test/tools/runner/hooks/configuration.ts +++ b/test/tools/runner/hooks/configuration.ts @@ -23,6 +23,7 @@ import { OSFilter } from '../filters/os_filter'; import { ServerlessFilter } from '../filters/serverless_filter'; import { type Filter } from '../filters/filter'; import { type Context } from 'mocha'; +import { flakyTests } from '../flaky'; // Default our tests to have auth enabled // A better solution will be tackled in NODE-3714 @@ -222,8 +223,26 @@ async function afterEachLogging(this: Context) { this.configuration.afterEachLogging(this); } +function checkFlakyTestList(this: Context) { + const allTests: string[] = []; + + const stack = [this.test.parent]; + while (stack.length) { + const suite = stack.pop(); + allTests.push(...suite.tests.map(test => test.fullTitle())); + stack.push(...suite.suites); + } + allTests.reverse(); // Doesn't matter but when debugging easier to see this in the expected order. + + const flakyTestDoesNotExist = flakyTests.find(testName => !allTests.includes(testName)); + if (flakyTestDoesNotExist != null) { + console.error('Flaky test:', flakyTestDoesNotExist, 'is not run at all'); + process.exitCode = 1; + } +} + export const mochaHooks = { - beforeAll: [beforeAllPluginImports, testConfigBeforeHook], + beforeAll: [beforeAllPluginImports, testConfigBeforeHook, checkFlakyTestList], beforeEach: [testSkipBeforeEachHook, beforeEachLogging], afterEach: [afterEachLogging], afterAll: [cleanUpMocksAfterHook] From 38630e5429fe4522f11fdcc308b784d06247271d Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Mon, 7 Apr 2025 15:52:00 -0400 Subject: [PATCH 12/13] chore: fix fail --- test/tools/runner/hooks/configuration.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/test/tools/runner/hooks/configuration.ts b/test/tools/runner/hooks/configuration.ts index 92361eb6f9c..d434f556c69 100644 --- a/test/tools/runner/hooks/configuration.ts +++ b/test/tools/runner/hooks/configuration.ts @@ -236,8 +236,8 @@ function checkFlakyTestList(this: Context) { const flakyTestDoesNotExist = flakyTests.find(testName => !allTests.includes(testName)); if (flakyTestDoesNotExist != null) { - console.error('Flaky test:', flakyTestDoesNotExist, 'is not run at all'); - process.exitCode = 1; + console.error('Flaky test:', JSON.stringify(flakyTestDoesNotExist), 'is not run at all'); + process.exit(1); } } From 0b37a1a76d0682f6249409dd2765691316758e95 Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Mon, 7 Apr 2025 17:03:42 -0400 Subject: [PATCH 13/13] chore: print-only --- test/tools/runner/hooks/configuration.ts | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/test/tools/runner/hooks/configuration.ts b/test/tools/runner/hooks/configuration.ts index d434f556c69..a5aa8c7f5dc 100644 --- a/test/tools/runner/hooks/configuration.ts +++ b/test/tools/runner/hooks/configuration.ts @@ -236,8 +236,13 @@ function checkFlakyTestList(this: Context) { const flakyTestDoesNotExist = flakyTests.find(testName => !allTests.includes(testName)); if (flakyTestDoesNotExist != null) { - console.error('Flaky test:', JSON.stringify(flakyTestDoesNotExist), 'is not run at all'); - process.exit(1); + console.error( + '\n' + '='.repeat(100) + '\n', + 'Flaky test:', + JSON.stringify(flakyTestDoesNotExist), + 'is not run at all', + '\n' + '='.repeat(100) + '\n' + ); } }