Where Did the Time Go?

Turning hostile event logs into one timing report

The Frame

Every session logs its time — then locks the answer away

Every Amplifier session writes an events.jsonl file recording exactly what happened and how long each step took. The record exists — but it's written for machines, not for reading.

So the log that holds the answer is precisely the thing you can't read. Why?

The Tension

events.jsonl is hostile to an LLM

A single session generates potentially thousands of events across a tree of parent/child agent sessions — and one tool output can run 100k+ tokens. Read it directly and you blow the context window.

A plan on paper wouldn't help. So what actually shipped?

Thousands of events per session, per the design spec
Nested parent/child agent session trees
100k+ token tool outputs as a real edge case
Durations hidden in timestamp math & duration_ms fields

The Proof

Session Insights is shipped and tested, not a plan

manojp99/amplifier-bundle-session-insights is a complete Amplifier bundle: a standard-library-only tool with a pure analysis engine and a full test suite — 66 pass, 5 skipped (those 5 need real session data on disk).

Shipped — so how does one tool make a hostile file tractable?

71

tests across 5 files (66 pass / 5 skipped)

0

runtime dependencies (dependencies = [])

1,061

lines in the core engine (4 files)

15

commits, one Microsoft-engineer author

The Mechanism

One tool computes; the agent is told not to parse

The timing_analysis tool does all the heavy computation in one pass — parsing events, building turn trees, computing durations, identifying bottlenecks. The agent is instructed: "You do NOT parse events yourself."

One pass on a flat file is easy. But the tree is nested…

One operation, not five — the tool computes it all in one pass
The agent slices the pre-computed data
Never parses events — the tool returns everything pre-computed
Pure engine — analyzer.py takes event dicts, returns a dict, no file I/O

The Mechanism

It recurses into the whole nested agent tree

The tool discovers child sessions from delegate:agent_spawned events (via data.sub_session_id) and recurses into them — the exact hostility a human reader can't chase by hand.

Now the analysis spans the whole tree. But won't the output be huge?

3

default recursion depth (max_depth)

4

maximum depth allowed

Child sessions found from delegate:agent_spawned
When the limit is hit, depth_limit_hit: true is set

The Mechanism

The output is budgeted for the context window

By design the report stays small enough to hand to a model — the move that closes the loop back on the hostile file. No raw payloads survive the summary.

Small enough to read. So what does one prompt actually get you?

No raw event payloads in the output
Tool calls summarized — count + total time per tool
Turn prompts truncated to 100 chars
Bottlenecks capped at 10 per level

The Payoff

One prompt, one time budget — no raw event touched

The hostile tree collapses into a single time budget that categorizes active time, while idle gaps are excluded. The specialist session-performance-analyst interprets the pre-computed JSON — and never touches a raw event.

That's the answer to "where did the time go?" — and it's a reusable pattern.

LLMtime spent waiting on model responses

toolstime spent in tool calls

delegationtime spent in child agent sessions

overheadthe remaining active time

The Takeaway

Compute outside, interpret inside

When data is hostile to a model, put a pure, budgeted tool between the events and the agent. The tool computes; the agent interprets. That's how a hostile event tree becomes an actionable report.

A pattern you can lift into any place raw data outsizes the context window.

Keep the analysis engine pure — events in, dict out, no file I/O
Make the tool compute everything in one pass
Budget the output for the context window
Let the agent interpret, never parse

Sources

Research Methodology

Feature status: Complete and tested Amplifier bundle (15 commits ending 2026-04-22; independently re-verified against a fresh clone).

Repository: manojp99/amplifier-bundle-session-insights (the suggested michaeljabbour/amplifier-module-hooks-event-broadcast was checked and ruled out — it is event broadcasting, not timing analysis).

Research performed:

Clone & verify: gh repo clone manojp99/amplifier-bundle-session-insights; gh repo view michaeljabbour/amplifier-module-hooks-event-broadcast
History: git log --pretty='%h %ad %s' --date=short; git shortlog -sne --all; git rev-list --count HEAD
Tests: uv run --with pytest --with pytest-asyncio python3 -m pytest -q → 66 passed, 5 skipped in 0.06s
Test count: grep -rc 'def test_' tests/test_*.py → 71
Line counts: wc -l amplifier_module_tool_timing_analysis/*.py → 1,061 total
Claims: cat README.md, cat docs/TIMING_GUIDE.md, grep -n '100' parser.py, grep -n '\[:10\]' analyzer.py, grep -n 'max_depth|depth_limit|agent_spawned' analyzer.py

Gaps: "304 sessions / six projects / a week of AI work" demo framing does not appear in the repo and is excluded. End-to-end runtime "in milliseconds" is not benchmarked here; what is verified is millisecond-granularity duration computation and a ~0.06s test suite.

Primary contributor: Manoj Prabhakar Paidiparthy <mpaidiparthy@microsoft.com> — 15 commits (sole author, 100%).