diff --git a/.changeset/reanalyze-wait-progress-line.md b/.changeset/reanalyze-wait-progress-line.md new file mode 100644 index 0000000..854dd5d --- /dev/null +++ b/.changeset/reanalyze-wait-progress-line.md @@ -0,0 +1,5 @@ +--- +"@codacy/codacy-cloud-cli": minor +--- + +`--reanalyze-and-wait` (on `repository` and `pull-request`) now prints an `elapsed m, status=` progress line to stderr every 60s when stderr is not a TTY. The ora spinner never wrote anything to a piped/non-interactive stderr, so silent CI/agent shells could kill the process as hung during the up-to-20-minute wait. TTY behavior, the 10s poll interval, and the 20-minute cap are unchanged. diff --git a/src/commands/AGENTS.md b/src/commands/AGENTS.md index 3152905..941e2e3 100644 --- a/src/commands/AGENTS.md +++ b/src/commands/AGENTS.md @@ -272,6 +272,11 @@ Keeps the two command handlers thin: they only supply the API-specific callbacks (`vi.spyOn(timers, "sleep").mockResolvedValue()`) for instant polling. Drive the poll loop in command tests with sequential `mockResolvedValueOnce` status values; use the optional `now` injection in `pollForAnalysis` to unit-test the timeout. +- **Non-TTY progress**: ora's spinner text never reaches a piped/non-interactive + stderr, so silent CI/agent shells (e.g. Gemini CLI) can kill the process as + hung. When `!process.stderr.isTTY` (injectable via `opts.isTTY`), the loop + writes `elapsed m, status=` to stderr every + `PROGRESS_INTERVAL_MS` (60s) instead. TTY output is unchanged. - **Rendering**: `renderReanalyzeReport(delta, durationMs)` prints the `Analysis finished in ` headline + By pattern / By severity / By category lists (pattern rows soft-capped at `PATTERN_LIMIT=20`) + an diff --git a/src/utils/reanalyze-wait.test.ts b/src/utils/reanalyze-wait.test.ts index a740a2a..543bd66 100644 --- a/src/utils/reanalyze-wait.test.ts +++ b/src/utils/reanalyze-wait.test.ts @@ -1,4 +1,4 @@ -import { describe, it, expect, vi, beforeEach } from "vitest"; +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; import { snapshotFromOverview, snapshotFromPrIssues, @@ -304,6 +304,106 @@ describe("pollForAnalysis", () => { expect(result.timedOut).toBe(true); }); + + describe("non-TTY progress line", () => { + let writeSpy: ReturnType; + beforeEach(() => { + writeSpy = vi.spyOn(process.stderr, "write").mockImplementation(() => true); + }); + afterEach(() => { + writeSpy.mockRestore(); + }); + + // Advances `now()` by one poll interval (10s) per call, still waiting to start. + function tickingClock(pollMs: number) { + let t = 0; + return () => { + const v = t; + t += pollMs; + return v; + }; + } + + it("prints nothing before 60s have elapsed", async () => { + const spinner = { text: "" }; + const now = tickingClock(10_000); + const getStatus = vi.fn<() => Promise>().mockResolvedValue({ + startedAnalysis: "2025-06-15T10:01:00Z", // after t0, never ends + endedAnalysis: "2025-06-15T10:00:00Z", + }); + + await pollForAnalysis(getStatus, { + triggeredAt: T0, + spinner, + maxWaitMs: 15_000, + now, + isTTY: false, + }); + + expect(writeSpy).not.toHaveBeenCalled(); + }); + + it("prints a line at 60s and 120s with status=waiting while not yet started", async () => { + const spinner = { text: "" }; + const now = tickingClock(10_000); + // No startedAnalysis at all: the reanalysis hasn't been picked up yet. + const getStatus = vi.fn<() => Promise>().mockResolvedValue({}); + + await pollForAnalysis(getStatus, { + triggeredAt: T0, + spinner, + maxWaitMs: 200_000, + now, + isTTY: false, + }); + + const lines = writeSpy.mock.calls.map((c: any) => c[0]); + expect(lines).toContain("elapsed 1m, status=waiting\n"); + expect(lines).toContain("elapsed 2m, status=waiting\n"); + }); + + it("prints status=inProgress once the analysis has started", async () => { + const spinner = { text: "" }; + const now = tickingClock(10_000); + const getStatus = vi + .fn<() => Promise>() + // in progress from the very first check onward + .mockResolvedValue({ + startedAnalysis: "2025-06-15T10:01:00Z", // after t0 + endedAnalysis: "2025-06-15T10:00:00Z", // not finished + }); + + await pollForAnalysis(getStatus, { + triggeredAt: T0, + spinner, + maxWaitMs: 70_000, + now, + isTTY: false, + }); + + const lines = writeSpy.mock.calls.map((c: any) => c[0]); + expect(lines).toContain("elapsed 1m, status=inProgress\n"); + }); + + it("prints nothing when stderr is a TTY", async () => { + const spinner = { text: "" }; + const now = tickingClock(10_000); + const getStatus = vi.fn<() => Promise>().mockResolvedValue({ + startedAnalysis: "2025-06-15T10:01:00Z", + endedAnalysis: "2025-06-15T10:00:00Z", + }); + + await pollForAnalysis(getStatus, { + triggeredAt: T0, + spinner, + maxWaitMs: 130_000, + now, + isTTY: true, + }); + + expect(writeSpy).not.toHaveBeenCalled(); + }); + }); }); describe("renderReanalyzeReport", () => { diff --git a/src/utils/reanalyze-wait.ts b/src/utils/reanalyze-wait.ts index 3ad4ae5..2acbcaa 100644 --- a/src/utils/reanalyze-wait.ts +++ b/src/utils/reanalyze-wait.ts @@ -25,6 +25,8 @@ import { export const POLL_INTERVAL_MS = 10_000; /** Give up after 20 minutes. */ export const MAX_WAIT_MS = 20 * 60_000; +/** Non-TTY progress line cadence: ora's spinner text never reaches a piped stderr. */ +export const PROGRESS_INTERVAL_MS = 60_000; /** Maximum number of per-pattern rows printed before collapsing into "… (N more)". */ export const PATTERN_LIMIT = 20; @@ -244,6 +246,8 @@ export interface PollOptions { maxWaitMs?: number; /** Injectable clock for tests. Defaults to Date.now. */ now?: () => number; + /** Injectable for tests. Defaults to whether stderr is a TTY. */ + isTTY?: boolean; } export interface PollResult { @@ -299,6 +303,7 @@ export async function pollForAnalysis( const pollMs = opts.pollMs ?? POLL_INTERVAL_MS; const maxWaitMs = opts.maxWaitMs ?? MAX_WAIT_MS; const now = opts.now ?? (() => Date.now()); + const isTTY = opts.isTTY ?? process.stderr.isTTY; const { spinner, triggeredAt } = opts; const startedAt = now(); const timedOut = () => now() - startedAt > maxWaitMs; @@ -306,6 +311,17 @@ export async function pollForAnalysis( const inProgress = (s: AnalysisStatus) => isAnalysisInProgress(s, triggeredAt); const done = (s: AnalysisStatus) => isAnalysisDone(s, triggeredAt); + // ora's spinner text never reaches a piped stderr, so print plain lines instead. + let phase: "waiting" | "inProgress" = "waiting"; + let nextProgressAtMs = PROGRESS_INTERVAL_MS; + const maybeLogProgress = () => { + if (isTTY) return; + while (now() - startedAt >= nextProgressAtMs) { + process.stderr.write(`elapsed ${nextProgressAtMs / 60_000}m, status=${phase}\n`); + nextProgressAtMs += PROGRESS_INTERVAL_MS; + } + }; + spinner.text = "Analysis requested. Waiting for it to start..."; let status = await getStatus(); @@ -314,15 +330,18 @@ export async function pollForAnalysis( if (timedOut()) return { status, timedOut: true }; await timers.sleep(pollMs); status = await getStatus(); + maybeLogProgress(); } // Phase B — analysis is running; wait for it to finish. if (!done(status)) { spinner.text = "Analysis in progress. This may take a few minutes..."; + phase = "inProgress"; while (!done(status)) { if (timedOut()) return { status, timedOut: true }; await timers.sleep(pollMs); status = await getStatus(); + maybeLogProgress(); } }