diff --git a/apps/rush-cli-client/README.md b/apps/rush-cli-client/README.md index 712ccb9fdb..e413088084 100644 --- a/apps/rush-cli-client/README.md +++ b/apps/rush-cli-client/README.md @@ -33,6 +33,56 @@ startup/reporting contract, not just engine installation. Until that separation is warranted, reusing the existing frontend preserves version selection and reporter behavior without duplicating or relocating bootstrap code. +## Repository invocation telemetry + +Repositories can configure an optional reporter in `common/config/rush-client/telemetry.json`: + +```json +{ + "reporterPath": "tools/client-telemetry.js", + "logFolder": "common/temp/client-telemetry", + "disabledEnvironmentVariable": "DISABLE_TELEMETRY_UPLOAD", + "localFolderEnvironmentVariable": "CLIENT_TELEMETRY_LOCAL_FOLDER" +} +``` + +Both paths must remain inside the repository. No reporter or network request runs without this file. +The configured opt-out disables collection when its value is `1`. Keep this file outside +`common/config/rush`, whose filenames are validated by older Rush engines. + +Before publishing a receipt or launching its reporter, the client writes a private +`.delivery-target` sidecar containing `{"kind":"upload"}` or +`{"kind":"local-only","folder":""}`. The optional +`localFolderEnvironmentVariable` names the repository's local-only logging variable; its value is +captured at initialization and relative destinations resolve against the repository root. Reporters +must honor this immutable target when retrying queued receipts, including receipts whose original +reporter could not start. The sidecar is local delivery metadata, not an upload property. + +Each completed client writes a private version-1 JSON receipt with a logical invocation ID, +distinct attempt IDs, the actual route/fallback reason, real exit code, integer millisecond timings, +original agent session, and hardware cohort. Argument scope is hashed after client controls are removed; +raw arguments and free-text telemetry labels are not written to receipts. The optional `cwdHash` captures +the SHA256 hash of the original repository-relative working directory, normalized to `/`, at initialization +as local-only recovery context. Raw working directories are not written to receipts; repository reporters +must not upload either raw working directories or `cwdHash`. Native routing is not fallback. +Pre-execution fallback records zero reexecuted operations; missing operation evidence is otherwise unknown. +Timings run from Node process start to client return, not the sum of parallel operation durations or +completion of work still draining after an early result. + +The reporter runs as `node --invocation ` from the repository root without +inheriting terminal pipes or delaying client return. It must bound its own lifetime, honor the repository's +upload policy, retain undelivered receipts, and write asynchronous errors to stderr, captured in +`/reporter-errors.log`. A `.reporter-status` JSON object with `success: false` makes the next +client warn about reporter failure. Reporter failures never replace the command's exit code. +The client also prints the receipt path on failure or fallback for recovery tooling. + +Request attribution uses the existing fingerprint-exempt `RUSHD_TELEMETRY_TAG`, prefixed with +`rush-client-v1:` and JSON context. Repository hooks must decode this context and restore `originalTag` +before recording a legacy free-text label. A recovery wrapper that owns the receipt may set +`RUSHD_CLIENT_TELEMETRY_PARENT=1` only for its native child to avoid a second logical invocation. +This is attribution, not permission to replay: cancellation, live-work ownership and replay-safety +checks still apply. + ## Routing Routing precedence: diff --git a/apps/rush-cli-client/src/ClientInvocationTelemetry.ts b/apps/rush-cli-client/src/ClientInvocationTelemetry.ts new file mode 100644 index 0000000000..7c40bf83ac --- /dev/null +++ b/apps/rush-cli-client/src/ClientInvocationTelemetry.ts @@ -0,0 +1,333 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. Licensed under the MIT license. +// See LICENSE in the project root for license information. + +import { spawn, type ChildProcess } from 'node:child_process'; +import { createHash, randomUUID } from 'node:crypto'; +import * as fs from 'node:fs'; +import * as os from 'node:os'; +import * as path from 'node:path'; + +import { JsonFile } from '@rushstack/node-core-library'; + +const CONTEXT_PREFIX: string = 'rush-client-v1:'; +const CLIENT_VERSION: string = (require('../package.json') as { version: string }).version; + +interface IReporterConfiguration { + readonly reporterPath: string; + readonly logFolder: string; + readonly disabledEnvironmentVariable?: string; + readonly localFolderEnvironmentVariable?: string; +} + +type DeliveryTarget = { kind: 'upload' } | { kind: 'local-only'; folder: string }; + +/** Request-local attribution, carried in the existing fingerprint-exempt telemetry tag. */ +export interface IClientInvocationContext { + readonly schemaVersion: 1; + readonly invocationId: string; + readonly attemptId: string; + readonly clientVersion: string; + readonly launcher: 'rush-client' | 'rushx-client'; + readonly route: 'daemon' | 'native' | 'fallback'; + readonly originalTag?: string; + readonly fallbackReason?: string; +} + +interface IAttempt { + readonly attemptId: string; + readonly backend: 'daemon' | 'native'; + readonly elapsedMs: number; + readonly outcome: 'fallback' | 'returned'; +} + +interface IClientMachine { + readonly os: string; + readonly arch: string; + readonly cores: number; + readonly processor?: string; + readonly totalMemoryBytes: number; +} + +/** One completed client return, not the sum of parallel operations or a daemon's remaining work. */ +export interface IClientInvocationEvent { + readonly schemaVersion: 1; + readonly eventId: string; + readonly invocationId: string; + readonly clientVersion: string; + readonly launcher: 'rush-client' | 'rushx-client'; + readonly command: string; + readonly scopeHash: string; + readonly cwdHash?: string; + readonly startedAt: string; + readonly completedAt: string; + readonly route: 'daemon' | 'native' | 'fallback'; + readonly routeReason: string; + readonly exitCode: number; + readonly elapsedMs: number; + readonly durationBasis: 'node-process-to-client-return'; + readonly attempts: readonly IAttempt[]; + readonly operationsReexecuted?: number; + readonly agentSessionId?: string; + readonly machine: IClientMachine; +} + +/** Repository-configured, best-effort reporting without a tenant-specific dependency in the client. */ +export class ClientInvocationTelemetry { + readonly #startedAt: string = new Date(performance.timeOrigin).toISOString(); + readonly #invocationId: string = randomUUID(); + #scopeHash: string; + readonly #cwdHash: string; + readonly #attempts: IAttempt[] = []; + readonly #root: string; + readonly #configuration: IReporterConfiguration; + readonly #deliveryTarget: DeliveryTarget; + readonly #agentSessionId: string | undefined = process.env.COPILOT_AGENT_SESSION_ID; + readonly #machine: IClientMachine; + #context: IClientInvocationContext; + #attemptStartedAtMs: number = 0; + #command: string = 'unknown'; + #routeReason: string = 'routing-not-completed'; + #reported: boolean = false; + #safePreExecutionFallback: boolean = false; + + private constructor(root: string, configuration: IReporterConfiguration, rushx: boolean) { + this.#root = root; + this.#cwdHash = createHash('sha256') + .update(path.relative(root, process.cwd()).split(path.sep).join('/')) + .digest('hex'); + this.#configuration = configuration; + const localFolder: string | undefined = configuration.localFolderEnvironmentVariable + ? process.env[configuration.localFolderEnvironmentVariable] + : undefined; + this.#deliveryTarget = localFolder + ? { kind: 'local-only', folder: path.resolve(root, localFolder) } + : { kind: 'upload' }; + const cpus: os.CpuInfo[] = os.cpus(); + this.#machine = { + os: process.platform, + arch: process.arch, + cores: cpus.length, + processor: cpus[0]?.model, + totalMemoryBytes: os.totalmem() + }; + this.#scopeHash = createHash('sha256') + .update(JSON.stringify(process.argv.slice(2))) + .digest('hex'); + this.#context = { + schemaVersion: 1, + invocationId: this.#invocationId, + attemptId: randomUUID(), + clientVersion: CLIENT_VERSION, + launcher: rushx ? 'rushx-client' : 'rush-client', + route: 'native', + ...(process.env.RUSHD_TELEMETRY_TAG === undefined + ? {} + : { originalTag: process.env.RUSHD_TELEMETRY_TAG }) + }; + // Native Rush starts asynchronous work and does not return its completion promise to the launcher. + process.once('beforeExit', (code: number) => this.#report(code)); + // An explicit exit can start the bounded, detached reporter, but cannot wait for its delivery. + process.once('exit', (code: number) => this.#report(code)); + } + + public static initialize( + rushJsonPath: string | undefined, + rushx: boolean + ): ClientInvocationTelemetry | undefined { + if (process.env.RUSHD_CLIENT_TELEMETRY_PARENT === '1') return undefined; + if (!rushJsonPath) return undefined; + const root: string = path.dirname(rushJsonPath); + const configurationPath: string = `${root}/common/config/rush-client/telemetry.json`; + if (!fs.existsSync(configurationPath)) return undefined; + try { + const configuration: IReporterConfiguration = JsonFile.load(configurationPath); + if ( + typeof configuration.reporterPath !== 'string' || + typeof configuration.logFolder !== 'string' || + (configuration.disabledEnvironmentVariable !== undefined && + typeof configuration.disabledEnvironmentVariable !== 'string') || + (configuration.localFolderEnvironmentVariable !== undefined && + (typeof configuration.localFolderEnvironmentVariable !== 'string' || + !configuration.localFolderEnvironmentVariable)) + ) { + throw new Error( + 'Expected reporterPath, logFolder and optional disabledEnvironmentVariable and localFolderEnvironmentVariable' + ); + } + if ( + configuration.disabledEnvironmentVariable && + process.env[configuration.disabledEnvironmentVariable] === '1' + ) { + return undefined; + } + resolveRepositoryPath(root, configuration.reporterPath); + const logFolder: string = resolveRepositoryPath(root, configuration.logFolder); + const statusPath: string = `${logFolder}/.reporter-status`; + try { + if (fs.existsSync(statusPath)) { + const status: { success?: boolean } = JsonFile.load(statusPath); + if (status.success === false) { + process.stderr.write( + 'rush-client: previous telemetry reporter failed; receipts and reporter-errors.log are retained.\n' + ); + } + } + } catch (error) { + process.stderr.write( + `rush-client: telemetry reporter status is unavailable: ${(error as Error).message}\n` + ); + } + return new ClientInvocationTelemetry(root, configuration, rushx); + } catch (error) { + process.stderr.write(`rush-client: invocation telemetry is unavailable: ${(error as Error).message}\n`); + return undefined; + } + } + + public selectRoute( + command: string | undefined, + daemon: boolean, + reason?: string, + argv?: ReadonlyArray + ): void { + this.#command = command ?? 'unknown'; + this.#routeReason = daemon ? 'daemon-selected' : (reason ?? 'explicit-native-or-help'); + this.#context = { ...this.#context, route: daemon ? 'daemon' : 'native' }; + if (argv) { + this.#scopeHash = createHash('sha256').update(JSON.stringify(argv)).digest('hex'); + } + } + + public get attemptId(): string { + return this.#context.attemptId; + } + + public getEnvironment( + environment: Readonly> + ): Readonly> { + return { ...environment, RUSHD_TELEMETRY_TAG: `${CONTEXT_PREFIX}${JSON.stringify(this.#context)}` }; + } + + public beginFallback(reason: string): void { + const now: number = Math.round(performance.now()); + this.#attempts.push({ + attemptId: this.#context.attemptId, + backend: 'daemon', + elapsedMs: now - this.#attemptStartedAtMs, + outcome: 'fallback' + }); + this.#attemptStartedAtMs = now; + this.#routeReason = reason; + this.#safePreExecutionFallback = true; + this.#context = { + ...this.#context, + attemptId: randomUUID(), + route: 'fallback', + fallbackReason: reason + }; + } + + public prepareNativeEnvironment(): void { + process.env.RUSHD_TELEMETRY_TAG = this.getEnvironment(process.env).RUSHD_TELEMETRY_TAG; + } + + #createEvent(exitCode: number): IClientInvocationEvent { + const elapsedMs: number = Math.round(performance.now()); + return { + schemaVersion: 1, + eventId: randomUUID(), + invocationId: this.#invocationId, + clientVersion: CLIENT_VERSION, + launcher: this.#context.launcher, + command: this.#command, + scopeHash: this.#scopeHash, + cwdHash: this.#cwdHash, + startedAt: this.#startedAt, + completedAt: new Date().toISOString(), + route: this.#context.route, + routeReason: this.#routeReason, + exitCode, + elapsedMs, + durationBasis: 'node-process-to-client-return', + attempts: [ + ...this.#attempts, + { + attemptId: this.#context.attemptId, + backend: this.#context.route === 'daemon' ? 'daemon' : 'native', + elapsedMs: elapsedMs - this.#attemptStartedAtMs, + outcome: 'returned' + } + ], + agentSessionId: this.#agentSessionId, + machine: this.#machine, + ...(this.#safePreExecutionFallback ? { operationsReexecuted: 0 } : {}) + }; + } + + #persist(exitCode: number): string | undefined { + if (this.#reported) return undefined; + this.#reported = true; + if ( + this.#configuration.disabledEnvironmentVariable && + process.env[this.#configuration.disabledEnvironmentVariable] === '1' + ) { + return undefined; + } + try { + const folder: string = resolveRepositoryPath(this.#root, this.#configuration.logFolder); + fs.mkdirSync(folder, { recursive: true }); + const file: string = `${folder}/${this.#invocationId}.json`; + fs.writeFileSync(`${file}.delivery-target`, JSON.stringify(this.#deliveryTarget), { + mode: 0o600, + flag: 'wx' + }); + fs.writeFileSync(file, JSON.stringify(this.#createEvent(exitCode)), { mode: 0o600, flag: 'wx' }); + if (exitCode !== 0 || this.#context.route === 'fallback') { + process.stderr.write( + `rush-client: invocation receipt: ${this.#configuration.logFolder}/${this.#invocationId}.json\n` + ); + } + return file; + } catch (error) { + this.#warn(error as Error); + return undefined; + } + } + + #report(exitCode: number): void { + const file: string | undefined = this.#persist(exitCode); + if (!file) return; + let errorLog: number | undefined; + try { + const reporter: string = resolveRepositoryPath(this.#root, this.#configuration.reporterPath); + if (!fs.statSync(reporter).isFile()) throw new Error('Reporter is not a regular file'); + const folder: string = resolveRepositoryPath(this.#root, this.#configuration.logFolder); + errorLog = fs.openSync(`${folder}/reporter-errors.log`, 'a', 0o600); + const child: ChildProcess = spawn(process.execPath, [reporter, '--invocation', file], { + cwd: this.#root, + detached: true, + windowsHide: true, + stdio: ['ignore', 'ignore', errorLog] + }); + child.once('error', (error: Error) => this.#warn(error)); + child.unref(); + } catch (error) { + this.#warn(error as Error); + } finally { + if (errorLog !== undefined) fs.closeSync(errorLog); + } + } + + #warn(error: Error): void { + process.stderr.write(`rush-client: invocation telemetry failed: ${error.message}\n`); + } +} + +function resolveRepositoryPath(root: string, value: string): string { + const resolved: string = path.resolve(root, value); + const relative: string = path.relative(root, resolved); + if (!value || path.isAbsolute(value) || relative.startsWith('..') || !relative) { + throw new Error('Client telemetry paths must be relative paths inside the repository'); + } + return resolved; +} diff --git a/apps/rush-cli-client/src/launchClient.ts b/apps/rush-cli-client/src/launchClient.ts index 1266d12ddb..4070e9517f 100644 --- a/apps/rush-cli-client/src/launchClient.ts +++ b/apps/rush-cli-client/src/launchClient.ts @@ -32,6 +32,7 @@ import { ConsoleTerminalProvider } from '@rushstack/terminal'; import { executeDaemonCommandAsync } from './daemonCommands'; import { getConfiguredAdmission, type ClientName } from './ClientAdmissionControls'; import { ClientOperationRenderer } from './ClientOperationRenderer'; +import type { ClientInvocationTelemetry } from './ClientInvocationTelemetry'; import type { AgentProgressRenderer } from './AgentProgressRenderer'; import { withNativeLockWaitNotices, type INativeLockWaitNoticeHandlers } from './nativeLockWaitNotice'; import { @@ -80,7 +81,8 @@ export function isConnectionFailure(error: unknown): boolean { export async function launchClientAsync( rushx: boolean, agentRenderer?: AgentProgressRenderer, - output: ClientOutput = new ClientOutput() + output: ClientOutput = new ClientOutput(), + invocationTelemetry?: ClientInvocationTelemetry ): Promise { const cwd: string = process.cwd(); const environment: Readonly = Object.freeze({ ...process.env }); @@ -103,6 +105,7 @@ export async function launchClientAsync( }); const selectedVersion: string = environment.RUSH_PREVIEW_VERSION ?? workspace?.rushVersion ?? getBundledRushVersion(); + invocationTelemetry?.selectRoute(route.commandName, route.daemon, route.inProcessReason, route.argv); if (!rushx && route.commandName === 'daemon') { agentRenderer?.dispose(); output.release(); @@ -123,6 +126,7 @@ export async function launchClientAsync( return; } if (!route.daemon || !rushJsonPath || route.commandName === undefined) { + invocationTelemetry?.prepareNativeEnvironment(); agentRenderer?.dispose(); output.release(); // Agent output says why a command runs in-process; legacy output, which rushx-client always uses, says so only @@ -148,6 +152,7 @@ export async function launchClientAsync( ? 'normal' : 'quiet'; const request: IDaemonRequestEnvelope = captureDaemonRequest({ + ...(invocationTelemetry ? { requestId: invocationTelemetry.attemptId } : {}), argv: route.argv, commandName: route.commandName, // The native resolver additionally validates the parsed action; rushx scripts never claim this origin. @@ -157,7 +162,7 @@ export async function launchClientAsync( // An agent acts on a failure as soon as it is known; the daemon finishes the independent work without it. ...(agentRenderer ? { returnEarlyOnFailure: true } : {}), cwd, - environment, + environment: invocationTelemetry?.getEnvironment(environment) ?? environment, terminal: { isTTY: !!process.stdout.isTTY, supportsColor: terminal.supportsColor, @@ -219,6 +224,10 @@ export async function launchClientAsync( agentRenderer?.dispose(); output.release(); process.stderr.write(formatInProcessFallbackMessage(error.message, clientName)); + invocationTelemetry?.beginFallback( + error instanceof DaemonClientError ? error.code : 'launcher-unavailable' + ); + invocationTelemetry?.prepareNativeEnvironment(); // No daemon admitted the request, so its whole wait timeout is left. await launchInProcessAsync(route.nativeArgv, rushx, selectedVersion, rushJsonPath, { startedAtMs: Date.now(), @@ -373,6 +382,8 @@ export async function launchClientAsync( } } if (restartFailure) { + invocationTelemetry?.beginFallback('restart-handoff-failed'); + invocationTelemetry?.prepareNativeEnvironment(); const explained: unknown = explainDaemonRestartFailure(restartFailure); agentRenderer?.dispose(); output.release(); @@ -440,6 +451,8 @@ export async function launchClientAsync( agentRenderer?.finish({ exitCode: 1, errorMessage: message }); throw new Error(message); } else { + invocationTelemetry?.beginFallback(outcome.reason); + invocationTelemetry?.prepareNativeEnvironment(); agentRenderer?.dispose(); output.release(); process.stderr.write(formatInProcessFallbackMessage(outcome.message ?? outcome.reason, clientName)); diff --git a/apps/rush-cli-client/src/start.ts b/apps/rush-cli-client/src/start.ts index 2173fbe213..9129ec53aa 100644 --- a/apps/rush-cli-client/src/start.ts +++ b/apps/rush-cli-client/src/start.ts @@ -3,6 +3,7 @@ import { AgentProgressRenderer } from './AgentProgressRenderer'; import { ClientOutput } from './clientOutput'; +import { ClientInvocationTelemetry } from './ClientInvocationTelemetry'; import { isDaemonOffBeforeRouting } from './earlyRouting'; import { findRushJsonPath, @@ -15,6 +16,10 @@ const startTimeMs: number = Date.now(); const argv: string[] = process.argv.slice(2); const commandName: string | undefined = getAgentCommandName(argv); const rushJsonPath: string | undefined = findRushJsonPath(process.cwd()); +const invocationTelemetry: ClientInvocationTelemetry | undefined = ClientInvocationTelemetry.initialize( + rushJsonPath, + false +); // Until Rush runs in-process, a reader of the output that exits (for example `| head`) cancels the command instead // of failing the process. const output: ClientOutput = new ClientOutput(); @@ -42,7 +47,7 @@ if (agentRenderer && !isDaemonOffBeforeRouting(process.env, rushJsonPath)) { const { launchClientAsync } = require('./launchClient') as typeof import('./launchClient'); -launchClientAsync(false, agentRenderer, output).catch((error: Error) => { +launchClientAsync(false, agentRenderer, output, invocationTelemetry).catch((error: Error) => { // In agent mode the summary line may already carry the complete message; do not repeat it. if (!agentRenderer?.finish({ exitCode: 1, errorMessage: error.message })) { process.stderr.write(`rush-client: ${error.message}\n`); diff --git a/apps/rush-cli-client/src/startRushX.ts b/apps/rush-cli-client/src/startRushX.ts index b29b7b7424..ac4f59b821 100644 --- a/apps/rush-cli-client/src/startRushX.ts +++ b/apps/rush-cli-client/src/startRushX.ts @@ -3,13 +3,20 @@ import { ClientOutput } from './clientOutput'; import { launchClientAsync } from './launchClient'; +import { ClientInvocationTelemetry } from './ClientInvocationTelemetry'; +import { findRushJsonPath } from './outputSelection'; + +const invocationTelemetry: ClientInvocationTelemetry | undefined = ClientInvocationTelemetry.initialize( + findRushJsonPath(process.cwd()), + true +); // Until Rush runs in-process, a reader of the output that exits (for example `| head`) cancels the command instead // of failing the process. const output: ClientOutput = new ClientOutput(); output.guard(); -launchClientAsync(true, undefined, output).catch((error: Error) => { +launchClientAsync(true, undefined, output, invocationTelemetry).catch((error: Error) => { process.stderr.write(`rushx-client: ${error.message}\n`); process.exitCode = 1; }); diff --git a/apps/rush-cli-client/src/test/ClientInvocationTelemetry.test.ts b/apps/rush-cli-client/src/test/ClientInvocationTelemetry.test.ts new file mode 100644 index 0000000000..d24570cf8c --- /dev/null +++ b/apps/rush-cli-client/src/test/ClientInvocationTelemetry.test.ts @@ -0,0 +1,322 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. Licensed under the MIT license. +// See LICENSE in the project root for license information. + +import * as fs from 'node:fs'; +import * as path from 'node:path'; +import * as childProcess from 'node:child_process'; +import { createHash } from 'node:crypto'; + +import { + ClientInvocationTelemetry, + type IClientInvocationContext, + type IClientInvocationEvent +} from '../ClientInvocationTelemetry'; + +const FOLDER: string = path.resolve(__dirname, '../../temp/test/client-invocation-telemetry'); +const RECEIPTS: string = `${FOLDER}/receipts`; +const ORIGINAL_TAG: string | undefined = process.env.RUSHD_TELEMETRY_TAG; + +function writeConfiguration(configuration: Record): void { + fs.mkdirSync(`${FOLDER}/common/config/rush-client`, { recursive: true }); + fs.writeFileSync(`${FOLDER}/common/config/rush-client/telemetry.json`, JSON.stringify(configuration)); +} + +function initialize(): ClientInvocationTelemetry { + const telemetry: ClientInvocationTelemetry | undefined = ClientInvocationTelemetry.initialize( + `${FOLDER}/rush.json`, + false + ); + if (!telemetry) throw new Error('Expected configured telemetry'); + return telemetry; +} + +function readReceipt(): IClientInvocationEvent { + const names: string[] = fs.readdirSync(RECEIPTS).filter((name: string) => name.endsWith('.json')); + expect(names).toHaveLength(1); + return JSON.parse(fs.readFileSync(`${RECEIPTS}/${names[0]}`, 'utf8')); +} + +describe(ClientInvocationTelemetry.name, () => { + let once: jest.SpyInstance; + let child: childProcess.ChildProcess; + + beforeEach(() => { + fs.mkdirSync(FOLDER, { recursive: true }); + once = jest.spyOn(process, 'once').mockReturnValue(process); + child = new childProcess.ChildProcess(); + jest.spyOn(jest.requireActual('node:child_process'), 'spawn').mockReturnValue(child); + jest.spyOn(child, 'unref').mockImplementation(() => {}); + jest.spyOn(process.stderr, 'write').mockReturnValue(true); + writeConfiguration({ reporterPath: 'reporter.cjs', logFolder: 'receipts' }); + fs.writeFileSync( + `${FOLDER}/reporter.cjs`, + "require('node:fs').writeFileSync('reporter-called',process.argv[3]);" + ); + }); + + afterEach(() => { + jest.restoreAllMocks(); + if (ORIGINAL_TAG === undefined) delete process.env.RUSHD_TELEMETRY_TAG; + else process.env.RUSHD_TELEMETRY_TAG = ORIGINAL_TAG; + fs.rmSync(FOLDER, { recursive: true, force: true }); + }); + + function onExit(code: number): void { + const call: unknown[] | undefined = once.mock.calls.find(([event]) => event === 'exit'); + const handler: ((exitCode: number) => void) | undefined = call?.[1] as + | ((exitCode: number) => void) + | undefined; + if (!handler) throw new Error('Missing exit hook'); + handler(code); + } + + it('leaves repositories without a telemetry configuration unchanged', () => { + expect(ClientInvocationTelemetry.initialize(undefined, false)).toBeUndefined(); + expect(ClientInvocationTelemetry.initialize(`${FOLDER}/other/rush.json`, false)).toBeUndefined(); + expect(once).not.toHaveBeenCalled(); + }); + + it('honors the configured upload opt-out before attaching hooks or writing a receipt', () => { + writeConfiguration({ + reporterPath: 'reporter.cjs', + logFolder: 'receipts', + disabledEnvironmentVariable: 'DISABLE_TELEMETRY_UPLOAD' + }); + const old: string | undefined = process.env.DISABLE_TELEMETRY_UPLOAD; + process.env.DISABLE_TELEMETRY_UPLOAD = '1'; + try { + expect(ClientInvocationTelemetry.initialize(`${FOLDER}/rush.json`, false)).toBeUndefined(); + expect(once).not.toHaveBeenCalled(); + } finally { + if (old === undefined) delete process.env.DISABLE_TELEMETRY_UPLOAD; + else process.env.DISABLE_TELEMETRY_UPLOAD = old; + } + }); + + it('attaches hooks and persists a normal invocation when the reporter status is malformed', () => { + fs.mkdirSync(RECEIPTS, { recursive: true }); + fs.writeFileSync(`${RECEIPTS}/.reporter-status`, '{"success":'); + const telemetry: ClientInvocationTelemetry = initialize(); + expect(process.stderr.write).toHaveBeenCalledWith( + expect.stringContaining('telemetry reporter status is unavailable') + ); + expect(once).toHaveBeenCalledWith('beforeExit', expect.any(Function)); + expect(once).toHaveBeenCalledWith('exit', expect.any(Function)); + telemetry.selectRoute('build', false, 'explicit-native'); + onExit(0); + expect(readReceipt()).toMatchObject({ + command: 'build', + route: 'native', + routeReason: 'explicit-native', + exitCode: 0 + }); + expect(childProcess.spawn).toHaveBeenCalledTimes(1); + }); + + it('does not publish receipts or targets when collection is disabled before command return', () => { + const previous: string | undefined = process.env.DISABLE_TELEMETRY_UPLOAD; + process.env.DISABLE_TELEMETRY_UPLOAD = '0'; + writeConfiguration({ + reporterPath: 'reporter.cjs', + logFolder: 'receipts', + disabledEnvironmentVariable: 'DISABLE_TELEMETRY_UPLOAD' + }); + try { + initialize().selectRoute('build', true); + process.env.DISABLE_TELEMETRY_UPLOAD = '1'; + onExit(0); + expect(fs.existsSync(RECEIPTS)).toBe(false); + expect(childProcess.spawn).not.toHaveBeenCalled(); + } finally { + if (previous === undefined) delete process.env.DISABLE_TELEMETRY_UPLOAD; + else process.env.DISABLE_TELEMETRY_UPLOAD = previous; + } + }); + + it('persists the original normalized relative cwd hash when the cwd changes after initialization', () => { + const originalCwd: string = path.join(FOLDER, 'projects', 'original-cwd'); + const laterCwd: string = path.join(FOLDER, 'projects', 'later-cwd'); + const cwd: jest.SpyInstance = jest.spyOn(process, 'cwd').mockReturnValue(originalCwd); + const telemetry: ClientInvocationTelemetry = initialize(); + cwd.mockReturnValue(laterCwd); + telemetry.selectRoute('build', false, 'explicit-native'); + onExit(0); + const event: IClientInvocationEvent = readReceipt(); + const originalRelativeCwd: string = path.relative(FOLDER, originalCwd).split(path.sep).join('/'); + const laterRelativeCwd: string = path.relative(FOLDER, laterCwd).split(path.sep).join('/'); + expect(event.cwdHash).toBe(createHash('sha256').update(originalRelativeCwd).digest('hex')); + expect(event.cwdHash).not.toBe(createHash('sha256').update(laterRelativeCwd).digest('hex')); + const receipt: string = JSON.stringify(event); + expect(receipt).not.toContain(FOLDER); + expect(receipt).not.toContain(originalRelativeCwd); + expect(receipt).not.toContain(laterRelativeCwd); + }); + + it('keeps intentional in-process routing out of the fallback population', () => { + const telemetry: ClientInvocationTelemetry = initialize(); + telemetry.selectRoute('test', false, 'custom-command'); + onExit(0); + const event: IClientInvocationEvent = readReceipt(); + expect(event.route).toBe('native'); + expect(event.routeReason).toBe('custom-command'); + expect(event.operationsReexecuted).toBeUndefined(); + expect(event.attempts).toHaveLength(1); + expect(Number.isSafeInteger(event.elapsedMs)).toBe(true); + }); + + it('correlates failed startup and safe native fallback without replaying daemon operations', () => { + process.env.RUSHD_TELEMETRY_TAG = 'benchmark-label'; + const telemetry: ClientInvocationTelemetry = initialize(); + telemetry.selectRoute('build', true); + const firstId: string = telemetry.attemptId; + telemetry.beginFallback('startupFailed'); + const environment: Readonly> = telemetry.getEnvironment({}); + const context: IClientInvocationContext = JSON.parse( + environment.RUSHD_TELEMETRY_TAG!.slice('rush-client-v1:'.length) + ); + expect(context.originalTag).toBe('benchmark-label'); + expect(context.attemptId).not.toBe(firstId); + expect(context.route).toBe('fallback'); + onExit(7); + const event: IClientInvocationEvent = readReceipt(); + expect(event.invocationId).toBe(context.invocationId); + expect(event.exitCode).toBe(7); + expect(event.operationsReexecuted).toBe(0); + expect(event.attempts.map((attempt) => attempt.backend)).toEqual(['daemon', 'native']); + expect(event.attempts.reduce((sum, attempt) => sum + attempt.elapsedMs, 0)).toBe(event.elapsedMs); + expect(JSON.stringify(event)).not.toContain('benchmark-label'); + expect(JSON.stringify(event)).not.toContain(FOLDER); + }); + + it('persists an explicit-exit failure once, with its actual exit code', () => { + initialize().selectRoute('build', true); + onExit(1); + onExit(1); + expect(readReceipt().exitCode).toBe(1); + expect(childProcess.spawn).toHaveBeenCalledTimes(1); + }); + + it('hashes routed arguments, not client-only native admission controls', () => { + const args: string[] = ['build', '-t', 'target']; + jest.replaceProperty(process, 'argv', ['node', 'client', '--no-daemon', ...args]); + initialize().selectRoute('build', false, 'explicit-native', args); + onExit(0); + expect(readReceipt().scopeHash).toBe(createHash('sha256').update(JSON.stringify(args)).digest('hex')); + }); + + it('starts the reporter without awaiting network delivery or inheriting terminal pipes', () => { + initialize().selectRoute('build', true); + onExit(0); + expect(childProcess.spawn).toHaveBeenCalledWith( + process.execPath, + [expect.stringContaining('reporter.cjs'), '--invocation', expect.stringContaining('.json')], + expect.objectContaining({ detached: true, stdio: ['ignore', 'ignore', expect.any(Number)] }) + ); + expect(child.unref).toHaveBeenCalledTimes(1); + }); + + it('retains the real command outcome when the reporter cannot be started', () => { + jest.mocked(childProcess.spawn).mockImplementation(() => { + throw new Error('reporter unavailable'); + }); + initialize().selectRoute('build', true); + expect(() => onExit(7)).not.toThrow(); + expect(readReceipt().exitCode).toBe(7); + expect( + JSON.parse(fs.readFileSync(`${RECEIPTS}/${readReceipt().invocationId}.json.delivery-target`, 'utf8')) + ).toEqual({ kind: 'upload' }); + expect(process.stderr.write).toHaveBeenCalledWith(expect.stringContaining('reporter unavailable')); + }); + + it('persists the delivery target before launching the background reporter', () => { + let observed: unknown; + jest.mocked(childProcess.spawn).mockImplementationOnce(() => { + const target: string = `${RECEIPTS}/${readReceipt().invocationId}.json.delivery-target`; + observed = fs.existsSync(target) ? JSON.parse(fs.readFileSync(target, 'utf8')) : undefined; + return child; + }); + initialize().selectRoute('build', true); + onExit(0); + expect(observed).toEqual({ kind: 'upload' }); + expect(child.unref).toHaveBeenCalledTimes(1); + }); + + it('does not publish an unclassified receipt when persisting its target fails', () => { + jest.spyOn(jest.requireActual('node:fs'), 'writeFileSync').mockImplementationOnce(() => { + throw new Error('target unavailable'); + }); + initialize().selectRoute('build', true); + expect(() => onExit(7)).not.toThrow(); + expect(fs.readdirSync(RECEIPTS)).toHaveLength(0); + expect(childProcess.spawn).not.toHaveBeenCalled(); + expect(process.stderr.write).toHaveBeenCalledWith(expect.stringContaining('target unavailable')); + }); + + it('retains the original local destination even when the reporter cannot start and the environment changed', () => { + const previous: string | undefined = process.env.CLIENT_TELEMETRY_LOCAL_FOLDER; + process.env.CLIENT_TELEMETRY_LOCAL_FOLDER = 'original-local'; + writeConfiguration({ + reporterPath: 'reporter.cjs', + logFolder: 'receipts', + localFolderEnvironmentVariable: 'CLIENT_TELEMETRY_LOCAL_FOLDER' + }); + try { + const telemetry: ClientInvocationTelemetry = initialize(); + process.env.CLIENT_TELEMETRY_LOCAL_FOLDER = 'different-local'; + jest.mocked(childProcess.spawn).mockImplementationOnce(() => { + throw new Error('reporter unavailable'); + }); + telemetry.selectRoute('build', true); + expect(() => onExit(7)).not.toThrow(); + const event: IClientInvocationEvent = readReceipt(); + expect(event.exitCode).toBe(7); + expect( + JSON.parse(fs.readFileSync(`${RECEIPTS}/${event.invocationId}.json.delivery-target`, 'utf8')) + ).toEqual({ kind: 'local-only', folder: path.resolve(FOLDER, 'original-local') }); + expect(JSON.stringify(event)).not.toContain('original-local'); + } finally { + if (previous === undefined) delete process.env.CLIENT_TELEMETRY_LOCAL_FOLDER; + else process.env.CLIENT_TELEMETRY_LOCAL_FOLDER = previous; + } + }); + + it('rejects invalid local-folder environment configuration instead of selecting upload delivery', () => { + for (const localFolderEnvironmentVariable of [42, '']) { + writeConfiguration({ + reporterPath: 'reporter.cjs', + logFolder: 'receipts', + localFolderEnvironmentVariable + }); + expect(ClientInvocationTelemetry.initialize(`${FOLDER}/rush.json`, false)).toBeUndefined(); + } + expect(once).not.toHaveBeenCalled(); + expect(process.stderr.write).toHaveBeenCalledWith( + expect.stringContaining('localFolderEnvironmentVariable') + ); + }); + + it('captures attribution when work starts, rather than when a queued record is uploaded', () => { + const original: string | undefined = process.env.COPILOT_AGENT_SESSION_ID; + process.env.COPILOT_AGENT_SESSION_ID = 'original-session'; + try { + initialize().selectRoute('build', true); + process.env.COPILOT_AGENT_SESSION_ID = 'later-session'; + onExit(0); + const event: IClientInvocationEvent = readReceipt(); + expect(event.agentSessionId).toBe('original-session'); + expect(event.machine.os).toBe(process.platform); + expect(event.machine.totalMemoryBytes).toBeGreaterThan(0); + } finally { + if (original === undefined) delete process.env.COPILOT_AGENT_SESSION_ID; + else process.env.COPILOT_AGENT_SESSION_ID = original; + } + }); + + it('rejects reporter paths outside the repository without failing the command', () => { + writeConfiguration({ reporterPath: '../outside.cjs', logFolder: 'receipts' }); + const stderr: jest.SpyInstance = jest.spyOn(process.stderr, 'write').mockReturnValue(true); + expect(ClientInvocationTelemetry.initialize(`${FOLDER}/rush.json`, false)).toBeUndefined(); + expect(stderr).toHaveBeenCalledWith(expect.stringContaining('paths inside the repository')); + expect(once).not.toHaveBeenCalled(); + }); +}); diff --git a/common/changes/@rushstack/rush-cli-client/user-selarkin-rush-client-invocation-telemetry_2026-10-22-22-32-00.json b/common/changes/@rushstack/rush-cli-client/user-selarkin-rush-client-invocation-telemetry_2026-10-22-22-32-00.json new file mode 100644 index 0000000000..bdf260e3e7 --- /dev/null +++ b/common/changes/@rushstack/rush-cli-client/user-selarkin-rush-client-invocation-telemetry_2026-10-22-22-32-00.json @@ -0,0 +1,10 @@ +{ + "changes": [ + { + "packageName": "@rushstack/rush-cli-client", + "comment": "Add opt-in repository invocation receipts and asynchronous reporting with correlated launcher/fallback attempts, original attribution, real client-return timing, and persisted original delivery targets for safe retries after reporter startup failures.", + "type": "minor" + } + ], + "packageName": "@rushstack/rush-cli-client" +} \ No newline at end of file