| 1 | import { describe, expect, it } from "vite-plus/test"; |
| 2 | |
| 3 | import { |
| 4 | formatDuration, |
| 5 | deriveActiveWorkStartedAt, |
| 6 | deriveSubagentElapsedMs, |
| 7 | } from "./orchestrationTiming.ts"; |
| 8 | |
| 9 | describe("formatDuration", () => { |
| 10 | it.each([ |
| 11 | [0, "1ms"], |
| 12 | [250, "250ms"], |
| 13 | [1_500, "1.5s"], |
| 14 | [9_950, "10s"], |
| 15 | [22_000, "22s"], |
| 16 | [60_000, "1m"], |
| 17 | [65_000, "1m 5s"], |
| 18 | [119_500, "2m"], |
| 19 | [3_599_499, "59m 59s"], |
| 20 | [3_599_500, "1h"], |
| 21 | [3_600_000, "1h"], |
| 22 | [3_601_000, "1h 1s"], |
| 23 | [3_660_000, "1h 1m"], |
| 24 | [3_661_000, "1h 1m 1s"], |
| 25 | [7_199_500, "2h"], |
| 26 | [25_190_000, "6h 59m 50s"], |
| 27 | [90_061_000, "25h 1m 1s"], |
| 28 | ])("formats %d ms as %s", (durationMs, expected) => { |
| 29 | expect(formatDuration(durationMs)).toBe(expected); |
| 30 | }); |
| 31 | |
| 32 | it.each([-1, NaN, Infinity, -Infinity])("handles invalid durations: %s", (durationMs) => { |
| 33 | expect(formatDuration(durationMs)).toBe("0ms"); |
| 34 | }); |
| 35 | }); |
| 36 | |
| 37 | describe("deriveActiveWorkStartedAt", () => { |
| 38 | it.each([null, "2026-09-06T23:34:00.000Z"])( |
| 39 | "does not time a superseded turn when the active turn differs", |
| 40 | (sendStartedAt) => { |
| 41 | expect( |
| 42 | deriveActiveWorkStartedAt( |
| 43 | { |
| 44 | runId: "old", |
| 45 | requestedAt: "2026-09-06T23:33:00.000Z", |
| 46 | startedAt: null, |
| 47 | completedAt: null, |
| 48 | }, |
| 49 | { orchestrationStatus: "running", activeRunId: "new" }, |
| 50 | sendStartedAt, |
| 51 | ), |
| 52 | ).toBe(sendStartedAt); |
| 53 | }, |
| 54 | ); |
| 55 | |
| 56 | it("stops timing a turn that failed before its provider started", () => { |
| 57 | expect( |
| 58 | deriveActiveWorkStartedAt( |
| 59 | { |
| 60 | runId: "turn-1", |
| 61 | requestedAt: "2026-09-06T23:33:00.000Z", |
| 62 | startedAt: null, |
| 63 | completedAt: "2026-09-06T23:33:05.000Z", |
| 64 | }, |
| 65 | { orchestrationStatus: "error", activeRunId: null }, |
| 66 | null, |
| 67 | ), |
| 68 | ).toBeNull(); |
| 69 | }); |
| 70 | // The gap this closes. The projector stamps startedAt in the same update |
| 71 | // that moves the session to "running", so during provider spin-up the turn |
| 72 | // is requested with no startedAt and the session is "starting". Returning |
| 73 | // null there blinks the working indicator out between "Setting up |
| 74 | // worktree..." and "Working for 0s". |
| 75 | it("counts from requestedAt while the provider is still starting", () => { |
| 76 | expect( |
| 77 | deriveActiveWorkStartedAt( |
| 78 | { |
| 79 | runId: "turn-1", |
| 80 | requestedAt: "2026-09-06T23:33:00.000Z", |
| 81 | startedAt: null, |
| 82 | completedAt: null, |
| 83 | }, |
| 84 | { orchestrationStatus: "starting", activeRunId: null }, |
| 85 | null, |
| 86 | ), |
| 87 | ).toBe("2026-09-06T23:33:00.000Z"); |
| 88 | }); |
| 89 | |
| 90 | it("prefers the turn's own startedAt once the provider reports it", () => { |
| 91 | expect( |
| 92 | deriveActiveWorkStartedAt( |
| 93 | { |
| 94 | runId: "turn-1", |
| 95 | requestedAt: "2026-09-06T23:33:00.000Z", |
| 96 | startedAt: "2026-09-06T23:33:05.000Z", |
| 97 | completedAt: null, |
| 98 | }, |
| 99 | { orchestrationStatus: "running", activeRunId: "turn-1" }, |
| 100 | null, |
| 101 | ), |
| 102 | ).toBe("2026-09-06T23:33:05.000Z"); |
| 103 | }); |
| 104 | |
| 105 | // requestedAt must not leak past the end of the work. |
| 106 | it("stops counting once the turn has settled", () => { |
| 107 | expect( |
| 108 | deriveActiveWorkStartedAt( |
| 109 | { |
| 110 | runId: "turn-1", |
| 111 | requestedAt: "2026-09-06T23:33:00.000Z", |
| 112 | startedAt: "2026-09-06T23:33:05.000Z", |
| 113 | completedAt: "2026-09-06T23:33:09.000Z", |
| 114 | }, |
| 115 | { orchestrationStatus: "idle", activeRunId: null }, |
| 116 | null, |
| 117 | ), |
| 118 | ).toBeNull(); |
| 119 | }); |
| 120 | |
| 121 | // A session restarting with no new turn must not resurrect the old one. |
| 122 | it("does not count a settled turn while a session is starting again", () => { |
| 123 | expect( |
| 124 | deriveActiveWorkStartedAt( |
| 125 | { |
| 126 | runId: "turn-1", |
| 127 | requestedAt: "2026-09-06T23:33:00.000Z", |
| 128 | startedAt: "2026-09-06T23:33:05.000Z", |
| 129 | completedAt: "2026-09-06T23:33:09.000Z", |
| 130 | }, |
| 131 | { orchestrationStatus: "starting", activeRunId: null }, |
| 132 | null, |
| 133 | ), |
| 134 | ).toBeNull(); |
| 135 | }); |
| 136 | |
| 137 | it("falls back to the caller's send timestamp when there is no turn yet", () => { |
| 138 | expect(deriveActiveWorkStartedAt(null, null, "2026-09-06T23:33:00.000Z")).toBe( |
| 139 | "2026-09-06T23:33:00.000Z", |
| 140 | ); |
| 141 | }); |
| 142 | }); |
| 143 | |
| 144 | describe("deriveSubagentElapsedMs", () => { |
| 145 | const startedAt = "2026-09-21T12:00:00.000Z"; |
| 146 | const completedAt = "2026-09-21T12:00:10.000Z"; |
| 147 | const now = Date.parse("2026-09-21T13:00:00.000Z"); |
| 148 | it.each(["idle", "completed", "failed", "cancelled", "interrupted"] as const)( |
| 149 | "does not count the age of %s work with unknown completion timing", |
| 150 | (status) => { |
| 151 | expect(deriveSubagentElapsedMs({ status, startedAt, completedAt: null }, now)).toBeNull(); |
| 152 | expect(deriveSubagentElapsedMs({ status, startedAt, completedAt }, now)).toBe(10_000); |
| 153 | }, |
| 154 | ); |
| 155 | it("counts a resumed activation despite a stale previous completion timestamp", () => { |
| 156 | expect(deriveSubagentElapsedMs({ status: "running", startedAt, completedAt }, now)).toBe( |
| 157 | 3_600_000, |
| 158 | ); |
| 159 | expect( |
| 160 | deriveSubagentElapsedMs({ status: "running", startedAt: null, completedAt: null }, now), |
| 161 | ).toBeNull(); |
| 162 | }); |
| 163 | }); |