Skip to content

Commit d54e253

Browse files
committed
[Telemetry] Add E2E test for watchdog/shutdown process & fix shutdown logs reliability
1 parent 299238b commit d54e253

3 files changed

Lines changed: 141 additions & 4 deletions

File tree

src/logger.ts

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -31,4 +31,27 @@ export function saveLogsToFile(fileName: string): fs.WriteStream {
3131
return logFile;
3232
}
3333

34+
export function saveLogsToFileSync(fileName: string): void {
35+
36+
debug.enable(namespacesToEnable.join(','));
37+
38+
let fd: number | undefined;
39+
try {
40+
fd = fs.openSync(fileName, 'a+');
41+
} catch (error: any) {
42+
console.error(`Error when opening log file: ${error.message}`);
43+
process.exit(1);
44+
}
45+
46+
debug.log = function (...chunks: any[]) {
47+
if (fd !== undefined) {
48+
try {
49+
fs.writeSync(fd, `${chunks.join(' ')}\n`);
50+
} catch (e) {
51+
52+
}
53+
}
54+
};
55+
}
56+
3457
export const logger = debug(mcpDebugNamespace);

src/telemetry/watchdog/main.ts

Lines changed: 11 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,7 @@ import readline from 'node:readline';
1111
import yargs from 'yargs';
1212
import {hideBin} from 'yargs/helpers';
1313

14-
import {logger, saveLogsToFile} from '../../logger.js';
14+
import {logger, saveLogsToFileSync} from '../../logger.js';
1515
import {IpcMessageType, OsType} from '../types.js';
1616

1717
import {ClearcutSender} from './clearcut-sender.js';
@@ -40,18 +40,25 @@ async function main() {
4040
.parse();
4141

4242
if (argv.logFile) {
43-
saveLogsToFile(argv.logFile);
43+
saveLogsToFileSync(argv.logFile);
4444
}
4545

46-
logger('Watchdog started', {
46+
logger('Watchdog started', JSON.stringify({
47+
pid: process.pid,
4748
parentPid: argv.parentPid,
4849
version: argv.appVersion,
4950
osType: argv.osType,
50-
});
51+
}, null, 2));
5152

5253
const sender = new ClearcutSender(argv.appVersion, argv.osType as OsType);
5354

55+
let isShuttingDown = false;
5456
function onParentDeath(reason: string) {
57+
if (isShuttingDown) {
58+
return;
59+
}
60+
61+
isShuttingDown = true;
5562
logger(`Parent death detected (${reason}). Sending shutdown event...`);
5663
sender
5764
.sendShutdownEvent()

tests/e2e/telemetry.test.ts

Lines changed: 107 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,107 @@
1+
/**
2+
* @license
3+
* Copyright 2026 Google LLC
4+
* SPDX-License-Identifier: Apache-2.0
5+
*/
6+
7+
import {describe, it} from 'node:test';
8+
import assert from 'node:assert';
9+
import {spawn} from 'node:child_process';
10+
import fs from 'node:fs';
11+
import path from 'node:path';
12+
import os from 'node:os';
13+
14+
describe('Telemetry E2E', () => {
15+
it('spawns server, logs events, and shuts down watchdog cleanly on termination', async () => {
16+
// Setup
17+
const logFile = path.join(os.tmpdir(), `test-mcp-telemetry-${Date.now()}.log`);
18+
const serverPath = path.resolve('build/src/main.js');
19+
20+
if (!fs.existsSync(serverPath)) {
21+
throw new Error(`Server build not found at ${serverPath}. Run 'npm run build' first.`);
22+
}
23+
24+
// Spawn Server
25+
console.log(`Spawning server at ${serverPath} with log file ${logFile}`);
26+
const server = spawn(process.execPath, [
27+
serverPath,
28+
`--log-file=${logFile}`,
29+
'--usage-statistics',
30+
'--headless',
31+
'--app-version=1.0.0'
32+
], {
33+
stdio: ['pipe', 'pipe', 'pipe'],
34+
});
35+
36+
server.stderr.on('data', (d) => console.log(`Stderr: ${d}`));
37+
38+
// Wait for Watchdog start
39+
let watchdogPid: number | undefined;
40+
const waitForWatchdogStart = new Promise<void>((resolve, reject) => {
41+
const checkInterval = setInterval(() => {
42+
if (server.exitCode !== null) {
43+
clearInterval(checkInterval);
44+
reject(new Error(`Server exited early with code ${server.exitCode}`));
45+
return;
46+
}
47+
48+
if (fs.existsSync(logFile)) {
49+
const content = fs.readFileSync(logFile, 'utf8');
50+
const match = content.match(/Watchdog started[\s\S]*?"pid":\s*(\d+)/);
51+
if (match) {
52+
watchdogPid = parseInt(match[1]);
53+
clearInterval(checkInterval);
54+
resolve();
55+
}
56+
}
57+
}, 100);
58+
setTimeout(() => {
59+
clearInterval(checkInterval);
60+
reject(new Error('Timeout waiting for Watchdog start'));
61+
}, 5000);
62+
});
63+
64+
await waitForWatchdogStart;
65+
assert.ok(watchdogPid, 'Watchdog PID not found');
66+
console.log(`Watchdog started with PID ${watchdogPid}`);
67+
68+
// Verify start event logged
69+
const contentBeforeKill = fs.readFileSync(logFile, 'utf8');
70+
assert.match(contentBeforeKill, /server_start/);
71+
72+
// Kill Server with SIGKILL
73+
console.log(`Killing server process ${server.pid} with SIGKILL`);
74+
server.kill('SIGKILL');
75+
76+
// Wait for Watchdog exit
77+
const waitForWatchdogExit = new Promise<void>((resolve, reject) => {
78+
const checkInterval = setInterval(() => {
79+
try {
80+
process.kill(watchdogPid!, 0); // Check if running
81+
} catch (e) {
82+
clearInterval(checkInterval);
83+
resolve();
84+
return;
85+
}
86+
}, 100);
87+
88+
setTimeout(() => {
89+
clearInterval(checkInterval);
90+
try { process.kill(watchdogPid!, 'SIGKILL'); } catch {}
91+
reject(new Error('Timeout waiting for Watchdog exit'));
92+
}, 5000);
93+
});
94+
95+
await waitForWatchdogExit;
96+
console.log('Watchdog process is gone');
97+
98+
// Verify shutdown logged
99+
const contentAfter = fs.readFileSync(logFile, 'utf8');
100+
assert.match(contentAfter, /Parent death detected/);
101+
assert.match(contentAfter, /server_shutdown/);
102+
console.log('Shutdown events verified');
103+
104+
// Cleanup
105+
if (fs.existsSync(logFile)) fs.unlinkSync(logFile);
106+
});
107+
});

0 commit comments

Comments
 (0)