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

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

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,19 +1,27 @@
+import * as util from 'node:util';
+import * as types from 'node:util/types';
+
 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';
 
 import {
   type AuthMechanism,
+  Double,
   HostAddress,
+  Long,
   MongoClient,
   type MongoClientOptions,
+  ObjectId,
   type ServerApi,
   TopologyType,
   type WriteConcernSettings
 } from '../../mongodb';
 import { getEnvironmentalOptions } from '../utils';
 import { type Filter } from './filters/filter';
+import { flakyTests } from './flaky';
 
 interface ProxyParams {
   proxyHost?: string;
@@ -205,6 +213,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 +440,59 @@ 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 = flakyTests;
+
+  setupLogging(options: MongoClientOptions, id?: string) {
+    id ??= new ObjectId().toString();
+    this.logs = [];
+    const write = log => this.logs.push({ t: log.t, id, ...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) {
+        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 { 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' };
+              return value;
+            },
+            0
+          )
+        );
+      }
+    }
+    this.loggingEnabled = false;
+    this.logs = [];
+  }
 }
 
 /**

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'
+];

test/tools/runner/hooks/configuration.ts

@@ -22,6 +22,8 @@ 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';
+import { flakyTests } from '../flaky';
 
 // Default our tests to have auth enabled
 // A better solution will be tackled in NODE-3714
@@ -211,8 +213,42 @@ 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);
+}
+
+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(
+      '\n' + '='.repeat(100) + '\n',
+      'Flaky test:',
+      JSON.stringify(flakyTestDoesNotExist),
+      'is not run at all',
+      '\n' + '='.repeat(100) + '\n'
+    );
+  }
+}
+
 export const mochaHooks = {
-  beforeAll: [beforeAllPluginImports, testConfigBeforeHook],
-  beforeEach: [testSkipBeforeEachHook],
+  beforeAll: [beforeAllPluginImports, testConfigBeforeHook, checkFlakyTestList],
+  beforeEach: [testSkipBeforeEachHook, beforeEachLogging],
+  afterEach: [afterEachLogging],
   afterAll: [cleanUpMocksAfterHook]
 };