diff --git a/CHANGELOG.md b/CHANGELOG.md index 18482354..5f54e525 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -3,6 +3,36 @@ All notable changes to **basou** are recorded here. The project follows [Semantic Versioning](https://semver.org/spec/v2.0.0.html) starting with v0.1.0. +## Unreleased + +### Added + +- `session.metrics.machine_active_time_ms` (additive, optional) — model compute + time: the summed duration of a source's per-turn spans (Codex + `task_complete.duration_ms`). A SUBSET of a session's active time, kept as a + separate labeled measure. Unlike `active_intervals` it is a plain sum, NOT + wall-clock-deduplicated, so two concurrent sessions can sum past their + billable (union) active wall-clock — intended, as two models working at once + did two machine-hours in one wall-clock hour. Captured only for sources that + record per-turn duration (Codex today); absent otherwise. Surfaced as a + `Model working` line in `basou stats` (and `--by-source` / `--by-day` / + `--json`), as a `machine` segment on the `basou session show` `Work:` line, + and in the `basou view` Stats tab. Re-import (`--force`, or `basou refresh`) + to backfill existing Codex sessions. + +### Changed + +- Codex active time is now derived from the rollout's real per-turn intervals + (`task_started` → `task_complete`) for the in-turn portion — the log's true + wall-clock span, uncapped, and crediting the session's final turn — unioned + with the gap-capped engagement series for between-turn bridging. + `active_time_method` is `turn-intervals` for these sessions. The active-time + SEMANTICS are unchanged (still human-engaged time with idle gaps over 5 + minutes excluded); only the in-turn precision improves, so a re-imported Codex + session's active time typically rises (long turns are no longer truncated at + the gap cap, and the final turn is counted). Claude imports are unchanged + (their transcripts carry no explicit per-turn duration). + ## 0.5.0 — 2026-06-04 ### Added diff --git a/packages/cli/src/commands/session.test.ts b/packages/cli/src/commands/session.test.ts index e85aec32..c9109029 100644 --- a/packages/cli/src/commands/session.test.ts +++ b/packages/cli/src/commands/session.test.ts @@ -109,12 +109,16 @@ type SessionFixture = { startedAt?: string; endedAt?: string; workingDirectory?: string; - source?: { kind: "claude-code-adapter" | "human" | "import" | "terminal"; version: "0.1.0" }; + source?: { + kind: "claude-code-adapter" | "codex-import" | "human" | "import" | "terminal"; + version: "0.1.0"; + }; label?: string; exitCode?: number | null; args?: string[]; command?: string; relatedFiles?: string[]; + metrics?: Record; events?: string; // raw events.jsonl body (concatenated lines, each with \n) }; @@ -142,6 +146,7 @@ async function createSession(repo: string, fixture: SessionFixture): Promise { // Work summary line: action counts + time proxies. expect(stdout).toContain("Work:"); expect(stdout).toContain("dec"); + // No machine metrics on this session, so no machine segment. + expect(stdout).not.toContain("machine "); + }); + + it("case 11b: Work line shows machine compute when captured", async () => { + const repo = await setupInitedRepo(); + const id = SES("Y0M"); + const events = + SESSION_STARTED_LINE(id, "M01", "2026-05-08T11:00:00+09:00") + + SESSION_ENDED_LINE(id, "M02", "2026-05-08T11:30:00+09:00"); + await createSession(repo, { + id, + source: { kind: "codex-import", version: "0.1.0" }, + endedAt: "2026-05-08T11:30:00+09:00", + metrics: { + active_time_ms: 30 * 60 * 1000, + active_intervals: [ + { start: "2026-05-08T11:00:00+09:00", end: "2026-05-08T11:30:00+09:00" }, + ], + active_time_method: "turn-intervals", + machine_active_time_ms: 12 * 60 * 1000, + }, + events, + }); + const out = captureStdout(); + await doRunSessionShow(id, {}, { cwd: repo }); + const stdout = joinCalls(out); + expect(stdout).toContain("Work:"); + expect(stdout).toContain("machine 12m"); }); it("case 12: unique prefix hit resolves to the full ID", async () => { diff --git a/packages/cli/src/commands/session.ts b/packages/cli/src/commands/session.ts index b58ea46a..7556ff46 100644 --- a/packages/cli/src/commands/session.ts +++ b/packages/cli/src/commands/session.ts @@ -390,6 +390,9 @@ function formatSessionWork(session: Session, events: Event[], now: Date): string parts.push(`${w.commandCount} cmd / ${w.fileChangedCount} files / ${w.decisionCount} dec`); const activeBasis = w.activeTimeBasis === "engaged-turns" ? "turns" : "events"; parts.push(`active ${formatDurationMs(w.activeTimeMs)} (${activeBasis})`); + if (w.availability.machineActive) { + parts.push(`machine ${formatDurationMs(w.machineActiveTimeMs)}`); + } parts.push(`span ${formatDurationMs(w.sessionSpanMs)}${w.open ? " (open)" : ""}`); parts.push( w.availability.commandTime diff --git a/packages/cli/src/commands/stats.test.ts b/packages/cli/src/commands/stats.test.ts index 8607d40b..46370bcb 100644 --- a/packages/cli/src/commands/stats.test.ts +++ b/packages/cli/src/commands/stats.test.ts @@ -137,6 +137,29 @@ describe("basou stats", () => { expect(text).toContain("Reasoning tokens:"); expect(text).toContain("Billable active:"); expect(text).toContain("Command:"); + // No machine_active_time_ms on this session, so no model-working line. + expect(text).not.toContain("Model working:"); + }); + + it("prints a model-working line when machine compute was captured", async () => { + const repo = await setupInitedRepo(); + await placeSession(repo, { + id: "ses_01HXABCDEF1234567890ABCDE1", + source: "codex-import", + endedAt: "2026-05-10T00:30:00.000Z", + metrics: { + active_time_ms: 30 * 60 * 1000, + active_intervals: [{ start: "2026-05-10T00:00:00.000Z", end: "2026-05-10T00:30:00.000Z" }], + active_time_method: "turn-intervals", + machine_active_time_ms: 12 * 60 * 1000, + }, + }); + const out = captureStdout(); + await doRunStats({}, ctx(repo)); + const text = out.join("\n"); + expect(text).toContain("Model working:"); + expect(text).toContain("12m"); + expect(text).toContain("1 of 1 sessions"); }); it("caveats command time when a claude-code-import session is present", async () => { @@ -217,6 +240,24 @@ describe("basou stats", () => { expect(text).toMatch(/2026-05-\d{2}: /); }); + it("--by-day shows model compute on a day with machine time", async () => { + const repo = await setupInitedRepo(); + await placeSession(repo, { + id: "ses_01HXABCDEF1234567890ABCDE6", + source: "codex-import", + endedAt: "2026-05-10T00:30:00.000Z", + metrics: { + active_intervals: [{ start: "2026-05-10T00:00:00.000Z", end: "2026-05-10T00:30:00.000Z" }], + active_time_method: "turn-intervals", + machine_active_time_ms: 12 * 60 * 1000, + }, + }); + const out = captureStdout(); + await doRunStats({ byDay: true }, ctx(repo)); + const text = out.join("\n"); + expect(text).toMatch(/active \(model 12m/); + }); + it("shows a summed line only when concurrent sessions overlap", async () => { const repo = await setupInitedRepo(); await placeSession(repo, { diff --git a/packages/cli/src/commands/stats.ts b/packages/cli/src/commands/stats.ts index f839e7bf..4d268c19 100644 --- a/packages/cli/src/commands/stats.ts +++ b/packages/cli/src/commands/stats.ts @@ -122,6 +122,12 @@ function printStatsText(result: WorkStatsResult, bySource: boolean, byDay: boole ` Summed: ${formatDurationMs(t.activeTimeMs)} (per-session sum; concurrent sessions double-counted)`, ); } + if (t.machineActiveAvailable) { + const machineSessions = result.sessions.filter((s) => s.availability.machineActive).length; + console.log( + ` Model working: ${formatDurationMs(t.machineActiveTimeMs)} (model compute, subset of active; Codex turn duration on ${machineSessions} of ${t.sessionCount} sessions; summed, not wall-clock-deduped)`, + ); + } const openPart = t.openSessionCount > 0 ? `; ${t.openSessionCount} open counted to now` : ""; console.log( ` Span: ${formatDurationMs(t.sessionSpanMs)} (total elapsed${openPart})`, @@ -145,8 +151,10 @@ function printStatsText(result: WorkStatsResult, bySource: boolean, byDay: boole console.log(""); console.log("By day (billable time x volume):"); for (const d of result.byDay) { + const machine = + d.machineActiveTimeMs > 0 ? ` (model ${formatDurationMs(d.machineActiveTimeMs)})` : ""; console.log( - ` ${d.date}: ${formatDurationMs(d.billableActiveTimeMs)} active, ${formatInt(d.tokens.output)} out tok, ${d.commandCount} cmd / ${d.fileChangedCount} files / ${d.decisionCount} dec`, + ` ${d.date}: ${formatDurationMs(d.billableActiveTimeMs)} active${machine}, ${formatInt(d.tokens.output)} out tok, ${d.commandCount} cmd / ${d.fileChangedCount} files / ${d.decisionCount} dec`, ); } } @@ -155,7 +163,10 @@ function printStatsText(result: WorkStatsResult, bySource: boolean, byDay: boole function describeSource(s: SourceWorkStats): string { const cmd = s.commandTimeReliable ? formatDurationMs(s.commandTimeMs) : "n/a"; const tokens = s.tokensAvailable ? `${formatInt(s.tokens.output)} out tok` : "no tokens"; - return `${s.sessionCount} sessions, ${tokens}, active ${formatDurationMs(s.activeTimeMs)}, command ${cmd}`; + const machine = s.machineActiveAvailable + ? `, model ${formatDurationMs(s.machineActiveTimeMs)}` + : ""; + return `${s.sessionCount} sessions, ${tokens}, active ${formatDurationMs(s.activeTimeMs)}${machine}, command ${cmd}`; } /** "1,234,567" — thousands-separated, fixed en-US so output is deterministic. */ diff --git a/packages/cli/src/lib/view-ui.ts b/packages/cli/src/lib/view-ui.ts index 7af7e6c6..0cd64273 100644 --- a/packages/cli/src/lib/view-ui.ts +++ b/packages/cli/src/lib/view-ui.ts @@ -279,6 +279,10 @@ export const VIEW_HTML = ` if (t.activeTimeMs !== t.billableActiveTimeMs) { timeRows.push(kvrow('summed', fmtDur(t.activeTimeMs) + ' (concurrent sessions double-counted)')); } + if (t.machineActiveAvailable) { + var machineSessions = sessions.filter(function (s) { return s.availability && s.availability.machineActive; }).length; + timeRows.push(kvrow('model working', fmtDur(t.machineActiveTimeMs) + ' (model compute, subset of active; Codex turn duration on ' + machineSessions + ' of ' + t.sessionCount + ' sessions; not wall-clock-deduped)')); + } timeRows.push(kvrow('span', fmtDur(t.sessionSpanMs) + (t.openSessionCount > 0 ? ' (' + t.openSessionCount + ' open)' : ''))); timeRows.push(kvrow('command', fmtDur(t.commandTimeMs) + (t.commandTimeReliable ? '' : ' (some sessions report 0)'))); detail.appendChild(el('table', { class: 'kv' }, [el('tbody', {}, timeRows)])); @@ -286,16 +290,18 @@ export const VIEW_HTML = ` detail.appendChild(el('h3', { text: 'By source' })); d.bySource.forEach(function (s) { var cmd = s.commandTimeReliable ? fmtDur(s.commandTimeMs) : 'n/a'; + var machine = s.machineActiveAvailable ? ', model ' + fmtDur(s.machineActiveTimeMs) : ''; detail.appendChild(el('div', { class: 'row' }, [ - el('span', { text: s.sourceKind + ': ' + s.sessionCount + ' sessions, ' + numfmt(s.tokens.output) + ' out tok, active ' + fmtDur(s.activeTimeMs) + ', command ' + cmd }) + el('span', { text: s.sourceKind + ': ' + s.sessionCount + ' sessions, ' + numfmt(s.tokens.output) + ' out tok, active ' + fmtDur(s.activeTimeMs) + machine + ', command ' + cmd }) ])); }); } if (d.byDay && d.byDay.length) { detail.appendChild(el('h3', { text: 'By day (billable time x volume)' })); d.byDay.forEach(function (day) { + var dayMachine = day.machineActiveTimeMs > 0 ? ' (model ' + fmtDur(day.machineActiveTimeMs) + ')' : ''; detail.appendChild(el('div', { class: 'row' }, [ - el('span', { text: day.date + ': ' + fmtDur(day.billableActiveTimeMs) + ' active, ' + numfmt(day.tokens.output) + ' out tok, ' + day.commandCount + ' cmd / ' + day.fileChangedCount + ' files / ' + day.decisionCount + ' dec' }) + el('span', { text: day.date + ': ' + fmtDur(day.billableActiveTimeMs) + ' active' + dayMachine + ', ' + numfmt(day.tokens.output) + ' out tok, ' + day.commandCount + ' cmd / ' + day.fileChangedCount + ' files / ' + day.decisionCount + ' dec' }) ])); }); } diff --git a/packages/core/src/adapters/codex/rollout-importer.test.ts b/packages/core/src/adapters/codex/rollout-importer.test.ts index 3da5744f..281aeef6 100644 --- a/packages/core/src/adapters/codex/rollout-importer.test.ts +++ b/packages/core/src/adapters/codex/rollout-importer.test.ts @@ -37,6 +37,22 @@ function execOutput(ts: string, callId: string, output: string): CodexRolloutRec }; } +function eventMsg(ts: string, type: string): CodexRolloutRecord { + return { type: "event_msg", timestamp: ts, payload: { type, message: "..." } }; +} + +function taskStarted(ts: string, turnId: string): CodexRolloutRecord { + return { type: "event_msg", timestamp: ts, payload: { type: "task_started", turn_id: turnId } }; +} + +function taskComplete(ts: string, turnId: string, durationMs: number): CodexRolloutRecord { + return { + type: "event_msg", + timestamp: ts, + payload: { type: "task_complete", turn_id: turnId, duration_ms: durationMs }, + }; +} + function transform(records: CodexRolloutRecord[]) { return codexRolloutToImportPayload(records, { workspaceId: WS_ID }); } @@ -256,11 +272,6 @@ describe("codexRolloutToImportPayload", () => { }); it("captures engaged time from conversation + exec, excluding token_count heartbeats", () => { - const eventMsg = (ts: string, type: string): CodexRolloutRecord => ({ - type: "event_msg", - timestamp: ts, - payload: { type, message: "..." }, - }); const tokenEvent = (ts: string): CodexRolloutRecord => ({ type: "event_msg", timestamp: ts, @@ -288,5 +299,140 @@ describe("codexRolloutToImportPayload", () => { ]); // The token_count is still captured as token usage, just not as engagement. expect(payload.session.metrics?.output_tokens).toBe(1); + // No task records: in-turn time stays gap-capped and machine time is absent. + expect(payload.session.metrics?.machine_active_time_ms).toBeUndefined(); + }); + + it("uses real task intervals (uncapped in-turn) and captures machine compute", () => { + const records: CodexRolloutRecord[] = [ + sessionMeta("2026-05-10T00:00:00.000Z"), + eventMsg("2026-05-10T00:00:00.000Z", "user_message"), + taskStarted("2026-05-10T00:00:00.000Z", "t1"), + // The only intermediate engagement point; the gap to task_complete is far + // over the cap, so the gap-capped series alone would credit < the turn. + execCall("2026-05-10T00:00:30.000Z", "call_1", "ls"), + taskComplete("2026-05-10T00:10:00.000Z", "t1", 10 * 60 * 1000), + ]; + const payload = transform(records); + expect(payload).not.toBeNull(); + if (payload === null) return; + expect(SessionImportPayloadSchema.safeParse(payload).success).toBe(true); + // The full 10-min turn span is credited (not the ~5.5 min the 5-min gap cap + // over the points would give), and the method is labeled accordingly. + expect(payload.session.metrics?.active_time_ms).toBe(10 * 60 * 1000); + expect(payload.session.metrics?.active_time_method).toBe("turn-intervals"); + expect(payload.session.metrics?.active_intervals).toEqual([ + { start: "2026-05-10T00:00:00.000Z", end: "2026-05-10T00:10:00.000Z" }, + ]); + // Machine compute = summed task_complete.duration_ms. + expect(payload.session.metrics?.machine_active_time_ms).toBe(10 * 60 * 1000); + }); + + it("bridges a sub-cap inter-turn gap but not an over-cap idle, and sums machine", () => { + const records: CodexRolloutRecord[] = [ + sessionMeta("2026-05-10T00:00:00.000Z"), + taskStarted("2026-05-10T00:00:00.000Z", "t1"), + execCall("2026-05-10T00:00:30.000Z", "call_1", "ls"), + taskComplete("2026-05-10T00:01:00.000Z", "t1", 60 * 1000), + // 9-min idle before the next turn: over the 5-min cap, so not bridged. + taskStarted("2026-05-10T00:10:00.000Z", "t2"), + execCall("2026-05-10T00:10:30.000Z", "call_2", "ls"), + taskComplete("2026-05-10T00:11:00.000Z", "t2", 60 * 1000), + ]; + const payload = transform(records); + expect(payload).not.toBeNull(); + if (payload === null) return; + expect(SessionImportPayloadSchema.safeParse(payload).success).toBe(true); + // Turn 1 [00:00,00:01] extends to 00:06 (5-min post-turn human-engaged + // credit from the gap cap), then idle; turn 2 [00:10,00:11] stands alone. + expect(payload.session.metrics?.active_intervals).toEqual([ + { start: "2026-05-10T00:00:00.000Z", end: "2026-05-10T00:06:00.000Z" }, + { start: "2026-05-10T00:10:00.000Z", end: "2026-05-10T00:11:00.000Z" }, + ]); + expect(payload.session.metrics?.active_time_ms).toBe(7 * 60 * 1000); + expect(payload.session.metrics?.machine_active_time_ms).toBe(2 * 60 * 1000); + }); + + it("reconstructs the turn start from duration when task_started is absent", () => { + const records: CodexRolloutRecord[] = [ + sessionMeta("2026-05-10T00:00:00.000Z"), + // A session that began mid-turn: only task_complete is present. + execCall("2026-05-10T00:05:00.000Z", "call_1", "ls"), + taskComplete("2026-05-10T00:10:00.000Z", "t1", 10 * 60 * 1000), + ]; + const payload = transform(records); + expect(payload).not.toBeNull(); + if (payload === null) return; + expect(SessionImportPayloadSchema.safeParse(payload).success).toBe(true); + // start = completion (00:10) - duration (10 min) = 00:00, even though the + // earliest engagement point is the exec at 00:05. + expect(payload.session.metrics?.active_intervals).toEqual([ + { start: "2026-05-10T00:00:00.000Z", end: "2026-05-10T00:10:00.000Z" }, + ]); + expect(payload.session.metrics?.active_time_method).toBe("turn-intervals"); + expect(payload.session.metrics?.machine_active_time_ms).toBe(10 * 60 * 1000); + }); + + it("de-duplicates a repeated task_complete so machine stays a subset of active", () => { + const records: CodexRolloutRecord[] = [ + sessionMeta("2026-05-10T00:00:00.000Z"), + taskStarted("2026-05-10T00:00:00.000Z", "t1"), + execCall("2026-05-10T00:00:30.000Z", "call_1", "ls"), + taskComplete("2026-05-10T00:10:00.000Z", "t1", 10 * 60 * 1000), + // A duplicate completion for the same turn must not double-count machine. + taskComplete("2026-05-10T00:10:00.000Z", "t1", 10 * 60 * 1000), + ]; + const payload = transform(records); + expect(payload).not.toBeNull(); + if (payload === null) return; + const m = payload.session.metrics; + expect(m?.machine_active_time_ms).toBe(10 * 60 * 1000); + expect(m?.machine_active_time_ms).toBeLessThanOrEqual(m?.active_time_ms ?? 0); + }); + + it("omits machine compute when only some completions carry a duration", () => { + const records: CodexRolloutRecord[] = [ + sessionMeta("2026-05-10T00:00:00.000Z"), + taskStarted("2026-05-10T00:00:00.000Z", "t1"), + execCall("2026-05-10T00:00:30.000Z", "call_1", "ls"), + taskComplete("2026-05-10T00:01:00.000Z", "t1", 60 * 1000), + taskStarted("2026-05-10T00:02:00.000Z", "t2"), + execCall("2026-05-10T00:02:30.000Z", "call_2", "ls"), + // Second turn carries no duration_ms (older format); machine is then + // partial and must be omitted rather than reported as complete. + { + type: "event_msg", + timestamp: "2026-05-10T00:03:00.000Z", + payload: { type: "task_complete", turn_id: "t2" }, + }, + ]; + const payload = transform(records); + expect(payload).not.toBeNull(); + if (payload === null) return; + // Active time is still derived from the turn intervals. + expect(payload.session.metrics?.active_time_method).toBe("turn-intervals"); + expect(payload.session.metrics?.active_time_ms).toBeGreaterThan(0); + expect(payload.session.metrics?.machine_active_time_ms).toBeUndefined(); + }); + + it("clamps a reconstructed turn start to the session floor", () => { + const records: CodexRolloutRecord[] = [ + // Session first becomes visible at 00:05; the only turn completed at 00:10 + // reporting a 10-min duration, so its reconstructed start (00:00) precedes + // the session and must be clamped to 00:05. + sessionMeta("2026-05-10T00:05:00.000Z"), + execCall("2026-05-10T00:05:00.000Z", "call_1", "ls"), + taskComplete("2026-05-10T00:10:00.000Z", "t1", 10 * 60 * 1000), + ]; + const payload = transform(records); + expect(payload).not.toBeNull(); + if (payload === null) return; + expect(payload.session.metrics?.active_intervals).toEqual([ + { start: "2026-05-10T00:05:00.000Z", end: "2026-05-10T00:10:00.000Z" }, + ]); + expect(payload.session.metrics?.active_time_ms).toBe(5 * 60 * 1000); + // Machine is bounded to the in-session span (5 min), not the full 10-min + // duration, so it stays a subset of active time. + expect(payload.session.metrics?.machine_active_time_ms).toBe(5 * 60 * 1000); }); }); diff --git a/packages/core/src/adapters/codex/rollout-importer.ts b/packages/core/src/adapters/codex/rollout-importer.ts index e1ced415..b97baeae 100644 --- a/packages/core/src/adapters/codex/rollout-importer.ts +++ b/packages/core/src/adapters/codex/rollout-importer.ts @@ -6,7 +6,10 @@ import { ACTIVE_GAP_CAP_MS, activeTimeFromTimestamps, ENGAGED_TURNS_METHOD, + type IntervalMs, intervalsMsToIso, + TURN_INTERVALS_METHOD, + unionDurationMs, } from "../../stats/active-time.js"; /** @@ -51,6 +54,13 @@ export type CodexRolloutToPayloadOptions = { * are parsed from the paired `function_call_output` (matched by `call_id`), * whose text carries `Process exited with code N` and `Wall time: X seconds`. * + * Per-session `metrics` are also derived: token totals from the cumulative + * `token_count` events; active time from the real `task_started` -> + * `task_complete` turn spans (in-turn, uncapped) unioned with the gap-capped + * engagement series (between-turn bridging), labeled `turn-intervals`; and + * `machine_active_time_ms` from the summed `task_complete.duration_ms` (model + * compute time, a subset of active time). + * * Unlike the Claude importer this derives no `file_changed`: Codex has no * dedicated edit tool and applies edits inside `exec_command` (e.g. * `apply_patch`), so there is no clean file-change signal to map. Decisions @@ -75,6 +85,10 @@ export function codexRolloutToImportPayload( // which arrives after the originating `function_call`; pre-index outputs by // call_id so commands can be completed in the single forward pass below. const outputsByCallId = indexOutputs(records); + // A turn's start lives on its `task_started`; pair it with the matching + // `task_complete` by turn_id so each turn yields a real wall-clock interval. + // Pre-indexed (rather than matched inline) so it is robust to record order. + const turnStartMsByTurnId = indexTaskStarts(records); const derived: Event[] = []; // Real rollouts are written in arrival order, but track the earliest / // latest timestamp explicitly (rather than trusting first / last line) and @@ -90,7 +104,22 @@ export function codexRolloutToImportPayload( // conversation turns (user / agent messages and task boundaries) plus the // exec_command actions. Token-count heartbeats, reasoning, web-search and // tool-output records are excluded so they cannot inflate billable time. + // These bridge BETWEEN turns (gap-capped); within a turn the explicit + // task interval below supersedes them on merge. const engagementTsMs: number[] = []; + // Real per-turn wall-clock spans (`task_started` -> `task_complete`). Used + // for the in-turn portion of active time (uncapped, and crediting the final + // turn), unioned with the gap-capped engagement series above. + // One per (deduped) `task_complete`: the turn's wall-clock interval and its + // reported model-compute duration. Resolved into active time + machine time + // after the loop, once `minTs` is known (so a reconstructed start can be + // clamped to the session floor). `durationMs` is 0 when the rollout records + // none (older format). + const completions: Array<{ interval: IntervalMs | undefined; durationMs: number }> = []; + // De-dup completions by turn_id: a duplicate `task_complete` for the same + // turn would double-count machine time (breaking machine <= active) while the + // union-merged interval counts the turn once. First completion per turn wins. + const completedTurnIds = new Set(); for (const record of records) { const ts = readString(record.timestamp); @@ -129,6 +158,17 @@ export function codexRolloutToImportPayload( const tsMs = Date.parse(ts); if (Number.isFinite(tsMs)) engagementTsMs.push(tsMs); } + if (pt === "task_complete") { + const turnId = readString(payload.turn_id); + // Skip a duplicate completion for an already-counted turn (F1). + if (turnId === undefined || !completedTurnIds.has(turnId)) { + if (turnId !== undefined) completedTurnIds.add(turnId); + completions.push({ + interval: turnIntervalFromComplete(ts, payload, turnStartMsByTurnId), + durationMs: readNonNegInt(payload.duration_ms), + }); + } + } // event_msg records are never response_items; skip the rest. continue; } @@ -176,13 +216,45 @@ export function codexRolloutToImportPayload( const date = minTs.slice(0, 10); const label = `codex ${date}: ${commandCount} ${commandCount === 1 ? "command" : "commands"}`; - // Engaged-active time from the genuine engagement series (needs >= 2 points - // to bound any gap); omitted when too sparse so stats falls back to the - // event-derived measure. + // Resolve per-turn intervals + machine compute now that `minTs` is known. + // A turn whose `task_started` is absent has its start reconstructed as + // `end - duration_ms`, which can precede the earliest record (and thus + // `started_at`); clamp to `minTs` so no active interval predates the session + // (F3). Machine compute for each turn is bounded by its clamped in-session + // span, so a clamped turn can never push the session's machine time above its + // active time (the documented `machine <= active` subset; F1). For ordinary + // fully-logged turns the span is >= the reported duration, so this is exactly + // `duration_ms`. `machine` is honest only when EVERY completed turn carried a + // duration: a mix of duration-bearing and duration-less completions would + // report a partial compute total as if complete, so it is omitted then (F2). + const minTsMs = Date.parse(minTs); + const turnIntervals: IntervalMs[] = []; + let machineActiveMs = 0; + let allCompletedTurnsHaveDuration = true; + for (const { interval, durationMs } of completions) { + if (durationMs <= 0) allCompletedTurnsHaveDuration = false; + if (interval === undefined) continue; + const start = Number.isFinite(minTsMs) ? Math.max(interval[0], minTsMs) : interval[0]; + const end = interval[1]; + if (!(start < end)) continue; + turnIntervals.push([start, end]); + machineActiveMs += Math.min(durationMs, end - start); + } + + // Active time = union of the real per-turn intervals (in-turn, uncapped) and + // the gap-capped engagement series (between-turn bridging). The merge dedups + // their overlap, so the in-turn portion is the turn span while between-turn + // human time is still credited up to the cap. A single explicit turn is + // enough to bound active time, so the >= 2-point fallback only matters when + // no turn intervals exist. Omitted when neither yields a span, so stats falls + // back to the event-derived measure. Method label reflects which was used. + const pointResult = activeTimeFromTimestamps(engagementTsMs, ACTIVE_GAP_CAP_MS); const active = - engagementTsMs.length >= 2 - ? activeTimeFromTimestamps(engagementTsMs, ACTIVE_GAP_CAP_MS) + turnIntervals.length > 0 || pointResult.intervals.length > 0 + ? unionDurationMs([...turnIntervals, ...pointResult.intervals]) : undefined; + const activeMethod = turnIntervals.length > 0 ? TURN_INTERVALS_METHOD : ENGAGED_TURNS_METHOD; + const machineActive = allCompletedTurnsHaveDuration ? machineActiveMs : 0; // Token totals from the last cumulative token_count event; include only the // fields actually present (> 0). Metrics is emitted if either token usage or @@ -209,11 +281,12 @@ export function codexRolloutToImportPayload( ...(active !== undefined && active.ms > 0 ? { active_time_ms: active.ms, - active_intervals: intervalsMsToIso(active.intervals), + active_intervals: intervalsMsToIso(active.merged), active_gap_cap_ms: ACTIVE_GAP_CAP_MS, - active_time_method: ENGAGED_TURNS_METHOD, + active_time_method: activeMethod, } : {}), + ...(machineActive > 0 ? { machine_active_time_ms: machineActive } : {}), }; const metrics = Object.keys(metricsFields).length > 0 ? metricsFields : undefined; @@ -330,6 +403,51 @@ function readCallId(value: unknown, outputs: ReadonlyMap): strin return callId !== undefined ? outputs.get(callId) : undefined; } +/** + * Build a turn's `[start, end]` wall-clock interval from its `task_complete`. + * `end` is the completion record's own timestamp (ISO, ms precision); `start` + * is the matching `task_started`'s timestamp, or — when that record is absent + * (a session whose first turn was already in progress at import) — + * reconstructed as `end - duration_ms`. Returns `undefined` when no start can + * be resolved or the span is non-positive, so the caller falls back to the + * gap-capped engagement series for that turn. + */ +function turnIntervalFromComplete( + endTs: string, + payload: Record, + startMsByTurnId: ReadonlyMap, +): IntervalMs | undefined { + const endMs = Date.parse(endTs); + if (!Number.isFinite(endMs)) return undefined; + const turnId = readString(payload.turn_id); + const indexedStart = turnId !== undefined ? startMsByTurnId.get(turnId) : undefined; + const durationMs = readNonNegInt(payload.duration_ms); + const startMs = + indexedStart !== undefined ? indexedStart : durationMs > 0 ? endMs - durationMs : undefined; + if (startMs === undefined || !(startMs < endMs)) return undefined; + return [startMs, endMs]; +} + +/** + * Index each turn's start time (epoch ms) by its `turn_id` from the + * `task_started` records. First occurrence wins. Lets a `task_complete` recover + * the real turn start regardless of record order. + */ +function indexTaskStarts(records: ReadonlyArray): Map { + const byTurnId = new Map(); + for (const record of records) { + if (readString(record.type) !== "event_msg") continue; + const payload = isObject(record.payload) ? record.payload : undefined; + if (payload === undefined || readString(payload.type) !== "task_started") continue; + const turnId = readString(payload.turn_id); + const startMs = Date.parse(readString(record.timestamp) ?? ""); + if (turnId !== undefined && Number.isFinite(startMs) && !byTurnId.has(turnId)) { + byTurnId.set(turnId, startMs); + } + } + return byTurnId; +} + /** * Codex's `exec_command` output text reports the child's exit code as * `Process exited with code N` (N may be negative for signal termination). diff --git a/packages/core/src/schemas/session.schema.test.ts b/packages/core/src/schemas/session.schema.test.ts index affb653e..78d2206f 100644 --- a/packages/core/src/schemas/session.schema.test.ts +++ b/packages/core/src/schemas/session.schema.test.ts @@ -62,4 +62,35 @@ describe("SessionSchema", () => { }; expect(SessionSchema.safeParse(variant).success).toBe(true); }); + + it("accepts metrics with machine_active_time_ms", () => { + const variant = { + ...VALID_SESSION, + session: { + ...VALID_SESSION.session, + metrics: { + output_tokens: 768, + active_time_ms: 600000, + active_intervals: [ + { start: "2026-05-04T09:00:00+09:00", end: "2026-05-04T09:10:00+09:00" }, + ], + active_gap_cap_ms: 300000, + active_time_method: "turn-intervals", + machine_active_time_ms: 420000, + }, + }, + }; + expect(SessionSchema.safeParse(variant).success).toBe(true); + }); + + it("rejects a negative machine_active_time_ms", () => { + const variant = { + ...VALID_SESSION, + session: { + ...VALID_SESSION.session, + metrics: { machine_active_time_ms: -1 }, + }, + }; + expect(SessionSchema.safeParse(variant).success).toBe(false); + }); }); diff --git a/packages/core/src/schemas/session.schema.ts b/packages/core/src/schemas/session.schema.ts index 439380bd..8377f9a0 100644 --- a/packages/core/src/schemas/session.schema.ts +++ b/packages/core/src/schemas/session.schema.ts @@ -73,7 +73,17 @@ const InvocationSchema = z.object({ * wall-clock ranges (so cross-session totals can de-duplicate overlapping * work by interval union); `active_time_ms` is their summed duration; * `active_gap_cap_ms` and `active_time_method` lock the methodology so the - * stored numbers stay interpretable if the method changes later. + * stored numbers stay interpretable if the method changes later. When a + * source records explicit per-turn intervals (Codex), `active_time_method` is + * `turn-intervals` and the in-turn time is the log's real wall-clock span + * rather than a gap-capped approximation; the active semantics are unchanged. + * - `machine_active_time_ms`: model compute time — the summed duration of the + * source's per-turn spans (Codex `task_complete.duration_ms`), a SUBSET of a + * single session's engaged active time. Unlike `active_intervals` it is a + * plain sum, NOT wall-clock-deduplicated, so two concurrent sessions can sum + * past their billable (union) active wall-clock — that is intended (two models + * working at once did two machine-hours in one wall-clock hour). Captured only + * for sources that record per-turn duration (Codex); absent otherwise. * * Absent on sessions imported before a given field existed (re-import to * backfill). Live sessions carry no engaged-time metrics and fall back to @@ -90,6 +100,7 @@ export const SessionMetricsSchema = z.object({ .optional(), active_gap_cap_ms: z.number().int().nonnegative().optional(), active_time_method: z.string().optional(), + machine_active_time_ms: z.number().int().nonnegative().optional(), }); /** Inferred runtime type for {@link SessionMetricsSchema}. */ export type SessionMetrics = z.infer; diff --git a/packages/core/src/stats/active-time.ts b/packages/core/src/stats/active-time.ts index 79ab5a1f..4caa95ab 100644 --- a/packages/core/src/stats/active-time.ts +++ b/packages/core/src/stats/active-time.ts @@ -19,6 +19,19 @@ export type IsoInterval = { start: string; end: string }; */ export const ENGAGED_TURNS_METHOD = "engaged-turns"; +/** + * Identifier stored in `metrics.active_time_method` for active time that uses a + * source's explicit per-turn intervals (e.g. Codex `task_started` / + * `task_complete`) for the in-turn duration, with the gap-capped engagement + * series only bridging between turns. More faithful than {@link + * ENGAGED_TURNS_METHOD}: in-turn time is the log's real wall-clock span, not a + * gap-capped approximation, and a session's final turn is credited. The active + * semantics are unchanged — still human-engaged time with idle gaps excluded — + * only the in-turn precision improves. Bump this string if the derivation + * method changes, so stored numbers stay interpretable. + */ +export const TURN_INTERVALS_METHOD = "turn-intervals"; + /** * Build active intervals from a list of engagement timestamps (epoch ms). * diff --git a/packages/core/src/stats/work-stats.test.ts b/packages/core/src/stats/work-stats.test.ts index bb8db318..3c8840c0 100644 --- a/packages/core/src/stats/work-stats.test.ts +++ b/packages/core/src/stats/work-stats.test.ts @@ -288,6 +288,53 @@ describe("computeWorkStats", () => { expect(s?.availability.activeTime).toBe(true); }); + it("rolls up machine compute time per-session, by source, and in totals", async () => { + const paths = await ensureBasouDirectory(getWorkDir()); + const codex = "ses_01HXABCDEF1234567890ABCDM1"; + const claude = "ses_01HXABCDEF1234567890ABCDM2"; + await placeSession(paths, { + id: codex, + source: "codex-import", + startedAt: "2026-05-10T00:00:00.000Z", + endedAt: "2026-05-10T00:30:00.000Z", + metrics: { + active_time_ms: 30 * 60 * 1000, + active_intervals: [{ start: "2026-05-10T00:00:00.000Z", end: "2026-05-10T00:30:00.000Z" }], + active_time_method: "turn-intervals", + machine_active_time_ms: 12 * 60 * 1000, + }, + }); + // A claude-code-import session has active time but no machine compute. + await placeSession(paths, { + id: claude, + source: "claude-code-import", + startedAt: "2026-05-10T00:00:00.000Z", + endedAt: "2026-05-10T00:30:00.000Z", + metrics: { + active_intervals: [{ start: "2026-05-10T00:00:00.000Z", end: "2026-05-10T00:10:00.000Z" }], + active_time_method: "engaged-turns", + }, + }); + const r = await computeWorkStats({ paths, now: NOW, timeZone: "UTC" }); + const cs = r.sessions.find((s) => s.sessionId === codex); + const ls = r.sessions.find((s) => s.sessionId === claude); + expect(cs?.machineActiveTimeMs).toBe(12 * 60 * 1000); + expect(cs?.availability.machineActive).toBe(true); + expect(cs?.activeTimeMethod).toBe("turn-intervals"); + expect(ls?.machineActiveTimeMs).toBe(0); + expect(ls?.availability.machineActive).toBe(false); + // Totals: summed (not wall-clock-deduped), available because one session has it. + expect(r.totals.machineActiveTimeMs).toBe(12 * 60 * 1000); + expect(r.totals.machineActiveAvailable).toBe(true); + const codexSource = r.bySource.find((s) => s.sourceKind === "codex-import"); + const claudeSource = r.bySource.find((s) => s.sourceKind === "claude-code-import"); + expect(codexSource?.machineActiveTimeMs).toBe(12 * 60 * 1000); + expect(codexSource?.machineActiveAvailable).toBe(true); + expect(claudeSource?.machineActiveAvailable).toBe(false); + // Per-day: attributed to the session start date. + expect(r.byDay.find((d) => d.date === "2026-05-10")?.machineActiveTimeMs).toBe(12 * 60 * 1000); + }); + it("de-duplicates overlapping sessions in the billable total", async () => { const paths = await ensureBasouDirectory(getWorkDir()); const a = "ses_01HXABCDEF1234567890ABCDEB"; diff --git a/packages/core/src/stats/work-stats.ts b/packages/core/src/stats/work-stats.ts index ddb6e463..45ebf9e4 100644 --- a/packages/core/src/stats/work-stats.ts +++ b/packages/core/src/stats/work-stats.ts @@ -58,6 +58,8 @@ export type MeasureAvailability = { activeTime: boolean; /** Token totals were captured (model-usage metrics present). */ tokens: boolean; + /** Model compute time was captured (`machine_active_time_ms`; Codex only). */ + machineActive: boolean; }; /** Token rollup. Zero when not captured; `reasoning` is Codex-only. */ @@ -95,6 +97,18 @@ export type SessionWorkStats = { * (concurrent) work is not double-counted in billable totals. */ activeIntervals: IsoInterval[]; + /** + * Model compute time: the source's summed per-turn duration + * (`metrics.machine_active_time_ms`). A subset of `activeTimeMs`; 0 when the + * source records no per-turn duration (everything but Codex today). + */ + machineActiveTimeMs: number; + /** + * Methodology lock copied from `metrics.active_time_method` (e.g. + * `turn-intervals` / `engaged-turns`); undefined when active time was derived + * from the event stream rather than stored metrics. + */ + activeTimeMethod: string | undefined; commandCount: number; fileChangedCount: number; decisionCount: number; @@ -113,6 +127,7 @@ export type SourceWorkStats = { sessionSpanMs: number; commandTimeMs: number; activeTimeMs: number; + machineActiveTimeMs: number; commandCount: number; fileChangedCount: number; decisionCount: number; @@ -122,6 +137,8 @@ export type SourceWorkStats = { commandTimeReliable: boolean; /** At least one session of this kind captured token totals. */ tokensAvailable: boolean; + /** At least one session of this kind captured model compute time. */ + machineActiveAvailable: boolean; }; export type StatusCount = { status: SessionStatus; count: number }; @@ -136,6 +153,12 @@ export type DayWorkStats = { /** Calendar date `YYYY-MM-DD` in the report timezone. */ date: string; billableActiveTimeMs: number; + /** + * Model compute time for sessions started on this date (summed + * `machine_active_time_ms`). Not wall-clock-deduplicated, so — unlike + * `billableActiveTimeMs` — concurrent sessions sum freely. + */ + machineActiveTimeMs: number; sessionCount: number; commandCount: number; fileChangedCount: number; @@ -156,6 +179,13 @@ export type WorkStatsTotals = { * `activeTimeMs` when no sessions overlap, and is smaller when they do. */ billableActiveTimeMs: number; + /** + * Workspace-wide model compute time: summed `machine_active_time_ms`. A plain + * sum (not interval union), so it can exceed `billableActiveTimeMs` when + * sessions ran concurrently — two models working at once is two machine-hours + * in one wall-clock hour. + */ + machineActiveTimeMs: number; commandCount: number; fileChangedCount: number; decisionCount: number; @@ -164,6 +194,8 @@ export type WorkStatsTotals = { /** No `claude-code-import` sessions present, so command time is workspace-wide real. */ commandTimeReliable: boolean; tokensAvailable: boolean; + /** At least one session captured model compute time (`machine_active_time_ms`). */ + machineActiveAvailable: boolean; }; export type WorkStatsResult = { @@ -312,6 +344,7 @@ export function sessionWorkStatsFromEvents( const span = computeSpan(inner.started_at, inner.ended_at, now); const tokens = readTokens(inner.metrics); const active = resolveActiveTime(inner.metrics, timestamps); + const machineActiveTimeMs = inner.metrics?.machine_active_time_ms ?? 0; return { sessionId, label: inner.label, @@ -325,6 +358,8 @@ export function sessionWorkStatsFromEvents( activeTimeMs: active.ms, activeTimeBasis: active.basis, activeIntervals: intervalsMsToIso(active.intervals), + machineActiveTimeMs, + activeTimeMethod: inner.metrics?.active_time_method, commandCount, fileChangedCount, decisionCount, @@ -335,6 +370,7 @@ export function sessionWorkStatsFromEvents( commandTime: inner.source.kind !== "claude-code-import", activeTime: active.intervals.length > 0, tokens: hasTokens(tokens), + machineActive: machineActiveTimeMs > 0, }, spanClamped: span.clamped, eventsUnreadable, @@ -409,6 +445,7 @@ function computeTotals( commandTimeMs: 0, activeTimeMs: 0, billableActiveTimeMs, + machineActiveTimeMs: 0, commandCount: 0, fileChangedCount: 0, decisionCount: 0, @@ -416,12 +453,14 @@ function computeTotals( tokens, commandTimeReliable: true, tokensAvailable: false, + machineActiveAvailable: false, }; for (const s of sessions) { if (s.open) totals.openSessionCount++; totals.sessionSpanMs += s.sessionSpanMs; totals.commandTimeMs += s.commandTimeMs; totals.activeTimeMs += s.activeTimeMs; + totals.machineActiveTimeMs += s.machineActiveTimeMs; totals.commandCount += s.commandCount; totals.fileChangedCount += s.fileChangedCount; totals.decisionCount += s.decisionCount; @@ -429,6 +468,7 @@ function computeTotals( addTokens(tokens, s.tokens); if (!s.availability.commandTime) totals.commandTimeReliable = false; if (s.availability.tokens) totals.tokensAvailable = true; + if (s.availability.machineActive) totals.machineActiveAvailable = true; } return totals; } @@ -444,6 +484,7 @@ function computeBySource(sessions: readonly SessionWorkStats[]): SourceWorkStats sessionSpanMs: 0, commandTimeMs: 0, activeTimeMs: 0, + machineActiveTimeMs: 0, commandCount: 0, fileChangedCount: 0, decisionCount: 0, @@ -451,6 +492,7 @@ function computeBySource(sessions: readonly SessionWorkStats[]): SourceWorkStats tokens: emptyTokens(), commandTimeReliable: true, tokensAvailable: false, + machineActiveAvailable: false, }; map.set(s.sourceKind, row); } @@ -458,6 +500,7 @@ function computeBySource(sessions: readonly SessionWorkStats[]): SourceWorkStats row.sessionSpanMs += s.sessionSpanMs; row.commandTimeMs += s.commandTimeMs; row.activeTimeMs += s.activeTimeMs; + row.machineActiveTimeMs += s.machineActiveTimeMs; row.commandCount += s.commandCount; row.fileChangedCount += s.fileChangedCount; row.decisionCount += s.decisionCount; @@ -465,6 +508,7 @@ function computeBySource(sessions: readonly SessionWorkStats[]): SourceWorkStats addTokens(row.tokens, s.tokens); if (!s.availability.commandTime) row.commandTimeReliable = false; if (s.availability.tokens) row.tokensAvailable = true; + if (s.availability.machineActive) row.machineActiveAvailable = true; } return [...map.values()].sort((a, b) => a.sourceKind.localeCompare(b.sourceKind)); } @@ -498,6 +542,7 @@ function computeByDay( day = { date, billableActiveTimeMs: 0, + machineActiveTimeMs: 0, sessionCount: 0, commandCount: 0, fileChangedCount: 0, @@ -516,6 +561,7 @@ function computeByDay( if (!Number.isFinite(startedMs)) continue; const day = ensure(tzDate(startedMs, timeZone)); day.sessionCount++; + day.machineActiveTimeMs += s.machineActiveTimeMs; day.commandCount += s.commandCount; day.fileChangedCount += s.fileChangedCount; day.decisionCount += s.decisionCount;