src/cli/update-cli/progress.test.ts

import { afterEach, beforeEach, describe, expect, it, vi } from "vitest";
import { getUpdateRun } from "../../infra/update-run-ledger.js";
import type { UpdateRunRecord } from "../../infra/update-run-record.js";
import { defaultRuntime } from "../../runtime.js";
import { formatCliJsonFailure } from "../failure-output.js";
import { createUpdateProgress, printResult } from "./progress.js";

vi.mock("../../infra/update-run-ledger.js", () => ({ getUpdateRun: vi.fn() }));

const runId = "6631ecee-adbf-41e8-a0e3-1b88b28b0a59";
const context = { runId, env: { OPENCLAW_STATE_DIR: "/isolated/update-progress" } };
const step = { name: "build", command: "pnpm build", index: 0, total: 1 };
const result = { runId, status: "ok" as const, mode: "git" as const, steps: [], durationMs: 1200 };

function runRecord(): UpdateRunRecord {
  return {
    runId,
    createdAtMs: 100,
    updatedAtMs: 100,
    trigger: "cli",
    status: "running",
    phase: "requested",
    reason: null,
    before: { version: "2026.9.2" },
    after: {},
    target: { version: "2026.9.3" },
    origin: {},
    steps: [{ step: "requested", status: "in_progress", startedAtMs: 100 }],
    verification: {},
    repair: [],
    confirmedAtMs: null,
    finishedAtMs: null,
    downtimeMs: null,
  };
}

describe("update progress", () => {
  let run: UpdateRunRecord;
  let presentation: ReturnType<typeof createUpdateProgress> | undefined;
  const tty = Object.getOwnPropertyDescriptor(process.stdout, "isTTY");

  beforeEach(() => {
    run = runRecord();
    vi.mocked(getUpdateRun).mockImplementation(() => run);
    Object.defineProperty(process.stdout, "isTTY", { configurable: true, value: false });
  });

  afterEach(() => {
    presentation?.dispose();
    presentation = undefined;
    if (tty) {
      Object.defineProperty(process.stdout, "isTTY", tty);
    } else {
      Reflect.deleteProperty(process.stdout, "isTTY");
    }
    vi.useRealTimers();
    vi.restoreAllMocks();
  });

  it("replays rapid recorded phases once and preserves redirected step failures", () => {
    const log = vi.spyOn(defaultRuntime, "log").mockImplementation(() => {});
    presentation = createUpdateProgress(true, context);
    run.phase = "validating";
    run.steps.push(
      { step: "staging", status: "completed" },
      { step: "validating", status: "in_progress" },
    );
    presentation.progress.onStepStart?.(step);
    expect(log).toHaveBeenCalledWith("validating — build...");
    presentation.progress.onStepComplete?.({
      ...step,
      durationMs: 1200,
      exitCode: 1,
      stdoutTail: "Build type error",
    });
    const lines = log.mock.calls.flat();
    expect(lines.filter((line) => typeof line === "string" && line.startsWith("Phase:"))).toEqual([
      "Phase: requested",
      "Phase: staging",
      "Phase: validating",
    ]);
    expect(lines.join("\n")).toContain("Build type error");
  });

  it("does not leave a phase observer after initial observation fails", () => {
    const log = vi.spyOn(defaultRuntime, "log").mockImplementation(() => {});
    vi.mocked(getUpdateRun).mockImplementationOnce(() => {
      throw new Error("initial ledger read failed");
    });
    try {
      expect(() => createUpdateProgress(true, context)).toThrow("initial ledger read failed");
      run.phase = "verifying";
      run.steps = [
        { step: "requested", status: "completed" },
        { step: "verifying", status: "in_progress" },
      ];
      printResult(result, { run: context });
      const lines = log.mock.calls.flat();
      expect(lines.join("\n")).toContain("OpenClaw update in progress: verifying.");
      expect(lines.filter((line) => typeof line === "string" && line.startsWith("Phase:"))).toEqual(
        [],
      );
    } finally {
      // Replace and dispose a leaked observer when this regression runs on old code.
      vi.mocked(getUpdateRun).mockImplementation(() => run);
      presentation = createUpdateProgress(true, context);
      presentation.dispose();
      presentation = undefined;
    }
  });

  it("releases the terminal spinner when its final ledger read fails", () => {
    vi.useFakeTimers();
    vi.spyOn(defaultRuntime, "log").mockImplementation(() => {});
    vi.spyOn(process.stdout, "write").mockImplementation(() => true);
    Object.defineProperty(process.stdout, "isTTY", { configurable: true, value: true });
    const timerCount = vi.getTimerCount();
    const signals = ["SIGINT", "SIGTERM"] as const;
    const listenerCounts = signals.map((signal) => process.listenerCount(signal));
    presentation = createUpdateProgress(true, context);
    presentation.progress.onStepStart?.(step);
    expect(vi.getTimerCount()).toBeGreaterThan(timerCount);
    const failure = new Error("final ledger read failed");
    vi.mocked(getUpdateRun).mockImplementationOnce(() => {
      throw failure;
    });

    expect(() => presentation?.dispose()).toThrow(failure);

    expect(vi.getTimerCount()).toBe(timerCount);
    expect(signals.map((signal) => process.listenerCount(signal))).toEqual(listenerCounts);
  });

  it("keeps unbound step presentation independent of ledger records", () => {
    const log = vi.spyOn(defaultRuntime, "log").mockImplementation(() => {});
    presentation = createUpdateProgress(true);
    run.phase = "validating";
    run.steps.push({ step: "validating", status: "in_progress" });
    vi.mocked(getUpdateRun).mockImplementation(() => {
      throw new Error("unbound presentation must not read the ledger");
    });
    try {
      presentation.progress.onStepStart?.(step, run);
      presentation.progress.onStepComplete?.(
        { ...step, durationMs: 1200, exitCode: 1, stdoutTail: "Build type error" },
        run,
      );
      expect(log).toHaveBeenCalledWith("build...");
      expect(log.mock.calls.flat().join("\n")).toContain("Build type error");
      expect(
        log.mock.calls
          .flat()
          .filter((line) => typeof line === "string" && line.startsWith("Phase:")),
      ).toEqual([]);
    } finally {
      vi.mocked(getUpdateRun).mockImplementation(() => run);
    }
  });

  it.each([true, false])(
    "renders the report and phases from one snapshot (present: %s)",
    (present) => {
      const log = vi.spyOn(defaultRuntime, "log").mockImplementation(() => {});
      presentation = createUpdateProgress(true, context);
      const captured: UpdateRunRecord = {
        ...run,
        phase: "verifying",
        steps: [
          { step: "requested", status: "completed" },
          { step: "verifying", status: "in_progress" },
        ],
      };
      const later: UpdateRunRecord = {
        ...captured,
        phase: "repairing",
        steps: [
          { step: "requested", status: "completed" },
          { step: "verifying", status: "completed" },
          { step: "repairing", status: "in_progress" },
        ],
      };
      vi.mocked(getUpdateRun)
        .mockReturnValueOnce(present ? captured : undefined)
        .mockReturnValue(later);
      try {
        printResult(result, { run: context });
        const lines = log.mock.calls.flat();
        expect(
          lines.filter((line) => typeof line === "string" && line.startsWith("Phase:")),
        ).toEqual(present ? ["Phase: requested", "Phase: verifying"] : ["Phase: requested"]);
        expect(lines.join("\n")).toContain(
          present ? "OpenClaw update in progress: verifying." : "OpenClaw updated.",
        );
        expect(log).not.toHaveBeenCalledWith("Phase: repairing");
      } finally {
        vi.mocked(getUpdateRun).mockImplementation(() => run);
      }
    },
  );

  it("prints the exact repair command from a recoverable step", () => {
    const log = vi.spyOn(defaultRuntime, "log").mockImplementation(() => {});
    presentation = createUpdateProgress(true, context);
    const message =
      "Skipped temporary cleanup. Run: rm -rf -- '/opt/update fixture/candidate'. Reason: permission denied";
    presentation.progress.onStepComplete?.({
      ...step,
      durationMs: 1,
      exitCode: 1,
      stderrTail: "permission denied",
      advisory: { kind: "recoverable-maintenance", message },
    });
    expect(log.mock.calls.flat().join("\n")).toContain(message);
  });

  it("shows recorded failure facts without replaying the child error envelope", () => {
    const log = vi.spyOn(defaultRuntime, "log").mockImplementation(() => {});
    presentation = createUpdateProgress(true, context);
    const envelope = formatCliJsonFailure(new Error("Unable to load plugin"), {
      argv: [],
      env: {},
    });
    const failed = {
      ...step,
      durationMs: 1,
      exitCode: 1,
      stdoutTail: JSON.stringify(envelope),
      stderrTail:
        "[openclaw] The CLI command failed.\n[openclaw] Reason: Unable to load plugin\n[openclaw] Help: openclaw --help",
      failureFacts: [{ check: "doctor", code: "doctor-failed", message: "Unable to load plugin" }],
    };
    presentation.progress.onStepComplete?.(failed);
    const progress = log.mock.calls.flat().join("\n");
    expect(progress.match(/Unable to load plugin/gu)).toHaveLength(1);
    expect(progress).not.toContain("The CLI command failed");
    log.mockClear();
    printResult(
      { ...result, runId: undefined, status: "error", steps: [{ ...failed, cwd: "/fixture" }] },
      {},
    );
    const report = log.mock.calls.flat().join("\n");
    expect(report.match(/Unable to load plugin/gu)).toHaveLength(1);
    expect(report).not.toContain("Help: openclaw --help");
    for (const stdoutTail of [
      "Additional diagnostic",
      JSON.stringify({ ...envelope, details: "Additional diagnostic" }),
    ]) {
      log.mockClear();
      const detailed = { ...failed, stdoutTail, cwd: "/fixture" };
      presentation.progress.onStepComplete?.(detailed);
      expect(log.mock.calls.flat().join("\n")).toContain("Additional diagnostic");
      log.mockClear();
      printResult({ ...result, runId: undefined, status: "error", steps: [detailed] }, {});
      expect(log.mock.calls.flat().join("\n")).toContain("Additional diagnostic");
    }
    log.mockClear();
    printResult(
      {
        ...result,
        runId: undefined,
        status: "error",
        steps: [
          {
            ...failed,
            cwd: "/fixture",
            stdoutTail: "x".repeat(160),
            stderrTail: `[openclaw] Reason: Unable to load plugin\nDistinct detail ${"y".repeat(160)}\n[openclaw] Help: openclaw --help\ndoctor: Candidate doctor failed (deadline exceeded) (1000ms)`,
          },
        ],
      },
      {},
    );
    expect(log.mock.calls.flat().join("\n")).toContain("deadline exceeded");
    log.mockClear();
    presentation.progress.onStepComplete?.({
      ...failed,
      stdoutTail: undefined,
      stderrTail: undefined,
    });
    expect(
      log.mock.calls
        .flat()
        .join("\n")
        .match(/Unable to load plugin/gu),
    ).toHaveLength(1);
  });

  it("follows restart verification after step progress stops and flushes before the final report", async () => {
    vi.useFakeTimers();
    const log = vi.spyOn(defaultRuntime, "log").mockImplementation(() => {});
    presentation = createUpdateProgress(true, context);
    presentation.stop();
    // The restarted gateway writes these phases while the CLI has no active step.
    run.phase = "verifying";
    run.steps.push(
      { step: "restarting", status: "completed" },
      { step: "verifying", status: "in_progress" },
    );
    await vi.waitFor(() => expect(log).toHaveBeenCalledWith("Phase: verifying"));
    expect(log).toHaveBeenCalledWith("Phase: restarting");
    expect(log).not.toHaveBeenCalledWith("Phase: repairing");
    run.phase = "finished";
    run.status = "succeeded";
    run.after = { version: "2026.9.3" };
    run.verification = { serviceRunning: true, versionMatch: true };
    printResult(result, { run: context });
    presentation.dispose();
    const lines = log.mock.calls.flat();
    const finalPhase = lines.indexOf("Phase: finished");
    const report = lines.findIndex(
      (line) => typeof line === "string" && line.includes("OpenClaw updated to 2026.9.3"),
    );
    expect(finalPhase).toBeGreaterThan(-1);
    expect(report).toBeGreaterThan(finalPhase);
    expect(lines.filter((line) => line === "Phase: verifying")).toHaveLength(1);
    expect(lines.filter((line) => line === "Phase: finished")).toHaveLength(1);
    expect(lines.join("\n")).toContain("service running; version verified");
  });

  it("keeps JSON stdout silent until one result containing the durable row", () => {
    const log = vi.spyOn(defaultRuntime, "log").mockImplementation(() => {});
    const writeJson = vi.spyOn(defaultRuntime, "writeJson").mockImplementation(() => {});
    presentation = createUpdateProgress(false, context);
    presentation.suspend();
    presentation.resume();
    presentation.progress.onStepStart?.(step);
    presentation.progress.onStepComplete?.({ ...step, durationMs: 1, exitCode: 0 });
    presentation.stop();
    run.phase = "finished";
    run.status = "succeeded";
    printResult(result, { json: true, run: context });
    expect(log).not.toHaveBeenCalled();
    expect(writeJson).toHaveBeenCalledExactlyOnceWith({ ...result, run });
  });

  it("suspends every ledger reader through activation and resumes the recorded timeline", () => {
    vi.useFakeTimers();
    const log = vi.spyOn(defaultRuntime, "log").mockImplementation(() => {});
    presentation = createUpdateProgress(true, context);
    presentation.suspend();
    const read = vi
      .mocked(getUpdateRun)
      .mockClear()
      .mockImplementation(() => {
        throw new Error("candidate owns the migrated ledger");
      });
    presentation.progress.onStepStart?.(step);
    presentation.progress.onStepComplete?.({ ...step, durationMs: 10, exitCode: 0 });
    vi.advanceTimersByTime(500);
    expect(read).not.toHaveBeenCalled();
    expect(log).toHaveBeenCalledWith("build...");

    run.phase = "verifying";
    run.steps.push(
      { step: "activating", status: "completed" },
      { step: "restarting", status: "completed" },
      { step: "verifying", status: "in_progress" },
    );
    read.mockImplementation(() => run);
    presentation.resume();
    vi.advanceTimersByTime(500);
    expect(read).toHaveBeenCalled();
    expect(
      log.mock.calls.flat().filter((line) => typeof line === "string" && line.startsWith("Phase:")),
    ).toEqual(["Phase: requested", "Phase: activating", "Phase: restarting", "Phase: verifying"]);

    presentation.suspend();
    read.mockClear().mockImplementation(() => {
      throw new Error("candidate owns the migrated ledger");
    });
    presentation.dispose();
    presentation.dispose();
    presentation.resume();
    vi.advanceTimersByTime(500);
    expect(read).not.toHaveBeenCalled();
  });
});