fix: More performance fixes + add dev-only timing instrumentation (#963)

Author: charlesvien

apps/twig/src/main/lib/timing.ts

@@ -1,15 +1,15 @@
+import { createTimingCollector, type TimingCollector } from "@posthog/shared";
+import { app } from "electron";
 import type { ScopedLogger } from "./logger.js";
 
+export type { TimingCollector };
+
 /**
- * Creates a timing helper that logs execution duration.
- * @param log - Scoped logger to use for timing output
- * @returns A function that times async operations and logs the result
+ * Creates a timing collector for the main process.
+ * No-op in packaged (production) builds.
  */
-export function createTimer(log: ScopedLogger) {
-  return async <T>(label: string, fn: () => Promise<T>): Promise<T> => {
-    const start = Date.now();
-    const result = await fn();
-    log.info(`[timing] ${label}: ${Date.now() - start}ms`);
-    return result;
-  };
+export function createMainTimingCollector(log: ScopedLogger): TimingCollector {
+  return createTimingCollector(!app.isPackaged, (msg, data) =>
+    log.info(msg, data),
+  );
 }

apps/twig/src/main/services/agent/schemas.ts

@@ -45,6 +45,8 @@ export const startSessionInput = z.object({
   runMode: z.enum(["local", "cloud"]).optional(),
   adapter: z.enum(["claude", "codex"]).optional(),
   additionalDirectories: z.array(z.string()).optional(),
+  /** Dev-only: timestamp from renderer when user submitted the task */
+  submittedAt: z.number().optional(),
 });
 
 export type StartSessionInput = z.infer<typeof startSessionInput>;

apps/twig/src/main/services/agent/service.ts

@@ -25,6 +25,7 @@ import { app } from "electron";
 import { inject, injectable, preDestroy } from "inversify";
 import { MAIN_TOKENS } from "../../di/tokens.js";
 import { logger } from "../../lib/logger.js";
+import { createMainTimingCollector } from "../../lib/timing.js";
 import { TypedEventEmitter } from "../../lib/typed-event-emitter.js";
 import type { FsService } from "../fs/service.js";
 import { getCurrentUserId, getPostHogClient } from "../posthog-analytics.js";
@@ -178,6 +179,8 @@ interface SessionConfig {
   additionalDirectories?: string[];
   /** Permission mode to use for the session */
   permissionMode?: string;
+  /** Dev-only: timestamp from renderer when user submitted the task */
+  submittedAt?: number;
 }
 
 interface ManagedSession {
@@ -418,6 +421,8 @@ export class AgentService extends TypedEventEmitter<AgentServiceEvents> {
     isReconnect: boolean,
     isRetry = false,
   ): Promise<ManagedSession | null> {
+    const tc = createMainTimingCollector(log);
+
     const {
       taskId,
       taskRunId,
@@ -427,8 +432,13 @@ export class AgentService extends TypedEventEmitter<AgentServiceEvents> {
       adapter,
       additionalDirectories,
       permissionMode,
+      submittedAt,
     } = config;
 
+    if (submittedAt) {
+      tc.record("ipcTransit", Date.now() - submittedAt);
+    }
+
     // Preview sessions don't need a real repo — use a temp directory
     const repoPath = taskId === "__preview__" ? tmpdir() : rawRepoPath;
 
@@ -439,23 +449,31 @@ export class AgentService extends TypedEventEmitter<AgentServiceEvents> {
       }
 
       // Kill any lingering processes from previous runs of this task
-      this.processTracking.killByTaskId(taskId);
+      tc.timeSync("killProcesses", () =>
+        this.processTracking.killByTaskId(taskId),
+      );
 
       // Clean up any prior session for this taskRunId before creating a new one
-      await this.cleanupSession(taskRunId);
+      await tc.time("cleanup", () => this.cleanupSession(taskRunId));
     }
 
     const channel = `agent-event:${taskRunId}`;
-    const mockNodeDir = this.setupMockNodeEnvironment(taskRunId);
-    this.setupEnvironment(credentials, mockNodeDir);
+    const mockNodeDir = tc.timeSync("mockNode", () =>
+      this.setupMockNodeEnvironment(taskRunId),
+    );
+    tc.timeSync("setupEnv", () =>
+      this.setupEnvironment(credentials, mockNodeDir),
+    );
 
     // Preview sessions don't persist logs — no real task exists
     const isPreview = taskId === "__preview__";
 
     // OTEL log pipeline or legacy S3 writer if FF false
     const useOtelPipeline = isPreview
       ? false
-      : await this.isFeatureFlagEnabled("twig-agent-logs-pipeline");
+      : await tc.time("featureFlag", () =>
+          this.isFeatureFlagEnabled("twig-agent-logs-pipeline"),
+        );
 
     log.info("Agent log transport", {
       transport: isPreview ? "none" : useOtelPipeline ? "otel" : "s3",
@@ -482,78 +500,83 @@ export class AgentService extends TypedEventEmitter<AgentServiceEvents> {
     });
 
     try {
-      const acpConnection = await agent.run(taskId, taskRunId, {
-        adapter,
-        codexBinaryPath: adapter === "codex" ? getCodexBinaryPath() : undefined,
-        processCallbacks: {
-          onProcessSpawned: (info) => {
-            this.processTracking.register(
-              info.pid,
-              "agent",
-              `agent:${taskRunId}`,
-              {
-                taskRunId,
+      const acpConnection = await tc.time("agentRun", () =>
+        agent.run(taskId, taskRunId, {
+          adapter,
+          codexBinaryPath:
+            adapter === "codex" ? getCodexBinaryPath() : undefined,
+          processCallbacks: {
+            onProcessSpawned: (info) => {
+              this.processTracking.register(
+                info.pid,
+                "agent",
+                `agent:${taskRunId}`,
+                {
+                  taskRunId,
+                  taskId,
+                  command: info.command,
+                },
                 taskId,
-                command: info.command,
-              },
-              taskId,
-            );
-          },
-          onProcessExited: (pid) => {
-            this.processTracking.unregister(pid, "agent-exited");
+              );
+            },
+            onProcessExited: (pid) => {
+              this.processTracking.unregister(pid, "agent-exited");
+            },
           },
-        },
-      });
+        }),
+      );
       const { clientStreams } = acpConnection;
 
-      const connection = this.createClientConnection(
-        taskRunId,
-        channel,
-        clientStreams,
+      const connection = tc.timeSync("clientConnection", () =>
+        this.createClientConnection(taskRunId, channel, clientStreams),
       );
 
-      await connection.initialize({
-        protocolVersion: PROTOCOL_VERSION,
-        clientCapabilities: {
-          fs: {
-            readTextFile: true,
-            writeTextFile: true,
+      await tc.time("initialize", () =>
+        connection.initialize({
+          protocolVersion: PROTOCOL_VERSION,
+          clientCapabilities: {
+            fs: {
+              readTextFile: true,
+              writeTextFile: true,
+            },
+            terminal: true,
           },
-          terminal: true,
-        },
-      });
+        }),
+      );
 
-      const mcpServers =
-        adapter === "codex" ? [] : this.buildMcpServers(credentials);
+      const mcpServers = tc.timeSync("buildMcp", () =>
+        adapter === "codex" ? [] : this.buildMcpServers(credentials),
+      );
 
       let configOptions: SessionConfigOption[] | undefined;
       let agentSessionId: string;
 
       if (isReconnect && adapter === "codex" && config.sessionId) {
-        const loadResponse = await connection.loadSession({
-          sessionId: config.sessionId,
-          cwd: repoPath,
-          mcpServers,
-        });
+        const loadResponse = await tc.time("loadSession", () =>
+          connection.loadSession({
+            sessionId: config.sessionId!,
+            cwd: repoPath,
+            mcpServers,
+          }),
+        );
         configOptions = loadResponse.configOptions ?? undefined;
         agentSessionId = config.sessionId;
       } else if (isReconnect && adapter !== "codex") {
         if (!config.sessionId) {
           throw new Error("Cannot resume session without sessionId");
         }
         const systemPrompt = this.buildPostHogSystemPrompt(credentials);
-        const resumeResponse = await connection.extMethod(
-          "_posthog/session/resume",
-          {
-            sessionId: config.sessionId,
+        const resumeResponse = await tc.time("resumeSession", () =>
+          connection.extMethod("_posthog/session/resume", {
+            sessionId: config.sessionId!,
             cwd: repoPath,
             mcpServers,
             _meta: {
               ...(logUrl && {
                 persistence: { taskId, runId: taskRunId, logUrl },
               }),
               taskRunId,
-              sessionId: config.sessionId,
+              sessionId: config.sessionId!,
               systemPrompt,
               ...(permissionMode && { permissionMode }),
               ...(additionalDirectories?.length && {
@@ -562,7 +585,7 @@ export class AgentService extends TypedEventEmitter<AgentServiceEvents> {
                 },
               }),
             },
-          },
+          }),
         );
         const resumeMeta = resumeResponse?._meta as
           | {
@@ -573,26 +596,31 @@ export class AgentService extends TypedEventEmitter<AgentServiceEvents> {
         agentSessionId = config.sessionId;
       } else {
         const systemPrompt = this.buildPostHogSystemPrompt(credentials);
-        const newSessionResponse = await connection.newSession({
-          cwd: repoPath,
-          mcpServers,
-          _meta: {
-            taskRunId,
-            systemPrompt,
-            ...(permissionMode && { permissionMode }),
-            ...(additionalDirectories?.length && {
-              claudeCode: {
-                options: { additionalDirectories },
-              },
-            }),
-          },
-        });
+        const newSessionResponse = await tc.time("newSession", () =>
+          connection.newSession({
+            cwd: repoPath,
+            mcpServers,
+            _meta: {
+              taskRunId,
+              systemPrompt,
+              ...(permissionMode && { permissionMode }),
+              ...(additionalDirectories?.length && {
+                claudeCode: {
+                  options: { additionalDirectories },
+                },
+              }),
+            },
+          }),
+        );
         configOptions = newSessionResponse.configOptions ?? undefined;
         agentSessionId = newSessionResponse.sessionId;
       }
 
       config.sessionId = agentSessionId;
 
+      const sessionType = isReconnect ? "reconnect" : "create";
+      tc.summarize(`getOrCreateSession(${sessionType})`);
+
       const session: ManagedSession = {
         taskRunId,
         taskId,
@@ -1300,6 +1328,7 @@ For git operations while detached:
           : undefined,
       permissionMode:
         "permissionMode" in params ? params.permissionMode : undefined,
+      submittedAt: "submittedAt" in params ? params.submittedAt : undefined,
     };
   }