feat(pi-tui): add opt-in render profiler

.changeset/pi-tui-render-profiler.md

@@ -0,0 +1,5 @@
+---
+"@moonshot-ai/pi-tui": patch
+---
+
+Add an opt-in render profiler that records per-frame render cost and stdout write timing for diagnosing terminal render stutter.

packages/pi-tui/src/render-profiler.ts

@@ -0,0 +1,156 @@
+/**
+ * Opt-in render profiler for diagnosing TUI render and stdout-write cost.
+ *
+ * Enabled via the `PI_TUI_RENDER_PROFILE` environment variable:
+ *   - unset / empty   -> disabled (near-zero overhead)
+ *   - "1" / "true"    -> write JSONL to ~/.pi/agent/pi-render-profile.jsonl
+ *   - any other value -> treated as the output file path
+ *
+ * Records every terminal write (duration, byte size, backpressure signal) and a
+ * per-frame summary (build time, line count, full-redraw flag, event-loop lag).
+ * Used to investigate streaming render stutter, especially on Windows where
+ * ConPTY / Windows Terminal stdout writes are significantly more expensive than
+ * on Unix pseudoterminals.
+ */
+
+import * as fs from "node:fs";
+import * as os from "node:os";
+import * as path from "node:path";
+import { monitorEventLoopDelay } from "node:perf_hooks";
+
+type EventLoopHistogram = ReturnType<typeof monitorEventLoopDelay>;
+
+const FLUSH_RECORD_THRESHOLD = 100;
+
+function resolveProfilePath(envValue: string): string {
+	if (envValue === "1" || envValue.toLowerCase() === "true") {
+		return path.join(os.homedir(), ".pi", "agent", "pi-render-profile.jsonl");
+	}
+	return envValue;
+}
+
+function roundMs(value: number): number {
+	return Math.round(value * 1000) / 1000;
+}
+
+function nsToMs(ns: number): number {
+	return Math.round((ns / 1e6) * 1000) / 1000;
+}
+
+export class RenderProfiler {
+	readonly enabled: boolean;
+	private readonly filePath: string;
+	private pending: string[] = [];
+	private histogram: EventLoopHistogram | undefined;
+	private closed = false;
+
+	constructor(envValue: string | undefined) {
+		this.enabled = Boolean(envValue);
+		if (!this.enabled) {
+			this.filePath = "";
+			return;
+		}
+		this.filePath = resolveProfilePath(envValue as string);
+		try {
+			fs.mkdirSync(path.dirname(this.filePath), { recursive: true });
+			// Start each profiled run with a clean file so sessions do not interleave.
+			fs.writeFileSync(this.filePath, "");
+		} catch {
+			// Best-effort: if the file cannot be prepared, profiling silently no-ops.
+		}
+		try {
+			const histogram = monitorEventLoopDelay({ resolution: 20 });
+			histogram.enable();
+			this.histogram = histogram;
+		} catch {
+			this.histogram = undefined;
+		}
+	}
+
+	/** Record a single stdout write: how long it took, its size, and whether the
+	 *  stream signalled backpressure (`write` returned false). */
+	recordWrite(durationMs: number, bytes: number, ok: boolean): void {
+		this.record({
+			kind: "write",
+			ms: roundMs(durationMs),
+			bytes,
+			ok,
+		});
+	}
+
+	/** Record a completed render frame with build cost and a since-last-frame
+	 *  event-loop lag snapshot. */
+	recordFrame(fields: {
+		fullRedraw: boolean;
+		lines: number;
+		height: number;
+		buildMs: number;
+		totalMs: number;
+	}): void {
+		this.record({
+			kind: "frame",
+			fullRedraw: fields.fullRedraw,
+			lines: fields.lines,
+			height: fields.height,
+			buildMs: roundMs(fields.buildMs),
+			totalMs: roundMs(fields.totalMs),
+			el: this.snapshotEventLoop(),
+		});
+	}
+
+	private record(entry: Record<string, unknown>): void {
+		if (!this.enabled || this.closed) return;
+		this.pending.push(`${JSON.stringify({ t: Date.now(), ...entry })}\n`);
+		if (this.pending.length >= FLUSH_RECORD_THRESHOLD) {
+			this.flushAsync();
+		}
+	}
+
+	private snapshotEventLoop(): { meanMs: number; maxMs: number } | undefined {
+		if (!this.histogram) return undefined;
+		// `mean` is NaN while the histogram has no samples yet (e.g. the very
+		// first frame); coerce to 0 so the JSONL stays numeric for parsers.
+		const mean = this.histogram.mean;
+		const snapshot = {
+			meanMs: Number.isFinite(mean) ? nsToMs(mean) : 0,
+			maxMs: nsToMs(this.histogram.max),
+		};
+		this.histogram.reset();
+		return snapshot;
+	}
+
+	private flushAsync(): void {
+		if (this.pending.length === 0) return;
+		const chunk = this.pending.join("");
+		this.pending = [];
+		fs.promises.appendFile(this.filePath, chunk).catch(() => {});
+	}
+
+	/** Synchronously flush any buffered records. Safe to call at shutdown. */
+	flush(): void {
+		if (!this.enabled || this.pending.length === 0) return;
+		try {
+			fs.appendFileSync(this.filePath, this.pending.join(""));
+		} catch {
+			// Ignore flush errors
+		}
+		this.pending = [];
+	}
+
+	close(): void {
+		if (this.closed) return;
+		this.closed = true;
+		this.flush();
+		this.histogram?.disable();
+		this.histogram = undefined;
+	}
+}
+
+let singleton: RenderProfiler | undefined;
+
+export function getRenderProfiler(): RenderProfiler {
+	if (!singleton) {
+		singleton = new RenderProfiler(process.env["PI_TUI_RENDER_PROFILE"]);
+	}
+	return singleton;
+}

packages/pi-tui/src/terminal.ts

@@ -1,9 +1,11 @@
 import * as fs from "node:fs";
 import { createRequire } from "node:module";
 import * as path from "node:path";
+import { performance } from "node:perf_hooks";
 import { fileURLToPath } from "node:url";
 import { setKittyProtocolActive } from "./keys.ts";
 import { isNativeModifierPressed } from "./native-modifiers.ts";
+import { getRenderProfiler } from "./render-profiler.ts";
 import { StdinBuffer } from "./stdin-buffer.ts";
 
 const cjsRequire = createRequire(import.meta.url);
@@ -452,7 +454,12 @@ export class ProcessTerminal implements Terminal {
 	}
 
 	write(data: string): void {
-		process.stdout.write(data);
+		const profiler = getRenderProfiler();
+		const start = profiler.enabled ? performance.now() : 0;
+		const ok = process.stdout.write(data);
+		if (profiler.enabled) {
+			profiler.recordWrite(performance.now() - start, Buffer.byteLength(data, "utf8"), ok);
+		}
 		if (this.writeLogPath) {
 			try {
 				fs.appendFileSync(this.writeLogPath, data, { encoding: "utf8" });

packages/pi-tui/src/tui.ts

@@ -8,6 +8,7 @@ import * as path from "node:path";
 import { performance } from "node:perf_hooks";
 import { isKeyRelease, matchesKey } from "./keys.ts";
 import type { Terminal } from "./terminal.ts";
+import { getRenderProfiler } from "./render-profiler.ts";
 import {
 	isOsc11BackgroundColorResponse,
 	parseOsc11BackgroundColor,
@@ -717,6 +718,7 @@ export class TUI extends Container {
 
 		this.terminal.showCursor();
 		this.terminal.stop();
+		getRenderProfiler().close();
 	}
 
 	requestRender(force = false): void {
@@ -1263,6 +1265,8 @@ export class TUI extends Container {
 
 	private doRender(): void {
 		if (this.stopped) return;
+		const profiler = getRenderProfiler();
+		const frameStart = profiler.enabled ? performance.now() : 0;
 		const width = this.terminal.columns;
 		const height = this.terminal.rows;
 		const widthChanged = this.previousWidth !== 0 && this.previousWidth !== width;
@@ -1278,6 +1282,7 @@ export class TUI extends Container {
 		};
 
 		// Render all components to get new lines
+		const buildStart = profiler.enabled ? performance.now() : 0;
 		let newLines = this.render(width);
 
 		// Composite overlays into the rendered lines (before differential compare)
@@ -1304,6 +1309,18 @@ export class TUI extends Container {
 
 		newLines = this.applyLineResets(newLines);
 
+		const buildMs = profiler.enabled ? performance.now() - buildStart : 0;
+		const recordFrame = (fullRedraw: boolean): void => {
+			if (!profiler.enabled) return;
+			profiler.recordFrame({
+				fullRedraw,
+				lines: newLines.length,
+				height,
+				buildMs,
+				totalMs: performance.now() - frameStart,
+			});
+		};
+
 		// Helper to clear scrollback and viewport and render all new lines
 		const fullRender = (clear: boolean): void => {
 			this.fullRedrawCount += 1;
@@ -1331,6 +1348,7 @@ export class TUI extends Container {
 			}
 			buffer += "\x1b[?2026l"; // End synchronized output
 			this.terminal.write(buffer);
+			recordFrame(true);
 			this.cursorRow = Math.max(0, newLines.length - 1);
 			this.hardwareCursorRow = this.cursorRow;
 			// Reset max lines when clearing, otherwise track growth
@@ -1596,6 +1614,7 @@ export class TUI extends Container {
 
 		// Write entire buffer at once
 		this.terminal.write(buffer);
+		recordFrame(false);
 
 		// Track cursor position for next render
 		// cursorRow tracks end of content (for viewport calculation)

packages/pi-tui/test/render-profiler.test.ts

@@ -0,0 +1,78 @@
+import assert from "node:assert";
+import * as fs from "node:fs";
+import * as os from "node:os";
+import * as path from "node:path";
+import { afterEach, beforeEach, describe, it } from "node:test";
+import { RenderProfiler } from "../src/render-profiler.ts";
+
+describe("RenderProfiler", () => {
+	let tmpDir: string;
+
+	beforeEach(() => {
+		tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), "pi-rp-test-"));
+	});
+
+	afterEach(() => {
+		try {
+			fs.rmSync(tmpDir, { recursive: true, force: true });
+		} catch {
+			// ignore cleanup errors
+		}
+	});
+
+	it("is disabled and writes nothing when env is unset", () => {
+		const file = path.join(tmpDir, "nope.jsonl");
+		const profiler = new RenderProfiler(undefined);
+		assert.equal(profiler.enabled, false);
+		profiler.recordWrite(1.2, 100, true);
+		profiler.recordFrame({ fullRedraw: false, lines: 10, height: 5, buildMs: 0.1, totalMs: 0.2 });
+		profiler.close();
+		assert.equal(fs.existsSync(file), false);
+	});
+
+	it("records writes and frames as JSONL when enabled via a custom path", () => {
+		const file = path.join(tmpDir, "profile.jsonl");
+		const profiler = new RenderProfiler(file);
+		assert.equal(profiler.enabled, true);
+		profiler.recordWrite(1.2345, 5678, true);
+		profiler.recordFrame({ fullRedraw: false, lines: 42, height: 24, buildMs: 0.567, totalMs: 3.1234 });
+		profiler.close();
+
+		const lines = fs.readFileSync(file, "utf8").trim().split("\n");
+		assert.equal(lines.length, 2);
+
+		const write = JSON.parse(lines[0]!);
+		assert.equal(write.kind, "write");
+		assert.equal(write.ok, true);
+		assert.equal(write.bytes, 5678);
+		// duration is rounded to millisecond precision
+		assert.equal(write.ms, 1.235);
+
+		const frame = JSON.parse(lines[1]!);
+		assert.equal(frame.kind, "frame");
+		assert.equal(frame.fullRedraw, false);
+		assert.equal(frame.lines, 42);
+		assert.equal(frame.height, 24);
+		assert.equal(frame.buildMs, 0.567);
+		assert.equal(frame.totalMs, 3.123);
+		assert.equal(typeof frame.el.meanMs, "number");
+		assert.equal(typeof frame.el.maxMs, "number");
+	});
+
+	it("creates the parent directory when it does not exist", () => {
+		const nested = path.join(tmpDir, "a", "b", "profile.jsonl");
+		const profiler = new RenderProfiler(nested);
+		profiler.recordWrite(0.1, 1, true);
+		profiler.close();
+		assert.equal(fs.existsSync(nested), true);
+	});
+
+	it("records backpressure via the write ok flag", () => {
+		const file = path.join(tmpDir, "bp.jsonl");
+		const profiler = new RenderProfiler(file);
+		profiler.recordWrite(10, 4096, false);
+		profiler.close();
+		const rec = JSON.parse(fs.readFileSync(file, "utf8").trim());
+		assert.equal(rec.ok, false);
+	});
+});