Skip to content

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

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 13 commits into from
Apr 8, 2025
Original file line number Diff line number Diff line change
Expand Up @@ -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;
}
);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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';
});
});
});
49 changes: 49 additions & 0 deletions test/tools/runner/config.ts
Original file line number Diff line number Diff line change
@@ -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';
Expand Down Expand Up @@ -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')) {
Expand Down Expand Up @@ -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 = [];
}
}

/**
Expand Down
14 changes: 13 additions & 1 deletion test/tools/runner/hooks/configuration.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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]
};
58 changes: 35 additions & 23 deletions test/tools/unified-spec-runner/entities.ts
Original file line number Diff line number Diff line change
Expand Up @@ -28,7 +28,9 @@ import {
type HostAddress,
type Log,
MongoClient,
type MongoClientOptions,
type MongoCredentials,
type MongoDBLogWritable,
ReadConcern,
ReadPreference,
SENSITIVE_COMMANDS,
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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 = [
Expand Down Expand Up @@ -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 ?? [];
}
}

Expand Down Expand Up @@ -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();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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 () {
Expand Down Expand Up @@ -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 () {
Expand Down