Skip to content

Commit 4a47cd2

Browse files
addaleaxaddaleax
authored
fix(logging): fix log flushing on exit MONGOSH-2883 (#2547)
1 parent eb7bcd6 commit 4a47cd2

File tree

9 files changed

+84
-33
lines changed

9 files changed

+84
-33
lines changed

‎package-lock.json‎

Lines changed: 6 additions & 6 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎packages/cli-repl/package.json‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -86,7 +86,7 @@
8686
"is-recoverable-error": "^1.0.3",
8787
"js-yaml": "^4.1.0",
8888
"mongodb-connection-string-url": "^3.0.2",
89-
"mongodb-log-writer": "^2.3.1",
89+
"mongodb-log-writer": "^2.4.3",
9090
"numeral": "^2.0.6",
9191
"pretty-repl": "^4.0.1",
9292
"semver": "^7.5.4",

‎packages/cli-repl/src/cli-repl.ts‎

Lines changed: 14 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -323,6 +323,18 @@ export class CliRepl implements MongoshIOProvider {
323323
async start(
324324
driverUri: string,
325325
driverOptions: DevtoolsConnectOptions
326+
): Promise<void> {
327+
try {
328+
return await this._start(driverUri, driverOptions);
329+
} catch (err) {
330+
await this.close();
331+
throw err;
332+
}
333+
}
334+
335+
private async _start(
336+
driverUri: string,
337+
driverOptions: DevtoolsConnectOptions
326338
): Promise<void> {
327339
// eslint-disable-next-line @typescript-eslint/no-var-requires
328340
const { version }: { version: string } = require('../package.json');
@@ -659,7 +671,7 @@ export class CliRepl implements MongoshIOProvider {
659671
if (enabled) {
660672
await this.startLogging();
661673
} else {
662-
this.loggingAndTelemetry?.detachLogger();
674+
await this.loggingAndTelemetry?.detachLogger();
663675
}
664676
}
665677

@@ -1172,7 +1184,7 @@ export class CliRepl implements MongoshIOProvider {
11721184
const analytics = this.toggleableAnalytics;
11731185
let flushError: string | null = null;
11741186
let flushDuration: number | null = null;
1175-
this.loggingAndTelemetry?.flush();
1187+
await this.loggingAndTelemetry?.flush();
11761188

11771189
if (analytics) {
11781190
const flushStart = Date.now();

‎packages/e2e-tests/package.json‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -33,7 +33,7 @@
3333
"strip-ansi": "^6.0.0"
3434
},
3535
"devDependencies": {
36-
"mongodb-log-writer": "^2.3.1",
36+
"mongodb-log-writer": "^2.4.3",
3737
"@mongodb-js/eslint-config-mongosh": "^1.0.0",
3838
"@mongodb-js/oidc-mock-provider": "^0.11.3",
3939
"@mongodb-js/prettier-config-devtools": "^1.0.1",

‎packages/e2e-tests/test/e2e.spec.ts‎

Lines changed: 41 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -2142,12 +2142,7 @@ describe('e2e', function () {
21422142
await shell.executeLine("log.info('This is a custom entry')");
21432143
expect(shell.assertNoErrors());
21442144
await eventually(async () => {
2145-
const log = await readLogFile<
2146-
MongoLogEntryFromFile & {
2147-
c: string;
2148-
ctx: string;
2149-
}
2150-
>();
2145+
const log = await readLogFile<MongoLogEntryFromFile>();
21512146
const customLogEntry = log.filter((logEntry) =>
21522147
logEntry.msg.includes('This is a custom entry')
21532148
);
@@ -2182,6 +2177,46 @@ describe('e2e', function () {
21822177
).to.have.lengthOf(1);
21832178
});
21842179
});
2180+
2181+
it('flushes log file (normal exit)', async function () {
2182+
const shell = this.startTestShell({
2183+
args: [
2184+
'--nodb',
2185+
'--eval',
2186+
'for(let i=0; i < 10; i++) log.info("logging", {i}); log.getPath();',
2187+
],
2188+
});
2189+
expect(await shell.waitForAnyExit()).to.equal(0);
2190+
const log = await readReplLogFile(shell.output.trim());
2191+
for (let i = 0; i < 10; i++) {
2192+
expect(
2193+
log.some(
2194+
(entry) => entry.msg === 'logging' && entry.attr?.i === i
2195+
)
2196+
).to.be.true;
2197+
}
2198+
});
2199+
2200+
it('flushes log file (exception thrown)', async function () {
2201+
const shell = this.startTestShell({
2202+
args: [
2203+
'--nodb',
2204+
'--eval',
2205+
'for(let i=0; i < 10; i++) log.info("logging", {i}); print(log.getPath()); throw new Error("uh oh")',
2206+
],
2207+
});
2208+
expect(await shell.waitForAnyExit()).to.equal(1);
2209+
const log = await readReplLogFile(
2210+
shell.output.replace(/Error: uh oh/g, '').trim()
2211+
);
2212+
for (let i = 0; i < 10; i++) {
2213+
expect(
2214+
log.some(
2215+
(entry) => entry.msg === 'logging' && entry.attr?.i === i
2216+
)
2217+
).to.be.true;
2218+
}
2219+
});
21852220
});
21862221

21872222
describe('history file', function () {

‎packages/logging/package.json‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -22,7 +22,7 @@
2222
"@mongosh/errors": "2.4.4",
2323
"@mongosh/history": "2.4.9",
2424
"@mongosh/types": "^3.14.0",
25-
"mongodb-log-writer": "^2.3.1",
25+
"mongodb-log-writer": "^2.4.3",
2626
"mongodb-redact": "^1.1.5",
2727
"native-machine-id": "^0.1.1"
2828
},

‎packages/logging/src/logging-and-telemetry.spec.ts‎

Lines changed: 13 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -61,7 +61,9 @@ describe('MongoshLoggingAndTelemetry', function () {
6161

6262
logger = new MongoLogWriter(logId, `/tmp/${logId}_log`, {
6363
write(chunk: string, cb: () => void) {
64-
logOutput.push(JSON.parse(chunk));
64+
if (chunk.trim()) {
65+
logOutput.push(JSON.parse(chunk));
66+
}
6567
cb();
6668
},
6769
end(cb: () => void) {
@@ -70,8 +72,8 @@ describe('MongoshLoggingAndTelemetry', function () {
7072
} as Writable);
7173
});
7274

73-
afterEach(function () {
74-
loggingAndTelemetry.detachLogger();
75+
afterEach(async function () {
76+
await loggingAndTelemetry.detachLogger();
7577
logger.destroy();
7678
});
7779

@@ -82,9 +84,9 @@ describe('MongoshLoggingAndTelemetry', function () {
8284
);
8385
});
8486

85-
it('does not throw when attaching and detaching loggers', function () {
87+
it('does not throw when attaching and detaching loggers', async function () {
8688
loggingAndTelemetry.attachLogger(logger);
87-
loggingAndTelemetry.detachLogger();
89+
await loggingAndTelemetry.detachLogger();
8890
expect(() => loggingAndTelemetry.attachLogger(logger)).does.not.throw();
8991
});
9092

@@ -308,7 +310,7 @@ describe('MongoshLoggingAndTelemetry', function () {
308310
.setupTelemetryPromise;
309311

310312
// Flush before it completes
311-
loggingAndTelemetry.flush();
313+
await loggingAndTelemetry.flush();
312314

313315
// Emit an event that would trigger analytics
314316
bus.emit('mongosh:new-user', { userId, anonymousId: userId });
@@ -377,7 +379,7 @@ describe('MongoshLoggingAndTelemetry', function () {
377379
expect(logOutput).to.have.lengthOf(0);
378380
expect(analyticsOutput).to.have.lengthOf(0);
379381

380-
loggingAndTelemetry.detachLogger();
382+
await loggingAndTelemetry.detachLogger();
381383

382384
// This event has both analytics and logging
383385
bus.emit('mongosh:use', { db: '' });
@@ -386,7 +388,7 @@ describe('MongoshLoggingAndTelemetry', function () {
386388
expect(analyticsOutput).to.have.lengthOf(1);
387389
});
388390

389-
it('detaching logger applies to devtools-connect events', function () {
391+
it('detaching logger applies to devtools-connect events', async function () {
390392
loggingAndTelemetry.attachLogger(logger);
391393

392394
bus.emit('devtools-connect:connect-fail-early');
@@ -396,7 +398,7 @@ describe('MongoshLoggingAndTelemetry', function () {
396398
// No analytics event attached to this
397399
expect(analyticsOutput).to.have.lengthOf(0);
398400

399-
loggingAndTelemetry.detachLogger();
401+
await loggingAndTelemetry.detachLogger();
400402
bus.emit('devtools-connect:connect-fail-early');
401403

402404
expect(logOutput).to.have.lengthOf(2);
@@ -423,7 +425,7 @@ describe('MongoshLoggingAndTelemetry', function () {
423425
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
424426
expect(analyticsOutput).to.have.lengthOf(1);
425427

426-
loggingAndTelemetry.detachLogger();
428+
await loggingAndTelemetry.detachLogger();
427429

428430
bus.emit('mongosh:use', { db: '' });
429431

@@ -446,7 +448,7 @@ describe('MongoshLoggingAndTelemetry', function () {
446448

447449
expect(analyticsOutput).to.have.lengthOf(1);
448450

449-
loggingAndTelemetry.detachLogger();
451+
await loggingAndTelemetry.detachLogger();
450452

451453
bus.emit('mongosh:use', { db: '' });
452454

‎packages/logging/src/logging-and-telemetry.ts‎

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -126,13 +126,15 @@ export class LoggingAndTelemetry implements MongoshLoggingAndTelemetry {
126126
this.isSetup = true;
127127
}
128128

129-
public flush(): void {
129+
public async flush(): Promise<void> {
130130
// Run any other pending events with the set or dummy log for telemetry purposes.
131131
this.runAndClearPendingBusEvents();
132132

133133
// Abort setup, which will cause the device ID to be set to 'unknown'
134134
// and run any remaining telemetry events
135135
this.telemetrySetupAbort.abort();
136+
137+
await this.log.flush();
136138
}
137139

138140
private async setupTelemetry(): Promise<void> {
@@ -177,10 +179,10 @@ export class LoggingAndTelemetry implements MongoshLoggingAndTelemetry {
177179
this.bus.emit('mongosh:log-initialized');
178180
}
179181

180-
public detachLogger() {
182+
public async detachLogger(): Promise<void> {
181183
this.log = LoggingAndTelemetry.dummyLogger;
182184

183-
this.flush();
185+
await this.flush();
184186
}
185187

186188
private runAndClearPendingBusEvents() {

‎packages/logging/src/types.ts‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -5,9 +5,9 @@ import type { MultiSet } from './helpers';
55

66
export interface MongoshLoggingAndTelemetry {
77
attachLogger(logger: MongoLogWriter): void;
8-
detachLogger(): void;
8+
detachLogger(): Promise<void>;
99
/** Flush any remaining log or telemetry events. */
10-
flush(): void;
10+
flush(): Promise<void>;
1111
}
1212

1313
export type MongoshLoggingAndTelemetryArguments = {

0 commit comments

Comments
 (0)