History

e2e: repro stale launchd registration causing 15s dead wait at desktop boot

Rhys Sullivan committed 4 months ago

Commit 13eca551 parent 68da8c22 files · +884 −-1Browse files

Unified · Split

2 files
  1. e2e/desktop-packaged/stale-launchd-registration.test.ts +885 −0
  2. e2e/recordings/stale-launchd-slow-boot.mp4 +0 −0
e2e/desktop-packaged/stale-launchd-registration.test.ts+885−0
@@ -0,0 +1,885 @@
1/* oxlint-disable executor/no-try-catch-or-throw, executor/no-error-constructor, executor/no-promise-reject -- e2e boundary: drives launchd, a packaged Electron process, CDP, and optional ffmpeg recording */
2import { type ChildProcess, execFile, execFileSync, spawn } from "node:child_process";
3import {
4 chmodSync,
5 existsSync,
6 mkdirSync,
7 mkdtempSync,
8 readFileSync,
9 rmSync,
10 statSync,
11 writeFileSync,
12} from "node:fs";
13import { homedir, tmpdir } from "node:os";
14import { dirname, join, resolve } from "node:path";
15import { promisify } from "node:util";
16
17import { expect, it } from "@effect/vitest";
18import { Effect } from "effect";
19
20import { scenario } from "../src/scenario";
21import { RunDir } from "../src/services";
22
23const execFileAsync = promisify(execFile);
24const SERVICE_LABEL = "sh.executor.daemon";
25const SCENARIO_NAME =
26 "Desktop packaged supervised attach: stale launchd registration pins the 15s dead boot wait";
27const RECORDING_FILE = resolve("recordings/stale-launchd-slow-boot.mp4");
28const RECORDING_WIDTH = 1280;
29const RECORDING_HEIGHT = 720;
30const STALE_PLIST_PORT = 58_251;
31
32interface PackagedExecutorBridge {
33 readonly getServerConnection: () => Promise<{
34 readonly kind: string;
35 readonly origin: string;
36 } | null>;
37}
38
39interface PackagedApp {
40 readonly child: ChildProcess;
41 cdp: CdpPage;
42 readonly debugPort: string;
43 readonly output: () => string;
44}
45
46interface CdpResponse<T> {
47 readonly id: number;
48 readonly result?: T;
49 readonly error?: { readonly message?: string; readonly data?: string };
50}
51
52interface CdpEvaluateResult {
53 readonly result: { readonly value?: unknown };
54 readonly exceptionDetails?: unknown;
55}
56
57interface CdpTarget {
58 readonly type: string;
59 readonly url: string;
60 readonly webSocketDebuggerUrl?: string;
61}
62
63interface ServerManifest {
64 readonly kind: string;
65 readonly pid: number;
66}
67
68interface LaunchTiming {
69 readonly app: PackagedApp;
70 readonly pageCdpMs: number;
71}
72
73interface BootResult {
74 readonly pageCdpMs: number;
75 readonly sidecarReadyMs: number;
76 readonly connectionKind: string;
77 readonly origin: string;
78 readonly manifestKind: string;
79 readonly manifestPid: number;
80 readonly matchedLogLine: string | null;
81}
82
83declare global {
84 interface Window {
85 readonly executor: PackagedExecutorBridge;
86 }
87}
88
89class CdpPage {
90 private nextId = 1;
91 private readonly pending = new Map<
92 number,
93 {
94 readonly resolve: (value: unknown) => void;
95 readonly reject: (error: Error) => void;
96 }
97 >();
98
99 private constructor(private readonly socket: WebSocket) {
100 socket.addEventListener("message", (event) => {
101 const data = event.data;
102 if (typeof data !== "string") return;
103 const message = JSON.parse(data) as CdpResponse<unknown>;
104 if (!message.id) return;
105 const pending = this.pending.get(message.id);
106 if (!pending) return;
107 this.pending.delete(message.id);
108 if (message.error) {
109 pending.reject(new Error(message.error.message ?? "CDP command failed"));
110 return;
111 }
112 pending.resolve(message.result);
113 });
114 socket.addEventListener("close", () => {
115 for (const [, pending] of this.pending) {
116 pending.reject(new Error("CDP socket closed"));
117 }
118 this.pending.clear();
119 });
120 }
121
122 static connect = (url: string): Promise<CdpPage> =>
123 new Promise((resolveConnect, rejectConnect) => {
124 const socket = new WebSocket(url);
125 const timer = setTimeout(() => {
126 socket.close();
127 rejectConnect(new Error(`Timed out connecting to page CDP target ${url}`));
128 }, 30_000);
129 socket.addEventListener(
130 "open",
131 () => {
132 clearTimeout(timer);
133 resolveConnect(new CdpPage(socket));
134 },
135 { once: true },
136 );
137 socket.addEventListener(
138 "error",
139 () => {
140 clearTimeout(timer);
141 rejectConnect(new Error(`Failed to connect to page CDP target ${url}`));
142 },
143 { once: true },
144 );
145 });
146
147 command = async <T>(method: string, params: Record<string, unknown> = {}): Promise<T> => {
148 const id = this.nextId;
149 this.nextId += 1;
150 const result = new Promise<T>((resolveCommand, rejectCommand) => {
151 this.pending.set(id, {
152 resolve: (value) => resolveCommand(value as T),
153 reject: rejectCommand,
154 });
155 });
156 this.socket.send(JSON.stringify({ id, method, params }));
157 return result;
158 };
159
160 evaluate = async <T>(expression: string): Promise<T> => {
161 const result = await this.command<CdpEvaluateResult>("Runtime.evaluate", {
162 expression,
163 awaitPromise: true,
164 returnByValue: true,
165 });
166 if (result.exceptionDetails) {
167 throw new Error(`CDP evaluation failed: ${JSON.stringify(result.exceptionDetails)}`);
168 }
169 return result.result.value as T;
170 };
171
172 waitForText = async (text: string, timeoutMs: number): Promise<void> => {
173 const deadline = Date.now() + timeoutMs;
174 const expression = `document.body?.innerText.includes(${JSON.stringify(text)}) ?? false`;
175 for (;;) {
176 if (await this.evaluate<boolean>(expression).catch(() => false)) return;
177 if (Date.now() >= deadline) throw new Error(`Timed out waiting for text: ${text}`);
178 await new Promise((resolveWait) => setTimeout(resolveWait, 250));
179 }
180 };
181
182 setViewport = async (width: number, height: number): Promise<void> => {
183 await this.command("Emulation.setDeviceMetricsOverride", {
184 width,
185 height,
186 deviceScaleFactor: 1,
187 mobile: false,
188 });
189 };
190
191 screenshot = async (path: string): Promise<void> => {
192 const result = await this.command<{ readonly data: string }>("Page.captureScreenshot", {
193 format: "png",
194 fromSurface: true,
195 });
196 writeFileSync(path, Buffer.from(result.data, "base64"));
197 };
198
199 close = (): void => {
200 this.socket.close();
201 };
202}
203
204const appExe = process.env.E2E_DESKTOP_APP_EXE;
205const executorBin = process.env.E2E_DESKTOP_EXECUTOR_BIN;
206
207const macAquaAvailable = (): boolean => {
208 if (process.platform !== "darwin") return false;
209 try {
210 return execFileSync("launchctl", ["managername"], { encoding: "utf8" }).trim() === "Aqua";
211 } catch {
212 return false;
213 }
214};
215
216const packagedSingleInstanceAvailable = (): boolean => {
217 if (process.platform !== "darwin" || !appExe) return true;
218 try {
219 const lines = execFileSync("pgrep", ["-fl", "Executor.app/Contents/MacOS/Executor"], {
220 encoding: "utf8",
221 })
222 .split("\n")
223 .filter(Boolean);
224 return !lines.some((line) => !line.includes(appExe));
225 } catch {
226 return true;
227 }
228};
229
230const requireBundle = (): { readonly app: string; readonly executor: string } => {
231 if (!appExe || !executorBin) {
232 throw new Error(
233 "E2E_DESKTOP_APP_EXE / E2E_DESKTOP_EXECUTOR_BIN not set, did desktop-packaged.globalsetup run?",
234 );
235 }
236 return { app: appExe, executor: executorBin };
237};
238
239const currentUid = (): number => {
240 const getuid = (process as { readonly getuid?: () => number }).getuid;
241 return typeof getuid === "function" ? getuid.call(process) : 0;
242};
243
244const serviceTarget = (): string => `gui/${currentUid()}/${SERVICE_LABEL}`;
245const launchAgentPath = (): string =>
246 join(homedir(), "Library", "LaunchAgents", `${SERVICE_LABEL}.plist`);
247const isolatedDesktopSettingsDir = (home: string): string =>
248 join(home, ".executor-desktop-settings");
249
250const packagedAppEnv = (home: string): NodeJS.ProcessEnv => ({
251 ...process.env,
252 HOME: home,
253 EXECUTOR_DESKTOP_SETTINGS_DIR: isolatedDesktopSettingsDir(home),
254});
255
256const cleanBootEnv = (home: string): NodeJS.ProcessEnv => ({
257 ...packagedAppEnv(home),
258 EXECUTOR_TEST_SKIP_BACKGROUND_SERVICE: "1",
259 EXECUTOR_TEST_AUTO_CONFIRM_BACKGROUND_SERVICE: "0",
260});
261
262interface LaunchdServiceSnapshot {
263 readonly plist: string | null;
264 readonly wasLoaded: boolean;
265}
266
267const launchctl = async (args: ReadonlyArray<string>): Promise<boolean> => {
268 try {
269 await execFileAsync("launchctl", [...args]);
270 return true;
271 } catch {
272 return false;
273 }
274};
275
276const captureLaunchdService = (): LaunchdServiceSnapshot | null => {
277 if (process.platform !== "darwin") return null;
278 const path = launchAgentPath();
279 const plist = existsSync(path) ? readFileSync(path, "utf8") : null;
280 let wasLoaded = false;
281 try {
282 execFileSync("launchctl", ["print", serviceTarget()], { stdio: "ignore" });
283 wasLoaded = true;
284 } catch {
285 wasLoaded = false;
286 }
287 return { plist, wasLoaded };
288};
289
290const restoreLaunchdService = async (snapshot: LaunchdServiceSnapshot | null): Promise<void> => {
291 if (!snapshot) return;
292 const target = serviceTarget();
293 await launchctl(["bootout", target]);
294 const path = launchAgentPath();
295 if (snapshot.plist === null) {
296 rmSync(path, { force: true });
297 return;
298 }
299 mkdirSync(dirname(path), { recursive: true });
300 writeFileSync(path, snapshot.plist, { mode: 0o600 });
301 chmodSync(path, 0o600);
302 await launchctl(["enable", target]);
303 if (snapshot.wasLoaded) {
304 const bootstrapped = await launchctl(["bootstrap", `gui/${currentUid()}`, path]);
305 if (bootstrapped) await launchctl(["kickstart", "-k", target]);
306 }
307};
308
309const waitForPageWebSocket = async (debugPort: string): Promise<string> => {
310 const deadline = Date.now() + 120_000;
311 for (;;) {
312 const targets = (await fetch(`http://127.0.0.1:${debugPort}/json/list`)
313 .then((response) => (response.ok ? response.json() : []))
314 .catch(() => [])) as ReadonlyArray<CdpTarget>;
315 const page = targets.find(
316 (target) =>
317 target.type === "page" &&
318 target.webSocketDebuggerUrl &&
319 !target.url.startsWith("devtools://"),
320 );
321 if (page?.webSocketDebuggerUrl) return page.webSocketDebuggerUrl;
322 if (Date.now() >= deadline) {
323 throw new Error("Timed out waiting for packaged app page CDP target");
324 }
325 await new Promise((resolveWait) => setTimeout(resolveWait, 100));
326 }
327};
328
329const launchPackaged = async (
330 env: NodeJS.ProcessEnv,
331 recorder: BootRecorder | null,
332): Promise<LaunchTiming> => {
333 const { app } = requireBundle();
334 const startedAt = Date.now();
335 let output = "";
336 let settled = false;
337 const child = spawn(app, ["--remote-debugging-port=0"], {
338 env,
339 stdio: ["ignore", "pipe", "pipe"],
340 });
341 recorder?.start(startedAt);
342
343 try {
344 const browserCdpUrl = await new Promise<string>((resolveLaunch, rejectLaunch) => {
345 const timer = setTimeout(() => {
346 rejectLaunch(new Error(`Timed out waiting for packaged app CDP URL\n${output}`));
347 }, 120_000);
348 const settle = (fn: () => void) => {
349 if (settled) return;
350 settled = true;
351 clearTimeout(timer);
352 fn();
353 };
354 const collectOutput = (chunk: Buffer) => {
355 const text = chunk.toString();
356 output = (output + text).slice(-16_384);
357 const match = output.match(/DevTools listening on (ws:\/\/[^\s]+)/);
358 if (match) settle(() => resolveLaunch(match[1]));
359 };
360 child.stdout?.on("data", collectOutput);
361 child.stderr?.on("data", collectOutput);
362 child.once("error", (error) => settle(() => rejectLaunch(error)));
363 child.once("exit", (code, signal) =>
364 settle(() =>
365 rejectLaunch(
366 new Error(`Packaged app exited before CDP (code=${code} signal=${signal})\n${output}`),
367 ),
368 ),
369 );
370 });
371
372 const debugPort = new URL(browserCdpUrl).port;
373 const pageCdpUrl = await waitForPageWebSocket(debugPort);
374 const cdp = await CdpPage.connect(pageCdpUrl);
375 await cdp.command("Runtime.enable");
376 await cdp.command("Page.enable");
377 await cdp.setViewport(RECORDING_WIDTH, RECORDING_HEIGHT);
378 recorder?.attachPage(cdp);
379 return {
380 app: { child, cdp, debugPort, output: () => output },
381 pageCdpMs: Date.now() - startedAt,
382 };
383 } catch (error) {
384 await stopProcess(child);
385 throw error;
386 }
387};
388
389const stopProcess = async (child: ChildProcess | undefined): Promise<void> => {
390 if (!child || child.exitCode !== null || child.signalCode !== null) return;
391 await new Promise<void>((resolveStop) => {
392 const timeout = setTimeout(() => {
393 child.kill("SIGKILL");
394 resolveStop();
395 }, 5_000);
396 child.once("exit", () => {
397 clearTimeout(timeout);
398 resolveStop();
399 });
400 child.kill("SIGTERM");
401 });
402};
403
404const closePackaged = async (app: PackagedApp | undefined): Promise<void> => {
405 app?.cdp.close();
406 await stopProcess(app?.child);
407};
408
409const xmlEscape = (value: string): string =>
410 value
411 .replaceAll("&", "&amp;")
412 .replaceAll('"', "&quot;")
413 .replaceAll(">", "&gt;")
414 .replaceAll("<", "&lt;");
415
416const writeStaleLaunchAgentPlist = (home: string): void => {
417 const { executor } = requireBundle();
418 const dataDir = join(home, ".executor");
419 const logs = join(dataDir, "logs");
420 const plistDir = join(home, "Library", "LaunchAgents");
421 mkdirSync(plistDir, { recursive: true });
422 mkdirSync(logs, { recursive: true });
423 mkdirSync(dataDir, { recursive: true });
424
425 const programArguments = [
426 executor,
427 "daemon",
428 "run",
429 "--foreground",
430 "--port",
431 String(STALE_PLIST_PORT),
432 "--hostname",
433 "127.0.0.1",
434 ];
435 const programArgs = programArguments
436 .map((arg) => ` <string>${xmlEscape(arg)}</string>`)
437 .join("\n");
438 const plist = `<?xml version="1.0" encoding="UTF-8"?>
439<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
440<plist version="1.0">
441<dict>
442 <key>Label</key>
443 <string>${SERVICE_LABEL}</string>
444 <key>ProgramArguments</key>
445 <array>
446${programArgs}
447 </array>
448 <key>EnvironmentVariables</key>
449 <dict>
450 <key>EXECUTOR_SUPERVISED</key>
451 <string>1</string>
452 <key>EXECUTOR_DATA_DIR</key>
453 <string>${xmlEscape(dataDir)}</string>
454 <key>EXECUTOR_SCOPE_DIR</key>
455 <string>${xmlEscape(dataDir)}</string>
456 <key>EXECUTOR_CLIENT</key>
457 <string>desktop</string>
458 </dict>
459 <key>RunAtLoad</key>
460 <true/>
461 <key>KeepAlive</key>
462 <dict>
463 <key>SuccessfulExit</key>
464 <false/>
465 </dict>
466 <key>ProcessType</key>
467 <string>Background</string>
468 <key>WorkingDirectory</key>
469 <string>${xmlEscape(dataDir)}</string>
470 <key>StandardOutPath</key>
471 <string>${xmlEscape(join(logs, "daemon.log"))}</string>
472 <key>StandardErrorPath</key>
473 <string>${xmlEscape(join(logs, "daemon.error.log"))}</string>
474</dict>
475</plist>
476`;
477 writeFileSync(join(plistDir, `${SERVICE_LABEL}.plist`), plist, { mode: 0o600 });
478};
479
480const readServerManifest = (home: string): ServerManifest => {
481 const manifestPath = join(home, ".executor", "server-control", "server.json");
482 return JSON.parse(readFileSync(manifestPath, "utf8")) as ServerManifest;
483};
484
485const readKickstartFailureLine = (home: string): string | null => {
486 const logPath = join(home, "Library", "Logs", "Executor", "main.log");
487 if (!existsSync(logPath)) return null;
488 return (
489 readFileSync(logPath, "utf8")
490 .split("\n")
491 .find(
492 (line) =>
493 line.includes("launchctl kickstart failed (exit 113)") &&
494 line.includes('Could not find service "sh.executor.daemon"'),
495 ) ?? null
496 );
497};
498
499const waitForKickstartFailureLine = async (home: string): Promise<string> => {
500 const deadline = Date.now() + 30_000;
501 for (;;) {
502 const line = readKickstartFailureLine(home);
503 if (line) return line;
504 if (Date.now() >= deadline) {
505 const logPath = join(home, "Library", "Logs", "Executor", "main.log");
506 const tail = existsSync(logPath)
507 ? readFileSync(logPath, "utf8").split("\n").slice(-20).join("\n")
508 : "<main.log missing>";
509 throw new Error(`Timed out waiting for kickstart failure log line\n${tail}`);
510 }
511 await new Promise((resolveWait) => setTimeout(resolveWait, 250));
512 }
513};
514
515const bootPackagedApp = async (input: {
516 readonly home: string;
517 readonly env: NodeJS.ProcessEnv;
518 readonly recorder: BootRecorder | null;
519 readonly expectKickstartFailure: boolean;
520}): Promise<BootResult> => {
521 let app: PackagedApp | undefined;
522 const startedAt = Date.now();
523 try {
524 const launched = await launchPackaged(input.env, input.recorder);
525 app = launched.app;
526 const page = app.cdp;
527 await page.waitForText("Settings", 120_000);
528 const sidecarReadyMs = Date.now() - startedAt;
529 await input.recorder?.captureReadyFrame();
530 await input.recorder?.captureReadyFrame();
531 const connection = await page.evaluate<{
532 readonly kind: string;
533 readonly origin: string;
534 } | null>("window.executor.getServerConnection()");
535 expect(connection, "the app eventually exposes a server connection").not.toBeNull();
536 const manifest = readServerManifest(input.home);
537 const matchedLogLine = input.expectKickstartFailure
538 ? await waitForKickstartFailureLine(input.home)
539 : readKickstartFailureLine(input.home);
540 return {
541 pageCdpMs: launched.pageCdpMs,
542 sidecarReadyMs,
543 connectionKind: connection!.kind,
544 origin: connection!.origin,
545 manifestKind: manifest.kind,
546 manifestPid: manifest.pid,
547 matchedLogLine,
548 };
549 } finally {
550 await input.recorder?.stop();
551 await closePackaged(app);
552 }
553};
554
555const commandAvailable = (command: string): boolean => {
556 try {
557 execFileSync("which", [command], { stdio: "ignore" });
558 return true;
559 } catch {
560 return false;
561 }
562};
563
564const emitEvidence = (line: string): void => {
565 execFileSync("printf", ["%s\n", line], { stdio: "inherit" });
566};
567
568const FONT: Record<string, readonly string[]> = {
569 " ": ["00000", "00000", "00000", "00000", "00000", "00000", "00000"],
570 ".": ["00000", "00000", "00000", "00000", "00000", "01100", "01100"],
571 "0": ["11110", "10010", "10010", "10010", "10010", "10010", "11110"],
572 "1": ["00100", "01100", "00100", "00100", "00100", "00100", "01110"],
573 "2": ["11110", "00010", "00010", "11110", "10000", "10000", "11110"],
574 "3": ["11110", "00010", "00010", "01110", "00010", "00010", "11110"],
575 "4": ["10010", "10010", "10010", "11110", "00010", "00010", "00010"],
576 "5": ["11110", "10000", "10000", "11110", "00010", "00010", "11110"],
577 "6": ["11110", "10000", "10000", "11110", "10010", "10010", "11110"],
578 "7": ["11110", "00010", "00010", "00100", "00100", "01000", "01000"],
579 "8": ["11110", "10010", "10010", "11110", "10010", "10010", "11110"],
580 "9": ["11110", "10010", "10010", "11110", "00010", "00010", "11110"],
581 A: ["01110", "10001", "10001", "11111", "10001", "10001", "10001"],
582 B: ["11110", "10001", "10001", "11110", "10001", "10001", "11110"],
583 C: ["01111", "10000", "10000", "10000", "10000", "10000", "01111"],
584 D: ["11110", "10001", "10001", "10001", "10001", "10001", "11110"],
585 E: ["11111", "10000", "10000", "11110", "10000", "10000", "11111"],
586 F: ["11111", "10000", "10000", "11110", "10000", "10000", "10000"],
587 G: ["01111", "10000", "10000", "10011", "10001", "10001", "01111"],
588 H: ["10001", "10001", "10001", "11111", "10001", "10001", "10001"],
589 I: ["11111", "00100", "00100", "00100", "00100", "00100", "11111"],
590 J: ["00111", "00010", "00010", "00010", "10010", "10010", "01100"],
591 K: ["10001", "10010", "10100", "11000", "10100", "10010", "10001"],
592 L: ["10000", "10000", "10000", "10000", "10000", "10000", "11111"],
593 M: ["10001", "11011", "10101", "10101", "10001", "10001", "10001"],
594 N: ["10001", "11001", "10101", "10011", "10001", "10001", "10001"],
595 O: ["01110", "10001", "10001", "10001", "10001", "10001", "01110"],
596 P: ["11110", "10001", "10001", "11110", "10000", "10000", "10000"],
597 Q: ["01110", "10001", "10001", "10001", "10101", "10010", "01101"],
598 R: ["11110", "10001", "10001", "11110", "10100", "10010", "10001"],
599 S: ["01111", "10000", "10000", "01110", "00001", "00001", "11110"],
600 T: ["11111", "00100", "00100", "00100", "00100", "00100", "00100"],
601 U: ["10001", "10001", "10001", "10001", "10001", "10001", "01110"],
602 V: ["10001", "10001", "10001", "10001", "10001", "01010", "00100"],
603 W: ["10001", "10001", "10001", "10101", "10101", "10101", "01010"],
604 X: ["10001", "10001", "01010", "00100", "01010", "10001", "10001"],
605 Y: ["10001", "10001", "01010", "00100", "00100", "00100", "00100"],
606 Z: ["11111", "00001", "00010", "00100", "01000", "10000", "11111"],
607};
608
609const putPixel = (pixels: Buffer, width: number, x: number, y: number, rgb: readonly number[]) => {
610 const index = (y * width + x) * 3;
611 pixels[index] = rgb[0];
612 pixels[index + 1] = rgb[1];
613 pixels[index + 2] = rgb[2];
614};
615
616const fillRect = (
617 pixels: Buffer,
618 width: number,
619 x: number,
620 y: number,
621 rectWidth: number,
622 rectHeight: number,
623 rgb: readonly number[],
624): void => {
625 for (let yy = y; yy < y + rectHeight; yy += 1) {
626 for (let xx = x; xx < x + rectWidth; xx += 1) {
627 putPixel(pixels, width, xx, yy, rgb);
628 }
629 }
630};
631
632const writePpm = (path: string, width: number, height: number, pixels: Buffer): void => {
633 writeFileSync(path, Buffer.concat([Buffer.from(`P6\n${width} ${height}\n255\n`), pixels]));
634};
635
636const makeLabelPpm = (path: string, label: string, height: number): void => {
637 const pixels = Buffer.alloc(RECORDING_WIDTH * height * 3);
638 fillRect(pixels, RECORDING_WIDTH, 0, 0, RECORDING_WIDTH, height, [17, 18, 23]);
639 fillRect(pixels, RECORDING_WIDTH, 0, 0, RECORDING_WIDTH, 110, [0, 0, 0]);
640 const scale = 6;
641 let x = 34;
642 const y = 34;
643 for (const char of label.toUpperCase()) {
644 const glyph = FONT[char] ?? FONT[" "];
645 for (let row = 0; row < glyph.length; row += 1) {
646 for (let col = 0; col < glyph[row].length; col += 1) {
647 if (glyph[row][col] === "1") {
648 fillRect(
649 pixels,
650 RECORDING_WIDTH,
651 x + col * scale,
652 y + row * scale,
653 scale,
654 scale,
655 [255, 255, 255],
656 );
657 }
658 }
659 }
660 x += 6 * scale;
661 if (x > RECORDING_WIDTH - 40) break;
662 }
663 writePpm(path, RECORDING_WIDTH, height, pixels);
664};
665
666class BootRecorder {
667 private frame = 0;
668 private page: CdpPage | null = null;
669 private startedAt = 0;
670 private timer: ReturnType<typeof setInterval> | null = null;
671 private queue: Promise<void> = Promise.resolve();
672 private enabled: boolean;
673
674 constructor(
675 private readonly frameDir: string,
676 private readonly outputPath: string,
677 ) {
678 this.enabled = process.env.E2E_RECORD === "1" && commandAvailable("ffmpeg");
679 }
680
681 static create = (runDir: string): BootRecorder | null => {
682 if (process.env.E2E_RECORD !== "1") return null;
683 const frameDir = join(runDir, "stale-launchd-slow-boot-frames");
684 rmSync(frameDir, { recursive: true, force: true });
685 mkdirSync(frameDir, { recursive: true });
686 mkdirSync(dirname(RECORDING_FILE), { recursive: true });
687 rmSync(RECORDING_FILE, { force: true });
688 return new BootRecorder(frameDir, RECORDING_FILE);
689 };
690
691 start = (startedAt: number): void => {
692 this.startedAt = startedAt;
693 if (!this.enabled) return;
694 this.enqueueFrame("waiting for Electron window", null);
695 this.timer = setInterval(() => {
696 this.enqueueFrame(
697 this.page ? "app window reachable" : "waiting for Electron window",
698 this.page,
699 );
700 }, 1_000);
701 };
702
703 attachPage = (page: CdpPage): void => {
704 this.page = page;
705 this.enqueueFrame("app window reachable", page);
706 };
707
708 captureReadyFrame = async (): Promise<void> => {
709 if (!this.enabled) return;
710 this.enqueueFrame("managed sidecar ready", this.page);
711 await this.queue;
712 };
713
714 stop = async (): Promise<void> => {
715 if (this.timer) {
716 clearInterval(this.timer);
717 this.timer = null;
718 }
719 if (!this.enabled) return;
720 await this.queue;
721 if (this.frame > 0) {
722 execFileSync(
723 "ffmpeg",
724 [
725 "-y",
726 "-framerate",
727 "1",
728 "-i",
729 join(this.frameDir, "frame-%04d.ppm"),
730 "-pix_fmt",
731 "yuv420p",
732 "-movflags",
733 "+faststart",
734 this.outputPath,
735 ],
736 { stdio: "ignore" },
737 );
738 }
739 };
740
741 recordingStats = (): {
742 readonly path: string;
743 readonly size: number;
744 readonly frames: number;
745 } | null => {
746 if (!existsSync(this.outputPath)) return null;
747 return { path: this.outputPath, size: statSync(this.outputPath).size, frames: this.frame };
748 };
749
750 private enqueueFrame = (state: string, page: CdpPage | null): void => {
751 if (!this.enabled) return;
752 this.queue = this.queue
753 .then(() => this.writeFrame(state, page))
754 .catch((error) => {
755 this.enabled = false;
756 console.warn(`[stale-launchd-repro] recording disabled after frame error: ${error}`);
757 });
758 };
759
760 private writeFrame = async (state: string, page: CdpPage | null): Promise<void> => {
761 this.frame += 1;
762 const elapsedSeconds = (Date.now() - this.startedAt) / 1000;
763 const output = join(this.frameDir, `frame-${String(this.frame).padStart(4, "0")}.ppm`);
764 const label = `${elapsedSeconds.toFixed(1)}s ${state}`;
765 if (!page) {
766 makeLabelPpm(output, label, RECORDING_HEIGHT);
767 return;
768 }
769 const raw = join(this.frameDir, `raw-${String(this.frame).padStart(4, "0")}.png`);
770 const labelFrame = join(this.frameDir, `label-${String(this.frame).padStart(4, "0")}.ppm`);
771 await page.screenshot(raw);
772 makeLabelPpm(labelFrame, label, 110);
773 execFileSync(
774 "ffmpeg",
775 [
776 "-y",
777 "-i",
778 raw,
779 "-i",
780 labelFrame,
781 "-filter_complex",
782 `[0:v]scale=${RECORDING_WIDTH}:${RECORDING_HEIGHT}:force_original_aspect_ratio=decrease,pad=${RECORDING_WIDTH}:${RECORDING_HEIGHT}:(ow-iw)/2:(oh-ih)/2:color=black[base];[base][1:v]overlay=0:0`,
783 "-frames:v",
784 "1",
785 output,
786 ],
787 { stdio: "ignore" },
788 );
789 rmSync(raw, { force: true });
790 rmSync(labelFrame, { force: true });
791 };
792}
793
794const run = async (runDir: string): Promise<void> => {
795 const cleanHome = mkdtempSync(join(tmpdir(), "executor-pkg-clean-boot-control-"));
796 const staleHome = mkdtempSync(join(tmpdir(), "executor-pkg-stale-launchd-"));
797 const launchdSnapshot = captureLaunchdService();
798 const staleRecorder = BootRecorder.create(runDir);
799
800 try {
801 const clean = await bootPackagedApp({
802 home: cleanHome,
803 env: cleanBootEnv(cleanHome),
804 recorder: null,
805 expectKickstartFailure: false,
806 });
807
808 writeStaleLaunchAgentPlist(staleHome);
809 await launchctl(["bootout", serviceTarget()]);
810 const stale = await bootPackagedApp({
811 home: staleHome,
812 env: packagedAppEnv(staleHome),
813 recorder: staleRecorder,
814 expectKickstartFailure: true,
815 });
816
817 /*
818 * Regression pin for the current broken behavior:
819 * a stale plist makes `service status` report registered even though launchd
820 * cannot find the label. The packaged app logs the kickstart failure, then
821 * still pays the full 15s wait before falling back to managed-spawn.
822 *
823 * When the fix lands, invert the >=14s stale assertions. The desired
824 * behavior is a fast-fail to managed-spawn, close to the clean control.
825 */
826 expect(stale.matchedLogLine, "stale boot logs the launchd kickstart failure").toContain(
827 "launchctl kickstart failed (exit 113)",
828 );
829 expect(stale.matchedLogLine, "stale boot says launchd cannot find the label").toContain(
830 'Could not find service "sh.executor.daemon"',
831 );
832 expect(
833 stale.pageCdpMs,
834 "window/CDP is not reachable until the dead wait is paid",
835 ).toBeGreaterThanOrEqual(14_000);
836 expect(
837 stale.sidecarReadyMs,
838 "managed sidecar readiness is delayed by the dead wait",
839 ).toBeGreaterThanOrEqual(14_000);
840 expect(stale.connectionKind, "the app eventually recovers through managed-spawn").toBe(
841 "desktop-sidecar",
842 );
843 expect(
844 new URL(stale.origin).port,
845 "managed recovery must not be a launchd attach to the stale plist port",
846 ).not.toBe(String(STALE_PLIST_PORT));
847 expect(
848 clean.sidecarReadyMs,
849 "the clean control skips supervision and boots quickly",
850 ).toBeLessThan(10_000);
851 expect(
852 stale.sidecarReadyMs,
853 "the stale launchd path is dramatically slower than the clean control",
854 ).toBeGreaterThan(clean.sidecarReadyMs + 5_000);
855
856 const recording = staleRecorder?.recordingStats();
857 emitEvidence(
858 `[stale-launchd-repro] clean=${clean.sidecarReadyMs}ms stale=${stale.sidecarReadyMs}ms stalePageCdp=${stale.pageCdpMs}ms cleanOrigin=${clean.origin} staleOrigin=${stale.origin} staleConnectionKind=${stale.connectionKind} staleManifestKind=${stale.manifestKind} stalePid=${stale.manifestPid}`,
859 );
860 emitEvidence(`[stale-launchd-repro] matchedLogLine=${stale.matchedLogLine}`);
861 if (recording) {
862 emitEvidence(
863 `[stale-launchd-repro] recording=${recording.path} frames=${recording.frames} size=${recording.size}`,
864 );
865 }
866 } finally {
867 await restoreLaunchdService(launchdSnapshot);
868 rmSync(cleanHome, { recursive: true, force: true });
869 rmSync(staleHome, { recursive: true, force: true });
870 }
871};
872
873if (!macAquaAvailable() || !packagedSingleInstanceAvailable()) {
874 it.skip(`${SCENARIO_NAME} (needs macOS Aqua and no already-running Executor.app)`, () => {});
875} else {
876 scenario(
877 SCENARIO_NAME,
878 { timeout: 360_000 },
879 Effect.gen(function* () {
880 requireBundle();
881 const runDir = yield* RunDir;
882 yield* Effect.promise(() => run(runDir));
883 }),
884 );
885}
e2e/recordings/stale-launchd-slow-boot.mp4+0−0

Binary file not shown.

Keyboard shortcuts

General

Show keyboard shortcuts
?
Focus the current search
/

Issues and pull requests

Open filters
f

Issues, pull requests and Inbox

Select next item
j↓
Select previous item
k↑
Open selected item
Enter
Dismiss filters or clear selection
Esc

Repository code

Go to file
t