Skip to content

Commit a63fbc2

Browse files
aditi-khare-mongoDBalenakhineikadurran
authored
perf(NODE-5854): Conditional logger instantiation and precompute willLog perf fix (#3984)
Co-authored-by: Alena Khineika <[email protected]> Co-authored-by: Durran Jordan <[email protected]>
1 parent ca3780a commit a63fbc2

File tree

9 files changed

+133
-59
lines changed

9 files changed

+133
-59
lines changed

Diff for: src/cmap/connection.ts

+1-1
Original file line numberDiff line numberDiff line change
@@ -280,7 +280,7 @@ export class Connection extends TypedEventEmitter<ConnectionEvents> {
280280
(this.monitorCommands ||
281281
(this.established &&
282282
!this.authContext?.reauthenticating &&
283-
this.mongoLogger?.willLog(SeverityLevel.DEBUG, MongoLoggableComponent.COMMAND))) ??
283+
this.mongoLogger?.willLog(MongoLoggableComponent.COMMAND, SeverityLevel.DEBUG))) ??
284284
false
285285
);
286286
}

Diff for: src/cmap/connection_pool.ts

+1-1
Original file line numberDiff line numberDiff line change
@@ -251,7 +251,7 @@ export class ConnectionPool extends TypedEventEmitter<ConnectionPoolEvents> {
251251
this[kMetrics] = new ConnectionPoolMetrics();
252252
this[kProcessingWaitQueue] = false;
253253

254-
this.mongoLogger = this[kServer].topology.client.mongoLogger;
254+
this.mongoLogger = this[kServer].topology.client?.mongoLogger;
255255
this.component = 'connection';
256256

257257
process.nextTick(() => {

Diff for: src/mongo_client.ts

+12-5
Original file line numberDiff line numberDiff line change
@@ -25,7 +25,8 @@ import {
2525
type LogComponentSeveritiesClientOptions,
2626
type MongoDBLogWritable,
2727
MongoLogger,
28-
type MongoLoggerOptions
28+
type MongoLoggerOptions,
29+
SeverityLevel
2930
} from './mongo_logger';
3031
import { TypedEventEmitter } from './mongo_types';
3132
import { executeOperation } from './operations/execute_operation';
@@ -345,7 +346,7 @@ export class MongoClient extends TypedEventEmitter<MongoClientEvents> {
345346
/** @internal */
346347
topology?: Topology;
347348
/** @internal */
348-
override readonly mongoLogger: MongoLogger;
349+
override readonly mongoLogger: MongoLogger | undefined;
349350
/** @internal */
350351
private connectionLock?: Promise<this>;
351352

@@ -359,7 +360,13 @@ export class MongoClient extends TypedEventEmitter<MongoClientEvents> {
359360
super();
360361

361362
this[kOptions] = parseOptions(url, this, options);
362-
this.mongoLogger = new MongoLogger(this[kOptions].mongoLoggerOptions);
363+
364+
const shouldSetLogger = Object.values(
365+
this[kOptions].mongoLoggerOptions.componentSeverities
366+
).some(value => value !== SeverityLevel.OFF);
367+
this.mongoLogger = shouldSetLogger
368+
? new MongoLogger(this[kOptions].mongoLoggerOptions)
369+
: undefined;
363370

364371
// eslint-disable-next-line @typescript-eslint/no-this-alias
365372
const client = this;
@@ -405,9 +412,9 @@ export class MongoClient extends TypedEventEmitter<MongoClientEvents> {
405412
const srvHostIsCosmosDB = isHostMatch(COSMOS_DB_CHECK, this[kOptions].srvHost);
406413

407414
if (documentDBHostnames.length !== 0 || srvHostIsDocumentDB) {
408-
this.mongoLogger.info('client', DOCUMENT_DB_MSG);
415+
this.mongoLogger?.info('client', DOCUMENT_DB_MSG);
409416
} else if (cosmosDBHostnames.length !== 0 || srvHostIsCosmosDB) {
410-
this.mongoLogger.info('client', COSMOS_DB_MSG);
417+
this.mongoLogger?.info('client', COSMOS_DB_MSG);
411418
}
412419
}
413420

Diff for: src/mongo_logger.ts

+23-5
Original file line numberDiff line numberDiff line change
@@ -728,6 +728,7 @@ export class MongoLogger {
728728
logDestination: MongoDBLogWritable;
729729
logDestinationIsStdErr: boolean;
730730
pendingLog: PromiseLike<unknown> | unknown = null;
731+
private severities: Record<MongoLoggableComponent, Record<SeverityLevel, boolean>>;
731732

732733
/**
733734
* This method should be used when logging errors that do not have a public driver API for
@@ -760,15 +761,27 @@ export class MongoLogger {
760761
this.maxDocumentLength = options.maxDocumentLength;
761762
this.logDestination = options.logDestination;
762763
this.logDestinationIsStdErr = options.logDestinationIsStdErr;
764+
this.severities = this.createLoggingSeverities();
763765
}
764766

765-
willLog(severity: SeverityLevel, component: MongoLoggableComponent): boolean {
766-
return compareSeverity(severity, this.componentSeverities[component]) <= 0;
767+
createLoggingSeverities(): Record<MongoLoggableComponent, Record<SeverityLevel, boolean>> {
768+
const severities = Object();
769+
for (const component of Object.values(MongoLoggableComponent)) {
770+
severities[component] = {};
771+
for (const severityLevel of Object.values(SeverityLevel)) {
772+
severities[component][severityLevel] =
773+
compareSeverity(severityLevel, this.componentSeverities[component]) <= 0;
774+
}
775+
}
776+
return severities;
767777
}
768778

769779
turnOffSeverities() {
770-
for (const key of Object.values(MongoLoggableComponent)) {
771-
this.componentSeverities[key as MongoLoggableComponent] = SeverityLevel.OFF;
780+
for (const component of Object.values(MongoLoggableComponent)) {
781+
this.componentSeverities[component] = SeverityLevel.OFF;
782+
for (const severityLevel of Object.values(SeverityLevel)) {
783+
this.severities[component][severityLevel] = false;
784+
}
772785
}
773786
}
774787

@@ -797,12 +810,17 @@ export class MongoLogger {
797810
this.pendingLog = null;
798811
}
799812

813+
willLog(component: MongoLoggableComponent, severity: SeverityLevel): boolean {
814+
if (severity === SeverityLevel.OFF) return false;
815+
return this.severities[component][severity];
816+
}
817+
800818
private log(
801819
severity: SeverityLevel,
802820
component: MongoLoggableComponent,
803821
message: Loggable | string
804822
): void {
805-
if (!this.willLog(severity, component)) return;
823+
if (!this.willLog(component, severity)) return;
806824

807825
let logMessage: Log = { t: new Date(), c: component, s: severity };
808826
if (typeof message === 'string') {

Diff for: src/sdam/monitor.ts

+1-1
Original file line numberDiff line numberDiff line change
@@ -120,7 +120,7 @@ export class Monitor extends TypedEventEmitter<MonitorEvents> {
120120
serverMonitoringMode: options.serverMonitoringMode
121121
});
122122
this.isRunningInFaasEnv = getFAASEnv() != null;
123-
this.mongoLogger = this[kServer].topology.client.mongoLogger;
123+
this.mongoLogger = this[kServer].topology.client?.mongoLogger;
124124

125125
const cancellationToken = this[kCancellationToken];
126126
// TODO: refactor this to pull it directly from the pool, requires new ConnectionPool integration

Diff for: src/sdam/topology.ts

+9-9
Original file line numberDiff line numberDiff line change
@@ -102,7 +102,7 @@ export type ServerSelectionCallback = Callback<Server>;
102102
export interface ServerSelectionRequest {
103103
serverSelector: ServerSelector;
104104
topologyDescription: TopologyDescription;
105-
mongoLogger: MongoLogger;
105+
mongoLogger: MongoLogger | undefined;
106106
transaction?: Transaction;
107107
startTime: number;
108108
callback: ServerSelectionCallback;
@@ -568,7 +568,7 @@ export class Topology extends TypedEventEmitter<TopologyEvents> {
568568
}
569569

570570
options = { serverSelectionTimeoutMS: this.s.serverSelectionTimeoutMS, ...options };
571-
this.client.mongoLogger.debug(
571+
this.client.mongoLogger?.debug(
572572
MongoLoggableComponent.SERVER_SELECTION,
573573
new ServerSelectionStartedEvent(selector, this.description, options.operationName)
574574
);
@@ -578,7 +578,7 @@ export class Topology extends TypedEventEmitter<TopologyEvents> {
578578
const transaction = session && session.transaction;
579579

580580
if (isSharded && transaction && transaction.server) {
581-
this.client.mongoLogger.debug(
581+
this.client.mongoLogger?.debug(
582582
MongoLoggableComponent.SERVER_SELECTION,
583583
new ServerSelectionSucceededEvent(
584584
selector,
@@ -611,7 +611,7 @@ export class Topology extends TypedEventEmitter<TopologyEvents> {
611611
`Server selection timed out after ${options.serverSelectionTimeoutMS} ms`,
612612
this.description
613613
);
614-
this.client.mongoLogger.debug(
614+
this.client.mongoLogger?.debug(
615615
MongoLoggableComponent.SERVER_SELECTION,
616616
new ServerSelectionFailedEvent(
617617
selector,
@@ -896,7 +896,7 @@ function drainWaitQueue(queue: List<ServerSelectionRequest>, err?: MongoDriverEr
896896

897897
if (!waitQueueMember[kCancelled]) {
898898
if (err) {
899-
waitQueueMember.mongoLogger.debug(
899+
waitQueueMember.mongoLogger?.debug(
900900
MongoLoggableComponent.SERVER_SELECTION,
901901
new ServerSelectionFailedEvent(
902902
waitQueueMember.serverSelector,
@@ -943,7 +943,7 @@ function processWaitQueue(topology: Topology) {
943943
: serverDescriptions;
944944
} catch (e) {
945945
waitQueueMember.timeoutController.clear();
946-
topology.client.mongoLogger.debug(
946+
topology.client.mongoLogger?.debug(
947947
MongoLoggableComponent.SERVER_SELECTION,
948948
new ServerSelectionFailedEvent(
949949
waitQueueMember.serverSelector,
@@ -959,7 +959,7 @@ function processWaitQueue(topology: Topology) {
959959
let selectedServer: Server | undefined;
960960
if (selectedDescriptions.length === 0) {
961961
if (!waitQueueMember.waitingLogged) {
962-
topology.client.mongoLogger.info(
962+
topology.client.mongoLogger?.info(
963963
MongoLoggableComponent.SERVER_SELECTION,
964964
new WaitingForSuitableServerEvent(
965965
waitQueueMember.serverSelector,
@@ -992,7 +992,7 @@ function processWaitQueue(topology: Topology) {
992992
'server selection returned a server description but the server was not found in the topology',
993993
topology.description
994994
);
995-
topology.client.mongoLogger.debug(
995+
topology.client.mongoLogger?.debug(
996996
MongoLoggableComponent.SERVER_SELECTION,
997997
new ServerSelectionFailedEvent(
998998
waitQueueMember.serverSelector,
@@ -1011,7 +1011,7 @@ function processWaitQueue(topology: Topology) {
10111011

10121012
waitQueueMember.timeoutController.clear();
10131013

1014-
topology.client.mongoLogger.debug(
1014+
topology.client.mongoLogger?.debug(
10151015
MongoLoggableComponent.SERVER_SELECTION,
10161016
new ServerSelectionSucceededEvent(
10171017
waitQueueMember.serverSelector,

Diff for: test/integration/node-specific/feature_flags.test.ts

+11-32
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,6 @@
11
import { expect } from 'chai';
22

3-
import { MongoClient, type MongoLoggableComponent, SeverityLevel } from '../../mongodb';
3+
import { MongoClient, SeverityLevel } from '../../mongodb';
44

55
describe('Feature Flags', () => {
66
describe('@@mdb.skipPingOnConnect', () => {
@@ -45,16 +45,10 @@ describe('Feature Flags', () => {
4545
}
4646
});
4747

48+
// TODO(NODE-5672): Release Standardized Logger
4849
describe('@@mdb.enableMongoLogger', () => {
4950
let cachedEnv;
5051
const loggerFeatureFlag = Symbol.for('@@mdb.enableMongoLogger');
51-
const components: Array<MongoLoggableComponent | 'default'> = [
52-
'default',
53-
'topology',
54-
'serverSelection',
55-
'connection',
56-
'command'
57-
];
5852

5953
before(() => {
6054
cachedEnv = process.env;
@@ -74,7 +68,7 @@ describe('Feature Flags', () => {
7468
const client = new MongoClient('mongodb://localhost:27017', {
7569
[loggerFeatureFlag]: true
7670
});
77-
expect(client.mongoLogger.componentSeverities).to.have.property(
71+
expect(client.mongoLogger?.componentSeverities).to.have.property(
7872
'command',
7973
SeverityLevel.EMERGENCY
8074
);
@@ -86,16 +80,11 @@ describe('Feature Flags', () => {
8680
process.env = {};
8781
});
8882

89-
it('does not enable logging for any component', () => {
83+
it('does not create logger', () => {
9084
const client = new MongoClient('mongodb://localhost:27017', {
9185
[loggerFeatureFlag]: true
9286
});
93-
for (const component of components) {
94-
expect(client.mongoLogger.componentSeverities).to.have.property(
95-
component,
96-
SeverityLevel.OFF
97-
);
98-
}
87+
expect(client.mongoLogger).to.not.exist;
9988
});
10089
});
10190
});
@@ -107,16 +96,11 @@ describe('Feature Flags', () => {
10796
process.env['MONGODB_LOG_COMMAND'] = SeverityLevel.EMERGENCY;
10897
});
10998

110-
it('does not enable logging', () => {
99+
it('does not instantiate logger', () => {
111100
const client = new MongoClient('mongodb://localhost:27017', {
112101
[loggerFeatureFlag]: featureFlagValue
113102
});
114-
for (const component of components) {
115-
expect(client.mongoLogger.componentSeverities).to.have.property(
116-
component,
117-
SeverityLevel.OFF
118-
);
119-
}
103+
expect(client.mongoLogger).to.not.exist;
120104
});
121105
});
122106

@@ -125,16 +109,11 @@ describe('Feature Flags', () => {
125109
process.env = {};
126110
});
127111

128-
it('does not enable logging', () => {
112+
it('does not instantiate logger', () => {
129113
const client = new MongoClient('mongodb://localhost:27017', {
130114
[loggerFeatureFlag]: featureFlagValue
131115
});
132-
for (const component of components) {
133-
expect(client.mongoLogger.componentSeverities).to.have.property(
134-
component,
135-
SeverityLevel.OFF
136-
);
137-
}
116+
expect(client.mongoLogger).to.not.exist;
138117
});
139118
});
140119
});
@@ -162,7 +141,7 @@ describe('Feature Flags', () => {
162141
[Symbol.for('@@mdb.internalLoggerConfig')]: undefined
163142
});
164143

165-
expect(client.mongoLogger.componentSeverities).to.have.property(
144+
expect(client.mongoLogger?.componentSeverities).to.have.property(
166145
'command',
167146
SeverityLevel.EMERGENCY
168147
);
@@ -178,7 +157,7 @@ describe('Feature Flags', () => {
178157
}
179158
});
180159

181-
expect(client.mongoLogger.componentSeverities).to.have.property(
160+
expect(client.mongoLogger?.componentSeverities).to.have.property(
182161
'command',
183162
SeverityLevel.ALERT
184163
);

Diff for: test/unit/mongo_client.test.js

+8-5
Original file line numberDiff line numberDiff line change
@@ -800,7 +800,10 @@ describe('MongoOptions', function () {
800800
context('loggingOptions', function () {
801801
const expectedLoggingObject = {
802802
maxDocumentLength: 20,
803-
logDestination: new Writable()
803+
logDestination: new Writable(),
804+
componentSeverities: Object.fromEntries(
805+
Object.values(MongoLoggableComponent).map(([value]) => [value, SeverityLevel.OFF])
806+
)
804807
};
805808

806809
before(() => {
@@ -1075,9 +1078,9 @@ describe('MongoOptions', function () {
10751078
).to.not.throw(MongoAPIError);
10761079
const client = new MongoClient('mongodb://a/', {
10771080
[loggerFeatureFlag]: true,
1078-
mongodbLogComponentSeverities: {}
1081+
mongodbLogComponentSeverities: { client: 'error' } // dummy so logger doesn't turn on
10791082
});
1080-
expect(client.mongoLogger.componentSeverities.default).to.equal('off');
1083+
expect(client.mongoLogger?.componentSeverities.command).to.equal('off');
10811084
});
10821085
});
10831086
context('when valid client option is provided', function () {
@@ -1091,9 +1094,9 @@ describe('MongoOptions', function () {
10911094
).to.not.throw(MongoAPIError);
10921095
const client = new MongoClient('mongodb://a/', {
10931096
[loggerFeatureFlag]: true,
1094-
mongodbLogComponentSeverities: { default: 'emergency' }
1097+
mongodbLogComponentSeverities: { command: 'emergency' }
10951098
});
1096-
expect(client.mongoLogger.componentSeverities.default).to.equal('emergency');
1099+
expect(client.mongoLogger?.componentSeverities.command).to.equal('emergency');
10971100
});
10981101
});
10991102
});

0 commit comments

Comments
 (0)