From c8a055d5640f518fd0f70cdb393c41cce23e1b80 Mon Sep 17 00:00:00 2001 From: arkon Date: Thu, 19 Feb 2026 23:21:28 +0100 Subject: [PATCH] chore: bump version to 0.1565 Co-Authored-By: Claude Opus 4.6 --- CLAUDE.md | 2 +- package.json | 2 +- src/subagent-watcher.ts | 155 +++++--- test/perf-subagent-load.test.ts | 611 ++++++++++++++++++++++++++++++++ 4 files changed, 727 insertions(+), 43 deletions(-) create mode 100644 test/perf-subagent-load.test.ts diff --git a/CLAUDE.md b/CLAUDE.md index ccc8caf1..62657c41 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -35,7 +35,7 @@ When user says "COM": 1. Increment version in BOTH `package.json` AND `CLAUDE.md` (verify they match with `grep version package.json && grep Version CLAUDE.md`) 2. Run: `git add -A && git commit -m "chore: bump version to X.XXXX" && git push && npm run build && systemctl --user restart claudeman-web` -**Version**: 0.1564 (must match `package.json` for npm publish) +**Version**: 0.1565 (must match `package.json` for npm publish) ## Project Overview diff --git a/package.json b/package.json index 76ca9b83..e74042da 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "claudeman", - "version": "0.1564", + "version": "0.1565", "description": "The missing control plane for Claude Code - run 20 autonomous agents with real-time monitoring and session persistence", "type": "module", "main": "dist/index.js", diff --git a/src/subagent-watcher.ts b/src/subagent-watcher.ts index a31ae3c2..7dfb5387 100644 --- a/src/subagent-watcher.ts +++ b/src/subagent-watcher.ts @@ -171,6 +171,9 @@ export class SubagentWatcher extends EventEmitter { private _isCheckingLiveness = false; // Counter for throttling full directory scans (only scan every FULL_SCAN_EVERY_N_POLLS) private _pollCount = 0; + // Short-lived cache for parsed parent transcript descriptions (TTL: 5s) + // Key: "{projectHash}/{sessionId}", Value: { descriptions: Map, timestamp } + private parentDescriptionCache = new Map; timestamp: number }>(); // Store error handlers for FSWatchers to enable proper cleanup (prevent memory leaks) private dirWatcherErrorHandlers = new Map void>(); private fileWatcherErrorHandlers = new Map void>(); @@ -243,16 +246,23 @@ export class SubagentWatcher extends EventEmitter { this._isCheckingLiveness = true; try { - for (const [agentId, info] of this.agentInfo) { + // Run pgrep ONCE and collect all claude process info + const pidMap = await this.getClaudePids(); + + for (const [_agentId, info] of this.agentInfo) { // Re-check status in case another check completed this agent if (info.status === 'active' || info.status === 'idle') { - const alive = await this.checkSubagentAlive(agentId); - if (!alive && (info.status === 'active' || info.status === 'idle')) { - // Double-check status after async call to prevent race - info.status = 'completed'; - // Clean up pendingToolCalls for this agent to prevent memory leak - this.pendingToolCalls.delete(agentId); - this.emit('subagent:completed', info); + const alive = this.checkSubagentAliveFromPidMap(info, pidMap); + // If process not found, fall back to file mtime check + if (!alive) { + const fileAlive = await this.checkSubagentFileAlive(info); + if (!fileAlive && (info.status === 'active' || info.status === 'idle')) { + // Double-check status after async call to prevent race + info.status = 'completed'; + // Clean up pendingToolCalls for this agent to prevent memory leak + this.pendingToolCalls.delete(info.agentId); + this.emit('subagent:completed', info); + } } } } @@ -265,18 +275,55 @@ export class SubagentWatcher extends EventEmitter { } /** - * Check if a subagent process is still running + * Run pgrep once and read /proc info for all Claude PIDs in parallel. + * Returns a Map of pid -> { environ, cmdline } for all running claude processes. */ - private async checkSubagentAlive(agentId: string): Promise { - const info = this.agentInfo.get(agentId); - if (!info) return false; + private async getClaudePids(): Promise> { + const result = new Map(); + try { + const pgrepOutput = await new Promise((resolve, reject) => { + execFile('pgrep', ['-f', 'claude'], { encoding: 'utf8' }, (err, stdout) => { + if (err) return reject(err); + resolve(stdout); + }); + }); + const pids = pgrepOutput.trim().split('\n').filter(Boolean).map(s => parseInt(s, 10)).filter(n => !Number.isNaN(n)); - // Method 1: Check if the process is still running - const pid = await this.findSubagentProcess(info.sessionId); - if (pid !== null) return true; + // Read /proc for all PIDs in parallel + await Promise.all(pids.map(async (pid) => { + let environ = ''; + let cmdline = ''; + try { environ = await readFile(`/proc/${pid}/environ`, 'utf8'); } catch { /* skip */ } + try { cmdline = await readFile(`/proc/${pid}/cmdline`, 'utf8'); } catch { /* skip */ } + if (environ || cmdline) { + result.set(pid, { environ, cmdline }); + } + })); + } catch { + // pgrep returns non-zero if no matches + } + return result; + } - // Method 2: Check if the transcript file was recently modified - // (within the last 60 seconds - gives some buffer for slow operations) + /** + * Check if a subagent is alive using the pre-fetched pid map (no process spawning). + */ + private checkSubagentAliveFromPidMap( + info: SubagentInfo, + pidMap: Map + ): boolean { + for (const [_pid, procInfo] of pidMap) { + if (procInfo.environ.includes(info.sessionId) || procInfo.cmdline.includes(info.sessionId)) { + return true; + } + } + return false; + } + + /** + * Check if a subagent's transcript file was recently modified (fallback for process check). + */ + private async checkSubagentFileAlive(info: SubagentInfo): Promise { try { const fileStat = await statAsync(info.filePath); const mtime = fileStat.mtime.getTime(); @@ -287,7 +334,6 @@ export class SubagentWatcher extends EventEmitter { } catch { // File doesn't exist or can't be read } - return false; } @@ -348,6 +394,7 @@ export class SubagentWatcher extends EventEmitter { this.agentInfo.clear(); this.knownSubagentDirs.clear(); this.pendingToolCalls.clear(); + this.parentDescriptionCache.clear(); this._pollCount = 0; } @@ -800,6 +847,15 @@ export class SubagentWatcher extends EventEmitter { sessionId: string, agentId: string ): Promise { + const cacheKey = `${projectHash}/${sessionId}`; + const CACHE_TTL_MS = 5000; + + // Check cache first (covers burst of simultaneous agent discoveries) + const cached = this.parentDescriptionCache.get(cacheKey); + if (cached && (Date.now() - cached.timestamp) < CACHE_TTL_MS) { + return cached.descriptions.get(agentId); + } + try { // The parent session's transcript is at: ~/.claude/projects/{projectHash}/{sessionId}.jsonl const transcriptPath = join(CLAUDE_PROJECTS_DIR, projectHash, `${sessionId}.jsonl`); @@ -808,21 +864,25 @@ export class SubagentWatcher extends EventEmitter { const content = await readFile(transcriptPath, 'utf8'); const lines = content.split('\n').filter((l) => l.trim()); - // Look for user entry with toolUseResult containing the agentId + // Parse ALL toolUseResult entries into a Map and cache them + const descriptions = new Map(); for (const line of lines) { try { const entry = JSON.parse(line); if ( entry.type === 'user' && - entry.toolUseResult?.agentId === agentId && + entry.toolUseResult?.agentId && entry.toolUseResult?.description ) { - return entry.toolUseResult.description; + descriptions.set(entry.toolUseResult.agentId, entry.toolUseResult.description); } } catch { // Skip malformed lines } } + + this.parentDescriptionCache.set(cacheKey, { descriptions, timestamp: Date.now() }); + return descriptions.get(agentId); } catch { // Failed to read transcript } @@ -834,30 +894,43 @@ export class SubagentWatcher extends EventEmitter { */ private async extractDescriptionFromFile(filePath: string): Promise { try { - const content = await readFile(filePath, 'utf8'); - const lines = content.split('\n').filter((l) => l.trim()); + // Only read the first 8KB — more than enough for 5 JSONL lines + const stream = createReadStream(filePath, { end: 8191 }); + const rl = createInterface({ input: stream }); - for (const line of lines.slice(0, 5)) { - try { - const entry = JSON.parse(line); - if (entry.type === 'user' && entry.message?.content) { - let text: string | undefined; - if (typeof entry.message.content === 'string') { - text = entry.message.content.trim(); - } else if (Array.isArray(entry.message.content)) { - const firstContent = entry.message.content[0]; - if (firstContent?.type === 'text' && firstContent.text) { - text = firstContent.text.trim(); + return await new Promise((resolve) => { + let lineCount = 0; + let resolved = false; + rl.on('line', (line) => { + if (resolved || lineCount >= 5) { rl.close(); stream.destroy(); return; } + lineCount++; + if (!line.trim()) return; + try { + const entry = JSON.parse(line); + if (entry.type === 'user' && entry.message?.content) { + let text: string | undefined; + if (typeof entry.message.content === 'string') { + text = entry.message.content.trim(); + } else if (Array.isArray(entry.message.content)) { + const firstContent = entry.message.content[0]; + if (firstContent?.type === 'text' && firstContent.text) { + text = firstContent.text.trim(); + } + } + if (text) { + resolved = true; + rl.close(); + stream.destroy(); + resolve(this.extractSmartTitle(text)); } } - if (text) { - return this.extractSmartTitle(text); - } + } catch { + // Skip malformed lines } - } catch { - // Skip malformed lines - } - } + }); + rl.on('close', () => { if (!resolved) resolve(undefined); }); + rl.on('error', () => { if (!resolved) resolve(undefined); }); + }); } catch { // Failed to read file } diff --git a/test/perf-subagent-load.test.ts b/test/perf-subagent-load.test.ts new file mode 100644 index 00000000..f9238f14 --- /dev/null +++ b/test/perf-subagent-load.test.ts @@ -0,0 +1,611 @@ +/** + * Performance tests: Claudeman responsiveness under subagent load + * + * Measures event loop lag caused by: + * 1. SubagentWatcher processing many agent files simultaneously + * 2. extractDescriptionFromParentTranscript reading full transcript files + * 3. findSubagentProcess spawning pgrep for every agent in liveness checks + * 4. SSE broadcast serialization under heavy event load + * 5. flushTerminalBatches with many concurrent sessions + * + * Port: none (no server needed — unit-level perf tests) + */ + +import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest'; +import { mkdtempSync, mkdirSync, writeFileSync, rmSync } from 'node:fs'; +import { join } from 'node:path'; +import { tmpdir } from 'node:os'; +import { SubagentWatcher } from '../src/subagent-watcher.js'; + +// ========== Helpers ========== + +/** Generate a realistic JSONL transcript entry */ +function makeTranscriptEntry(type: 'user' | 'assistant', content: string, extras: Record = {}): string { + const base: Record = { + type, + timestamp: new Date().toISOString(), + message: { + role: type, + content: type === 'user' + ? [{ type: 'text', text: content }] + : content, + ...(type === 'assistant' ? { model: 'claude-sonnet-4-20250514', usage: { input_tokens: 1500, output_tokens: 800 } } : {}), + }, + ...extras, + }; + return JSON.stringify(base); +} + +/** Generate a realistic large parent transcript (many lines of JSONL) */ +function generateParentTranscript(lineCount: number, agentIds: string[] = []): string { + const lines: string[] = []; + for (let i = 0; i < lineCount; i++) { + if (i % 2 === 0) { + lines.push(makeTranscriptEntry('user', `Please do task ${i} for the project`)); + } else { + lines.push(makeTranscriptEntry('assistant', `Working on task ${i}...`)); + } + } + // Sprinkle in toolUseResult entries for agent descriptions + for (const agentId of agentIds) { + lines.push(JSON.stringify({ + type: 'user', + timestamp: new Date().toISOString(), + toolUseResult: { agentId, description: `Research task for ${agentId}` }, + })); + } + return lines.join('\n') + '\n'; +} + +/** Generate a subagent transcript file */ +function generateAgentTranscript(lineCount: number): string { + const lines: string[] = []; + lines.push(makeTranscriptEntry('user', 'Investigate the authentication module and suggest improvements for rate limiting')); + for (let i = 1; i < lineCount; i++) { + if (i % 3 === 0) { + lines.push(JSON.stringify({ + type: 'tool_call', + timestamp: new Date().toISOString(), + tool: 'Read', + input: { file_path: `/home/user/project/src/file-${i}.ts` }, + toolUseId: `tool-${i}`, + })); + } else if (i % 3 === 1) { + lines.push(JSON.stringify({ + type: 'tool_result', + timestamp: new Date().toISOString(), + toolUseId: `tool-${i - 1}`, + content: 'x'.repeat(500), + })); + } else { + lines.push(makeTranscriptEntry('assistant', `Analysis step ${i}: Found pattern in module...`)); + } + } + return lines.join('\n') + '\n'; +} + +/** Measure event loop lag over a duration */ +function measureEventLoopLag(durationMs: number): Promise<{ maxLagMs: number; avgLagMs: number; samples: number[] }> { + return new Promise((resolve) => { + const samples: number[] = []; + let lastTime = performance.now(); + const interval = setInterval(() => { + const now = performance.now(); + const lag = now - lastTime - 2; // subtract the 2ms expected interval + samples.push(Math.max(0, lag)); + lastTime = now; + }, 2); + + setTimeout(() => { + clearInterval(interval); + const maxLagMs = Math.max(...samples, 0); + const avgLagMs = samples.length > 0 ? samples.reduce((a, b) => a + b, 0) / samples.length : 0; + resolve({ maxLagMs, avgLagMs, samples }); + }, durationMs); + }); +} + +// ========== Tests ========== + +describe('SubagentWatcher performance', () => { + let tmpDir: string; + let projectsDir: string; + + beforeEach(() => { + tmpDir = mkdtempSync(join(tmpdir(), 'claudeman-perf-')); + projectsDir = join(tmpDir, 'projects'); + mkdirSync(projectsDir, { recursive: true }); + }); + + afterEach(() => { + rmSync(tmpDir, { recursive: true, force: true }); + }); + + describe('extractDescriptionFromParentTranscript — full file reads', () => { + it('should parse a 1000-line parent transcript without significant event loop lag', async () => { + // Setup: create a realistic parent transcript with 1000 lines + const projectHash = 'abc123'; + const sessionId = 'session-001'; + const agentIds = Array.from({ length: 10 }, (_, i) => `agent-${i}`); + + const projectDir = join(projectsDir, projectHash); + const sessionDir = join(projectDir, sessionId); + const subagentDir = join(sessionDir, 'subagents'); + mkdirSync(subagentDir, { recursive: true }); + + // Write a large parent transcript + const transcript = generateParentTranscript(1000, agentIds); + writeFileSync(join(projectDir, `${sessionId}.jsonl`), transcript); + + // Write 10 agent files + for (const id of agentIds) { + writeFileSync(join(subagentDir, `agent-${id}.jsonl`), generateAgentTranscript(50)); + } + + // Measure: call extractDescriptionFromParentTranscript via public path + // We can't call private methods directly, so we test via watchAgentFile indirection + // Instead, test the raw approach: read + parse + search (same as the method does) + const { readFile } = await import('node:fs/promises'); + const transcriptPath = join(projectDir, `${sessionId}.jsonl`); + + const start = performance.now(); + const content = await readFile(transcriptPath, 'utf8'); + const lines = content.split('\n').filter((l: string) => l.trim()); + let found = false; + for (const line of lines) { + try { + const entry = JSON.parse(line); + if (entry.type === 'user' && entry.toolUseResult?.agentId === 'agent-5') { + found = true; + break; + } + } catch { /* skip */ } + } + const elapsed = performance.now() - start; + + expect(found).toBe(true); + // 1000-line transcript should parse in under 10ms + expect(elapsed).toBeLessThan(50); + }); + + it('should handle 10,000-line transcript without blocking event loop > 50ms', async () => { + const projectHash = 'bigproject'; + const sessionId = 'session-big'; + const agentIds = ['target-agent']; + + const projectDir = join(projectsDir, projectHash); + mkdirSync(projectDir, { recursive: true }); + + // 10K lines = realistic for a long Claude session + const transcript = generateParentTranscript(10000, agentIds); + writeFileSync(join(projectDir, `${sessionId}.jsonl`), transcript); + + const { readFile } = await import('node:fs/promises'); + const transcriptPath = join(projectDir, `${sessionId}.jsonl`); + + // Start event loop lag measurement + const lagPromise = measureEventLoopLag(500); + + // Simulate 5 concurrent reads (5 subagents discovered simultaneously) + const reads = Array.from({ length: 5 }, async () => { + const content = await readFile(transcriptPath, 'utf8'); + const lines = content.split('\n').filter((l: string) => l.trim()); + for (const line of lines) { + try { + const entry = JSON.parse(line); + if (entry.type === 'user' && entry.toolUseResult?.agentId === 'target-agent') { + return entry.toolUseResult.description; + } + } catch { /* skip */ } + } + return undefined; + }); + + const results = await Promise.all(reads); + const lag = await lagPromise; + + // All 5 should find the description + for (const r of results) { + expect(r).toBe('Research task for target-agent'); + } + + // Key assertion: max event loop lag should stay reasonable + // JSON.parse of 10K lines is synchronous and blocks the event loop + console.log(`[10K transcript × 5 reads] max lag: ${lag.maxLagMs.toFixed(1)}ms, avg: ${lag.avgLagMs.toFixed(1)}ms`); + + // This WILL likely fail — proving the bottleneck + // 50ms is the threshold where users notice UI jank + expect(lag.maxLagMs).toBeLessThan(100); + }); + }); + + describe('extractDescriptionFromFile — full subagent file reads', () => { + it('should not read entire large agent file just for first 5 lines', async () => { + const agentDir = join(tmpDir, 'agent-files'); + mkdirSync(agentDir, { recursive: true }); + + // Create a large agent file (5000 lines, ~2MB) + const agentFile = join(agentDir, 'agent-large.jsonl'); + writeFileSync(agentFile, generateAgentTranscript(5000)); + + const { readFile, stat: statAsync } = await import('node:fs/promises'); + const fileStat = await statAsync(agentFile); + const fileSizeKB = fileStat.size / 1024; + + // Current implementation: reads ENTIRE file then slices first 5 lines + const start = performance.now(); + const content = await readFile(agentFile, 'utf8'); + const lines = content.split('\n').filter((l: string) => l.trim()); + const firstFive = lines.slice(0, 5); + let description: string | undefined; + for (const line of firstFive) { + try { + const entry = JSON.parse(line); + if (entry.type === 'user' && entry.message?.content) { + const firstContent = Array.isArray(entry.message.content) + ? entry.message.content[0] + : undefined; + if (firstContent?.type === 'text') { + description = firstContent.text.trim().slice(0, 45); + } + } + } catch { /* skip */ } + } + const readAllElapsed = performance.now() - start; + + // Compare with streaming approach (only read first N bytes) + const { createReadStream } = await import('node:fs'); + const { createInterface } = await import('node:readline'); + + const start2 = performance.now(); + let description2: string | undefined; + await new Promise((resolve) => { + const stream = createReadStream(agentFile, { end: 8192 }); // Only read first 8KB + const rl = createInterface({ input: stream }); + let lineCount = 0; + rl.on('line', (line) => { + if (lineCount >= 5) { rl.close(); stream.destroy(); return; } + lineCount++; + try { + const entry = JSON.parse(line); + if (entry.type === 'user' && entry.message?.content) { + const firstContent = Array.isArray(entry.message.content) + ? entry.message.content[0] + : undefined; + if (firstContent?.type === 'text') { + description2 = firstContent.text.trim().slice(0, 45); + rl.close(); + stream.destroy(); + } + } + } catch { /* skip */ } + }); + rl.on('close', resolve); + rl.on('error', resolve); + }); + const streamElapsed = performance.now() - start2; + + console.log(`[extractDescription] file: ${fileSizeKB.toFixed(0)}KB, readAll: ${readAllElapsed.toFixed(1)}ms, stream-first-8KB: ${streamElapsed.toFixed(1)}ms`); + console.log(`[extractDescription] speedup: ${(readAllElapsed / Math.max(streamElapsed, 0.1)).toFixed(1)}x`); + + expect(description).toBeDefined(); + expect(description2).toBeDefined(); + expect(description).toBe(description2); + + // Stream approach should be significantly faster on large files + // This test documents the waste in the current approach + expect(streamElapsed).toBeLessThan(readAllElapsed); + }); + }); + + describe('findSubagentProcess — pgrep + /proc reads for every agent', () => { + it('should measure cost of pgrep per agent in liveness check', async () => { + const { execFile } = await import('node:child_process'); + + // Measure single pgrep call (what happens per agent per liveness check) + const times: number[] = []; + for (let i = 0; i < 10; i++) { + const start = performance.now(); + await new Promise((resolve) => { + execFile('pgrep', ['-f', 'claude'], { encoding: 'utf8' }, () => { + times.push(performance.now() - start); + resolve(); + }); + }); + } + + const avgMs = times.reduce((a, b) => a + b, 0) / times.length; + const maxMs = Math.max(...times); + console.log(`[pgrep per call] avg: ${avgMs.toFixed(1)}ms, max: ${maxMs.toFixed(1)}ms`); + + // Now simulate what happens with 20 active agents (sequential, as the liveness checker does) + const start20 = performance.now(); + for (let i = 0; i < 20; i++) { + await new Promise((resolve) => { + execFile('pgrep', ['-f', 'claude'], { encoding: 'utf8' }, () => resolve()); + }); + } + const total20 = performance.now() - start20; + console.log(`[pgrep × 20 agents] total: ${total20.toFixed(1)}ms`); + + // 20 sequential pgrep calls at ~5-10ms each = 100-200ms blocking the liveness check + // The liveness checker runs every 10s and blocks the event loop during iteration + // because it awaits each agent serially: for (const [agentId, info] of this.agentInfo) + }); + + it('should measure /proc environ reads (per pgrep hit)', async () => { + const { readFile } = await import('node:fs/promises'); + + // Read our own /proc/self/environ as baseline + const times: number[] = []; + for (let i = 0; i < 20; i++) { + const start = performance.now(); + try { + await readFile('/proc/self/environ', 'utf8'); + } catch { /* may fail in containers */ } + times.push(performance.now() - start); + } + + const avgMs = times.reduce((a, b) => a + b, 0) / times.length; + console.log(`[/proc/environ read] avg: ${avgMs.toFixed(1)}ms over 20 reads`); + // Each findSubagentProcess reads /proc/{pid}/environ + /proc/{pid}/cmdline + // for every PID returned by pgrep — if 50 claude-related PIDs, that's 100 reads + }); + }); + + describe('SSE broadcast serialization under load', () => { + it('should measure JSON.stringify cost for typical broadcast payloads', () => { + // Simulate subagent:discovered events (fired for each new agent) + const agentInfo = { + agentId: 'abc-123-def', + sessionId: 'session-001', + projectHash: 'proj-hash', + filePath: '/home/user/.claude/projects/hash/session/subagents/agent-abc.jsonl', + startedAt: new Date().toISOString(), + lastActivityAt: Date.now(), + status: 'active', + toolCallCount: 0, + entryCount: 0, + fileSize: 1024, + description: 'Research authentication patterns in the codebase', + model: 'claude-sonnet-4-20250514', + modelShort: 'sonnet', + totalInputTokens: 15000, + totalOutputTokens: 8000, + }; + + // Simulate burst of 20 agents discovered at once + const start = performance.now(); + const messages: string[] = []; + for (let i = 0; i < 20; i++) { + const payload = { ...agentInfo, agentId: `agent-${i}` }; + messages.push(`event: subagent:discovered\ndata: ${JSON.stringify(payload)}\n\n`); + } + const elapsed = performance.now() - start; + console.log(`[broadcast × 20 agents] serialization: ${elapsed.toFixed(2)}ms`); + + // Now simulate what happens when each is written to 10 SSE clients + // (the inner loop in broadcast()) + const totalBytes = messages.reduce((sum, m) => sum + m.length, 0); + console.log(`[broadcast × 20 agents] total payload: ${(totalBytes / 1024).toFixed(1)}KB`); + + // Serialization alone should be fast + expect(elapsed).toBeLessThan(5); + }); + + it('should measure cost of rapid terminal broadcasts with large payloads', () => { + // Simulate 20 sessions each flushing 16KB of terminal data + const sessions = Array.from({ length: 20 }, (_, i) => ({ + id: `session-${i}`, + data: '\x1b[?2026h' + 'x'.repeat(16 * 1024) + '\x1b[?2026l', + })); + + const start = performance.now(); + const messages: string[] = []; + for (const session of sessions) { + messages.push(`event: session:terminal\ndata: ${JSON.stringify(session)}\n\n`); + } + const elapsed = performance.now() - start; + + const totalMB = messages.reduce((sum, m) => sum + m.length, 0) / (1024 * 1024); + console.log(`[terminal flush × 20 sessions] serialization: ${elapsed.toFixed(1)}ms, payload: ${totalMB.toFixed(2)}MB`); + + // 20 × 16KB = 320KB serialized simultaneously — should still be < 20ms + expect(elapsed).toBeLessThan(50); + }); + }); + + describe('combined load scenario: subagent storm', () => { + it('should simulate 10 agents starting while terminal data is flowing', async () => { + // This is the real-world scenario: user is working, Claude spawns agents, + // and the UI freezes because: + // 1. 10× extractDescriptionFromParentTranscript (read + parse full transcripts) + // 2. 10× extractDescriptionFromFile (read + parse agent files) + // 3. 10× subagent:discovered broadcasts + // 4. Terminal data keeps flowing and needs to flush + // All of this on the same event loop + + const projectDir = join(tmpDir, 'storm-project', 'hash123', 'session-main'); + const subagentDir = join(projectDir, 'subagents'); + mkdirSync(subagentDir, { recursive: true }); + + // Large parent transcript (5000 lines) + const parentTranscript = generateParentTranscript(5000, + Array.from({ length: 10 }, (_, i) => `storm-agent-${i}`) + ); + writeFileSync(join(tmpDir, 'storm-project', 'hash123', 'session-main.jsonl'), parentTranscript); + + // 10 agent transcript files (500 lines each) + for (let i = 0; i < 10; i++) { + writeFileSync(join(subagentDir, `agent-storm-agent-${i}.jsonl`), generateAgentTranscript(500)); + } + + const { readFile } = await import('node:fs/promises'); + const parentPath = join(tmpDir, 'storm-project', 'hash123', 'session-main.jsonl'); + + // Start event loop lag measurement + const lagPromise = measureEventLoopLag(2000); + + // Simulate what SubagentWatcher does when 10 agents appear: + const start = performance.now(); + + // Phase 1: Read parent transcript 10 times (once per agent to find description) + const descriptionReads = Array.from({ length: 10 }, async (_, i) => { + const content = await readFile(parentPath, 'utf8'); + const lines = content.split('\n').filter((l: string) => l.trim()); + for (const line of lines) { + try { + const entry = JSON.parse(line); + if (entry.type === 'user' && entry.toolUseResult?.agentId === `storm-agent-${i}`) { + return entry.toolUseResult.description; + } + } catch { /* skip */ } + } + return undefined; + }); + + // Phase 2: Concurrently, simulate terminal data serialization (every 16ms) + let terminalSerializations = 0; + const terminalInterval = setInterval(() => { + // Simulate flushTerminalBatches for 5 active sessions + for (let s = 0; s < 5; s++) { + JSON.stringify({ id: `session-${s}`, data: 'x'.repeat(4096) }); + } + terminalSerializations++; + }, 16); + + const descriptions = await Promise.all(descriptionReads); + clearInterval(terminalInterval); + + const totalElapsed = performance.now() - start; + const lag = await lagPromise; + + console.log(`[subagent storm] 10 agents + terminal: ${totalElapsed.toFixed(0)}ms`); + console.log(`[subagent storm] terminal flushes during: ${terminalSerializations}`); + console.log(`[subagent storm] max event loop lag: ${lag.maxLagMs.toFixed(1)}ms`); + console.log(`[subagent storm] avg event loop lag: ${lag.avgLagMs.toFixed(1)}ms`); + + // Count how many lag samples exceeded 50ms (UI jank threshold) + const jankSamples = lag.samples.filter(s => s > 50).length; + const totalSamples = lag.samples.length; + console.log(`[subagent storm] jank samples (>50ms): ${jankSamples}/${totalSamples} (${((jankSamples / totalSamples) * 100).toFixed(1)}%)`); + + // Verify correctness + for (const d of descriptions) { + expect(d).toMatch(/^Research task for storm-agent-\d+$/); + } + + // This is the key metric: during a subagent storm, max lag should stay under 100ms + // In practice, the synchronous JSON.parse of 5000 lines × 10 concurrent reads + // will cause significant lag spikes + if (lag.maxLagMs > 100) { + console.warn(`⚠️ MAX LAG ${lag.maxLagMs.toFixed(0)}ms EXCEEDS 100ms — UI will feel unresponsive`); + } + }); + }); + + describe('liveness checker: serial pgrep amplification', () => { + it('should measure total event loop impact of serial liveness checks', async () => { + // The liveness checker iterates all active agents SERIALLY with await: + // for (const [agentId, info] of this.agentInfo) { + // const alive = await this.checkSubagentAlive(agentId); + // } + // Each checkSubagentAlive calls findSubagentProcess which runs: + // 1. pgrep -f claude + // 2. For each PID: readFile(/proc/{pid}/environ) + readFile(/proc/{pid}/cmdline) + // + // With 20 active agents, the entire for-loop holds the event loop hostage + // because Node's microtask queue won't process other work between awaits + // in a tight loop. + + const { execFile } = await import('node:child_process'); + const { readFile } = await import('node:fs/promises'); + + // Simulate the liveness check loop for 20 agents + const lagPromise = measureEventLoopLag(3000); + + const start = performance.now(); + for (let agent = 0; agent < 20; agent++) { + // Step 1: pgrep (what findSubagentProcess does) + const pids = await new Promise((resolve) => { + execFile('pgrep', ['-f', 'node'], { encoding: 'utf8' }, (_err, stdout) => { + resolve((stdout || '').trim().split('\n').filter(Boolean)); + }); + }); + + // Step 2: Read /proc for each PID (what findSubagentProcess does per PID) + for (const pidStr of pids.slice(0, 5)) { // limit to 5 PIDs for test sanity + try { + await readFile(`/proc/${pidStr}/environ`, 'utf8'); + } catch { /* expected for many PIDs */ } + try { + await readFile(`/proc/${pidStr}/cmdline`, 'utf8'); + } catch { /* expected */ } + } + } + const elapsed = performance.now() - start; + + const lag = await lagPromise; + + console.log(`[liveness × 20 agents] total: ${elapsed.toFixed(0)}ms`); + console.log(`[liveness × 20 agents] max event loop lag: ${lag.maxLagMs.toFixed(1)}ms`); + console.log(`[liveness × 20 agents] avg event loop lag: ${lag.avgLagMs.toFixed(1)}ms`); + + // Document the cost: this runs every 10 seconds and takes N×hundreds of ms + // During this time, SSE broadcasts, terminal data, and API responses are delayed + }); + }); + + describe('transcript JSON.parse line-by-line cost', () => { + it('should measure synchronous JSON.parse cost for transcript tailing', () => { + // tailFile does JSON.parse(line) for every line in the stream + // When a subagent first appears, tailFile reads from position 0 = entire file + // With 1000 entry files, that's 1000 synchronous JSON.parse calls + + const lines = Array.from({ length: 1000 }, (_, i) => + makeTranscriptEntry(i % 2 === 0 ? 'user' : 'assistant', `Content for line ${i}`) + ); + + // Measure synchronous JSON.parse of all lines (what tailFile does) + const start = performance.now(); + let parsed = 0; + for (const line of lines) { + JSON.parse(line); + parsed++; + } + const elapsed = performance.now() - start; + + console.log(`[JSON.parse × ${parsed} lines] ${elapsed.toFixed(2)}ms (${(elapsed / parsed * 1000).toFixed(1)}µs/line)`); + + // 1000 lines should be fast, but 10 agents × 1000 lines = 10000 parses + // all happening synchronously on the event loop during initial tail + }); + + it('should measure cumulative cost when 10 agents are tailed simultaneously', () => { + // When 10 subagents are discovered at once, all 10 call tailFile from position 0 + // Each agent file has ~500 lines → 5000 JSON.parse calls + + const agentFiles = Array.from({ length: 10 }, () => + Array.from({ length: 500 }, (_, i) => + makeTranscriptEntry(i % 2 === 0 ? 'user' : 'assistant', `Agent content ${i}`) + ) + ); + + const start = performance.now(); + let totalParsed = 0; + for (const lines of agentFiles) { + for (const line of lines) { + JSON.parse(line); + totalParsed++; + } + } + const elapsed = performance.now() - start; + + console.log(`[10 agents × 500 lines] ${totalParsed} parses in ${elapsed.toFixed(1)}ms`); + + // This all happens synchronously — the event loop is completely blocked + // during this time. No SSE events, no API responses, no terminal data. + expect(elapsed).toBeLessThan(100); // Should be fast enough + }); + }); +});