Skip to content

Milestone 5: observability - event log, usage ledger, trace (Tasks 22-24)#8

Merged
inhaq merged 2 commits into
m3-persistencefrom
m5-observability
Jun 13, 2026
Merged

Milestone 5: observability - event log, usage ledger, trace (Tasks 22-24)#8
inhaq merged 2 commits into
m3-persistencefrom
m5-observability

Conversation

@inhaq

@inhaq inhaq commented Jun 13, 2026

Copy link
Copy Markdown
Owner

This pull request was created by @kiro-agent on behalf of @inhaq 👻

Comment with /kiro fix to address specific feedback or /kiro all to address everything.
Learn about Kiro Web


Summary

Completes Milestone 5 (Observability) — Tasks 22, 23, 24.

Stacked PR. Top of the chain: task-13-role-binding (#4) → m2-runners (#5) → m3-persistence (#6) → m4-parallel (#7) → this. Merge in order. Targets m4-parallel so the diff shows only Milestone 5.

This is the final engine milestone — with it, the headless engine (Milestones 1–5) is feature-complete against the spec.

Task 22 — Structured event log

  • The Store gains a generic event stream (recordEvent / listEvents).
  • observability/instrument.ts wraps any runner so every invocation emits a role-attributed runner_call event (prompt/output chars, duration, quota flag, normalized token usage) — transparently, returning the result unchanged.
  • createRoles takes an onRunnerCall hook; session.runGoal records runner calls plus session_started / plan_reviewed / session_finished lifecycle markers. (State transitions/attempts/outcomes were already persisted in M3.)

Task 23 — Usage/cost ledger (observability/usage.ts)

  • computeUsage aggregates runner calls per role and per run: calls, prompt/completion/total tokens, duration, quota hits. Optional per-1k-token rates yield a dollar estimate. normalizeUsage handles OpenAI-style and input/output-style usage objects.

Task 24 — Session trace (observability/trace.ts)

  • buildTrace assembles a session's lifecycle, per-task state history, attempts, outcomes, events, and the usage ledger into one inspectable object; formatTrace renders it for humans. New npm run trace -- <sessionId> CLI.

Testing

  • npm run typecheck clean.
  • npm test: 125 passing (+6). Covers usage normalization, transparent instrumentation with token capture, per-role/total/cost aggregation, and an end-to-end run asserting the persisted event stream (lifecycle + runner calls) and a built trace.

Summary by CodeRabbit

  • New Features

    • Added session trace inspection command to examine execution history, including task states, transitions, and performance metrics
    • Implemented structured event logging with automatic usage and cost tracking for session activities and AI model interactions
  • Chores

    • Updated development task tracking for current milestone

@coderabbitai

coderabbitai Bot commented Jun 13, 2026

Copy link
Copy Markdown

Important

Review skipped

Auto reviews are disabled on base/target branches other than the default branch.

🗂️ Base branches to auto review (1)
  • '.*'

Please check the settings in the CodeRabbit UI or the .coderabbit.yaml file in this repository. To trigger a single review, invoke the @coderabbitai review command.

⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro Plus

Run ID: ac31556a-65ea-4717-9767-3b906ace5cc4

You can disable this status message by setting the reviews.review_status to false in the CodeRabbit configuration file.

Use the checkbox below for a quick retry:

  • 🔍 Trigger review
✨ Finishing Touches
🧪 Generate unit tests (beta)
  • Create PR with unit tests
  • Commit unit tests in branch m5-observability

Comment @coderabbitai help to get the list of available commands and usage tips.

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 1

🧹 Nitpick comments (1)
src/observability/trace.ts (1)

42-46: ⚡ Quick win

Consider parallelizing outcome fetches.

Fetching outcomes sequentially adds cumulative latency for sessions with many tasks. Since getOutcome calls are independent, they can be parallelized.

⚡ Proposed refactor to parallelize outcome fetches
-  const outcomes: OutcomeRecord[] = [];
-  for (const t of tasks) {
-    const o = await store.getOutcome(sessionId, t.taskId);
-    if (o) outcomes.push(o);
-  }
+  const outcomePromises = tasks.map((t) => store.getOutcome(sessionId, t.taskId));
+  const outcomeResults = await Promise.all(outcomePromises);
+  const outcomes = outcomeResults.filter((o): o is OutcomeRecord => o !== undefined);
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In `@src/observability/trace.ts` around lines 42 - 46, The current loop in which
outcomes are fetched sequentially should be changed to run store.getOutcome
calls in parallel: replace the for-await pattern over tasks with constructing an
array of promises via tasks.map(t => store.getOutcome(sessionId, t.taskId)),
await Promise.all(...) to get results, then filter out any undefined/null
entries into the outcomes array; ensure you preserve existing behavior by
keeping the OutcomeRecord[] type, and propagate or handle errors the same way as
before (or wrap individual promises if you need per-call isolation).
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Inline comments:
In `@src/observability/events.ts`:
- Around line 54-57: The current fallback uses || which treats 0 as falsy;
change the logic in the prompt, completion, and totalRaw assignments to detect
presence of keys instead of truthiness so zero is preserved — e.g. replace
expressions like const prompt = num(u["prompt_tokens"]) ||
num(u["input_tokens"]) || num(u["promptTokens"]); with a presence-based chain
such as: if ('prompt_tokens' in u) use num(u['prompt_tokens']) else if
('input_tokens' in u) use num(u['input_tokens']) else use
num(u['promptTokens']); apply the same pattern to completion and totalRaw (or
alternatively use the nullish coalescing approach on raw values:
num(u['prompt_tokens'] ?? u['input_tokens'] ?? u['promptTokens']) if num handles
undefined/null), referencing the variables prompt, completion, totalRaw and the
num(u[...]) calls.

---

Nitpick comments:
In `@src/observability/trace.ts`:
- Around line 42-46: The current loop in which outcomes are fetched sequentially
should be changed to run store.getOutcome calls in parallel: replace the
for-await pattern over tasks with constructing an array of promises via
tasks.map(t => store.getOutcome(sessionId, t.taskId)), await Promise.all(...) to
get results, then filter out any undefined/null entries into the outcomes array;
ensure you preserve existing behavior by keeping the OutcomeRecord[] type, and
propagate or handle errors the same way as before (or wrap individual promises
if you need per-call isolation).
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro Plus

Run ID: 56a647a7-9107-4f0e-8d39-6ff6427ae0d9

📥 Commits

Reviewing files that changed from the base of the PR and between 8e927cb and e2d8d4d.

📒 Files selected for processing (11)
  • .kiro/specs/loop-engine/tasks.md
  • package.json
  • src/adapters/roleBindings.ts
  • src/observability/events.ts
  • src/observability/instrument.ts
  • src/observability/trace.ts
  • src/observability/usage.ts
  • src/session.ts
  • src/storage/store.ts
  • src/trace.ts
  • test/observability.test.ts

Comment thread src/observability/events.ts Outdated
Comment on lines +54 to +57
const prompt = num(u["prompt_tokens"]) || num(u["input_tokens"]) || num(u["promptTokens"]);
const completion =
num(u["completion_tokens"]) || num(u["output_tokens"]) || num(u["completionTokens"]);
const totalRaw = num(u["total_tokens"]) || num(u["totalTokens"]);

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ Potential issue | 🟠 Major | ⚡ Quick win

Fix the || chaining logic to handle zero values correctly.

The current logic uses || to try fallback keys, but this incorrectly prefers fallback keys when the primary key exists with a valid zero value. For example, {prompt_tokens: 0, input_tokens: 5} would return promptTokens: 5 instead of the correct 0.

This corrupts usage aggregation when a provider legitimately returns zero tokens (e.g., for an empty prompt or certain model responses).

🔧 Proposed fix using key existence checks
-  const prompt = num(u["prompt_tokens"]) || num(u["input_tokens"]) || num(u["promptTokens"]);
-  const completion =
-    num(u["completion_tokens"]) || num(u["output_tokens"]) || num(u["completionTokens"]);
-  const totalRaw = num(u["total_tokens"]) || num(u["totalTokens"]);
+  const prompt = "prompt_tokens" in u ? num(u["prompt_tokens"])
+               : "input_tokens" in u ? num(u["input_tokens"])
+               : num(u["promptTokens"]);
+  const completion = "completion_tokens" in u ? num(u["completion_tokens"])
+                   : "output_tokens" in u ? num(u["output_tokens"])
+                   : num(u["completionTokens"]);
+  const totalRaw = "total_tokens" in u ? num(u["total_tokens"]) : num(u["totalTokens"]);
📝 Committable suggestion

‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.

Suggested change
const prompt = num(u["prompt_tokens"]) || num(u["input_tokens"]) || num(u["promptTokens"]);
const completion =
num(u["completion_tokens"]) || num(u["output_tokens"]) || num(u["completionTokens"]);
const totalRaw = num(u["total_tokens"]) || num(u["totalTokens"]);
const prompt = "prompt_tokens" in u ? num(u["prompt_tokens"])
: "input_tokens" in u ? num(u["input_tokens"])
: num(u["promptTokens"]);
const completion = "completion_tokens" in u ? num(u["completion_tokens"])
: "output_tokens" in u ? num(u["output_tokens"])
: num(u["completionTokens"]);
const totalRaw = "total_tokens" in u ? num(u["total_tokens"]) : num(u["totalTokens"]);
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In `@src/observability/events.ts` around lines 54 - 57, The current fallback uses
|| which treats 0 as falsy; change the logic in the prompt, completion, and
totalRaw assignments to detect presence of keys instead of truthiness so zero is
preserved — e.g. replace expressions like const prompt = num(u["prompt_tokens"])
|| num(u["input_tokens"]) || num(u["promptTokens"]); with a presence-based chain
such as: if ('prompt_tokens' in u) use num(u['prompt_tokens']) else if
('input_tokens' in u) use num(u['input_tokens']) else use
num(u['promptTokens']); apply the same pattern to completion and totalRaw (or
alternatively use the nullish coalescing approach on raw values:
num(u['prompt_tokens'] ?? u['input_tokens'] ?? u['promptTokens']) if num handles
undefined/null), referencing the variables prompt, completion, totalRaw and the
num(u[...]) calls.

inhaq added 2 commits June 13, 2026 16:26
…-24)

Task 22 - structured event log: Store gains a generic event stream
(recordEvent/listEvents); observability/instrument.ts wraps each runner so
every invocation emits a role-attributed runner_call event (chars, duration,
quota, normalized token usage). createRoles takes an onRunnerCall hook;
session.runGoal records runner calls plus session_started / plan_reviewed /
session_finished lifecycle markers to the store.

Task 23 - observability/usage.ts: computeUsage aggregates runner calls per role
and per run (calls, tokens, duration, quota hits), with optional per-1k-token
rates yielding a cost estimate. normalizeUsage handles OpenAI- and
input/output-style usage objects.

Task 24 - observability/trace.ts: buildTrace assembles a session's lifecycle,
per-task state history, attempts, outcomes, events, and usage ledger;
formatTrace renders it. New 'npm run trace -- <sessionId>' CLI.

Adds 6 tests (125 total); typecheck clean.
Select the first usage key that is actually present rather than the first
truthy one. The previous '||' chain discarded a legitimate 0 (e.g. an empty
prompt) in favor of a later alias, corrupting usage aggregation.
@inhaq inhaq force-pushed the m5-observability branch from e2d8d4d to df23e27 Compare June 13, 2026 16:34
Base automatically changed from m4-parallel to m3-persistence June 13, 2026 16:37
@inhaq inhaq merged commit 9f5f944 into m3-persistence Jun 13, 2026
2 checks passed
@inhaq inhaq deleted the m5-observability branch June 13, 2026 16:38
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant