diff --git a/src/sdam/topology.ts b/src/sdam/topology.ts index 2526aad535..4bf816f238 100644 --- a/src/sdam/topology.ts +++ b/src/sdam/topology.ts @@ -31,7 +31,7 @@ import { MongoTopologyClosedError } from '../error'; import type { MongoClient, ServerApi } from '../mongo_client'; -import { MongoLoggableComponent, type MongoLogger } from '../mongo_logger'; +import { MongoLoggableComponent, type MongoLogger, SeverityLevel } from '../mongo_logger'; import { TypedEventEmitter } from '../mongo_types'; import { ReadPreference, type ReadPreferenceLike } from '../read_preference'; import type { ClientSession } from '../sessions'; @@ -568,25 +568,36 @@ export class Topology extends TypedEventEmitter { } options = { serverSelectionTimeoutMS: this.s.serverSelectionTimeoutMS, ...options }; - this.client.mongoLogger?.debug( - MongoLoggableComponent.SERVER_SELECTION, - new ServerSelectionStartedEvent(selector, this.description, options.operationName) - ); + if ( + this.client.mongoLogger?.willLog(MongoLoggableComponent.SERVER_SELECTION, SeverityLevel.DEBUG) + ) { + this.client.mongoLogger?.debug( + MongoLoggableComponent.SERVER_SELECTION, + new ServerSelectionStartedEvent(selector, this.description, options.operationName) + ); + } const isSharded = this.description.type === TopologyType.Sharded; const session = options.session; const transaction = session && session.transaction; if (isSharded && transaction && transaction.server) { - this.client.mongoLogger?.debug( - MongoLoggableComponent.SERVER_SELECTION, - new ServerSelectionSucceededEvent( - selector, - this.description, - transaction.server.pool.address, - options.operationName + if ( + this.client.mongoLogger?.willLog( + MongoLoggableComponent.SERVER_SELECTION, + SeverityLevel.DEBUG ) - ); + ) { + this.client.mongoLogger?.debug( + MongoLoggableComponent.SERVER_SELECTION, + new ServerSelectionSucceededEvent( + selector, + this.description, + transaction.server.pool.address, + options.operationName + ) + ); + } callback(undefined, transaction.server); return; } @@ -611,15 +622,22 @@ export class Topology extends TypedEventEmitter { `Server selection timed out after ${options.serverSelectionTimeoutMS} ms`, this.description ); - this.client.mongoLogger?.debug( - MongoLoggableComponent.SERVER_SELECTION, - new ServerSelectionFailedEvent( - selector, - this.description, - timeoutError, - options.operationName + if ( + this.client.mongoLogger?.willLog( + MongoLoggableComponent.SERVER_SELECTION, + SeverityLevel.DEBUG ) - ); + ) { + this.client.mongoLogger?.debug( + MongoLoggableComponent.SERVER_SELECTION, + new ServerSelectionFailedEvent( + selector, + this.description, + timeoutError, + options.operationName + ) + ); + } waitQueueMember.callback(timeoutError); }); @@ -896,15 +914,22 @@ function drainWaitQueue(queue: List, err?: MongoDriverEr if (!waitQueueMember[kCancelled]) { if (err) { - waitQueueMember.mongoLogger?.debug( - MongoLoggableComponent.SERVER_SELECTION, - new ServerSelectionFailedEvent( - waitQueueMember.serverSelector, - waitQueueMember.topologyDescription, - err, - waitQueueMember.operationName + if ( + waitQueueMember.mongoLogger?.willLog( + MongoLoggableComponent.SERVER_SELECTION, + SeverityLevel.DEBUG ) - ); + ) { + waitQueueMember.mongoLogger?.debug( + MongoLoggableComponent.SERVER_SELECTION, + new ServerSelectionFailedEvent( + waitQueueMember.serverSelector, + waitQueueMember.topologyDescription, + err, + waitQueueMember.operationName + ) + ); + } } waitQueueMember.callback(err); } @@ -943,15 +968,22 @@ function processWaitQueue(topology: Topology) { : serverDescriptions; } catch (e) { waitQueueMember.timeoutController.clear(); - topology.client.mongoLogger?.debug( - MongoLoggableComponent.SERVER_SELECTION, - new ServerSelectionFailedEvent( - waitQueueMember.serverSelector, - topology.description, - e, - waitQueueMember.operationName + if ( + topology.client.mongoLogger?.willLog( + MongoLoggableComponent.SERVER_SELECTION, + SeverityLevel.DEBUG ) - ); + ) { + topology.client.mongoLogger?.debug( + MongoLoggableComponent.SERVER_SELECTION, + new ServerSelectionFailedEvent( + waitQueueMember.serverSelector, + topology.description, + e, + waitQueueMember.operationName + ) + ); + } waitQueueMember.callback(e); continue; } @@ -959,17 +991,24 @@ function processWaitQueue(topology: Topology) { let selectedServer: Server | undefined; if (selectedDescriptions.length === 0) { if (!waitQueueMember.waitingLogged) { - topology.client.mongoLogger?.info( - MongoLoggableComponent.SERVER_SELECTION, - new WaitingForSuitableServerEvent( - waitQueueMember.serverSelector, - topology.description, - topology.s.serverSelectionTimeoutMS !== 0 - ? topology.s.serverSelectionTimeoutMS - (now() - waitQueueMember.startTime) - : -1, - waitQueueMember.operationName + if ( + topology.client.mongoLogger?.willLog( + MongoLoggableComponent.SERVER_SELECTION, + SeverityLevel.INFORMATIONAL ) - ); + ) { + topology.client.mongoLogger?.info( + MongoLoggableComponent.SERVER_SELECTION, + new WaitingForSuitableServerEvent( + waitQueueMember.serverSelector, + topology.description, + topology.s.serverSelectionTimeoutMS !== 0 + ? topology.s.serverSelectionTimeoutMS - (now() - waitQueueMember.startTime) + : -1, + waitQueueMember.operationName + ) + ); + } waitQueueMember.waitingLogged = true; } topology[kWaitQueue].push(waitQueueMember); @@ -992,15 +1031,22 @@ function processWaitQueue(topology: Topology) { 'server selection returned a server description but the server was not found in the topology', topology.description ); - topology.client.mongoLogger?.debug( - MongoLoggableComponent.SERVER_SELECTION, - new ServerSelectionFailedEvent( - waitQueueMember.serverSelector, - topology.description, - error, - waitQueueMember.operationName + if ( + topology.client.mongoLogger?.willLog( + MongoLoggableComponent.SERVER_SELECTION, + SeverityLevel.DEBUG ) - ); + ) { + topology.client.mongoLogger?.debug( + MongoLoggableComponent.SERVER_SELECTION, + new ServerSelectionFailedEvent( + waitQueueMember.serverSelector, + topology.description, + error, + waitQueueMember.operationName + ) + ); + } waitQueueMember.callback(error); return; } @@ -1011,15 +1057,22 @@ function processWaitQueue(topology: Topology) { waitQueueMember.timeoutController.clear(); - topology.client.mongoLogger?.debug( - MongoLoggableComponent.SERVER_SELECTION, - new ServerSelectionSucceededEvent( - waitQueueMember.serverSelector, - waitQueueMember.topologyDescription, - selectedServer.pool.address, - waitQueueMember.operationName + if ( + topology.client.mongoLogger?.willLog( + MongoLoggableComponent.SERVER_SELECTION, + SeverityLevel.DEBUG ) - ); + ) { + topology.client.mongoLogger?.debug( + MongoLoggableComponent.SERVER_SELECTION, + new ServerSelectionSucceededEvent( + waitQueueMember.serverSelector, + waitQueueMember.topologyDescription, + selectedServer.pool.address, + waitQueueMember.operationName + ) + ); + } waitQueueMember.callback(undefined, selectedServer); } diff --git a/test/unit/sdam/server_selection.test.ts b/test/unit/sdam/server_selection.test.ts index 925d40eef0..c26f3b9651 100644 --- a/test/unit/sdam/server_selection.test.ts +++ b/test/unit/sdam/server_selection.test.ts @@ -3,17 +3,21 @@ import * as sinon from 'sinon'; import { MIN_SECONDARY_WRITE_WIRE_VERSION, + MongoLogger, ObjectId, ReadPreference, readPreferenceServerSelector, sameServerSelector, secondaryWritableServerSelector, ServerDescription, + ServerSelectionEvent, TopologyDescription, TopologyType } from '../../mongodb'; +import * as mock from '../../tools/mongodb-mock/index'; +import { topologyWithPlaceholderClient } from '../../tools/utils'; -describe('server selection', function () { +describe('server selection', async function () { const primary = new ServerDescription('127.0.0.1:27017', { setName: 'test', isWritablePrimary: true, @@ -605,4 +609,40 @@ describe('server selection', function () { }); }); }); + + describe('server selection logging feature flagging', async function () { + const topologyDescription = sinon.stub(); + + let mockServer; + let topology; + + beforeEach(async () => { + mockServer = await mock.createServer(); + topology = topologyWithPlaceholderClient(mockServer.hostAddress(), {}); + }); + + afterEach(async () => { + await mock.cleanup(); + }); + + context('when willLog returns false', function () { + const original = Object.getPrototypeOf(ServerSelectionEvent); + let serverSelectionEventStub; + beforeEach(async () => { + sinon.stub(MongoLogger.prototype, 'willLog').callsFake((_v, _w) => false); + serverSelectionEventStub = sinon.stub(); + Object.setPrototypeOf(ServerSelectionEvent, serverSelectionEventStub); + }); + + afterEach(async () => { + sinon.restore(); + Object.setPrototypeOf(ServerSelectionEvent, original); + }); + + it('should not create server selection event instances', function () { + topology?.selectServer(topologyDescription, { operationName: 'test' }, v => v); + expect(serverSelectionEventStub.getCall(0)).to.be.null; + }); + }); + }); });