Skip to content

Commit 0e8279f

Browse files
aditi-khare-mongoDBaditi-khare-mongoDB
committed
feat(NODE-4719): add SDAM Logging Spec (#3940)
1 parent a407143 commit 0e8279f

File tree

64 files changed

+3908
-133
lines changed

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

64 files changed

+3908
-133
lines changed

‎src/constants.ts

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,11 +17,17 @@ export const MESSAGE = 'message' as const;
1717
export const PINNED = 'pinned' as const;
1818
export const UNPINNED = 'unpinned' as const;
1919
export const DESCRIPTION_RECEIVED = 'descriptionReceived';
20+
/** @internal */
2021
export const SERVER_OPENING = 'serverOpening' as const;
22+
/** @internal */
2123
export const SERVER_CLOSED = 'serverClosed' as const;
24+
/** @internal */
2225
export const SERVER_DESCRIPTION_CHANGED = 'serverDescriptionChanged' as const;
26+
/** @internal */
2327
export const TOPOLOGY_OPENING = 'topologyOpening' as const;
28+
/** @internal */
2429
export const TOPOLOGY_CLOSED = 'topologyClosed' as const;
30+
/** @internal */
2531
export const TOPOLOGY_DESCRIPTION_CHANGED = 'topologyDescriptionChanged' as const;
2632
/** @internal */
2733
export const SERVER_SELECTION_STARTED = 'serverSelectionStarted' as const;
@@ -57,8 +63,11 @@ export const CLUSTER_TIME_RECEIVED = 'clusterTimeReceived' as const;
5763
export const COMMAND_STARTED = 'commandStarted' as const;
5864
export const COMMAND_SUCCEEDED = 'commandSucceeded' as const;
5965
export const COMMAND_FAILED = 'commandFailed' as const;
66+
/** @internal */
6067
export const SERVER_HEARTBEAT_STARTED = 'serverHeartbeatStarted' as const;
68+
/** @internal */
6169
export const SERVER_HEARTBEAT_SUCCEEDED = 'serverHeartbeatSucceeded' as const;
70+
/** @internal */
6271
export const SERVER_HEARTBEAT_FAILED = 'serverHeartbeatFailed' as const;
6372
export const RESPONSE = 'response' as const;
6473
export const MORE = 'more' as const;

‎src/index.ts

Lines changed: 13 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -316,7 +316,16 @@ export type {
316316
SERVER_SELECTION_FAILED,
317317
SERVER_SELECTION_STARTED,
318318
SERVER_SELECTION_SUCCEEDED,
319-
WAITING_FOR_SUITABLE_SERVER
319+
WAITING_FOR_SUITABLE_SERVER,
320+
SERVER_CLOSED,
321+
SERVER_DESCRIPTION_CHANGED,
322+
SERVER_HEARTBEAT_FAILED,
323+
SERVER_HEARTBEAT_STARTED,
324+
SERVER_HEARTBEAT_SUCCEEDED,
325+
SERVER_OPENING,
326+
TOPOLOGY_CLOSED,
327+
TOPOLOGY_DESCRIPTION_CHANGED,
328+
TOPOLOGY_OPENING
320329
} from './constants';
321330
export type {
322331
AbstractCursorEvents,
@@ -368,6 +377,9 @@ export type {
368377
LogConvertible,
369378
Loggable,
370379
LoggableEvent,
380+
LoggableServerHeartbeatFailedEvent,
381+
LoggableServerHeartbeatStartedEvent,
382+
LoggableServerHeartbeatSucceededEvent,
371383
MongoDBLogWritable,
372384
MongoLoggableComponent,
373385
MongoLogger,

‎src/mongo_logger.ts

Lines changed: 151 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
import { EJSON } from 'bson';
1+
import { type Document, EJSON, type EJSONOptions } from 'bson';
22
import type { Writable } from 'stream';
33
import { inspect } from 'util';
44

@@ -38,7 +38,15 @@ import {
3838
SERVER_SELECTION_FAILED,
3939
SERVER_SELECTION_STARTED,
4040
SERVER_SELECTION_SUCCEEDED,
41-
WAITING_FOR_SUITABLE_SERVER
41+
WAITING_FOR_SUITABLE_SERVER,
42+
SERVER_CLOSED,
43+
SERVER_HEARTBEAT_FAILED,
44+
SERVER_HEARTBEAT_STARTED,
45+
SERVER_HEARTBEAT_SUCCEEDED,
46+
SERVER_OPENING,
47+
TOPOLOGY_CLOSED,
48+
TOPOLOGY_DESCRIPTION_CHANGED,
49+
TOPOLOGY_OPENING
4250
} from './constants';
4351
import type {
4452
ServerSelectionEvent,
@@ -47,6 +55,13 @@ import type {
4755
ServerSelectionSucceededEvent,
4856
WaitingForSuitableServerEvent
4957
} from './sdam/server_selection_events';
58+
import type {
59+
ServerClosedEvent,
60+
ServerOpeningEvent,
61+
TopologyClosedEvent,
62+
TopologyDescriptionChangedEvent,
63+
TopologyOpeningEvent
64+
} from './sdam/events';
5065
import { HostAddress, parseUnsignedInteger } from './utils';
5166

5267
/** @internal */
@@ -280,6 +295,54 @@ function compareSeverity(s0: SeverityLevel, s1: SeverityLevel): 1 | 0 | -1 {
280295
return s0Num < s1Num ? -1 : s0Num > s1Num ? 1 : 0;
281296
}
282297

298+
/**
299+
* @internal
300+
* Must be separate from Events API due to differences in spec requirements for logging server heartbeat beginning
301+
*/
302+
export type LoggableServerHeartbeatStartedEvent = {
303+
topologyId: number;
304+
awaited: boolean;
305+
connectionId: string;
306+
name: typeof SERVER_HEARTBEAT_STARTED;
307+
};
308+
309+
/**
310+
* @internal
311+
* Must be separate from Events API due to differences in spec requirements for logging server heartbeat success
312+
*/
313+
export type LoggableServerHeartbeatSucceededEvent = {
314+
topologyId: number;
315+
awaited: boolean;
316+
connectionId: string;
317+
reply: Document;
318+
serverConnectionId: number | '<monitor>';
319+
duration: number;
320+
name: typeof SERVER_HEARTBEAT_SUCCEEDED;
321+
};
322+
323+
/**
324+
* @internal
325+
* Must be separate from Events API due to differences in spec requirements for logging server heartbeat failure
326+
*/
327+
export type LoggableServerHeartbeatFailedEvent = {
328+
topologyId: number;
329+
awaited: boolean;
330+
connectionId: string;
331+
failure: Error;
332+
duration: number;
333+
name: typeof SERVER_HEARTBEAT_FAILED;
334+
};
335+
336+
type SDAMLoggableEvent =
337+
| ServerClosedEvent
338+
| LoggableServerHeartbeatFailedEvent
339+
| LoggableServerHeartbeatStartedEvent
340+
| LoggableServerHeartbeatSucceededEvent
341+
| ServerOpeningEvent
342+
| TopologyClosedEvent
343+
| TopologyDescriptionChangedEvent
344+
| TopologyOpeningEvent;
345+
283346
/** @internal */
284347
export type LoggableEvent =
285348
| ServerSelectionStartedEvent
@@ -299,16 +362,28 @@ export type LoggableEvent =
299362
| ConnectionCheckedInEvent
300363
| ConnectionCheckedOutEvent
301364
| ConnectionCheckOutStartedEvent
302-
| ConnectionCheckOutFailedEvent;
365+
| ConnectionCheckOutFailedEvent
366+
| ServerClosedEvent
367+
| LoggableServerHeartbeatFailedEvent
368+
| LoggableServerHeartbeatStartedEvent
369+
| LoggableServerHeartbeatSucceededEvent
370+
| ServerOpeningEvent
371+
| TopologyClosedEvent
372+
| TopologyDescriptionChangedEvent
373+
| TopologyOpeningEvent;
303374

304375
/** @internal */
305376
export interface LogConvertible extends Record<string, any> {
306377
toLog(): Record<string, any>;
307378
}
308379

309380
/** @internal */
310-
export function stringifyWithMaxLen(value: any, maxDocumentLength: number): string {
311-
const ejson = EJSON.stringify(value) ?? 'custom function';
381+
export function stringifyWithMaxLen(
382+
value: any,
383+
maxDocumentLength: number,
384+
options: EJSONOptions = {}
385+
): string {
386+
const ejson = EJSON.stringify(value, options);
312387

313388
return maxDocumentLength !== 0 && ejson.length > maxDocumentLength
314389
? `${ejson.slice(0, maxDocumentLength)}...`
@@ -363,6 +438,27 @@ function attachConnectionFields(log: Record<string, any>, event: any) {
363438
return log;
364439
}
365440

441+
function attachSDAMFields(log: Record<string, any>, sdamEvent: SDAMLoggableEvent) {
442+
log.topologyId = sdamEvent.topologyId;
443+
return log;
444+
}
445+
446+
function attachServerHeartbeatFields(
447+
log: Record<string, any>,
448+
serverHeartbeatEvent:
449+
| LoggableServerHeartbeatFailedEvent
450+
| LoggableServerHeartbeatStartedEvent
451+
| LoggableServerHeartbeatSucceededEvent
452+
) {
453+
const { awaited, connectionId } = serverHeartbeatEvent;
454+
log.awaited = awaited;
455+
log.driverConnectionId = serverHeartbeatEvent.connectionId;
456+
const { host, port } = HostAddress.fromString(connectionId).toHostPort();
457+
log.serverHost = host;
458+
log.serverPort = port;
459+
return log;
460+
}
461+
366462
function defaultLogTransform(
367463
logObject: LoggableEvent | Record<string, any>,
368464
maxDocumentLength: number = DEFAULT_MAX_DOCUMENT_LENGTH
@@ -497,14 +593,63 @@ function defaultLogTransform(
497593
case CONNECTION_CHECKED_OUT:
498594
log = attachConnectionFields(log, logObject);
499595
log.message = 'Connection checked out';
500-
501596
log.driverConnectionId = logObject.connectionId;
502597
return log;
503598
case CONNECTION_CHECKED_IN:
504599
log = attachConnectionFields(log, logObject);
505600
log.message = 'Connection checked in';
506601
log.driverConnectionId = logObject.connectionId;
507602
return log;
603+
case SERVER_OPENING:
604+
log = attachSDAMFields(log, logObject);
605+
log = attachConnectionFields(log, logObject);
606+
log.message = 'Starting server monitoring';
607+
return log;
608+
case SERVER_CLOSED:
609+
log = attachSDAMFields(log, logObject);
610+
log = attachConnectionFields(log, logObject);
611+
log.message = 'Stopped server monitoring';
612+
return log;
613+
case SERVER_HEARTBEAT_STARTED:
614+
log = attachSDAMFields(log, logObject);
615+
log = attachServerHeartbeatFields(log, logObject);
616+
log.message = 'Server heartbeat started';
617+
return log;
618+
case SERVER_HEARTBEAT_SUCCEEDED:
619+
log = attachSDAMFields(log, logObject);
620+
log = attachServerHeartbeatFields(log, logObject);
621+
log.message = 'Server heartbeat succeeded';
622+
log.durationMS = logObject.duration;
623+
log.serverConnectionId = logObject.serverConnectionId;
624+
log.reply = stringifyWithMaxLen(logObject.reply, maxDocumentLength, { relaxed: true });
625+
return log;
626+
case SERVER_HEARTBEAT_FAILED:
627+
log = attachSDAMFields(log, logObject);
628+
log = attachServerHeartbeatFields(log, logObject);
629+
log.message = 'Server heartbeat failed';
630+
log.durationMS = logObject.duration;
631+
log.failure = logObject.failure.message;
632+
return log;
633+
case TOPOLOGY_OPENING:
634+
log = attachSDAMFields(log, logObject);
635+
log.message = 'Starting topology monitoring';
636+
return log;
637+
case TOPOLOGY_CLOSED:
638+
log = attachSDAMFields(log, logObject);
639+
log.message = 'Stopped topology monitoring';
640+
return log;
641+
case TOPOLOGY_DESCRIPTION_CHANGED:
642+
log = attachSDAMFields(log, logObject);
643+
log.message = 'Topology description changed';
644+
log.previousDescription = log.reply = stringifyWithMaxLen(
645+
logObject.previousDescription,
646+
maxDocumentLength
647+
);
648+
log.newDescription = log.reply = stringifyWithMaxLen(
649+
logObject.newDescription,
650+
maxDocumentLength
651+
);
652+
return log;
508653
default:
509654
for (const [key, value] of Object.entries(logObject)) {
510655
if (value != null) log[key] = value;

‎src/mongo_types.ts

Lines changed: 28 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,13 @@ import type {
1212
ObjectId,
1313
Timestamp
1414
} from './bson';
15-
import type { MongoLoggableComponent, MongoLogger } from './mongo_logger';
15+
import type {
16+
LoggableServerHeartbeatFailedEvent,
17+
LoggableServerHeartbeatStartedEvent,
18+
LoggableServerHeartbeatSucceededEvent,
19+
MongoLoggableComponent,
20+
MongoLogger
21+
} from './mongo_logger';
1622
import type { Sort } from './sort';
1723

1824
/** @internal */
@@ -405,13 +411,33 @@ export class TypedEventEmitter<Events extends EventsDescription> extends EventEm
405411
/** @internal */
406412
protected component?: MongoLoggableComponent;
407413
/** @internal */
408-
protected emitAndLog<EventKey extends keyof Events>(
414+
emitAndLog<EventKey extends keyof Events>(
409415
event: EventKey | symbol,
410416
...args: Parameters<Events[EventKey]>
411417
): void {
412418
this.emit(event, ...args);
413419
if (this.component) this.mongoLogger?.debug(this.component, args[0]);
414420
}
421+
/** @internal */
422+
emitAndLogHeartbeat<EventKey extends keyof Events>(
423+
event: EventKey | symbol,
424+
topologyId: number,
425+
serverConnectionId?: number | '<monitor>',
426+
...args: Parameters<Events[EventKey]>
427+
): void {
428+
this.emit(event, ...args);
429+
if (this.component) {
430+
const loggableHeartbeatEvent:
431+
| LoggableServerHeartbeatFailedEvent
432+
| LoggableServerHeartbeatSucceededEvent
433+
| LoggableServerHeartbeatStartedEvent = {
434+
topologyId: topologyId,
435+
serverConnectionId: serverConnectionId ?? null,
436+
...args[0]
437+
};
438+
this.mongoLogger?.debug(this.component, loggableHeartbeatEvent);
439+
}
440+
}
415441
}
416442

417443
/** @public */

0 commit comments

Comments
 (0)