[api] Add timing collection and dump via environment variable (#64846)

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
Copilot-Session: 9920adc3-3fc7-4d27-8ec1-c9c4490b9cf9

Author: andrewbranch

packages/typescript/src/api/async/api.ts

@@ -838,8 +838,8 @@ export class API<FromLSP extends boolean = false> implements FormatDiagnosticsHo
      *
      * Fetching the snapshot issues a lightweight request to the server to
      * retrieve its timing collection. Collection must be enabled via the
-     * `collectTiming` option; when it is not, the returned snapshot has
-     * `enabled: false` and zeroed totals.
+     * `collectTiming` option or `TS_API_TIMING_DIR` environment variable; when
+     * it is not, the returned snapshot has `enabled: false` and zeroed totals.
      */
     getTimingInfo(): Promise<TimingInfo> {
         return this.client.getTimingInfo();

packages/typescript/src/api/async/client.ts

@@ -43,6 +43,7 @@ import {
     TimingCollector,
     type TimingInfo,
 } from "../timing.ts";
+import { TimingDump } from "../timingDump.ts";
 
 export type { ClientOptions, ClientSocketOptions, ClientSpawnOptions };
 
@@ -59,16 +60,22 @@ export class Client {
     private closed = false;
     private connecting: Promise<void> | undefined;
     private timing: TimingCollector | undefined;
+    private timingDump: TimingDump | undefined;
+    private closing: Promise<void> | undefined;
     private batchedRequests: { method: APIRequest["method"]; params: APIRequest["params"]; resolve: (value: unknown) => void; reject: (reason?: any) => void; }[] = [];
     private nextBatch: NodeJS.Immediate | "manual" | undefined;
 
     constructor(options: ClientOptions) {
+        this.timingDump = TimingDump.fromEnvironment("async", isSpawnOptions(options) ? "spawn" : "socket");
+        if (this.timingDump || isSpawnOptions(options) && options.collectTiming) {
+            this.timing = new TimingCollector();
+        }
+        if (this.timingDump && isSpawnOptions(options)) {
+            options = { ...options, collectTiming: true };
+        }
         this.options = options;
         if (isSpawnOptions(options)) {
             configureFileSystemCallbacks(options.fs);
-            if (options.collectTiming) {
-                this.timing = new TimingCollector();
-            }
         }
     }
 
@@ -401,26 +408,52 @@ export class Client {
         return this.connection.sendRequest(requestType, undefined);
     }
 
-    async close(): Promise<void> {
+    close(): Promise<void> {
+        return this.closing ??= this.closeWorker();
+    }
+
+    private async closeWorker(): Promise<void> {
         await this.connecting?.catch(() => {}); // if connection is still in-progress, wait for it to finish before closing the connection
         this.closed = true;
-        if (this.connection) {
-            this.connection.dispose();
-            this.connection = undefined;
-        }
-        if (this.socket) {
-            this.socket.destroy();
-            this.socket = undefined;
+        try {
+            if (this.timingDump && this.timing) {
+                const local = this.timing.getInfo();
+                let server: ServerTimingInfo | undefined;
+                let serverTimingError: string | undefined;
+                const connection = this.connection;
+                // Closing alone does not reject pending JSON-RPC requests.
+                const onClose = connection?.onClose(() => connection.dispose());
+                try {
+                    if (this.connected) server = await this.fetchServerTiming();
+                }
+                catch (error) {
+                    serverTimingError = String(error);
+                }
+                finally {
+                    onClose?.dispose();
+                }
+                this.timingDump.write(local, server, serverTimingError);
+            }
         }
-        if (this.process) {
-            // Close stdin to unblock the server's read loop, allowing it to exit cleanly.
-            // The server is blocked on stdin.Read(), so just sending SIGTERM would deadlock:
-            // - Node won't exit while child is alive
-            // - Child can't process SIGTERM while blocked on read
-            // - Read won't error until stdin is closed
-            this.process.stdin?.end();
-            this.process = undefined;
+        finally {
+            if (this.connection) {
+                this.connection.dispose();
+                this.connection = undefined;
+            }
+            if (this.socket) {
+                this.socket.destroy();
+                this.socket = undefined;
+            }
+            if (this.process) {
+                // Close stdin to unblock the server's read loop, allowing it to exit cleanly.
+                // The server is blocked on stdin.Read(), so just sending SIGTERM would deadlock:
+                // - Node won't exit while child is alive
+                // - Child can't process SIGTERM while blocked on read
+                // - Read won't error until stdin is closed
+                this.process.stdin?.end();
+                this.process = undefined;
+            }
+            this.connected = false;
         }
-        this.connected = false;
     }
 }

packages/typescript/src/api/options.ts

@@ -33,6 +33,9 @@ export interface ClientSpawnOptions {
      * measures its own per-request processing time; both are combined (along
      * with an estimated transport overhead) in the snapshot returned by
      * {@link API.getTimingInfo}.
+     * Setting `TS_API_TIMING_DIR` to a nonempty output directory also enables
+     * collection, even when this option is false, and writes a JSON snapshot
+     * when the API is closed.
      */
     collectTiming?: boolean | undefined;
 }

packages/typescript/src/api/sync/api.ts

@@ -1343,8 +1343,8 @@ export class API<FromLSP extends boolean = false> implements FormatDiagnosticsHo
      *
      * Fetching the snapshot issues a lightweight request to the server to
      * retrieve its timing collection. Collection must be enabled via the
-     * `collectTiming` option; when it is not, the returned snapshot has
-     * `enabled: false` and zeroed totals.
+     * `collectTiming` option or `TS_API_TIMING_DIR` environment variable; when
+     * it is not, the returned snapshot has `enabled: false` and zeroed totals.
      */
     get getTimingInfo(): {
         (): TimingInfo;

packages/typescript/src/api/sync/client.ts

@@ -25,20 +25,27 @@ import {
     TimingCollector,
     type TimingInfo,
 } from "../timing.ts";
+import { TimingDump } from "../timingDump.ts";
 
 export type { ClientOptions, ClientSocketOptions, ClientSpawnOptions };
 
 export class Client {
     private channel: SyncRpcChannel;
     private encoder = new TextEncoder();
     private timing: TimingCollector | undefined;
+    private timingDump: TimingDump | undefined;
+    private closed = false;
     private maxResponseBytesPerPage: number | undefined;
 
     constructor(options: ClientOptions) {
         if (!isSpawnOptions(options)) {
             throw new Error("Socket connections are not yet supported in the sync client");
         }
 
+        this.timingDump = TimingDump.fromEnvironment("sync", "spawn");
+        if (this.timingDump) {
+            options = { ...options, collectTiming: true };
+        }
         const args = getAPIProcessArgs(options, false);
         this.maxResponseBytesPerPage = options.maxResponseBytesPerPage;
 
@@ -184,6 +191,24 @@ export class Client {
     }
 
     close(): void {
-        this.channel.close();
+        if (this.closed) return;
+        this.closed = true;
+        try {
+            if (this.timingDump && this.timing) {
+                const local = this.timing.getInfo();
+                let server: ServerTimingInfo | undefined;
+                let serverTimingError: string | undefined;
+                try {
+                    server = JSON.parse(this.channel.requestSync("getServerTiming", "")) as ServerTimingInfo;
+                }
+                catch (error) {
+                    serverTimingError = String(error);
+                }
+                this.timingDump.write(local, server, serverTimingError);
+            }
+        }
+        finally {
+            this.channel.close();
+        }
     }
 }

packages/typescript/src/api/syncChannel.ts

@@ -113,6 +113,7 @@ export class SyncRpcChannel {
     private writeFd: number;
     private pipeFd: number | undefined;
     private callbacks = new Map<string, (name: string, payload: string) => string>();
+    private callbackFailure: { error: unknown; } | undefined;
 
     private methodBufCache = new Map<string, Buffer>();
 
@@ -280,6 +281,9 @@ export class SyncRpcChannel {
         if (this.readFd < 0) {
             throw new Error("SyncRpcChannel is closed");
         }
+        if (this.callbackFailure) {
+            throw this.callbackFailure.error;
+        }
     }
 
     private getMethodBuf(method: string): Buffer {
@@ -326,7 +330,14 @@ export class SyncRpcChannel {
                     );
                 }
                 case MSG_CALL: {
-                    this.handleCall(this._msgName.toString("utf-8"), this._msgPayload);
+                    try {
+                        this.handleCall(this._msgName.toString("utf-8"), this._msgPayload);
+                    }
+                    catch (error) {
+                        // The pending response is unread, so further I/O cannot be synchronized.
+                        this.callbackFailure = { error };
+                        throw error;
+                    }
                     break;
                 }
                 default:

packages/typescript/src/api/timing.ts

@@ -182,7 +182,7 @@ export function disabledServerTimingInfo(): ServerTimingInfo {
  * requests used to fetch timing) do not misalign the two ring buffers.
  */
 export function combineTimingInfo(client: TimingInfo, server: ServerTimingInfo): TimingInfo {
-    if (!client.enabled) {
+    if (!client.enabled || !server.enabled) {
         return client;
     }
 

packages/typescript/src/api/timingDump.ts

@@ -0,0 +1,55 @@
+import { randomUUID } from "node:crypto";
+import {
+    mkdirSync,
+    writeFileSync,
+} from "node:fs";
+import {
+    join,
+    resolve,
+} from "node:path";
+import {
+    combineTimingInfo,
+    type ServerTimingInfo,
+    type TimingInfo,
+} from "./timing.ts";
+
+/** One final snapshot per client, written before its connection is closed. */
+export class TimingDump {
+    private readonly instanceId = randomUUID();
+    private readonly startedAt = new Date().toISOString();
+    private readonly directory: string;
+    private readonly mode: "sync" | "async";
+    private readonly transport: "spawn" | "socket";
+
+    static fromEnvironment(mode: "sync" | "async", transport: "spawn" | "socket"): TimingDump | undefined {
+        const directory = process.env.TS_API_TIMING_DIR;
+        return directory ? new TimingDump(resolve(directory), mode, transport) : undefined;
+    }
+
+    private constructor(directory: string, mode: "sync" | "async", transport: "spawn" | "socket") {
+        this.directory = directory;
+        this.mode = mode;
+        this.transport = transport;
+    }
+
+    write(client: TimingInfo, server: ServerTimingInfo | undefined, serverTimingError?: string): void {
+        const snapshot = {
+            schemaVersion: 1,
+            instanceId: this.instanceId,
+            pid: process.pid,
+            mode: this.mode,
+            transport: this.transport,
+            startedAt: this.startedAt,
+            closedAt: new Date().toISOString(),
+            timing: server ? combineTimingInfo(client, server) : client,
+            serverTiming: server ?? null,
+            serverTimingError,
+        };
+        mkdirSync(this.directory, { recursive: true });
+        writeFileSync(
+            join(this.directory, `timing-${process.pid}-${this.instanceId}.json`),
+            JSON.stringify(snapshot) + "\n",
+            { flag: "wx" },
+        );
+    }
+}