Skip to content

Commit 95d93a5

Browse files
gagikgagik
committed
refactor: delay telemetry until device ID is resolved
1 parent e6fa06e commit 95d93a5

File tree

4 files changed

+209
-163
lines changed

4 files changed

+209
-163
lines changed

‎packages/logging/src/analytics-helpers.ts‎

Lines changed: 3 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -18,7 +18,7 @@ export type AnalyticsIdentifyMessage = MongoshAnalyticsIdentity & {
1818
timestamp?: Date;
1919
};
2020

21-
type AnalyticsTrackMessage = MongoshAnalyticsIdentity & {
21+
export type AnalyticsTrackMessage = MongoshAnalyticsIdentity & {
2222
event: string;
2323
properties: {
2424
mongosh_version: string;
@@ -272,11 +272,8 @@ export class ThrottledAnalytics implements MongoshAnalytics {
272272

273273
identify(message: AnalyticsIdentifyMessage): void {
274274
message = addTimestamp(message);
275-
276-
if (this.currentUserId && !message.deviceId) {
277-
throw new Error(
278-
'Identifying without device ID can only be called once per user session'
279-
);
275+
if (this.currentUserId) {
276+
throw new Error('Identify can only be called once per user session');
280277
}
281278
this.currentUserId = message.userId ?? message.anonymousId;
282279
this.restorePromise = this.restoreThrottleState().then((enabled) => {

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

Lines changed: 117 additions & 72 deletions
Original file line numberDiff line numberDiff line change
@@ -7,10 +7,10 @@ import type { MongoshBus } from '@mongosh/types';
77
import type { Writable } from 'stream';
88
import type { MongoshLoggingAndTelemetry } from '.';
99
import { setupLoggingAndTelemetry } from '.';
10+
import type { LoggingAndTelemetry } from './logging-and-telemetry';
1011
import { getDeviceId } from './logging-and-telemetry';
1112
import sinon from 'sinon';
1213
import type { MongoshLoggingAndTelemetryArguments } from './types';
13-
import { eventually } from '../../../testing/eventually';
1414

1515
describe('MongoshLoggingAndTelemetry', function () {
1616
let logOutput: any[];
@@ -86,9 +86,11 @@ describe('MongoshLoggingAndTelemetry', function () {
8686
expect(() => loggingAndTelemetry.attachLogger(logger)).does.not.throw();
8787
});
8888

89-
it('tracks new local connection events', function () {
89+
it('tracks new local connection events', async function () {
9090
loggingAndTelemetry.attachLogger(logger);
9191

92+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
93+
9294
expect(logOutput).to.have.lengthOf(0);
9395
expect(analyticsOutput).to.be.empty;
9496

@@ -142,8 +144,9 @@ describe('MongoshLoggingAndTelemetry', function () {
142144
]);
143145
});
144146

145-
it('tracks new atlas connection events', function () {
147+
it('tracks new atlas connection events', async function () {
146148
loggingAndTelemetry.attachLogger(logger);
149+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
147150

148151
expect(logOutput).to.have.lengthOf(0);
149152
expect(analyticsOutput).to.be.empty;
@@ -203,95 +206,122 @@ describe('MongoshLoggingAndTelemetry', function () {
203206
});
204207

205208
describe('device ID', function () {
206-
let loggingAndTelemetry: MongoshLoggingAndTelemetry;
207209
let bus: EventEmitter;
208210
beforeEach(function () {
209211
bus = new EventEmitter();
210-
loggingAndTelemetry = setupLoggingAndTelemetry({
212+
});
213+
214+
afterEach(function () {
215+
sinon.restore();
216+
});
217+
218+
it('uses device ID "unknown" and logs error if it fails to resolve it', async function () {
219+
// eslint-disable-next-line @typescript-eslint/no-var-requires
220+
sinon.stub(require('child_process'), 'exec').throws(new Error('Test'));
221+
const loggingAndTelemetry = setupLoggingAndTelemetry({
211222
...testLoggingArguments,
212223
bus,
213224
deviceId: undefined,
214225
});
215-
});
216-
217-
it('uses device ID "unknown" if it fails to resolve it', async function () {
218226
loggingAndTelemetry.attachLogger(logger);
219-
// eslint-disable-next-line @typescript-eslint/no-var-requires
220-
sinon.stub(require('child_process'), 'exec').throws();
227+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
221228

222229
bus.emit('mongosh:new-user', { userId, anonymousId: userId });
223230

224-
await eventually(() => {
225-
expect(analyticsOutput).deep.equal([
226-
[
227-
'identify',
228-
{
229-
deviceId: undefined,
230-
anonymousId: userId,
231-
traits: {
232-
platform: process.platform,
233-
arch: process.arch,
234-
session_id: logId,
235-
},
236-
},
237-
],
238-
[
239-
'identify',
240-
{
241-
deviceId: 'unknown',
242-
anonymousId: userId,
243-
traits: {
244-
platform: process.platform,
245-
arch: process.arch,
246-
session_id: logId,
247-
},
231+
expect(analyticsOutput).deep.equal([
232+
[
233+
'identify',
234+
{
235+
deviceId: 'unknown',
236+
anonymousId: userId,
237+
traits: {
238+
platform: process.platform,
239+
arch: process.arch,
240+
session_id: logId,
248241
},
249-
],
250-
]);
242+
},
243+
],
244+
]);
245+
expect(logOutput[0]).contains({
246+
c: 'MONGOSH',
247+
id: 1000000006,
248+
ctx: 'telemetry',
249+
msg: 'Error: Test',
251250
});
252-
sinon.restore();
253251
});
254252

255253
it('automatically sets up device ID for telemetry', async function () {
254+
const loggingAndTelemetry = setupLoggingAndTelemetry({
255+
...testLoggingArguments,
256+
bus,
257+
deviceId: undefined,
258+
});
259+
256260
loggingAndTelemetry.attachLogger(logger);
257261

258262
bus.emit('mongosh:new-user', { userId, anonymousId: userId });
259263

260264
const deviceId = await getDeviceId();
261265

262-
await eventually(() => {
263-
expect(analyticsOutput).deep.equal([
264-
[
265-
'identify',
266-
{
267-
deviceId: undefined,
268-
anonymousId: userId,
269-
traits: {
270-
platform: process.platform,
271-
arch: process.arch,
272-
session_id: logId,
273-
},
266+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
267+
268+
expect(analyticsOutput).deep.equal([
269+
[
270+
'identify',
271+
{
272+
deviceId,
273+
anonymousId: userId,
274+
traits: {
275+
platform: process.platform,
276+
arch: process.arch,
277+
session_id: logId,
274278
},
275-
],
276-
[
277-
'identify',
278-
{
279-
deviceId,
280-
anonymousId: userId,
281-
traits: {
282-
platform: process.platform,
283-
arch: process.arch,
284-
session_id: logId,
285-
},
286-
},
287-
],
288-
]);
279+
},
280+
],
281+
]);
282+
});
283+
284+
it('only delays analytic outputs, not logging', async function () {
285+
// eslint-disable-next-line @typescript-eslint/no-empty-function
286+
let resolveTelemetry: (value: unknown) => void = () => {};
287+
const delayedTelemetry = new Promise((resolve) => {
288+
resolveTelemetry = (value) => resolve(value);
289289
});
290+
sinon
291+
// eslint-disable-next-line @typescript-eslint/no-var-requires
292+
.stub(require('node-machine-id'), 'machineId')
293+
.resolves(delayedTelemetry);
294+
295+
const loggingAndTelemetry = setupLoggingAndTelemetry({
296+
...testLoggingArguments,
297+
bus,
298+
deviceId: undefined,
299+
});
300+
301+
loggingAndTelemetry.attachLogger(logger);
302+
303+
// This event has both analytics and logging
304+
bus.emit('mongosh:use', { db: '' });
305+
306+
expect(logOutput).to.have.lengthOf(1);
307+
expect(analyticsOutput).to.have.lengthOf(0);
308+
309+
resolveTelemetry('1234');
310+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
311+
312+
expect(logOutput).to.have.lengthOf(1);
313+
expect(analyticsOutput).to.have.lengthOf(1);
314+
315+
// Hash created from machine ID 1234
316+
expect(analyticsOutput[0][1].deviceId).equals(
317+
'8c9f929608f0ef13bfd5a290e0233f283e2cc25ffefc2ad8d9ef0650eb224a52'
318+
);
290319
});
291320
});
292321

293-
it('detaching logger leads to no logging but persists analytics', function () {
322+
it('detaching logger leads to no logging but persists analytics', async function () {
294323
loggingAndTelemetry.attachLogger(logger);
324+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
295325

296326
expect(logOutput).to.have.lengthOf(0);
297327
expect(analyticsOutput).to.have.lengthOf(0);
@@ -328,7 +358,7 @@ describe('MongoshLoggingAndTelemetry', function () {
328358
expect(logOutput).to.have.lengthOf(4);
329359
});
330360

331-
it('detaching logger mid-way leads to no logging but persists analytics', function () {
361+
it('detaching logger mid-way leads to no logging but persists analytics', async function () {
332362
loggingAndTelemetry.attachLogger(logger);
333363

334364
expect(logOutput).to.have.lengthOf(0);
@@ -338,17 +368,21 @@ describe('MongoshLoggingAndTelemetry', function () {
338368
bus.emit('mongosh:use', { db: '' });
339369

340370
expect(logOutput).to.have.lengthOf(1);
371+
372+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
341373
expect(analyticsOutput).to.have.lengthOf(1);
342374

343375
loggingAndTelemetry.detachLogger();
344376

345377
bus.emit('mongosh:use', { db: '' });
346378

347379
expect(logOutput).to.have.lengthOf(1);
380+
381+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
348382
expect(analyticsOutput).to.have.lengthOf(2);
349383
});
350384

351-
it('detaching logger is recoverable', function () {
385+
it('detaching logger is recoverable', async function () {
352386
loggingAndTelemetry.attachLogger(logger);
353387

354388
expect(logOutput).to.have.lengthOf(0);
@@ -358,25 +392,32 @@ describe('MongoshLoggingAndTelemetry', function () {
358392
bus.emit('mongosh:use', { db: '' });
359393

360394
expect(logOutput).to.have.lengthOf(1);
395+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
396+
361397
expect(analyticsOutput).to.have.lengthOf(1);
362398

363399
loggingAndTelemetry.detachLogger();
364400

365401
bus.emit('mongosh:use', { db: '' });
366402

367403
expect(logOutput).to.have.lengthOf(1);
404+
405+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
368406
expect(analyticsOutput).to.have.lengthOf(2);
369407

370408
loggingAndTelemetry.attachLogger(logger);
371409

372410
bus.emit('mongosh:use', { db: '' });
373411

374412
expect(logOutput).to.have.lengthOf(2);
413+
414+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
375415
expect(analyticsOutput).to.have.lengthOf(3);
376416
});
377417

378-
it('tracks a sequence of events', function () {
418+
it('tracks a sequence of events', async function () {
379419
loggingAndTelemetry.attachLogger(logger);
420+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
380421

381422
expect(logOutput).to.have.lengthOf(0);
382423
expect(analyticsOutput).to.be.empty;
@@ -677,7 +718,7 @@ describe('MongoshLoggingAndTelemetry', function () {
677718
[
678719
'identify',
679720
{
680-
anonymousId: '53defe995fa47e6c13102d9d',
721+
anonymousId: userId,
681722
deviceId: 'test-device',
682723
traits: {
683724
platform: process.platform,
@@ -689,7 +730,7 @@ describe('MongoshLoggingAndTelemetry', function () {
689730
[
690731
'identify',
691732
{
692-
anonymousId: '53defe995fa47e6c13102d9d',
733+
anonymousId: userId,
693734
deviceId: 'test-device',
694735
traits: {
695736
platform: process.platform,
@@ -701,7 +742,7 @@ describe('MongoshLoggingAndTelemetry', function () {
701742
[
702743
'track',
703744
{
704-
anonymousId: '53defe995fa47e6c13102d9d',
745+
anonymousId: userId,
705746
deviceId: 'test-device',
706747
event: 'Startup Time',
707748
properties: {
@@ -850,8 +891,9 @@ describe('MongoshLoggingAndTelemetry', function () {
850891
]);
851892
});
852893

853-
it('buffers deprecated API calls', function () {
894+
it('buffers deprecated API calls', async function () {
854895
loggingAndTelemetry.attachLogger(logger);
896+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
855897

856898
expect(logOutput).to.have.lengthOf(0);
857899
expect(analyticsOutput).to.be.empty;
@@ -1005,6 +1047,7 @@ describe('MongoshLoggingAndTelemetry', function () {
10051047
]);
10061048

10071049
bus.emit('mongosh:new-user', { userId, anonymousId: userId });
1050+
10081051
logOutput = [];
10091052
analyticsOutput = [];
10101053

@@ -1027,6 +1070,7 @@ describe('MongoshLoggingAndTelemetry', function () {
10271070
class: 'Database',
10281071
method: 'cloneDatabase',
10291072
});
1073+
10301074
expect(analyticsOutput).to.have.lengthOf(2);
10311075
});
10321076

@@ -1054,11 +1098,12 @@ describe('MongoshLoggingAndTelemetry', function () {
10541098
expect(analyticsOutput).to.be.empty;
10551099
});
10561100

1057-
it('tracks custom logging events', function () {
1101+
it('tracks custom logging events', async function () {
10581102
expect(logOutput).to.have.lengthOf(0);
10591103
expect(analyticsOutput).to.be.empty;
10601104

10611105
loggingAndTelemetry.attachLogger(logger);
1106+
await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise;
10621107

10631108
bus.emit('mongosh:connect', {
10641109
uri: 'mongodb://localhost/',

0 commit comments

Comments
 (0)