From 3c2a96d5f09238a7f728f13117c55d9cec721d72 Mon Sep 17 00:00:00 2001 From: Brad Harris Date: Tue, 10 Mar 2026 14:52:26 -0600 Subject: [PATCH] Fix CI logs appending instead of updating in place (#21) `gh run watch` uses ANSI cursor-up sequences (ESC[A) to redraw its multi-line status block. The previous fix only handled carriage returns (\r) for single-line replacement, so each refresh appended the entire block again. - Detect ESC[A cursor-up sequences in streamProcess and rewind the log by N lines before appending the new block - Strip ANSI escape sequences from log output for clean display - Add log.rewind event type so the frontend removes stale lines - Include test with mock gh-run-watch script to validate behavior Co-Authored-By: Claude Opus 4.6 --- src/server.ts | 25 ++- test/mock-gh-watch.sh | 47 ++++++ test/stream-process.test.ts | 168 +++++++++++++++++++++ web/src/components/app/release-manager.tsx | 6 +- 4 files changed, 244 insertions(+), 2 deletions(-) create mode 100755 test/mock-gh-watch.sh create mode 100644 test/stream-process.test.ts diff --git a/src/server.ts b/src/server.ts index d6191c92..602633b2 100644 --- a/src/server.ts +++ b/src/server.ts @@ -180,6 +180,7 @@ type ReleaseStreamEvent = | { type: "snapshot"; job: ReleaseJob | null } | { type: "log"; line: string } | { type: "log.replace"; line: string } + | { type: "log.rewind"; count: number } | { type: "phase"; phase: ReleasePhase; error?: string } | { type: "runUrl"; url: string } | { type: "tag"; tag: string }; @@ -214,6 +215,19 @@ function replaceReleaseLog(job: ReleaseJob, line: string): void { broadcastReleaseEvent({ type: "log.replace", line }); } +function rewindReleaseLog(job: ReleaseJob, count: number): void { + const actual = Math.min(count, job.log.length); + if (actual > 0) { + job.log.splice(-actual); + broadcastReleaseEvent({ type: "log.rewind", count: actual }); + } +} + +/** Strip ANSI escape sequences for clean log display */ +function stripAnsi(str: string): string { + return str.replace(/\x1b\[[0-9;]*[A-Za-z]/g, ""); +} + function setReleasePhase(job: ReleaseJob, phase: ReleasePhase, error?: string): void { job.phase = phase; broadcastReleaseEvent({ type: "phase", phase, error }); @@ -238,7 +252,16 @@ function streamProcess( buffer += chunk.toString(); const lines = buffer.split("\n"); buffer = lines.pop() ?? ""; - for (const line of lines) { + for (const rawLine of lines) { + // Detect ANSI cursor-up sequence (ESC[A) used by tools like + // `gh run watch` to redraw multi-line output blocks in-place. + const cursorUpMatch = rawLine.match(/\x1b\[(\d+)A/); + if (cursorUpMatch) { + rewindReleaseLog(job, parseInt(cursorUpMatch[1], 10)); + } + + const line = stripAnsi(rawLine); + // A line may contain \r-separated segments (in-place terminal updates). // Only the final segment matters; earlier ones were meant to be overwritten. const crParts = line.split("\r").filter(Boolean); diff --git a/test/mock-gh-watch.sh b/test/mock-gh-watch.sh new file mode 100755 index 00000000..b1f619ee --- /dev/null +++ b/test/mock-gh-watch.sh @@ -0,0 +1,47 @@ +#!/bin/bash +# Simulates gh run watch output with ANSI cursor-up redraws. +# Usage: ./test/mock-gh-watch.sh +# +# This outputs 3 refresh cycles similar to what `gh run watch` produces, +# using ESC[A (cursor up) + ESC[J (clear to end) to redraw in-place. + +block_lines=9 + +# --- First render (in_progress) --- +echo "* main Release · 12345" +echo "Triggered via workflow_dispatch" +echo "" +echo "JOBS" +echo "* release (ID 999)" +echo "✓ Set up job" +echo "* Install dependencies" +echo "* Build" +echo "Refreshing run status every 3 seconds. Press Ctrl+C to quit." + +sleep 0.3 + +# --- Second render (more steps complete) --- +printf "\033[${block_lines}A\033[J" +echo "* main Release · 12345" +echo "Triggered via workflow_dispatch" +echo "" +echo "JOBS" +echo "* release (ID 999)" +echo "✓ Set up job" +echo "✓ Install dependencies" +echo "* Build" +echo "Refreshing run status every 3 seconds. Press Ctrl+C to quit." + +sleep 0.3 + +# --- Third render (all complete) --- +printf "\033[${block_lines}A\033[J" +echo "✓ main Release · 12345" +echo "Triggered via workflow_dispatch" +echo "" +echo "JOBS" +echo "✓ release (ID 999)" +echo "✓ Set up job" +echo "✓ Install dependencies" +echo "✓ Build" +echo "" diff --git a/test/stream-process.test.ts b/test/stream-process.test.ts new file mode 100644 index 00000000..66d0d59a --- /dev/null +++ b/test/stream-process.test.ts @@ -0,0 +1,168 @@ +/** + * Test that streamProcess correctly handles ANSI cursor-up redraws + * (as produced by `gh run watch`) instead of appending duplicate blocks. + * + * Run: npx tsx test/stream-process.test.ts + */ +import { spawn } from "node:child_process"; +import path from "node:path"; + +// ---- Minimal replicas of the server helpers ---- + +type LogEvent = + | { type: "log"; line: string } + | { type: "log.replace"; line: string } + | { type: "log.rewind"; count: number }; + +interface FakeJob { + log: string[]; +} + +const events: LogEvent[] = []; + +function appendReleaseLog(job: FakeJob, line: string): void { + job.log.push(line); + events.push({ type: "log", line }); +} + +function replaceReleaseLog(job: FakeJob, line: string): void { + if (job.log.length > 0) { + job.log[job.log.length - 1] = line; + } else { + job.log.push(line); + } + events.push({ type: "log.replace", line }); +} + +function rewindReleaseLog(job: FakeJob, count: number): void { + const actual = Math.min(count, job.log.length); + if (actual > 0) { + job.log.splice(-actual); + events.push({ type: "log.rewind", count: actual }); + } +} + +function stripAnsi(str: string): string { + return str.replace(/\x1b\[[0-9;]*[A-Za-z]/g, ""); +} + +// ---- streamProcess (copy of server logic) ---- + +function streamProcess( + command: string, + args: string[], + options: { cwd?: string }, + job: FakeJob, +): Promise { + return new Promise((resolve, reject) => { + const child = spawn(command, args, { + cwd: options.cwd, + stdio: ["ignore", "pipe", "pipe"], + }); + + let buffer = ""; + let lastWasCR = false; + const processChunk = (chunk: Buffer): void => { + buffer += chunk.toString(); + const lines = buffer.split("\n"); + buffer = lines.pop() ?? ""; + for (const rawLine of lines) { + const cursorUpMatch = rawLine.match(/\x1b\[(\d+)A/); + if (cursorUpMatch) { + rewindReleaseLog(job, parseInt(cursorUpMatch[1], 10)); + } + + const line = stripAnsi(rawLine); + + const crParts = line.split("\r").filter(Boolean); + if (crParts.length > 1 || lastWasCR) { + const final = crParts[crParts.length - 1] ?? ""; + replaceReleaseLog(job, final); + } else { + appendReleaseLog(job, crParts[0] ?? line); + } + lastWasCR = false; + } + if (buffer.includes("\r")) { + const crParts = buffer.split("\r").filter(Boolean); + const final = crParts[crParts.length - 1] ?? ""; + replaceReleaseLog(job, final); + buffer = ""; + lastWasCR = true; + } + }; + + child.stdout.on("data", processChunk); + child.stderr.on("data", processChunk); + + child.on("error", (err) => reject(err)); + child.on("close", (code) => { + if (buffer) { + appendReleaseLog(job, buffer); + } + if (code !== 0) { + reject(new Error(`Process exited with code ${code}`)); + } else { + resolve(); + } + }); + }); +} + +// ---- Run the test ---- + +async function main() { + const job: FakeJob = { log: [] }; + const mockScript = path.join(import.meta.dirname, "mock-gh-watch.sh"); + + console.log("Running mock gh run watch through streamProcess...\n"); + await streamProcess("bash", [mockScript], {}, job); + + console.log("=== Final log state ==="); + for (const [i, line] of job.log.entries()) { + console.log(` [${i}] ${JSON.stringify(line)}`); + } + + console.log(`\n=== Events emitted (${events.length}) ===`); + for (const evt of events) { + if (evt.type === "log") console.log(` log: ${JSON.stringify(evt.line)}`); + else if (evt.type === "log.replace") console.log(` replace: ${JSON.stringify(evt.line)}`); + else if (evt.type === "log.rewind") console.log(` rewind: ${evt.count}`); + } + + // Assertions + const rewinds = events.filter((e) => e.type === "log.rewind"); + const finalLogCount = job.log.length; + + console.log("\n=== Assertions ==="); + + // Should have exactly 2 rewinds (second and third render) + console.assert(rewinds.length === 2, `Expected 2 rewinds, got ${rewinds.length}`); + console.log(`✓ Rewind events: ${rewinds.length}`); + + // Final log should have ~9 lines (the last render), not 27 (3x9) + console.assert(finalLogCount <= 12, `Expected ≤12 final log lines, got ${finalLogCount}`); + console.log(`✓ Final log lines: ${finalLogCount} (would be ~27 without fix)`); + + // Should NOT contain duplicate "Refreshing" lines + const refreshLines = job.log.filter((l) => l.includes("Refreshing")); + console.assert(refreshLines.length <= 1, `Expected ≤1 Refreshing lines, got ${refreshLines.length}`); + console.log(`✓ Refreshing lines: ${refreshLines.length}`); + + // Final log should end with the completed state + const hasCompleted = job.log.some((l) => l.includes("✓ main Release")); + console.assert(hasCompleted, "Expected final log to contain completed state"); + console.log(`✓ Contains completed state`); + + // No ANSI escape sequences should remain in the log + const hasAnsi = job.log.some((l) => /\x1b\[/.test(l)); + console.assert(!hasAnsi, "Expected no ANSI sequences in final log"); + console.log(`✓ No ANSI escape sequences in output`); + + console.log("\nAll assertions passed!"); +} + +main().catch((err) => { + console.error("Test failed:", err); + process.exit(1); +}); diff --git a/web/src/components/app/release-manager.tsx b/web/src/components/app/release-manager.tsx index 145f925b..917e270b 100644 --- a/web/src/components/app/release-manager.tsx +++ b/web/src/components/app/release-manager.tsx @@ -32,6 +32,7 @@ type ReleaseStreamEvent = | { type: "snapshot"; job: ReleaseJob | null } | { type: "log"; line: string } | { type: "log.replace"; line: string } + | { type: "log.rewind"; count: number } | { type: "phase"; phase: ReleasePhase; error?: string } | { type: "runUrl"; url: string } | { type: "tag"; tag: string }; @@ -164,6 +165,9 @@ export function ReleaseManager(): JSX.Element { setJob((prev) => { if (!prev) return prev; if (event.type === "log") return { ...prev, log: [...prev.log, event.line] }; + if (event.type === "log.rewind") { + return { ...prev, log: prev.log.slice(0, -event.count) }; + } if (event.type === "log.replace") { const updated = [...prev.log]; if (updated.length > 0) { @@ -370,7 +374,7 @@ export function ReleaseManager(): JSX.Element {