diff --git a/.depalignrc.json b/.depalignrc.json index d42c9548c1..4b9119aaad 100644 --- a/.depalignrc.json +++ b/.depalignrc.json @@ -18,6 +18,10 @@ "@typescript-eslint/parser": [ "^5.59.0", "^4.33.0" + ], + "node-fetch": [ + "^3.3.2", + "2.6.12" ] } } \ No newline at end of file diff --git a/package-lock.json b/package-lock.json index 69fe852368..979193e436 100644 --- a/package-lock.json +++ b/package-lock.json @@ -21748,6 +21748,29 @@ "license": "MIT", "optional": true }, + "node_modules/native-machine-id": { + "version": "0.1.1", + "resolved": "https://registry.npmjs.org/native-machine-id/-/native-machine-id-0.1.1.tgz", + "integrity": "sha512-TNuaM2fiqnYER3XbfO0ki+ykXeWiWEeu2EYaeSjKu1L6NV1ZKetrLX1JY0dpGeOrNKLHOeVdfQDN38mX+h8WoA==", + "hasInstallScript": true, + "license": "Apache-2.0", + "dependencies": { + "bindings": "^1.5.0", + "node-addon-api": "^8.0.0" + }, + "bin": { + "native-machine-id": "dist/bin/machine-id.js" + } + }, + "node_modules/native-machine-id/node_modules/node-addon-api": { + "version": "8.3.1", + "resolved": "https://registry.npmjs.org/node-addon-api/-/node-addon-api-8.3.1.tgz", + "integrity": "sha512-lytcDEdxKjGJPTLEfW4mYMigRezMlyJY8W4wxJK8zE533Jlb8L8dRuObJFWg2P+AuOIxoCgKF+2Oq4d4Zd0OUA==", + "license": "MIT", + "engines": { + "node": "^18 || ^20 || >= 21" + } + }, "node_modules/natural-compare": { "version": "1.4.0", "license": "MIT" @@ -21994,6 +22017,8 @@ }, "node_modules/node-machine-id": { "version": "1.1.12", + "resolved": "https://registry.npmjs.org/node-machine-id/-/node-machine-id-1.1.12.tgz", + "integrity": "sha512-QNABxbrPa3qEIfrE6GOJ7BYIuignnJw7iQ2YPbc3Nla1HzRJjXzZOiikfF8m7eAMfichLt3M4VgLOetqgDmgGQ==", "license": "MIT", "optional": true }, @@ -29828,7 +29853,8 @@ "@mongosh/history": "2.4.6", "@mongosh/types": "3.6.0", "mongodb-log-writer": "^2.3.1", - "mongodb-redact": "^1.1.5" + "mongodb-redact": "^1.1.5", + "native-machine-id": "^0.1.1" }, "devDependencies": { "@mongodb-js/eslint-config-mongosh": "^1.0.0", @@ -29836,12 +29862,79 @@ "@mongodb-js/tsconfig-mongosh": "^1.0.0", "depcheck": "^1.4.7", "eslint": "^7.25.0", - "prettier": "^2.8.8" + "prettier": "^2.8.8", + "sinon": "^19.0.4" }, "engines": { "node": ">=14.15.1" } }, + "packages/logging/node_modules/@sinonjs/commons": { + "version": "3.0.1", + "resolved": "https://registry.npmjs.org/@sinonjs/commons/-/commons-3.0.1.tgz", + "integrity": "sha512-K3mCHKQ9sVh8o1C9cxkwxaOmXoAMlDxC1mYyHrjqOWEcBjYr76t96zL2zlj5dUGZ3HSw240X1qgH3Mjf1yJWpQ==", + "dev": true, + "license": "BSD-3-Clause", + "dependencies": { + "type-detect": "4.0.8" + } + }, + "packages/logging/node_modules/@sinonjs/fake-timers": { + "version": "13.0.5", + "resolved": "https://registry.npmjs.org/@sinonjs/fake-timers/-/fake-timers-13.0.5.tgz", + "integrity": "sha512-36/hTbH2uaWuGVERyC6da9YwGWnzUZXuPro/F2LfsdOsLnCojz/iSH8MxUt/FD2S5XBSVPhmArFUXcpCQ2Hkiw==", + "dev": true, + "license": "BSD-3-Clause", + "dependencies": { + "@sinonjs/commons": "^3.0.1" + } + }, + "packages/logging/node_modules/@sinonjs/samsam": { + "version": "8.0.2", + "resolved": "https://registry.npmjs.org/@sinonjs/samsam/-/samsam-8.0.2.tgz", + "integrity": "sha512-v46t/fwnhejRSFTGqbpn9u+LQ9xJDse10gNnPgAcxgdoCDMXj/G2asWAC/8Qs+BAZDicX+MNZouXT1A7c83kVw==", + "dev": true, + "license": "BSD-3-Clause", + "dependencies": { + "@sinonjs/commons": "^3.0.1", + "lodash.get": "^4.4.2", + "type-detect": "^4.1.0" + } + }, + "packages/logging/node_modules/@sinonjs/samsam/node_modules/type-detect": { + "version": "4.1.0", + "resolved": "https://registry.npmjs.org/type-detect/-/type-detect-4.1.0.tgz", + "integrity": "sha512-Acylog8/luQ8L7il+geoSxhEkazvkslg7PSNKOX59mbB9cOveP5aq9h74Y7YU8yDpJwetzQQrfIwtf4Wp4LKcw==", + "dev": true, + "license": "MIT", + "engines": { + "node": ">=4" + } + }, + "packages/logging/node_modules/@sinonjs/text-encoding": { + "version": "0.7.3", + "resolved": "https://registry.npmjs.org/@sinonjs/text-encoding/-/text-encoding-0.7.3.tgz", + "integrity": "sha512-DE427ROAphMQzU4ENbliGYrBSYPXF+TtLg9S8vzeA+OF4ZKzoDdzfL8sxuMUGS/lgRhM6j1URSk9ghf7Xo1tyA==", + "dev": true, + "license": "(Unlicense OR Apache-2.0)" + }, + "packages/logging/node_modules/diff": { + "version": "7.0.0", + "resolved": "https://registry.npmjs.org/diff/-/diff-7.0.0.tgz", + "integrity": "sha512-PJWHUb1RFevKCwaFA9RlG5tCd+FO5iRh9A8HEtkmBH2Li03iJriB6m6JIN4rGz3K3JLawI7/veA1xzRKP6ISBw==", + "dev": true, + "license": "BSD-3-Clause", + "engines": { + "node": ">=0.3.1" + } + }, + "packages/logging/node_modules/just-extend": { + "version": "6.2.0", + "resolved": "https://registry.npmjs.org/just-extend/-/just-extend-6.2.0.tgz", + "integrity": "sha512-cYofQu2Xpom82S6qD778jBDpwvvy39s1l/hrYij2u9AMdQcGRpaBu6kY4mVhuno5kJVi1DAz4aiphA2WI1/OAw==", + "dev": true, + "license": "MIT" + }, "packages/logging/node_modules/mongodb-log-writer": { "version": "2.3.1", "resolved": "https://registry.npmjs.org/mongodb-log-writer/-/mongodb-log-writer-2.3.1.tgz", @@ -29860,6 +29953,49 @@ "integrity": "sha512-bLTHIHviJvTGJDvCECDBEDMk7beJQ4Fvoec50hgIax98ojzyTk9xIyrewFPM7yzlDVKTkkh864uxlkkTTLVsbg==", "license": "Apache-2.0" }, + "packages/logging/node_modules/nise": { + "version": "6.1.1", + "resolved": "https://registry.npmjs.org/nise/-/nise-6.1.1.tgz", + "integrity": "sha512-aMSAzLVY7LyeM60gvBS423nBmIPP+Wy7St7hsb+8/fc1HmeoHJfLO8CKse4u3BtOZvQLJghYPI2i/1WZrEj5/g==", + "dev": true, + "license": "BSD-3-Clause", + "dependencies": { + "@sinonjs/commons": "^3.0.1", + "@sinonjs/fake-timers": "^13.0.1", + "@sinonjs/text-encoding": "^0.7.3", + "just-extend": "^6.2.0", + "path-to-regexp": "^8.1.0" + } + }, + "packages/logging/node_modules/path-to-regexp": { + "version": "8.2.0", + "resolved": "https://registry.npmjs.org/path-to-regexp/-/path-to-regexp-8.2.0.tgz", + "integrity": "sha512-TdrF7fW9Rphjq4RjrW0Kp2AW0Ahwu9sRGTkS6bvDi0SCwZlEZYmcfDbEsTz8RVk0EHIS/Vd1bv3JhG+1xZuAyQ==", + "dev": true, + "license": "MIT", + "engines": { + "node": ">=16" + } + }, + "packages/logging/node_modules/sinon": { + "version": "19.0.4", + "resolved": "https://registry.npmjs.org/sinon/-/sinon-19.0.4.tgz", + "integrity": "sha512-myidFob7fjmYHJb+CHNLtAYScxn3sngGq4t75L2rCGGpE/k4OQVkN3KE5FsN+XkO2+fcDZ65PGvq3KHrlLAm7g==", + "dev": true, + "license": "BSD-3-Clause", + "dependencies": { + "@sinonjs/commons": "^3.0.1", + "@sinonjs/fake-timers": "^13.0.5", + "@sinonjs/samsam": "^8.0.1", + "diff": "^7.0.0", + "nise": "^6.1.1", + "supports-color": "^7.2.0" + }, + "funding": { + "type": "opencollective", + "url": "https://opencollective.com/sinon" + } + }, "packages/mongosh": { "version": "2.5.0", "license": "Apache-2.0", diff --git a/packages/build/src/compile/signable-compiler.ts b/packages/build/src/compile/signable-compiler.ts index c7cab80ffb..ad2fd544c5 100644 --- a/packages/build/src/compile/signable-compiler.ts +++ b/packages/build/src/compile/signable-compiler.ts @@ -132,6 +132,10 @@ export class SignableCompiler { path: await findModulePath('cli-repl', 'glibc-version'), requireRegexp: /\bglibc_version\.node$/, }; + const nativeMachineIdAddon = { + path: await findModulePath('logging', 'native-machine-id'), + requireRegexp: /\bnative_machine_id\.node$/, + }; // Warning! Until https://jira.mongodb.org/browse/MONGOSH-990, // packages/service-provider-node-driver *also* has a copy of these. // We use the versions included in packages/cli-repl here, so these @@ -186,6 +190,7 @@ export class SignableCompiler { kerberosAddon, cryptLibraryVersionAddon, glibcVersionAddon, + nativeMachineIdAddon, ] .concat(winCAAddon ? [winCAAddon] : []) .concat(winConsoleProcessListAddon ? [winConsoleProcessListAddon] : []) diff --git a/packages/cli-repl/src/cli-repl.ts b/packages/cli-repl/src/cli-repl.ts index b67ca31356..b00c52e1cf 100644 --- a/packages/cli-repl/src/cli-repl.ts +++ b/packages/cli-repl/src/cli-repl.ts @@ -1172,6 +1172,8 @@ export class CliRepl implements MongoshIOProvider { const analytics = this.toggleableAnalytics; let flushError: string | null = null; let flushDuration: number | null = null; + this.loggingAndTelemetry?.flush(); + if (analytics) { const flushStart = Date.now(); try { @@ -1194,6 +1196,7 @@ export class CliRepl implements MongoshIOProvider { } ); await this.logWriter?.flush(); + markTime(TimingCategories.Logging, 'flushed log writer'); this.bus.emit('mongosh:closed'); })()); @@ -1211,6 +1214,7 @@ export class CliRepl implements MongoshIOProvider { // onExit never returns. If it does, that's a bug. const error = new MongoshInternalError('onExit() unexpectedly returned'); this.bus.emit('mongosh:error', error, 'fatal'); + throw error; } diff --git a/packages/connectivity-tests/test/all.sh b/packages/connectivity-tests/test/all.sh index 49b7270436..a11dba694a 100755 --- a/packages/connectivity-tests/test/all.sh +++ b/packages/connectivity-tests/test/all.sh @@ -20,7 +20,7 @@ fi git clone https://github.com/mongodb-js/devtools-docker-test-envs.git test-envs cd test-envs -git checkout ac8e6675fcd769f0bfc868c3ac73cdd8bcdcc792 +git checkout cbec3a65efe9def50638994ae6b36ffa3b4708ee "$CONNECTIVITY_TEST_SOURCE_DIR/ldap.sh" "$CONNECTIVITY_TEST_SOURCE_DIR/localhost.sh" diff --git a/packages/e2e-tests/test/e2e-snapshot.spec.ts b/packages/e2e-tests/test/e2e-snapshot.spec.ts index f887fae94b..4406ab4c41 100644 --- a/packages/e2e-tests/test/e2e-snapshot.spec.ts +++ b/packages/e2e-tests/test/e2e-snapshot.spec.ts @@ -144,7 +144,7 @@ describe('e2e snapshot support', function () { ); verifyAllInCategoryMatch( 'nodb-eval', - /^node_modules\/(kerberos|mongodb-client-encryption|glibc-version|@mongodb-js\/devtools-proxy-support|@mongodb-js\/socksv5|agent-base|(win|macos)-export-certificate-and-key|@tootallnate\/quickjs-emscripten)\// + /^node_modules\/(kerberos|native-machine-id|mongodb-client-encryption|glibc-version|@mongodb-js\/devtools-proxy-support|@mongodb-js\/socksv5|agent-base|(win|macos)-export-certificate-and-key|@tootallnate\/quickjs-emscripten)\// ); if (process.arch !== 's390x') { // quickjs is in the list above but should be exlucded anywhere but on s390x diff --git a/packages/e2e-tests/test/e2e.spec.ts b/packages/e2e-tests/test/e2e.spec.ts index ff8004afd2..38fa95b9bf 100644 --- a/packages/e2e-tests/test/e2e.spec.ts +++ b/packages/e2e-tests/test/e2e.spec.ts @@ -771,6 +771,25 @@ describe('e2e', function () { ).to.include('string'); }); + it('sets device ID for telemetry', async function () { + const deviceId = ( + await shell.executeLine( + 'db._mongo._instanceState.evaluationListener.ioProvider.loggingAndTelemetry.deviceId' + ) + ) + .split('\n')[0] + // Remove all whitespace + .replace(/\s+/g, ''); + + expect(deviceId).not.to.equal('unknown'); + // Our hashed key is 64 hex chars + + expect(deviceId).to.match( + /^[a-f0-9]{64}$/, + `deviceId did not match: |${deviceId}|` + ); + }); + context('post-4.2', function () { skipIfServerVersion(testServer, '< 4.4'); it('allows calling convertShardKeyToHashed() as a global function', async function () { diff --git a/packages/logging/package.json b/packages/logging/package.json index 9f684d34a4..eb3fc72674 100644 --- a/packages/logging/package.json +++ b/packages/logging/package.json @@ -22,7 +22,8 @@ "@mongosh/history": "2.4.6", "@mongosh/types": "3.6.0", "mongodb-log-writer": "^2.3.1", - "mongodb-redact": "^1.1.5" + "mongodb-redact": "^1.1.5", + "native-machine-id": "^0.1.1" }, "devDependencies": { "@mongodb-js/eslint-config-mongosh": "^1.0.0", @@ -30,7 +31,8 @@ "@mongodb-js/tsconfig-mongosh": "^1.0.0", "depcheck": "^1.4.7", "eslint": "^7.25.0", - "prettier": "^2.8.8" + "prettier": "^2.8.8", + "sinon": "^19.0.4" }, "scripts": { "test": "mocha -r \"../../scripts/import-expansions.js\" --timeout 15000 -r ts-node/register --reporter \"../../configs/mocha-config-mongosh/reporter.ts\" \"./src/**/*.spec.ts\"", diff --git a/packages/logging/src/analytics-helpers.ts b/packages/logging/src/analytics-helpers.ts index b1f9229368..3123111c00 100644 --- a/packages/logging/src/analytics-helpers.ts +++ b/packages/logging/src/analytics-helpers.ts @@ -3,10 +3,12 @@ import path from 'path'; export type MongoshAnalyticsIdentity = | { + deviceId?: string; userId: string; anonymousId?: never; } | { + deviceId?: string; userId?: never; anonymousId: string; }; @@ -16,7 +18,7 @@ export type AnalyticsIdentifyMessage = MongoshAnalyticsIdentity & { timestamp?: Date; }; -type AnalyticsTrackMessage = MongoshAnalyticsIdentity & { +export type AnalyticsTrackMessage = MongoshAnalyticsIdentity & { event: string; properties: { mongosh_version: string; diff --git a/packages/logging/src/logging-and-telemetry.spec.ts b/packages/logging/src/logging-and-telemetry.spec.ts index bfcfd8af78..7581f3a604 100644 --- a/packages/logging/src/logging-and-telemetry.spec.ts +++ b/packages/logging/src/logging-and-telemetry.spec.ts @@ -7,6 +7,10 @@ import type { MongoshBus } from '@mongosh/types'; import type { Writable } from 'stream'; import type { MongoshLoggingAndTelemetry } from '.'; import { setupLoggingAndTelemetry } from '.'; +import type { LoggingAndTelemetry } from './logging-and-telemetry'; +import { getDeviceId } from './logging-and-telemetry'; +import sinon from 'sinon'; +import type { MongoshLoggingAndTelemetryArguments } from './types'; describe('MongoshLoggingAndTelemetry', function () { let logOutput: any[]; @@ -32,19 +36,25 @@ describe('MongoshLoggingAndTelemetry', function () { let loggingAndTelemetry: MongoshLoggingAndTelemetry; + const testLoggingArguments: Omit = + { + analytics, + deviceId: 'test-device', + userTraits: { + platform: process.platform, + arch: process.arch, + }, + mongoshVersion: '1.0.0', + }; + beforeEach(function () { logOutput = []; analyticsOutput = []; bus = new EventEmitter(); loggingAndTelemetry = setupLoggingAndTelemetry({ + ...testLoggingArguments, bus, - analytics, - userTraits: { - platform: process.platform, - arch: process.arch, - }, - mongoshVersion: '1.0.0', }); logger = new MongoLogWriter(logId, `/tmp/${logId}_log`, { @@ -76,9 +86,11 @@ describe('MongoshLoggingAndTelemetry', function () { expect(() => loggingAndTelemetry.attachLogger(logger)).does.not.throw(); }); - it('tracks new local connection events', function () { + it('tracks new local connection events', async function () { loggingAndTelemetry.attachLogger(logger); + await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise; + expect(logOutput).to.have.lengthOf(0); expect(analyticsOutput).to.be.empty; @@ -105,6 +117,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'identify', { anonymousId: userId, + deviceId: 'test-device', traits: { arch: process.arch, platform: process.platform, @@ -116,6 +129,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'track', { anonymousId: userId, + deviceId: 'test-device', event: 'New Connection', properties: { mongosh_version: '1.0.0', @@ -130,8 +144,9 @@ describe('MongoshLoggingAndTelemetry', function () { ]); }); - it('tracks new atlas connection events', function () { + it('tracks new atlas connection events', async function () { loggingAndTelemetry.attachLogger(logger); + await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise; expect(logOutput).to.have.lengthOf(0); expect(analyticsOutput).to.be.empty; @@ -163,6 +178,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'identify', { anonymousId: userId, + deviceId: 'test-device', traits: { arch: process.arch, platform: process.platform, @@ -174,6 +190,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'track', { anonymousId: userId, + deviceId: 'test-device', event: 'New Connection', properties: { mongosh_version: '1.0.0', @@ -188,8 +205,126 @@ describe('MongoshLoggingAndTelemetry', function () { ]); }); - it('detaching logger leads to no logging but persists analytics', function () { + describe('device ID', function () { + let bus: EventEmitter; + beforeEach(function () { + bus = new EventEmitter(); + }); + + afterEach(function () { + sinon.restore(); + }); + + it('uses device ID "unknown" and logs error if it fails to resolve it', async function () { + // eslint-disable-next-line @typescript-eslint/no-var-requires + sinon + // eslint-disable-next-line @typescript-eslint/no-var-requires + .stub(require('native-machine-id'), 'getMachineId') + .rejects(new Error('Test')); + const loggingAndTelemetry = setupLoggingAndTelemetry({ + ...testLoggingArguments, + bus, + deviceId: undefined, + }); + loggingAndTelemetry.attachLogger(logger); + await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise; + + bus.emit('mongosh:new-user', { userId, anonymousId: userId }); + + expect(analyticsOutput).deep.equal([ + [ + 'identify', + { + deviceId: 'unknown', + anonymousId: userId, + traits: { + platform: process.platform, + arch: process.arch, + session_id: logId, + }, + }, + ], + ]); + expect(logOutput[0]).contains({ + c: 'MONGOSH', + id: 1000000006, + ctx: 'telemetry', + msg: 'Error: Test', + }); + }); + + it('automatically sets up device ID for telemetry', async function () { + const loggingAndTelemetry = setupLoggingAndTelemetry({ + ...testLoggingArguments, + bus, + deviceId: undefined, + }); + + loggingAndTelemetry.attachLogger(logger); + + bus.emit('mongosh:new-user', { userId, anonymousId: userId }); + + const deviceId = await getDeviceId(); + + await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise; + + expect(analyticsOutput).deep.equal([ + [ + 'identify', + { + deviceId, + anonymousId: userId, + traits: { + platform: process.platform, + arch: process.arch, + session_id: logId, + }, + }, + ], + ]); + }); + + it('only delays analytic outputs, not logging', async function () { + // eslint-disable-next-line @typescript-eslint/no-empty-function + let resolveTelemetry: (value: unknown) => void = () => {}; + const delayedTelemetry = new Promise((resolve) => { + resolveTelemetry = (value) => resolve(value); + }); + sinon + // eslint-disable-next-line @typescript-eslint/no-var-requires + .stub(require('native-machine-id'), 'getMachineId') + .resolves(delayedTelemetry); + + const loggingAndTelemetry = setupLoggingAndTelemetry({ + ...testLoggingArguments, + bus, + deviceId: undefined, + }); + + loggingAndTelemetry.attachLogger(logger); + + // This event has both analytics and logging + bus.emit('mongosh:use', { db: '' }); + + expect(logOutput).to.have.lengthOf(1); + expect(analyticsOutput).to.have.lengthOf(0); + + resolveTelemetry('1234'); + await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise; + + expect(logOutput).to.have.lengthOf(1); + expect(analyticsOutput).to.have.lengthOf(1); + + // Hash created from machine ID 1234 + expect(analyticsOutput[0][1].deviceId).equals( + '8c9f929608f0ef13bfd5a290e0233f283e2cc25ffefc2ad8d9ef0650eb224a52' + ); + }); + }); + + it('detaching logger leads to no logging but persists analytics', async function () { loggingAndTelemetry.attachLogger(logger); + await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise; expect(logOutput).to.have.lengthOf(0); expect(analyticsOutput).to.have.lengthOf(0); @@ -226,7 +361,7 @@ describe('MongoshLoggingAndTelemetry', function () { expect(logOutput).to.have.lengthOf(4); }); - it('detaching logger mid-way leads to no logging but persists analytics', function () { + it('detaching logger mid-way leads to no logging but persists analytics', async function () { loggingAndTelemetry.attachLogger(logger); expect(logOutput).to.have.lengthOf(0); @@ -236,6 +371,8 @@ describe('MongoshLoggingAndTelemetry', function () { bus.emit('mongosh:use', { db: '' }); expect(logOutput).to.have.lengthOf(1); + + await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise; expect(analyticsOutput).to.have.lengthOf(1); loggingAndTelemetry.detachLogger(); @@ -243,10 +380,11 @@ describe('MongoshLoggingAndTelemetry', function () { bus.emit('mongosh:use', { db: '' }); expect(logOutput).to.have.lengthOf(1); + expect(analyticsOutput).to.have.lengthOf(2); }); - it('detaching logger is recoverable', function () { + it('detaching logger is recoverable', async function () { loggingAndTelemetry.attachLogger(logger); expect(logOutput).to.have.lengthOf(0); @@ -256,6 +394,8 @@ describe('MongoshLoggingAndTelemetry', function () { bus.emit('mongosh:use', { db: '' }); expect(logOutput).to.have.lengthOf(1); + await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise; + expect(analyticsOutput).to.have.lengthOf(1); loggingAndTelemetry.detachLogger(); @@ -263,6 +403,7 @@ describe('MongoshLoggingAndTelemetry', function () { bus.emit('mongosh:use', { db: '' }); expect(logOutput).to.have.lengthOf(1); + expect(analyticsOutput).to.have.lengthOf(2); loggingAndTelemetry.attachLogger(logger); @@ -270,11 +411,13 @@ describe('MongoshLoggingAndTelemetry', function () { bus.emit('mongosh:use', { db: '' }); expect(logOutput).to.have.lengthOf(2); + expect(analyticsOutput).to.have.lengthOf(3); }); - it('tracks a sequence of events', function () { + it('tracks a sequence of events', async function () { loggingAndTelemetry.attachLogger(logger); + await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise; expect(logOutput).to.have.lengthOf(0); expect(analyticsOutput).to.be.empty; @@ -575,7 +718,8 @@ describe('MongoshLoggingAndTelemetry', function () { [ 'identify', { - anonymousId: '53defe995fa47e6c13102d9d', + anonymousId: userId, + deviceId: 'test-device', traits: { platform: process.platform, arch: process.arch, @@ -586,7 +730,8 @@ describe('MongoshLoggingAndTelemetry', function () { [ 'identify', { - anonymousId: '53defe995fa47e6c13102d9d', + anonymousId: userId, + deviceId: 'test-device', traits: { platform: process.platform, arch: process.arch, @@ -597,7 +742,8 @@ describe('MongoshLoggingAndTelemetry', function () { [ 'track', { - anonymousId: '53defe995fa47e6c13102d9d', + anonymousId: userId, + deviceId: 'test-device', event: 'Startup Time', properties: { is_interactive: true, @@ -613,6 +759,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'track', { anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', event: 'Error', properties: { mongosh_version: '1.0.0', @@ -628,6 +775,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'track', { anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', event: 'Error', properties: { mongosh_version: '1.0.0', @@ -643,6 +791,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'track', { anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', event: 'Use', properties: { mongosh_version: '1.0.0', @@ -654,6 +803,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'track', { anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', event: 'Show', properties: { mongosh_version: '1.0.0', @@ -673,6 +823,7 @@ describe('MongoshLoggingAndTelemetry', function () { shell: true, }, anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', }, ], [ @@ -685,6 +836,7 @@ describe('MongoshLoggingAndTelemetry', function () { nested: false, }, anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', }, ], [ @@ -696,6 +848,7 @@ describe('MongoshLoggingAndTelemetry', function () { session_id: logId, }, anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', }, ], [ @@ -707,6 +860,7 @@ describe('MongoshLoggingAndTelemetry', function () { session_id: logId, }, anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', }, ], [ @@ -719,12 +873,14 @@ describe('MongoshLoggingAndTelemetry', function () { shell: true, }, anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', }, ], [ 'track', { anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', event: 'Snippet Install', properties: { mongosh_version: '1.0.0', @@ -735,8 +891,9 @@ describe('MongoshLoggingAndTelemetry', function () { ]); }); - it('buffers deprecated API calls', function () { + it('buffers deprecated API calls', async function () { loggingAndTelemetry.attachLogger(logger); + await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise; expect(logOutput).to.have.lengthOf(0); expect(analyticsOutput).to.be.empty; @@ -819,6 +976,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'track', { anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', event: 'Deprecated Method', properties: { mongosh_version: '1.0.0', @@ -832,6 +990,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'track', { anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', event: 'Deprecated Method', properties: { mongosh_version: '1.0.0', @@ -845,6 +1004,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'track', { anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', event: 'Deprecated Method', properties: { mongosh_version: '1.0.0', @@ -858,6 +1018,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'track', { anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', event: 'API Call', properties: { mongosh_version: '1.0.0', @@ -872,6 +1033,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'track', { anonymousId: '53defe995fa47e6c13102d9d', + deviceId: 'test-device', event: 'API Call', properties: { mongosh_version: '1.0.0', @@ -885,6 +1047,7 @@ describe('MongoshLoggingAndTelemetry', function () { ]); bus.emit('mongosh:new-user', { userId, anonymousId: userId }); + logOutput = []; analyticsOutput = []; @@ -907,6 +1070,7 @@ describe('MongoshLoggingAndTelemetry', function () { class: 'Database', method: 'cloneDatabase', }); + expect(analyticsOutput).to.have.lengthOf(2); }); @@ -934,11 +1098,12 @@ describe('MongoshLoggingAndTelemetry', function () { expect(analyticsOutput).to.be.empty; }); - it('tracks custom logging events', function () { + it('tracks custom logging events', async function () { expect(logOutput).to.have.lengthOf(0); expect(analyticsOutput).to.be.empty; loggingAndTelemetry.attachLogger(logger); + await (loggingAndTelemetry as LoggingAndTelemetry).setupTelemetryPromise; bus.emit('mongosh:connect', { uri: 'mongodb://localhost/', @@ -1023,6 +1188,7 @@ describe('MongoshLoggingAndTelemetry', function () { 'track', { anonymousId: undefined, + deviceId: 'test-device', event: 'New Connection', properties: { mongosh_version: '1.0.0', @@ -1036,4 +1202,13 @@ describe('MongoshLoggingAndTelemetry', function () { ], ]); }); + + describe('getDeviceId()', function () { + it('is consistent on the same machine', async function () { + const idA = await getDeviceId(); + const idB = await getDeviceId(); + + expect(idA).equals(idB); + }); + }); }); diff --git a/packages/logging/src/logging-and-telemetry.ts b/packages/logging/src/logging-and-telemetry.ts index 69b77fa50c..6007ff8ee8 100644 --- a/packages/logging/src/logging-and-telemetry.ts +++ b/packages/logging/src/logging-and-telemetry.ts @@ -39,6 +39,7 @@ import { MongoLogWriter } from 'mongodb-log-writer'; import { mongoLogId } from 'mongodb-log-writer'; import type { AnalyticsIdentifyMessage, + AnalyticsTrackMessage, MongoshAnalytics, MongoshAnalyticsIdentity, } from './analytics-helpers'; @@ -52,6 +53,40 @@ import type { MongoshLoggingAndTelemetryArguments, MongoshTrackingProperties, } from './types'; +import { createHmac } from 'crypto'; + +/** + * @returns A hashed, unique identifier for the running device or `"unknown"` if not known. + */ +export async function getDeviceId({ + onError, +}: { + onError?: (error: Error) => void; +} = {}): Promise { + try { + // Create a hashed format from the all uppercase version of the machine ID + // to match it exactly with the denisbrodbeck/machineid library that Atlas CLI uses. + const originalId: string = + // eslint-disable-next-line @typescript-eslint/no-var-requires + await require('native-machine-id').getMachineId({ + raw: true, + }); + + if (!originalId) { + return 'unknown'; + } + const hmac = createHmac('sha256', originalId); + + /** This matches the message used to create the hashes in Atlas CLI */ + const DEVICE_ID_HASH_MESSAGE = 'atlascli'; + + hmac.update(DEVICE_ID_HASH_MESSAGE); + return hmac.digest('hex'); + } catch (error) { + onError?.(error as Error); + return 'unknown'; + } +} export function setupLoggingAndTelemetry( props: MongoshLoggingAndTelemetryArguments @@ -62,7 +97,8 @@ export function setupLoggingAndTelemetry( return loggingAndTelemetry; } -class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { +/** @internal */ +export class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { private static dummyLogger = new MongoLogWriter( '', null, @@ -82,30 +118,71 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { private readonly mongoshVersion: string; private log: MongoLogWriter; - private pendingLogEvents: CallableFunction[] = []; + private pendingBusEvents: CallableFunction[] = []; + private pendingTelemetryEvents: CallableFunction[] = []; private isSetup = false; - private isBufferingEvents = false; + private isBufferingBusEvents = false; + private isBufferingTelemetryEvents = false; + + private deviceId: string | undefined; + /** @internal */ + public setupTelemetryPromise: Promise = Promise.resolve(); + + // eslint-disable-next-line @typescript-eslint/no-empty-function + private resolveDeviceId: (value: string) => void = () => {}; constructor({ bus, analytics, userTraits, mongoshVersion, + deviceId, }: MongoshLoggingAndTelemetryArguments) { this.bus = bus; this.analytics = analytics; this.log = LoggingAndTelemetry.dummyLogger; this.userTraits = userTraits; this.mongoshVersion = mongoshVersion; + this.deviceId = deviceId; } public setup(): void { if (this.isSetup) { throw new Error('Setup can only be called once.'); } + this.isBufferingTelemetryEvents = true; + this.isBufferingBusEvents = true; + + this.setupTelemetryPromise = this.setupTelemetry(); this.setupBusEventListeners(); + this.isSetup = true; - this.isBufferingEvents = true; + } + + public flush(): void { + // Run any telemetry events even if device ID hasn't been resolved yet + this.runAndClearPendingTelemetryEvents(); + + // Run any other pending events with the set or dummy log for telemetry purposes. + this.runAndClearPendingBusEvents(); + + this.resolveDeviceId('unknown'); + } + + private async setupTelemetry(): Promise { + if (!this.deviceId) { + this.deviceId = await Promise.race([ + getDeviceId({ + onError: (error) => + this.bus.emit('mongosh:error', error, 'telemetry'), + }), + new Promise((resolve) => { + this.resolveDeviceId = resolve; + }), + ]); + } + + this.runAndClearPendingTelemetryEvents(); } public attachLogger(logger: MongoLogWriter): void { @@ -119,24 +196,32 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { ); } this.log = logger; - this.isBufferingEvents = false; - this.runAndClearPendingEvents(); + this.runAndClearPendingBusEvents(); this.bus.emit('mongosh:log-initialized'); } public detachLogger() { this.log = LoggingAndTelemetry.dummyLogger; - // Still run any remaining pending events with the dummy log for telemetry purposes. - this.runAndClearPendingEvents(); + + this.flush(); + } + + private runAndClearPendingBusEvents() { + let pendingEvent: CallableFunction | undefined; + while ((pendingEvent = this.pendingBusEvents.shift())) { + pendingEvent(); + } + this.isBufferingBusEvents = false; } - private runAndClearPendingEvents() { + private runAndClearPendingTelemetryEvents() { let pendingEvent: CallableFunction | undefined; - while ((pendingEvent = this.pendingLogEvents.shift())) { + while ((pendingEvent = this.pendingTelemetryEvents.shift())) { pendingEvent(); } + this.isBufferingTelemetryEvents = false; } /** Information used and set by different bus events. */ @@ -171,11 +256,10 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { listener: (...args: Parameters) => void ) => { this.bus.on(event, ((...args: Parameters) => { - if (this.isBufferingEvents) { - this.pendingLogEvents.push(() => listener(...args)); + if (this.isBufferingBusEvents) { + this.pendingBusEvents.push(() => listener(...args)); return; } - listener(...args); }) as MongoshBusEventsMap[K]); return this.bus; @@ -193,12 +277,52 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { const getTelemetryUserIdentity = (): MongoshAnalyticsIdentity => { return { + deviceId: this.deviceId, anonymousId: this.busEventState.telemetryAnonymousId ?? (this.busEventState.userId as string), }; }; + const track = ( + message: Pick & { + properties?: Omit< + AnalyticsTrackMessage['properties'], + keyof MongoshTrackingProperties + >; + } + ): void => { + const callback = () => + this.analytics.track({ + ...getTelemetryUserIdentity(), + ...message, + properties: { + ...getTrackingProperties(), + ...message.properties, + }, + }); + + if (this.isBufferingTelemetryEvents) { + this.pendingTelemetryEvents.push(callback); + } else { + callback(); + } + }; + + const identify = (): void => { + const callback = () => + this.analytics.identify({ + ...getTelemetryUserIdentity(), + traits: getUserTraits(), + }); + + if (this.isBufferingTelemetryEvents) { + this.pendingTelemetryEvents.push(callback); + } else { + callback(); + } + }; + onBus('mongosh:start-mongosh-repl', (ev: StartMongoshReplEvent) => { this.log.info( 'MONGOSH', @@ -230,7 +354,6 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { atlas_hostname: args.is_atlas ? resolved_hostname : null, }; const properties = { - ...getTrackingProperties(), ...argsWithoutUriAndHostname, ...atlasHostname, }; @@ -248,8 +371,7 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { } ); - this.analytics.track({ - ...getTelemetryUserIdentity(), + track({ event: 'New Connection', properties, }); @@ -264,11 +386,9 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { ); const normalizedTimings = Object.fromEntries(normalizedTimingsArray); - this.analytics.track({ - ...getTelemetryUserIdentity(), + track({ event: 'Startup Time', properties: { - ...getTrackingProperties(), is_interactive: args.isInteractive, js_context: args.jsContext, ...normalizedTimings, @@ -284,10 +404,8 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { } this.busEventState.telemetryAnonymousId = newTelemetryUserIdentity.anonymousId; - this.analytics.identify({ - anonymousId: newTelemetryUserIdentity.anonymousId, - traits: getUserTraits(), - }); + + identify(); } ); @@ -303,10 +421,7 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { } else { this.busEventState.userId = updatedTelemetryUserIdentity.userId; } - this.analytics.identify({ - ...getTelemetryUserIdentity(), - traits: getUserTraits(), - }); + identify(); this.log.info( 'MONGOSH', mongoLogId(1_000_000_005), @@ -334,11 +449,9 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { ); if (error.name.includes('Mongosh')) { - this.analytics.track({ - ...getTelemetryUserIdentity(), + track({ event: 'Error', properties: { - ...getTrackingProperties(), name: mongoshError.name, code: mongoshError.code, scope: mongoshError.scope, @@ -388,12 +501,8 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { args ); - this.analytics.track({ - ...getTelemetryUserIdentity(), + track({ event: 'Use', - properties: { - ...getTrackingProperties(), - }, }); }); @@ -406,11 +515,9 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { args ); - this.analytics.track({ - ...getTelemetryUserIdentity(), + track({ event: 'Show', properties: { - ...getTrackingProperties(), method: args.method, }, }); @@ -452,13 +559,11 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { args ); - this.analytics.track({ - ...getTelemetryUserIdentity(), + track({ event: this.busEventState.hasStartedMongoshRepl ? 'Script Loaded' : 'Script Loaded CLI', properties: { - ...getTrackingProperties(), nested: args.nested, ...(this.busEventState.hasStartedMongoshRepl ? {} @@ -475,11 +580,9 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { 'Evaluating script passed on the command line' ); - this.analytics.track({ - ...getTelemetryUserIdentity(), + track({ event: 'Script Evaluated', properties: { - ...getTrackingProperties(), shell: this.busEventState.usesShellOption, }, }); @@ -493,12 +596,8 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { 'Loading .mongoshrc.js' ); - this.analytics.track({ - ...getTelemetryUserIdentity(), + track({ event: 'Mongoshrc Loaded', - properties: { - ...getTrackingProperties(), - }, }); }); @@ -510,12 +609,8 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { 'Warning about .mongorc.js/.mongoshrc.js mismatch' ); - this.analytics.track({ - ...getTelemetryUserIdentity(), + track({ event: 'Mongorc Warning', - properties: { - ...getTrackingProperties(), - }, }); }); @@ -680,12 +775,8 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { ); if (ev.args[0] === 'install') { - this.analytics.track({ - ...getTelemetryUserIdentity(), + track({ event: 'Snippet Install', - properties: { - ...getTrackingProperties(), - }, }); } }); @@ -738,21 +829,17 @@ class LoggingAndTelemetry implements MongoshLoggingAndTelemetry { entry ); - this.analytics.track({ - ...getTelemetryUserIdentity(), + track({ event: 'Deprecated Method', properties: { - ...getTrackingProperties(), ...entry, }, }); } for (const [entry, count] of apiCalls) { - this.analytics.track({ - ...getTelemetryUserIdentity(), + track({ event: 'API Call', properties: { - ...getTrackingProperties(), ...entry, count, }, diff --git a/packages/logging/src/types.ts b/packages/logging/src/types.ts index 797fd5990c..4f8f40eaab 100644 --- a/packages/logging/src/types.ts +++ b/packages/logging/src/types.ts @@ -6,6 +6,8 @@ import type { MultiSet } from './helpers'; export interface MongoshLoggingAndTelemetry { attachLogger(logger: MongoLogWriter): void; detachLogger(): void; + /** Flush any remaining log or telemetry events. */ + flush(): void; } export type MongoshLoggingAndTelemetryArguments = { @@ -15,6 +17,8 @@ export type MongoshLoggingAndTelemetryArguments = { [key: string]: unknown; }; mongoshVersion: string; + /** Machine-specific ID; gets set automatically when omitted */ + deviceId?: string | undefined; }; export type MongoshTrackingProperties = {