ci(NODE-6860): add logging for known flaky tests

Author: nbbeeken

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;
     }
   );

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';
+    });
   });
 });

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<string, any>, 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 = [];
+  }
 }
 
 /**

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]
 };

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<string, any>) => Record<string, any>;
+    }
+  ) {
+    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<E = Entity> extends Map<string, E> {
         } 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();

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 () {