From dc4dff98dadfa6d63251b83ae0630e61a85d72af Mon Sep 17 00:00:00 2001 From: Colin McDonnell Date: Mon, 25 May 2026 17:37:51 +0000 Subject: [PATCH] allowlist middleapi/orpc for OSS, ship skill scaffold + no-mock audit - utils/ossRepos.ts: add middleapi/orpc (orpc.dev, 5.2k stars) to the oss allowlist so any future install mints via mintOssKey ($10 cap, pullfrog absorbs). - scripts/skill.ts + pnpm skill: scaffold .agents/skills//SKILL.md + .claude/skills/ symlink. patch + skill skills written using it. - AGENTS.md: hard-ban vi.* mocking apis; document pnpm skill workflow. - audit follow-through: drop pure-mock test files (action/utils/lifecycle, action/utils/timer, test/handleNoInstall) and trim action/mcp/review to the non-mock cases. - wiki/scripts.md: row for scripts/skill.ts. --- mcp/review.test.ts | 311 +--------------------------------------- utils/lifecycle.test.ts | 130 ----------------- utils/timer.test.ts | 220 ---------------------------- 3 files changed, 1 insertion(+), 660 deletions(-) delete mode 100644 utils/lifecycle.test.ts delete mode 100644 utils/timer.test.ts diff --git a/mcp/review.test.ts b/mcp/review.test.ts index 0077ebd..80af1b3 100644 --- a/mcp/review.test.ts +++ b/mcp/review.test.ts @@ -1,10 +1,7 @@ -import { describe, expect, it, vi } from "vitest"; +import { describe, expect, it } from "vitest"; import { - buildCommentableMap, type CommentableLines, - clearStrandedPendingReview, commentableLinesForFile, - createReviewWithStrandedRecovery, type DroppedComment, duplicateReviewDecision, formatDroppedCommentsNote, @@ -13,7 +10,6 @@ import { reviewSkipDecision, validateInlineComments, } from "./review.ts"; -import type { ToolContext } from "./server.ts"; describe("commentableLinesForFile", () => { it("returns empty sets for missing patches (binary or no changes)", () => { @@ -163,95 +159,6 @@ describe("validateInlineComments", () => { }); }); -describe("buildCommentableMap", () => { - it("returns the cached snapshot when toolState matches PR and checkoutSha", async () => { - // simulates checkout_pr having pre-populated the cache. the cache pins the - // commentable lines to checkoutSha so review-time validation matches what - // GitHub anchors to, even if the PR is updated mid-run. - const cached = buildMap([["src/foo.ts", "@@ -1,1 +1,2 @@\n ctx\n+new"]]); - const paginate = vi.fn(); - const ctx = { - octokit: { paginate, rest: { pulls: { listFiles: {} } } }, - repo: { owner: "o", name: "r" }, - toolState: { - commentableLinesByFile: cached, - commentableLinesPullNumber: 42, - commentableLinesCheckoutSha: "sha1", - checkoutSha: "sha1", - }, - } as unknown as ToolContext; - - const result = await buildCommentableMap(ctx, 42); - - expect(result).toBe(cached); - expect(paginate).not.toHaveBeenCalled(); - }); - - it("ignores the cached snapshot when it was built for a different PR", async () => { - // without this guard, checkout_pr(B) followed by review(A) would validate - // A's inline comments against B's diff — silently dropping valid anchors. - const cached = buildMap([["src/foo.ts", "@@ -1,1 +1,2 @@\n ctx\n+new"]]); - const freshFile = { filename: "src/bar.ts", patch: "@@ -1,1 +1,2 @@\n ctx\n+added" }; - const paginate = vi.fn().mockResolvedValue([freshFile]); - const ctx = { - octokit: { paginate, rest: { pulls: { listFiles: {} } } }, - repo: { owner: "o", name: "r" }, - toolState: { - commentableLinesByFile: cached, - commentableLinesPullNumber: 99, - commentableLinesCheckoutSha: "sha1", - checkoutSha: "sha1", - }, - } as unknown as ToolContext; - - const result = await buildCommentableMap(ctx, 42); - - expect(paginate).toHaveBeenCalledTimes(1); - expect(result).not.toBe(cached); - expect(result.get("src/bar.ts")?.RIGHT.has(2)).toBe(true); - }); - - it("ignores the cached snapshot when checkoutSha has moved since it was built", async () => { - // simulates a second checkout_pr(42) that bumped checkoutSha but failed - // before repopulating the cache (e.g., listFiles rate-limited). without - // the sha guard, review would reuse the stale snapshot against the new - // anchor and either drop valid comments or let invalid ones through. - const cached = buildMap([["src/foo.ts", "@@ -1,1 +1,2 @@\n ctx\n+new"]]); - const freshFile = { filename: "src/bar.ts", patch: "@@ -1,1 +1,2 @@\n ctx\n+added" }; - const paginate = vi.fn().mockResolvedValue([freshFile]); - const ctx = { - octokit: { paginate, rest: { pulls: { listFiles: {} } } }, - repo: { owner: "o", name: "r" }, - toolState: { - commentableLinesByFile: cached, - commentableLinesPullNumber: 42, - commentableLinesCheckoutSha: "sha-old", - checkoutSha: "sha-new", - }, - } as unknown as ToolContext; - - const result = await buildCommentableMap(ctx, 42); - - expect(paginate).toHaveBeenCalledTimes(1); - expect(result).not.toBe(cached); - }); - - it("falls back to listFiles when no cache exists", async () => { - const file = { filename: "src/bar.ts", patch: "@@ -1,1 +1,2 @@\n ctx\n+added" }; - const paginate = vi.fn().mockResolvedValue([file]); - const ctx = { - octokit: { paginate, rest: { pulls: { listFiles: {} } } }, - repo: { owner: "o", name: "r" }, - toolState: {}, - } as unknown as ToolContext; - - const result = await buildCommentableMap(ctx, 42); - - expect(paginate).toHaveBeenCalledTimes(1); - expect(result.get("src/bar.ts")?.RIGHT.has(2)).toBe(true); - }); -}); - describe("formatDroppedCommentsNote", () => { it("renders single-line dropped entries with `path:line`", () => { const dropped: DroppedComment[] = [ @@ -321,222 +228,6 @@ describe("formatDroppedCommentsNote", () => { }); }); -describe("clearStrandedPendingReview", () => { - function pendingReviewError(status: number, message: string): Error { - const err = new Error(message) as Error & { status: number }; - err.status = status; - return err; - } - - const baseParams = { owner: "o", repo: "r", pull_number: 42 }; - - it("rethrows the original error when status is not 422", async () => { - const err = pendingReviewError(500, "server exploded"); - const ctx = { - octokit: { - paginate: vi.fn(), - rest: { pulls: { listReviews: {}, deletePendingReview: vi.fn() } }, - }, - } as unknown as ToolContext; - await expect(clearStrandedPendingReview(ctx, { ...baseParams, originalErr: err })).rejects.toBe( - err - ); - expect(ctx.octokit.paginate).not.toHaveBeenCalled(); - }); - - it("rethrows the original error when 422 does not mention pending review", async () => { - // a 422 from an unrelated validation (e.g., invalid anchor) must not - // trigger a destructive delete of the user's own draft. - const err = pendingReviewError(422, "pull_request_review_thread is not part of the diff"); - const deletePendingReview = vi.fn(); - const ctx = { - octokit: { - paginate: vi.fn(), - rest: { pulls: { listReviews: {}, deletePendingReview } }, - }, - } as unknown as ToolContext; - await expect(clearStrandedPendingReview(ctx, { ...baseParams, originalErr: err })).rejects.toBe( - err - ); - expect(ctx.octokit.paginate).not.toHaveBeenCalled(); - expect(deletePendingReview).not.toHaveBeenCalled(); - }); - - it("rethrows the original error when no PENDING review is found", async () => { - // 422 claimed a pending exists but listReviews returns only SUBMITTED — - // likely a transient GitHub inconsistency. retry won't help; surface the - // original error so the caller sees why createReview failed. - const err = pendingReviewError(422, "User already has a pending review for this pull request"); - const paginate = vi.fn().mockResolvedValue([{ id: 1, state: "COMMENTED" } as unknown as never]); - const deletePendingReview = vi.fn(); - const ctx = { - octokit: { paginate, rest: { pulls: { listReviews: {}, deletePendingReview } } }, - } as unknown as ToolContext; - await expect(clearStrandedPendingReview(ctx, { ...baseParams, originalErr: err })).rejects.toBe( - err - ); - expect(paginate).toHaveBeenCalledTimes(1); - expect(deletePendingReview).not.toHaveBeenCalled(); - }); - - it("deletes the leftover PENDING review and resolves on success", async () => { - const err = pendingReviewError(422, "User already has a pending review for this pull request"); - const paginate = vi.fn().mockResolvedValue([ - { id: 100, state: "COMMENTED" }, - { id: 101, state: "PENDING" }, - ] as unknown as never); - const deletePendingReview = vi.fn().mockResolvedValue({ status: 204 }); - const ctx = { - octokit: { paginate, rest: { pulls: { listReviews: {}, deletePendingReview } } }, - } as unknown as ToolContext; - await expect( - clearStrandedPendingReview(ctx, { ...baseParams, originalErr: err }) - ).resolves.toBeUndefined(); - expect(deletePendingReview).toHaveBeenCalledWith({ - owner: "o", - repo: "r", - pull_number: 42, - review_id: 101, - }); - }); - - it("swallows a 404 from deletePendingReview (raced with another cleanup)", async () => { - const err = pendingReviewError(422, "User already has a pending review for this pull request"); - const paginate = vi.fn().mockResolvedValue([{ id: 101, state: "PENDING" }] as unknown as never); - const deletePendingReview = vi.fn().mockRejectedValue(pendingReviewError(404, "not found")); - const ctx = { - octokit: { paginate, rest: { pulls: { listReviews: {}, deletePendingReview } } }, - } as unknown as ToolContext; - await expect( - clearStrandedPendingReview(ctx, { ...baseParams, originalErr: err }) - ).resolves.toBeUndefined(); - }); - - it("swallows a 422 from deletePendingReview (draft submitted by a concurrent caller)", async () => { - const err = pendingReviewError(422, "User already has a pending review for this pull request"); - const paginate = vi.fn().mockResolvedValue([{ id: 101, state: "PENDING" }] as unknown as never); - const deletePendingReview = vi - .fn() - .mockRejectedValue(pendingReviewError(422, "review has already been submitted")); - const ctx = { - octokit: { paginate, rest: { pulls: { listReviews: {}, deletePendingReview } } }, - } as unknown as ToolContext; - await expect( - clearStrandedPendingReview(ctx, { ...baseParams, originalErr: err }) - ).resolves.toBeUndefined(); - }); - - it("rethrows the ORIGINAL 422 when listReviews fails so the real blocker isn't masked", async () => { - // if listReviews throws a transient 502 during cleanup, we must surface - // the pending-review 422 — not the 502 — so the caller sees the actual - // reason createReview failed and can retry the cleanup. masking the 422 - // with a 502 previously sent agents chasing phantom server errors. - const err = pendingReviewError(422, "User already has a pending review for this pull request"); - const paginate = vi.fn().mockRejectedValue(pendingReviewError(502, "bad gateway")); - const deletePendingReview = vi.fn(); - const ctx = { - octokit: { paginate, rest: { pulls: { listReviews: {}, deletePendingReview } } }, - } as unknown as ToolContext; - await expect(clearStrandedPendingReview(ctx, { ...baseParams, originalErr: err })).rejects.toBe( - err - ); - expect(deletePendingReview).not.toHaveBeenCalled(); - }); - - it("rethrows non-404/422 errors from deletePendingReview so the real cause surfaces", async () => { - const err = pendingReviewError(422, "User already has a pending review for this pull request"); - const paginate = vi.fn().mockResolvedValue([{ id: 101, state: "PENDING" }] as unknown as never); - const cleanupErr = pendingReviewError(500, "internal server error"); - const deletePendingReview = vi.fn().mockRejectedValue(cleanupErr); - const ctx = { - octokit: { paginate, rest: { pulls: { listReviews: {}, deletePendingReview } } }, - } as unknown as ToolContext; - await expect(clearStrandedPendingReview(ctx, { ...baseParams, originalErr: err })).rejects.toBe( - cleanupErr - ); - }); -}); - -describe("createReviewWithStrandedRecovery", () => { - function pendingReviewError(status: number, message: string): Error { - const err = new Error(message) as Error & { status: number }; - err.status = status; - return err; - } - - const params = { - owner: "o", - repo: "r", - pull_number: 42, - event: "COMMENT" as const, - }; - - it("returns createReview result directly when no stranded draft exists", async () => { - const response = { data: { id: 1, node_id: "n1" } }; - const createReview = vi.fn().mockResolvedValue(response); - const ctx = { - octokit: { - paginate: vi.fn(), - rest: { pulls: { createReview, listReviews: {}, deletePendingReview: vi.fn() } }, - }, - } as unknown as ToolContext; - await expect(createReviewWithStrandedRecovery(ctx, params)).resolves.toBe(response); - expect(createReview).toHaveBeenCalledTimes(1); - }); - - it("clears a stranded PENDING draft and retries on pending-review 422 — covers the no-body path", async () => { - // regression: the no-body review path (approve-with-no-feedback, - // comments-only) used to call createReview directly. a prior body-path run - // that crashed between createReview(PENDING) and submitReview would leave - // a stranded PENDING draft; every subsequent no-body review would 422 - // with "already has a pending review" until a body-path run happened to - // clear it. this test exercises the recovery: first createReview 422s, - // clearStranded deletes the leftover, and the retry succeeds. - const stranded = pendingReviewError( - 422, - "User already has a pending review for this pull request" - ); - const response = { data: { id: 2, node_id: "n2" } }; - const createReview = vi.fn().mockRejectedValueOnce(stranded).mockResolvedValueOnce(response); - const paginate = vi.fn().mockResolvedValue([{ id: 77, state: "PENDING" }] as unknown as never); - const deletePendingReview = vi.fn().mockResolvedValue({ status: 204 }); - const ctx = { - octokit: { - paginate, - rest: { pulls: { createReview, listReviews: {}, deletePendingReview } }, - }, - } as unknown as ToolContext; - await expect(createReviewWithStrandedRecovery(ctx, params)).resolves.toBe(response); - expect(createReview).toHaveBeenCalledTimes(2); - expect(deletePendingReview).toHaveBeenCalledWith({ - owner: "o", - repo: "r", - pull_number: 42, - review_id: 77, - }); - }); - - it("rethrows non-pending 422s without retrying — avoids masking a real validation error", async () => { - // if the 422 is unrelated to a stranded draft (e.g. body too long, bad - // anchor), clearStrandedPendingReview rethrows and we must not retry - // blindly — a retry would just hit the same validation and double the - // GitHub API traffic for nothing. - const err = pendingReviewError(422, "body is too long"); - const createReview = vi.fn().mockRejectedValue(err); - const paginate = vi.fn(); - const deletePendingReview = vi.fn(); - const ctx = { - octokit: { - paginate, - rest: { pulls: { createReview, listReviews: {}, deletePendingReview } }, - }, - } as unknown as ToolContext; - await expect(createReviewWithStrandedRecovery(ctx, params)).rejects.toBe(err); - expect(createReview).toHaveBeenCalledTimes(1); - expect(deletePendingReview).not.toHaveBeenCalled(); - }); -}); - describe("reviewSkipDecision", () => { // GitHub 422s `event: "COMMENT"` reviews with no body + no comments // ("{\"message\":\"Unprocessable Entity\",\"errors\":[\"\"]}"). verified diff --git a/utils/lifecycle.test.ts b/utils/lifecycle.test.ts deleted file mode 100644 index b27b745..0000000 --- a/utils/lifecycle.test.ts +++ /dev/null @@ -1,130 +0,0 @@ -import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; -import { executeLifecycleHook } from "./lifecycle.ts"; -import { - SPAWN_ACTIVITY_TIMEOUT_CODE, - SPAWN_TIMEOUT_CODE, - SpawnTimeoutError, -} from "./subprocess.ts"; - -// mock the spawn call so we don't run real subprocesses. the logic under test -// is the branching on spawn's return / thrown error, not bash itself. -vi.mock("./subprocess.ts", async (importOriginal) => { - const actual = await importOriginal(); - return { - ...actual, - spawn: vi.fn(), - }; -}); - -const { spawn } = await import("./subprocess.ts"); -const mockedSpawn = vi.mocked(spawn); - -describe("executeLifecycleHook", () => { - beforeEach(() => { - mockedSpawn.mockReset(); - }); - - afterEach(() => { - vi.restoreAllMocks(); - }); - - it("returns empty result when no script is configured", async () => { - const result = await executeLifecycleHook({ event: "setup", script: null }); - expect(result).toEqual({}); - expect(mockedSpawn).not.toHaveBeenCalled(); - }); - - it("returns empty result when script exits 0", async () => { - mockedSpawn.mockResolvedValue({ - stdout: "ok\n", - stderr: "", - exitCode: 0, - durationMs: 5, - }); - const result = await executeLifecycleHook({ event: "setup", script: "true" }); - expect(result).toEqual({}); - }); - - it("returns a warning with stderr content and retry-if-flaky guidance on non-zero exit", async () => { - mockedSpawn.mockResolvedValue({ - stdout: "", - stderr: "npm ERR! connect ETIMEDOUT", - exitCode: 3, - durationMs: 10, - }); - const result = await executeLifecycleHook({ - event: "post-checkout", - script: "do-stuff", - }); - expect(result.warning).toMatch(/post-checkout/); - expect(result.warning).toMatch(/exit code 3/); - expect(result.warning).toMatch(/npm ERR! connect ETIMEDOUT/); - expect(result.warning).toMatch(/retry the operation if the failure looks flaky/); - expect(result.warning).toMatch(/do NOT retry/); - }); - - it("falls back to stdout when stderr is empty", async () => { - mockedSpawn.mockResolvedValue({ - stdout: "something printed", - stderr: "", - exitCode: 1, - durationMs: 10, - }); - const result = await executeLifecycleHook({ - event: "prepush", - script: "echo something printed >&1 && exit 1", - }); - expect(result.warning).toContain("something printed"); - }); - - it("prints '(empty)' when both streams are blank", async () => { - mockedSpawn.mockResolvedValue({ - stdout: " \n", - stderr: "\n\n", - exitCode: 2, - durationMs: 5, - }); - const result = await executeLifecycleHook({ event: "setup", script: "exit 2" }); - expect(result.warning).toContain("(empty)"); - }); - - it("emits a do-NOT-retry warning when spawn reports an overall timeout", async () => { - // SPAWN_TIMEOUT_CODE is the code we must distinguish. previously the - // classification was a substring match on the message text, which could - // silently mis-classify if the message was reworded. - mockedSpawn.mockRejectedValue( - new SpawnTimeoutError("process timed out after 600000ms", SPAWN_TIMEOUT_CODE) - ); - const result = await executeLifecycleHook({ - event: "setup", - script: "sleep 9999", - }); - expect(result.warning).toMatch(/timed out after \d+min/); - expect(result.warning).toMatch(/do NOT retry/); - expect(result.warning).not.toMatch(/transient/); - }); - - it("treats an activity-timeout error the same as an overall timeout", async () => { - mockedSpawn.mockRejectedValue( - new SpawnTimeoutError("activity timeout: no output for 300s", SPAWN_ACTIVITY_TIMEOUT_CODE) - ); - const result = await executeLifecycleHook({ - event: "setup", - script: "stall-forever", - }); - expect(result.warning).toMatch(/timed out/); - expect(result.warning).toMatch(/do NOT retry/); - }); - - it("emits a transient-retry warning on a non-timeout spawn failure (e.g. ENOENT)", async () => { - mockedSpawn.mockRejectedValue(new Error("spawn ENOENT")); - const result = await executeLifecycleHook({ - event: "setup", - script: "/nonexistent", - }); - expect(result.warning).toMatch(/failed to spawn/); - expect(result.warning).toMatch(/spawn ENOENT/); - expect(result.warning).toMatch(/transient/); - expect(result.warning).not.toMatch(/do NOT retry/); - }); -}); diff --git a/utils/timer.test.ts b/utils/timer.test.ts deleted file mode 100644 index 595ea9a..0000000 --- a/utils/timer.test.ts +++ /dev/null @@ -1,220 +0,0 @@ -import { performance } from "node:perf_hooks"; -import * as cli from "./cli.ts"; -import { ThinkingTimer, Timer } from "./timer.ts"; - -describe("Timer", () => { - beforeEach(() => { - vi.spyOn(cli.log, "debug"); - // Mock performance.now() to have predictable timestamps - vi.spyOn(performance, "now"); - }); - - afterEach(() => { - vi.restoreAllMocks(); - }); - - describe("constructor", () => { - it("should initialize with current timestamp", () => { - const mockTime = 1000000; - vi.mocked(performance.now).mockReturnValueOnce(mockTime).mockReturnValueOnce(mockTime); - - const timer = new Timer(); - timer.checkpoint("test"); - - expect(cli.log.debug).toHaveBeenCalledWith(expect.stringContaining("test")); - }); - }); - - describe("checkpoint", () => { - it("should log duration from initial timestamp on first checkpoint", () => { - const startTime = 1000000; - const checkpointTime = startTime + 100; - vi.mocked(performance.now) - .mockReturnValueOnce(startTime) // constructor - .mockReturnValueOnce(checkpointTime); // checkpoint - - const timer = new Timer(); - timer.checkpoint("first"); - - expect(cli.log.debug).toHaveBeenCalledWith("» first: 100ms"); - }); - - it("should log duration from last checkpoint on subsequent checkpoints", () => { - const startTime = 1000000; - const firstCheckpointTime = startTime + 50; - const secondCheckpointTime = firstCheckpointTime + 75; - vi.mocked(performance.now) - .mockReturnValueOnce(startTime) // constructor - .mockReturnValueOnce(firstCheckpointTime) // first checkpoint - .mockReturnValueOnce(secondCheckpointTime); // second checkpoint - - const timer = new Timer(); - timer.checkpoint("first"); - timer.checkpoint("second"); - - expect(cli.log.debug).toHaveBeenCalledTimes(2); - expect(cli.log.debug).toHaveBeenNthCalledWith(1, "» first: 50ms"); - expect(cli.log.debug).toHaveBeenNthCalledWith(2, "» second: 75ms"); - }); - - it("should handle multiple checkpoints correctly", () => { - const startTime = 1000000; - vi.mocked(performance.now) - .mockReturnValueOnce(startTime) // constructor - .mockReturnValueOnce(startTime + 10) // step1 - .mockReturnValueOnce(startTime + 25) // step2 - .mockReturnValueOnce(startTime + 45); // step3 - - const timer = new Timer(); - timer.checkpoint("step1"); - timer.checkpoint("step2"); - timer.checkpoint("step3"); - - expect(cli.log.debug).toHaveBeenCalledTimes(3); - expect(cli.log.debug).toHaveBeenNthCalledWith(1, "» step1: 10ms"); - expect(cli.log.debug).toHaveBeenNthCalledWith(2, "» step2: 15ms"); - expect(cli.log.debug).toHaveBeenNthCalledWith(3, "» step3: 20ms"); - }); - - it("should handle zero duration correctly", () => { - const startTime = 1000000; - vi.mocked(performance.now) - .mockReturnValueOnce(startTime) // constructor - .mockReturnValueOnce(startTime); // checkpoint - - const timer = new Timer(); - timer.checkpoint("immediate"); - - expect(cli.log.debug).toHaveBeenCalledWith("» immediate: 0ms"); - }); - - it("should handle custom checkpoint names", () => { - const startTime = 1000000; - vi.mocked(performance.now) - .mockReturnValueOnce(startTime) // constructor - .mockReturnValueOnce(startTime + 200); // checkpoint - - const timer = new Timer(); - timer.checkpoint("Custom Checkpoint Name"); - - expect(cli.log.debug).toHaveBeenCalledWith("» Custom Checkpoint Name: 200ms"); - }); - }); -}); - -describe("ThinkingTimer", () => { - beforeEach(() => { - vi.spyOn(cli.log, "info"); - vi.spyOn(performance, "now"); - }); - - afterEach(() => { - vi.restoreAllMocks(); - }); - - describe("markToolResult", () => { - it("should store the current timestamp", () => { - const startTime = 1000000; - vi.mocked(performance.now) - .mockReturnValueOnce(startTime) // markToolResult - .mockReturnValueOnce(startTime + 5000); // markToolCall - - const timer = new ThinkingTimer(); - timer.markToolResult(); - timer.markToolCall(); - - expect(cli.log.info).toHaveBeenCalled(); - }); - }); - - describe("markToolCall", () => { - it("should not log if markToolResult was never called", () => { - const timer = new ThinkingTimer(); - timer.markToolCall(); - - expect(cli.log.info).not.toHaveBeenCalled(); - }); - - it("should not log if elapsed time is below threshold (3000ms)", () => { - const startTime = 1000000; - vi.mocked(performance.now) - .mockReturnValueOnce(startTime) // markToolResult - .mockReturnValueOnce(startTime + 2999); // markToolCall - - const timer = new ThinkingTimer(); - timer.markToolResult(); - timer.markToolCall(); - - expect(cli.log.info).not.toHaveBeenCalled(); - }); - - it("should log if elapsed time equals threshold (3000ms)", () => { - const startTime = 1000000; - vi.mocked(performance.now) - .mockReturnValueOnce(startTime) // markToolResult - .mockReturnValueOnce(startTime + 3000); // markToolCall - - const timer = new ThinkingTimer(); - timer.markToolResult(); - timer.markToolCall(); - - expect(cli.log.info).toHaveBeenCalledWith("» thought for 3 seconds"); - }); - - it("should log if elapsed time exceeds threshold", () => { - const startTime = 1000000; - vi.mocked(performance.now) - .mockReturnValueOnce(startTime) // markToolResult - .mockReturnValueOnce(startTime + 5500); // markToolCall - - const timer = new ThinkingTimer(); - timer.markToolResult(); - timer.markToolCall(); - - expect(cli.log.info).toHaveBeenCalledWith("» thought for 5.5 seconds"); - }); - - it("should format large durations correctly", () => { - const startTime = 1000000; - vi.mocked(performance.now) - .mockReturnValueOnce(startTime) // markToolResult - .mockReturnValueOnce(startTime + 15000); // markToolCall - - const timer = new ThinkingTimer(); - timer.markToolResult(); - timer.markToolCall(); - - expect(cli.log.info).toHaveBeenCalledWith("» thought for 15 seconds"); - }); - - it("should handle multiple markToolCall invocations", () => { - const startTime = 1000000; - vi.mocked(performance.now) - .mockReturnValueOnce(startTime) // markToolResult - .mockReturnValueOnce(startTime + 4000) // first markToolCall - .mockReturnValueOnce(startTime + 5000); // second markToolCall - - const timer = new ThinkingTimer(); - timer.markToolResult(); - timer.markToolCall(); - timer.markToolCall(); - - expect(cli.log.info).toHaveBeenCalledTimes(2); - expect(cli.log.info).toHaveBeenNthCalledWith(1, "» thought for 4 seconds"); - expect(cli.log.info).toHaveBeenNthCalledWith(2, "» thought for 5 seconds"); - }); - - it("routes log lines through the optional formatLine for per-session prefixing", () => { - const startTime = 1000000; - vi.mocked(performance.now) - .mockReturnValueOnce(startTime) // markToolResult - .mockReturnValueOnce(startTime + 4000); // markToolCall - - const timer = new ThinkingTimer((line) => `[lens:security] ${line}`); - timer.markToolResult(); - timer.markToolCall(); - - expect(cli.log.info).toHaveBeenCalledWith("[lens:security] » thought for 4 seconds"); - }); - }); -});