From 68db2ce6498a9fc2874fe5ca69297c111125f87c Mon Sep 17 00:00:00 2001 From: roboomp Date: Sat, 27 Jun 2026 20:50:19 +0000 Subject: [PATCH] fix(tui): track active processing time for time_spent status segment MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The time_spent segment rendered Date.now() - sessionStartTime, so an idle session displayed hours of "time spent" while the agent did nothing — the only inputs were wall-clock and the unmoving session start. Replace sessionStartTime with activeMs in SegmentContext and accumulate inside StatusLineComponent across agent_start -> agent_end windows. markActivityStart/markActivityEnd are idempotent (reentrant agent_start events and superseded agent_end events never double-count); the segment ticks live during an open window and freezes when the agent yields. The session-boundary hook drops the now-meaningless wall-clock argument and is renamed setSessionStartTime -> resetActiveTime; it zeroes the accumulator and drops any in-flight window so /clear / fresh-session / joined-collab paths start the meter at zero. Fixes #3681 --- packages/coding-agent/CHANGELOG.md | 4 + packages/coding-agent/src/collab/guest.ts | 2 +- .../modes/components/status-line/component.ts | 60 ++++- .../modes/components/status-line/segments.ts | 14 +- .../src/modes/components/status-line/types.ts | 9 +- .../modes/controllers/command-controller.ts | 4 +- .../src/modes/controllers/event-controller.ts | 2 + .../controllers/extension-ui-controller.ts | 2 +- .../modes/controllers/selector-controller.ts | 2 +- .../test/collab/chunked-welcome.test.ts | 2 +- .../test/collab/guest-subagent-badge.test.ts | 2 +- .../coding-agent/test/issue-953-repro.test.ts | 2 +- .../test/status-line-model.test.ts | 2 +- .../test/status-line-overflow.test.ts | 2 +- .../test/status-line-path.test.ts | 2 +- .../test/status-line-time-spent.test.ts | 221 ++++++++++++++++++ 16 files changed, 312 insertions(+), 20 deletions(-) create mode 100644 packages/coding-agent/test/status-line-time-spent.test.ts diff --git a/packages/coding-agent/CHANGELOG.md b/packages/coding-agent/CHANGELOG.md index c98881efa..110628c3e 100644 --- a/packages/coding-agent/CHANGELOG.md +++ b/packages/coding-agent/CHANGELOG.md @@ -2,6 +2,10 @@ ## [Unreleased] +### Fixed + +- Fixed the `time_spent` status-line segment ticking on wall-clock since session start, so an idle session displayed hours of "time spent" while the agent did nothing. The segment now accumulates only the union of `agent_start`→`agent_end` windows, ticking live during a turn and freezing the instant the agent yields; `/clear` and fresh-session flows zero the meter via the renamed `resetActiveTime` boundary hook. ([#3681](https://github.com/can1357/oh-my-pi/issues/3681)) + ## [16.2.2] - 2026-06-27 ### Added diff --git a/packages/coding-agent/src/collab/guest.ts b/packages/coding-agent/src/collab/guest.ts index c86261917..d85f96f94 100644 --- a/packages/coding-agent/src/collab/guest.ts +++ b/packages/coding-agent/src/collab/guest.ts @@ -588,7 +588,7 @@ export class CollabGuestLink { await this.#ctx.session.newSession(); setSessionTerminalTitle(this.#ctx.sessionManager.getSessionName(), this.#ctx.sessionManager.getCwd()); this.#ctx.statusLine.invalidate(); - this.#ctx.statusLine.setSessionStartTime(Date.now()); + this.#ctx.statusLine.resetActiveTime(); this.#ctx.updateEditorTopBorder(); this.#ctx.updateEditorBorderColor(); this.#ctx.renderInitialMessages({ clearTerminalHistory: true }); diff --git a/packages/coding-agent/src/modes/components/status-line/component.ts b/packages/coding-agent/src/modes/components/status-line/component.ts index dc9143bce..79fe8ee5d 100644 --- a/packages/coding-agent/src/modes/components/status-line/component.ts +++ b/packages/coding-agent/src/modes/components/status-line/component.ts @@ -200,7 +200,21 @@ export class StatusLineComponent implements Component { #autoCompactEnabled: boolean = true; #hookStatuses: Map = new Map(); #subagentCount: number = 0; - #sessionStartTime: number = Date.now(); + /** + * Active-processing accounting for the `time_spent` segment. + * + * `#activeMs` is the union of every completed `agent_start`→`agent_end` + * window since `resetActiveTime` last reset the counters; `#activeStartedAt` + * holds the start timestamp of the currently-running window (or `null` when + * idle). The segment displays `#activeMs + (now - #activeStartedAt)` so the + * counter ticks live during a turn and freezes the instant the agent yields. + * + * Reset by {@link resetActiveTime} so /clear and fresh-session flows + * start the meter at zero, matching the previous segment's session-reset + * behaviour without ticking through idle time. + */ + #activeMs: number = 0; + #activeStartedAt: number | null = null; #planModeStatus: { enabled: boolean; paused: boolean } | null = null; #loopModeStatus: { enabled: boolean } | null = null; #goalModeStatus: { enabled: boolean; paused: boolean } | null = null; @@ -310,8 +324,46 @@ export class StatusLineComponent implements Component { return this.#subagentCount; } - setSessionStartTime(time: number): void { - this.#sessionStartTime = time; + /** + * Reset the per-session active-time accumulators so the `time_spent` + * segment starts from zero. Called from `/clear`, fresh-session, and + * joined-collab paths; both the completed accumulator and any in-flight + * window are dropped, so a reset mid-turn ignores the running window + * (the matching `markActivityEnd` will see an idle meter and no-op). + */ + resetActiveTime(): void { + this.#activeMs = 0; + this.#activeStartedAt = null; + } + + /** + * Mark the agent as having started a unit of active processing. Idempotent: + * a second start while a window is already open is a no-op, so reentrant + * `agent_start` events (e.g. nested auto-compaction loops) do not double-count. + */ + markActivityStart(): void { + if (this.#activeStartedAt !== null) return; + this.#activeStartedAt = Date.now(); + } + + /** + * Close the currently-open active-processing window, folding its elapsed + * time into the accumulator. Idempotent when the meter is already idle so + * callers can fire it on every `agent_end` without guarding. + */ + markActivityEnd(): void { + if (this.#activeStartedAt === null) return; + this.#activeMs += Date.now() - this.#activeStartedAt; + this.#activeStartedAt = null; + } + + /** + * Snapshot of total active-processing time including the in-flight window. + * Exposed for the segment context builder; tests assert against this too. + */ + getActiveMs(): number { + if (this.#activeStartedAt === null) return this.#activeMs; + return this.#activeMs + Date.now() - this.#activeStartedAt; } setPlanModeStatus(status: { enabled: boolean; paused: boolean } | undefined): void { @@ -864,7 +916,7 @@ export class StatusLineComponent implements Component { contextWindow, autoCompactEnabled: this.#autoCompactEnabled, subagentCount: this.#subagentCount, - sessionStartTime: this.#sessionStartTime, + activeMs: this.getActiveMs(), git: { branch: gitBranch, status: gitStatus, diff --git a/packages/coding-agent/src/modes/components/status-line/segments.ts b/packages/coding-agent/src/modes/components/status-line/segments.ts index c993a5c3a..85d8060e1 100644 --- a/packages/coding-agent/src/modes/components/status-line/segments.ts +++ b/packages/coding-agent/src/modes/components/status-line/segments.ts @@ -400,13 +400,19 @@ const contextTotalSegment: StatusLineSegment = { }, }; +/** + * Total time the agent was actively processing this session — the union of + * every `agent_start`→`agent_end` window plus the currently-running window, + * sourced from {@link SegmentContext.activeMs}. Idle wall-clock between turns + * never accumulates, so the displayed total reflects how long the agent has + * been working for the user, not how long the session has been open. Hidden + * before the first second of activity to avoid flashing `0s` at session start. + */ const timeSpentSegment: StatusLineSegment = { id: "time_spent", render(ctx) { - const elapsed = Date.now() - ctx.sessionStartTime; - if (elapsed < 1000) return { content: "", visible: false }; - - return { content: withIcon(theme.icon.time, formatDuration(elapsed)), visible: true }; + if (ctx.activeMs < 1000) return { content: "", visible: false }; + return { content: withIcon(theme.icon.time, formatDuration(ctx.activeMs)), visible: true }; }, }; diff --git a/packages/coding-agent/src/modes/components/status-line/types.ts b/packages/coding-agent/src/modes/components/status-line/types.ts index b8528bdd2..4f047f86c 100644 --- a/packages/coding-agent/src/modes/components/status-line/types.ts +++ b/packages/coding-agent/src/modes/components/status-line/types.ts @@ -79,7 +79,14 @@ export interface SegmentContext { contextWindow: number; autoCompactEnabled: boolean; subagentCount: number; - sessionStartTime: number; + /** + * Active processing time accumulated this session, in ms — the union of + * every `agent_start`→`agent_end` window plus the currently-streaming + * window if the agent is running. Idle wall-clock never contributes, so + * this is what {@link StatusLineSegmentId.time_spent} renders instead of + * `Date.now() - sessionStart`. + */ + activeMs: number; git: { branch: string | null; status: { staged: number; unstaged: number; untracked: number } | null; diff --git a/packages/coding-agent/src/modes/controllers/command-controller.ts b/packages/coding-agent/src/modes/controllers/command-controller.ts index 67f0463aa..d0747b9d2 100644 --- a/packages/coding-agent/src/modes/controllers/command-controller.ts +++ b/packages/coding-agent/src/modes/controllers/command-controller.ts @@ -846,7 +846,7 @@ export class CommandController { setSessionTerminalTitle(this.ctx.sessionManager.getSessionName(), this.ctx.sessionManager.getCwd()); this.ctx.statusLine.invalidate(); - this.ctx.statusLine.setSessionStartTime(Date.now()); + this.ctx.statusLine.resetActiveTime(); this.ctx.updateEditorTopBorder(); this.ctx.updateEditorBorderColor(); this.ctx.chatContainer.clear(); @@ -1018,7 +1018,7 @@ export class CommandController { this.ctx.streamingMessage = undefined; this.ctx.pendingTools.clear(); this.ctx.statusLine.invalidate(); - this.ctx.statusLine.setSessionStartTime(Date.now()); + this.ctx.statusLine.resetActiveTime(); this.ctx.updateEditorTopBorder(); this.ctx.updateEditorBorderColor(); await this.ctx.reloadTodos(); diff --git a/packages/coding-agent/src/modes/controllers/event-controller.ts b/packages/coding-agent/src/modes/controllers/event-controller.ts index b30ac3b30..b67b4ee4c 100644 --- a/packages/coding-agent/src/modes/controllers/event-controller.ts +++ b/packages/coding-agent/src/modes/controllers/event-controller.ts @@ -302,6 +302,7 @@ export class EventController { this.ctx.statusContainer.clear(); } this.#cancelIdleCompaction(); + this.ctx.statusLine.markActivityStart(); this.#setTerminalProgress(true); this.ctx.ensureLoadingAnimation(); this.ctx.ui.requestRender(); @@ -967,6 +968,7 @@ export class EventController { async #finishAgentEnd(): Promise { this.#setTerminalProgress(false); + this.ctx.statusLine.markActivityEnd(); this.#streamingReveal.stop(); this.#toolArgsReveal.flushAll(); if (this.ctx.loadingAnimation) { diff --git a/packages/coding-agent/src/modes/controllers/extension-ui-controller.ts b/packages/coding-agent/src/modes/controllers/extension-ui-controller.ts index 5ceeb4816..a380b1d3e 100644 --- a/packages/coding-agent/src/modes/controllers/extension-ui-controller.ts +++ b/packages/coding-agent/src/modes/controllers/extension-ui-controller.ts @@ -170,7 +170,7 @@ export class ExtensionUiController { // Reset and update status line this.ctx.statusLine.invalidate(); - this.ctx.statusLine.setSessionStartTime(Date.now()); + this.ctx.statusLine.resetActiveTime(); this.ctx.updateEditorTopBorder(); this.ctx.ui.requestRender(); diff --git a/packages/coding-agent/src/modes/controllers/selector-controller.ts b/packages/coding-agent/src/modes/controllers/selector-controller.ts index 7c5c880f6..7f25a3f42 100644 --- a/packages/coding-agent/src/modes/controllers/selector-controller.ts +++ b/packages/coding-agent/src/modes/controllers/selector-controller.ts @@ -933,7 +933,7 @@ export class SelectorController { this.ctx.clearTransientSessionUi(); this.ctx.statusLine.invalidate(); - this.ctx.statusLine.setSessionStartTime(Date.now()); + this.ctx.statusLine.resetActiveTime(); this.ctx.updateEditorTopBorder(); this.ctx.updateEditorBorderColor(); this.ctx.renderInitialMessages({ clearTerminalHistory: true }); diff --git a/packages/coding-agent/test/collab/chunked-welcome.test.ts b/packages/coding-agent/test/collab/chunked-welcome.test.ts index 15f63c311..61e54fc85 100644 --- a/packages/coding-agent/test/collab/chunked-welcome.test.ts +++ b/packages/coding-agent/test/collab/chunked-welcome.test.ts @@ -208,7 +208,7 @@ function makeFailingGuestContext(failure: Error): InteractiveModeContext { statusLine: { setCollabStatus: () => {}, invalidate: () => {}, - setSessionStartTime: () => {}, + resetActiveTime: () => {}, }, ui: { requestRender: () => {} }, chatContainer: { clear: () => {} }, diff --git a/packages/coding-agent/test/collab/guest-subagent-badge.test.ts b/packages/coding-agent/test/collab/guest-subagent-badge.test.ts index 1683ea778..cb6c1738b 100644 --- a/packages/coding-agent/test/collab/guest-subagent-badge.test.ts +++ b/packages/coding-agent/test/collab/guest-subagent-badge.test.ts @@ -174,7 +174,7 @@ function makeGuestContext(counts: number[]): InteractiveModeContext { }, setCollabStatus: () => {}, invalidate: () => {}, - setSessionStartTime: () => {}, + resetActiveTime: () => {}, }, ui: { requestRender: () => {} }, chatContainer: { clear: () => {} }, diff --git a/packages/coding-agent/test/issue-953-repro.test.ts b/packages/coding-agent/test/issue-953-repro.test.ts index 3444f4d75..6d959b0ec 100644 --- a/packages/coding-agent/test/issue-953-repro.test.ts +++ b/packages/coding-agent/test/issue-953-repro.test.ts @@ -36,7 +36,7 @@ function createCtx(usage: Partial): SegmentContext contextWindow: 0, autoCompactEnabled: false, subagentCount: 0, - sessionStartTime: Date.now(), + activeMs: 0, activeRepo: null, git: { branch: null, diff --git a/packages/coding-agent/test/status-line-model.test.ts b/packages/coding-agent/test/status-line-model.test.ts index 0bdcc2807..36de22561 100644 --- a/packages/coding-agent/test/status-line-model.test.ts +++ b/packages/coding-agent/test/status-line-model.test.ts @@ -36,7 +36,7 @@ function createModelContext(advisorActive: boolean): SegmentContext { contextWindow: 0, autoCompactEnabled: false, subagentCount: 0, - sessionStartTime: Date.now(), + activeMs: 0, activeRepo: null, git: { branch: null, status: null, pr: null }, usage: null, diff --git a/packages/coding-agent/test/status-line-overflow.test.ts b/packages/coding-agent/test/status-line-overflow.test.ts index 69e806244..375ba32c2 100644 --- a/packages/coding-agent/test/status-line-overflow.test.ts +++ b/packages/coding-agent/test/status-line-overflow.test.ts @@ -60,7 +60,7 @@ function createCtx(overrides?: { pathMaxLength?: number; branch?: string | null contextWindow: 0, autoCompactEnabled: false, subagentCount: 0, - sessionStartTime: Date.now(), + activeMs: 0, activeRepo: null, git: { branch: overrides?.branch ?? null, diff --git a/packages/coding-agent/test/status-line-path.test.ts b/packages/coding-agent/test/status-line-path.test.ts index 25ca6b0fe..3c211a912 100644 --- a/packages/coding-agent/test/status-line-path.test.ts +++ b/packages/coding-agent/test/status-line-path.test.ts @@ -46,7 +46,7 @@ function createPathContext(): SegmentContext { contextWindow: 0, autoCompactEnabled: false, subagentCount: 0, - sessionStartTime: Date.now(), + activeMs: 0, activeRepo: null, git: { branch: null, diff --git a/packages/coding-agent/test/status-line-time-spent.test.ts b/packages/coding-agent/test/status-line-time-spent.test.ts new file mode 100644 index 000000000..c31c8243d --- /dev/null +++ b/packages/coding-agent/test/status-line-time-spent.test.ts @@ -0,0 +1,221 @@ +/** + * Regression for #3681: the `time_spent` status segment used to display + * `Date.now() - sessionStartTime`, i.e. wall-clock since session start, so a + * session that sat idle for hours still reported hours of "time spent". + * + * Contract: + * - The segment reads `SegmentContext.activeMs` only — wall-clock never + * leaks in. + * - `StatusLineComponent` accumulates `agent_start`→`agent_end` windows; + * reentrant starts and unmatched ends never double-count. + * - `resetActiveTime` resets both the accumulator and any in-flight + * window so `/clear` and fresh-session flows zero the meter. + */ +import { afterAll, afterEach, beforeAll, describe, expect, it, vi } from "bun:test"; +import { resetSettingsForTest, Settings } from "@oh-my-pi/pi-coding-agent/config/settings"; +import { StatusLineComponent } from "@oh-my-pi/pi-coding-agent/modes/components/status-line"; +import type { SegmentContext } from "@oh-my-pi/pi-coding-agent/modes/components/status-line/segments"; +import { renderSegment } from "@oh-my-pi/pi-coding-agent/modes/components/status-line/segments"; +import { initTheme } from "@oh-my-pi/pi-coding-agent/modes/theme/theme"; + +beforeAll(async () => { + resetSettingsForTest(); + await Settings.init({ inMemory: true }); + await initTheme(); +}); + +afterAll(() => { + resetSettingsForTest(); +}); + +afterEach(() => { + vi.restoreAllMocks(); +}); + +function createCtx(activeMs: number): SegmentContext { + return { + // The segment under test never touches `session`; stub it. + session: {} as unknown as SegmentContext["session"], + width: 120, + options: {}, + planMode: null, + loopMode: null, + goalMode: null, + collab: null, + usageStats: { + input: 0, + output: 0, + cacheRead: 0, + cacheWrite: 0, + premiumRequests: 0, + cost: 0, + tokensPerSecond: null, + }, + contextPercent: 0, + contextTokens: 0, + contextWindow: 0, + autoCompactEnabled: false, + subagentCount: 0, + activeMs, + activeRepo: null, + git: { branch: null, status: null, pr: null }, + usage: null, + }; +} + +function makeSession(): ConstructorParameters[0] { + // The component reads the session for usage stats, model, etc. The + // time-spent accounting path never touches it — stub with the minimum + // surface the constructor needs to settle. + return { + state: { messages: [], model: undefined }, + messages: [], + systemPrompt: [], + agent: { state: { tools: [] } }, + skills: [], + isStreaming: false, + isAutoThinking: false, + autoResolvedThinkingLevel: () => undefined, + isFastModeActive: () => false, + isFastModeEnabled: () => false, + getGoalModeState: () => null, + getAsyncJobSnapshot: () => ({ running: [] }), + modelRegistry: { isUsingOAuth: () => false }, + sessionManager: { + getSessionName: () => "time-spent test", + getUsageStatistics: () => ({ + input: 0, + output: 0, + cacheRead: 0, + cacheWrite: 0, + premiumRequests: 0, + cost: 0, + }), + }, + } as unknown as ConstructorParameters[0]; +} + +describe("time_spent segment", () => { + it("renders active processing time and ignores wall-clock", () => { + const rendered = renderSegment("time_spent", createCtx(10_000)); + expect(rendered.visible).toBe(true); + expect(rendered.content).toContain("10"); + expect(rendered.content).toContain("s"); + }); + + it("hides under one second of activity so the segment does not flash 0s at session start", () => { + expect(renderSegment("time_spent", createCtx(0)).visible).toBe(false); + expect(renderSegment("time_spent", createCtx(999)).visible).toBe(false); + expect(renderSegment("time_spent", createCtx(1000)).visible).toBe(true); + }); + + it("scales beyond seconds: formatDuration produces minute/hour suffixes", () => { + const fiveMin = renderSegment("time_spent", createCtx(5 * 60_000)); + expect(fiveMin.content).toContain("5m"); + const twoHours = renderSegment("time_spent", createCtx(2 * 3_600_000)); + expect(twoHours.content).toContain("2h"); + }); +}); + +describe("StatusLineComponent active-time accounting", () => { + it("accumulates only across markActivityStart/markActivityEnd windows, not idle time", () => { + const c = new StatusLineComponent(makeSession()); + let now = 1_000_000_000; + vi.spyOn(Date, "now").mockImplementation(() => now); + + // Idle: nothing accrues even as wall-clock advances. + now += 10_000; + expect(c.getActiveMs()).toBe(0); + + // First turn: 3s. + now += 10_000; + c.markActivityStart(); + now += 3_000; + c.markActivityEnd(); + expect(c.getActiveMs()).toBe(3_000); + + // Long idle gap (5 minutes) — total stays at 3s. + now += 300_000; + expect(c.getActiveMs()).toBe(3_000); + + // Second turn: 2s. Total = 5s. + c.markActivityStart(); + now += 2_000; + c.markActivityEnd(); + expect(c.getActiveMs()).toBe(5_000); + }); + + it("ticks live during an open window so the segment animates while the agent runs", () => { + const c = new StatusLineComponent(makeSession()); + let now = 2_000_000_000; + vi.spyOn(Date, "now").mockImplementation(() => now); + + c.markActivityStart(); + now += 1_500; + expect(c.getActiveMs()).toBe(1_500); + now += 2_700; + expect(c.getActiveMs()).toBe(4_200); + }); + + it("is idempotent: reentrant markActivityStart and unmatched markActivityEnd never double-count", () => { + const c = new StatusLineComponent(makeSession()); + let now = 3_000_000_000; + vi.spyOn(Date, "now").mockImplementation(() => now); + + // Unmatched end while idle is a no-op. + c.markActivityEnd(); + expect(c.getActiveMs()).toBe(0); + + c.markActivityStart(); + // A second start while already running must not reset the anchor. + now += 5_000; + c.markActivityStart(); + now += 2_000; + c.markActivityEnd(); + expect(c.getActiveMs()).toBe(7_000); + + // Closing again is a no-op. + now += 92_000; + c.markActivityEnd(); + expect(c.getActiveMs()).toBe(7_000); + }); + + it("resetActiveTime resets the active accumulator for /clear and fresh-session flows", () => { + const c = new StatusLineComponent(makeSession()); + let now = 4_000_000_000; + vi.spyOn(Date, "now").mockImplementation(() => now); + + c.markActivityStart(); + now += 10_000; + c.markActivityEnd(); + expect(c.getActiveMs()).toBe(10_000); + + c.resetActiveTime(); + expect(c.getActiveMs()).toBe(0); + + // Starting after reset begins from zero, not the prior total. + now += 2_000; + c.markActivityStart(); + now += 1_500; + c.markActivityEnd(); + expect(c.getActiveMs()).toBe(1_500); + }); + + it("resetActiveTime also drops an in-flight window so /clear during a turn starts fresh", () => { + const c = new StatusLineComponent(makeSession()); + let now = 5_000_000_000; + vi.spyOn(Date, "now").mockImplementation(() => now); + + c.markActivityStart(); + now += 4_000; + expect(c.getActiveMs()).toBe(4_000); + + c.resetActiveTime(); + expect(c.getActiveMs()).toBe(0); + + // A stale markActivityEnd after the reset must not re-credit the dropped window. + now += 5_000; + c.markActivityEnd(); + expect(c.getActiveMs()).toBe(0); + }); +});