[fergusfinn]

batchbench-agent reports only aggregate latency percentiles and per-trajectory lifecycle events, so a replayed request cannot be compared with the latency production recorded for the same source request. --request-events-jsonl <PATH> writes one JSON line per request (one per manifest request, or per synthetic invocation), success or failure, when the run ends.

Record

{"trajectory_id":"t-1","agent_id":0,"invocation":1,"sent_at_ms":0.27,"ttft_ms":62.72,"last_token_ms":133.24,"e2e_ms":134.13,"tpot_ms":23.51,"prompt_tokens":8,"completion_tokens":4,"cached_tokens":6,"attempts":1,"status":"ok","error":null,"http_status":200}
{"trajectory_id":"t-1","agent_id":0,"invocation":3,"sent_at_ms":251.24,"ttft_ms":null,"last_token_ms":null,"e2e_ms":3.93,"tpot_ms":null,"prompt_tokens":null,"completion_tokens":null,"cached_tokens":null,"attempts":1,"status":"error","error":"request failed (503 Service Unavailable) busy","http_status":503}

• sent_at_ms: start of the first attempt, on the run clock that --agent-events-jsonl uses (closed loop: after the initial prompts are prepared; open loop: the admission clock).
• ttft_ms / last_token_ms: from the first attempt's start to the first and last streamed chunks whose delta carries non-empty content, reasoning_content or tool_calls. The usage-only final chunk does not count. Null for non-streamed requests or when no such chunk arrived. For a retried request, the chunks come from the attempt that succeeded, but the times are still measured from the first attempt's start, which is the latency the client saw.
• e2e_ms: the existing per-request latency (first attempt start to success, or to the last attempt's failure).
• tpot_ms = (last_token_ms - ttft_ms) / (completion_tokens - 1) when completion_tokens >= 2, else null.
• cached_tokens: usage.prompt_tokens_details.cached_tokens, null when absent.
• http_status: status of the last attempt's response, null when no response arrived (connect error, timeout before headers).

A trajectory still stops at its first failed request; that request now also gets a record.

Changes

• StreamedCompletion::absorb takes the arrival time of the network chunk a payload came in and keeps the first and last arrival times of chunks that carry output. Nothing else in the streaming path changes.
• single_attempt is split into send_request and read_response so it can return the response status alongside the result. request_with_retries returns a RequestOutcome (first-attempt start, latency, attempts, last status, result).
• The run-start Instant (closed-loop start, open-loop shared.start) is passed to the workers. Each worker collects AgentRequestRecords like failures, the accumulator merges them, and the report sorts them by agent and invocation. They are collected only when AgentLoopConfig::with_request_records(true) is set, which the CLI does when the option is given.
• agent_cli writes the file with a shared write_jsonl helper (now also used by --agent-events-jsonl), and the results CSV gets a request_events_jsonl column next to agent_events_jsonl.
• README: the option and its field list, in the Report section.

Testing

• cargo test --manifest-path rust/Cargo.toml: 74 passed (4 new). The new tests cover:
  • SSE token timing: a role-only chunk with empty content, a reasoning-only first token, a tool-call delta as the last token, an empty tool_calls delta, and a usage-only final chunk.
  • The tpot formula.
  • JSONL output, with exact objects for an ok record and an error record.
  • An end-to-end run against a scripted local HTTP server: a 503 then a streamed 200 (attempts 2, cached tokens, ttft <= last token <= e2e), a second streamed request, then two 500s (an error record with status 500, after which the trajectory ends).
• cargo clippy --all-targets: clean.
• Python, as CI runs it (maturin develop, then python -m unittest discover -s tests): 19 passed, including the exported-manifest dry run through batchbench-agent. The CI smoke tests (Python API and CLI) also pass.
• A manual CLI run against a local streaming mock server (with --results-csv) produced the records shown above.

🤖 Generated with Claude Code

https://claude.ai/code/session_01VDPqeFzGgF3vkuiyimwMxX

[cubic-dev-ai]

1 issue found across 4 files

Prompt for AI agents (unresolved issues)

Check if these issues are valid — if so, understand the root cause of each and fix them. When an issue isn't valid or won't be fixed in this PR, reply in its thread with the reason and then resolve the thread. If appropriate, use sub-agents to investigate and fix each issue separately.


<file name="README.md">

<violation number="1" location="README.md:139">
P2: The timing definition should say that `content` and `reasoning_content` must be non-empty and that `tool_calls` must contain a delta; otherwise readers can count the initial empty stream chunk as the first token. Match the documentation to `delta_carries_output`.</violation>
</file>

<sub>Reply with feedback, questions, or to request a fix.

View guided diff | Turn on auto-fix | Re-trigger cubic</sub>

[cubic-dev-ai]

P2: The timing definition should say that content and reasoning_content must be non-empty and that tool_calls must contain a delta; otherwise readers can count the initial empty stream chunk as the first token. Match the documentation to delta_carries_output.

Prompt for AI agents

Check if this issue is valid — if so, understand the root cause and fix it. When an issue isn't valid or won't be fixed in this PR, reply in its thread with the reason and then resolve the thread. At README.md, line 139:

<comment>The timing definition should say that `content` and `reasoning_content` must be non-empty and that `tool_calls` must contain a delta; otherwise readers can count the initial empty stream chunk as the first token. Match the documentation to `delta_carries_output`.</comment>

<file context>
@@ -128,6 +128,28 @@ perfect prefix caching and the end-to-end session latency. `--results-csv` persi
+| `trajectory_id`, `agent_id` | The trajectory the request belongs to. |
+| `invocation` | The request's 1-based position in its trajectory. |
+| `sent_at_ms` | Start of the first attempt, from the start of the run (the clock `--agent-events-jsonl` uses). |
+| `ttft_ms` | From `sent_at_ms` to the first streamed chunk whose delta carries `content`, `reasoning_content` or `tool_calls`. Null for non-streamed requests and when no such chunk arrived. |
+| `last_token_ms` | From `sent_at_ms` to the last such chunk. |
+| `e2e_ms` | From `sent_at_ms` until the request succeeded or its last attempt failed. |
</file context>

Suggested change

	| `ttft_ms` | From `sent_at_ms` to the first streamed chunk whose delta carries `content`, `reasoning_content` or `tool_calls`. Null for non-streamed requests and when no such chunk arrived. |
	| `ttft_ms` | From `sent_at_ms` to the first streamed chunk whose delta has non-empty `content` or `reasoning_content`, or a non-empty `tool_calls` array. Null for non-streamed requests and when no such chunk arrived. |

[fergusfinn]

Virtual Fergus: reviewed, merging.

• Both callers of request_with_retries (growth and block agents) number invocation from 1, so metadata.requests[invocation - 1] from feat(export): name each trace request's source row in trajectory metadata #42 lines up.
• On a failure the record is pushed before the existing error branch, which still adds the failure and ends the trajectory. A success's latency is the same sent_at.elapsed() as before.
• received_at is taken after each network chunk, and only deltas with non-empty content, reasoning or tool calls move the first and last token times. The usage-only final chunk does not.
• The write_jsonl refactor leaves --agent-events-jsonl output unchanged.
• CI is green (rust, python), and the PR is level with main.