From 2bac8fcedcce9a9df99d2f0c187c4f0a1433494f Mon Sep 17 00:00:00 2001 From: Hesham Salman Date: Wed, 16 Sep 2026 00:04:39 -0400 Subject: [PATCH] fix(tracing): record session outcomes on root spans Closed Claude, Pi, and Codex root spans never populated output, so root-based summaries and turn evaluators omitted every session outcome even when descendant turns held the final assistant response. Track the last completed turn output in each translator and merge it into the root span at session end (Claude SessionEnd and daemon finalize, Pi session_shutdown and finalize, Codex main-scope Stop). Pi turns now also carry their last completed assistant message; errored or aborted messages are not outcomes. --- bt-daemon/src/translate/claude.rs | 18 ++- bt-daemon/src/translate/codex.rs | 13 ++- bt-daemon/src/translate/pi.rs | 15 +++ bt-daemon/tests/claude_translator.rs | 164 +++++++++++++++++++++++++++ bt-daemon/tests/codex_translator.rs | 39 +++++++ bt-daemon/tests/pi_translator.rs | 98 ++++++++++++++++ 6 files changed, 340 insertions(+), 7 deletions(-) diff --git a/bt-daemon/src/translate/claude.rs b/bt-daemon/src/translate/claude.rs index 123b507..2d8986c 100644 --- a/bt-daemon/src/translate/claude.rs +++ b/bt-daemon/src/translate/claude.rs @@ -270,6 +270,7 @@ struct ClaudeTranslator { git: Arc, current_cwd: Option, last_turn_cwd: Option, + last_turn_output: Option, last_ts_ms: i64, } @@ -302,6 +303,7 @@ impl ClaudeTranslator { git, current_cwd: None, last_turn_cwd: None, + last_turn_output: None, last_ts_ms: 0, } } @@ -842,15 +844,19 @@ impl ClaudeTranslator { "Turn ended before tool completion", ops, ); + let output = event + .payload + .get("last_assistant_message") + .cloned() + .or_else(|| event.payload.get("output").cloned()); + if output.as_ref().is_some_and(|output| !output.is_null()) { + self.last_turn_output = output.clone(); + } ops.push(SpanOp::Merge(SpanRow { span_id: turn_id.clone(), root_span_id: self.root_span_id.clone(), end_ms: Some(event.ts_ms), - output: event - .payload - .get("last_assistant_message") - .cloned() - .or_else(|| event.payload.get("output").cloned()), + output, error, ..Default::default() })); @@ -920,6 +926,7 @@ impl ClaudeTranslator { span_id: self.session_span_id.clone(), root_span_id: self.root_span_id.clone(), end_ms: Some(event.ts_ms), + output: self.last_turn_output.clone(), ..Default::default() })); } @@ -1064,6 +1071,7 @@ impl AgentTranslator for ClaudeTranslator { span_id: self.session_span_id.clone(), root_span_id: self.root_span_id.clone(), end_ms: Some(end_ms), + output: self.last_turn_output.clone(), ..Default::default() })); } diff --git a/bt-daemon/src/translate/codex.rs b/bt-daemon/src/translate/codex.rs index a496b57..00f0c8e 100644 --- a/bt-daemon/src/translate/codex.rs +++ b/bt-daemon/src/translate/codex.rs @@ -191,6 +191,7 @@ struct Scope { open_llm: Option, open_tools: HashMap, // call_id -> (tool span_id, turn_id) last_turn_end_ms: Option, + last_turn_output: Option, turn_seq: u32, // Subagent-only: agent_id: Option, @@ -1206,6 +1207,9 @@ impl CodexTranslator { let output = str_field(payload, "last_agent_message") .or_else(|| str_field(payload, "last_assistant_message")) .map(|s| json!(s)); + if let Some(output) = &output { + scope.last_turn_output = Some(output.clone()); + } ops.push(SpanOp::Merge(SpanRow { span_id: turn.span_id, root_span_id: self.root_span_id.clone(), @@ -1326,16 +1330,20 @@ impl CodexTranslator { if !self.root_opened { return; } - let end_ms = self + let main_scope = self .main_path .as_ref() - .and_then(|path| self.scopes.get(path)) + .and_then(|path| self.scopes.get(path)); + let end_ms = main_scope .and_then(|scope| scope.last_turn_end_ms) .unwrap_or(fallback_ts); + // The session outcome is the last completed turn's output. + let output = main_scope.and_then(|scope| scope.last_turn_output.clone()); ops.push(SpanOp::Merge(SpanRow { span_id: self.root_span_id.clone(), root_span_id: self.root_span_id.clone(), end_ms: Some(end_ms), + output, late_merge_key: Some(format!("session:stop:{end_ms}")), ..Default::default() })); @@ -1471,6 +1479,7 @@ impl Scope { open_llm: None, open_tools: HashMap::new(), last_turn_end_ms: None, + last_turn_output: None, turn_seq: 0, agent_id: None, agent_type: None, diff --git a/bt-daemon/src/translate/pi.rs b/bt-daemon/src/translate/pi.rs index 6b132ef..b572e2d 100644 --- a/bt-daemon/src/translate/pi.rs +++ b/bt-daemon/src/translate/pi.rs @@ -35,6 +35,8 @@ impl TranslatorFactory for PiTranslatorFactory { external_parent: None, opened: false, turn: None, + turn_output: None, + last_turn_output: None, turn_seq: 0, llm_seq: 0, total_tools: 0, @@ -309,6 +311,8 @@ struct PiTranslator { external_parent: Option, opened: bool, turn: Option<(String, Value)>, + turn_output: Option, + last_turn_output: Option, turn_seq: u32, llm_seq: u32, total_tools: u32, @@ -667,6 +671,11 @@ impl PiTranslator { .error_message .clone() .filter(|_| matches!(message.stop_reason.as_deref(), Some("error" | "aborted"))); + // Turn and root outcomes come from the latest completed assistant + // message; errored or aborted messages are not outcomes. + if error.is_none() { + self.turn_output = Some(output.clone()); + } let ttft = pending .first_token_ms .map(|first| (first - pending.start_ms) as f64 / 1000.0); @@ -842,10 +851,15 @@ impl PiTranslator { let Some((id, _)) = turn else { return vec![]; }; + let output = self.turn_output.take(); + if output.is_some() { + self.last_turn_output = output.clone(); + } vec![SpanOp::Merge(SpanRow { span_id: id, root_span_id: self.effective_root_span_id.clone(), end_ms: Some(ts), + output, error, ..Default::default() })] @@ -859,6 +873,7 @@ impl PiTranslator { span_id: self.root_span_id.clone(), root_span_id: self.effective_root_span_id.clone(), end_ms: Some(ts), + output: self.last_turn_output.take(), metadata: Some( json!({"total_turns":self.turn_seq,"total_tool_calls":self.total_tools}), ), diff --git a/bt-daemon/tests/claude_translator.rs b/bt-daemon/tests/claude_translator.rs index 0fc3a21..3e98c7b 100644 --- a/bt-daemon/tests/claude_translator.rs +++ b/bt-daemon/tests/claude_translator.rs @@ -373,6 +373,170 @@ fn claude_passive_hooks_do_not_create_blank_session_traces() { assert_eq!(metadata["model"], "claude-test"); } +#[test] +fn claude_root_records_last_turn_output_on_session_end() { + let registry = Registry::default_agents(); + let mut translator = registry.create("claude-code", "outcome-session"); + let ctx = SessionCtx { + session_id: "outcome-session".into(), + config: None, + }; + let event = |name: &str, ts_ms: i64, payload: Value| Envelope { + source: "claude-code".into(), + source_version: None, + plugin_version: None, + session_id: "outcome-session".into(), + event: name.into(), + ts_ms, + managed_run_id: None, + payload, + route: None, + config: None, + capture: None, + }; + + let mut ops = Vec::new(); + for event in [ + event( + "SessionStart", + 1, + json!({"cwd":"/workspace/demo", "source":"startup", "model":"claude-test"}), + ), + event( + "UserPromptSubmit", + 2, + json!({"cwd":"/workspace/demo", "prompt":"ship it"}), + ), + event( + "Stop", + 3, + json!({"cwd":"/workspace/demo", "last_assistant_message":"Done. Shipped it."}), + ), + event("SessionEnd", 4, json!({"cwd":"/workspace/demo"})), + ] { + ops.extend(translator.handle(&event, &ctx).unwrap()); + } + + let rows = reduce(ops); + let turn = rows + .values() + .find(|row| row.name == "Turn 1") + .expect("turn span"); + assert_eq!(turn.output, Some(json!("Done. Shipped it."))); + let root = rows + .values() + .find(|row| row.name == "Claude Code: demo") + .expect("root span"); + assert_eq!( + root.output, + Some(json!("Done. Shipped it.")), + "the session outcome must land on the root span" + ); +} + +#[test] +fn claude_root_records_last_turn_output_on_finalize() { + let registry = Registry::default_agents(); + let mut translator = registry.create("claude-code", "finalize-session"); + let ctx = SessionCtx { + session_id: "finalize-session".into(), + config: None, + }; + let event = |name: &str, ts_ms: i64, payload: Value| Envelope { + source: "claude-code".into(), + source_version: None, + plugin_version: None, + session_id: "finalize-session".into(), + event: name.into(), + ts_ms, + managed_run_id: None, + payload, + route: None, + config: None, + capture: None, + }; + + let mut ops = Vec::new(); + for event in [ + event( + "SessionStart", + 1, + json!({"cwd":"/workspace/demo", "source":"startup", "model":"claude-test"}), + ), + event( + "UserPromptSubmit", + 2, + json!({"cwd":"/workspace/demo", "prompt":"ship it"}), + ), + event( + "Stop", + 3, + json!({"cwd":"/workspace/demo", "last_assistant_message":"Done. Shipped it."}), + ), + ] { + ops.extend(translator.handle(&event, &ctx).unwrap()); + } + // No SessionEnd hook: the daemon finalizes the session after a teardown. + ops.extend(translator.finalize(&ctx).unwrap()); + + let rows = reduce(ops); + let root = rows + .values() + .find(|row| row.name == "Claude Code: demo") + .expect("root span"); + assert_eq!(root.output, Some(json!("Done. Shipped it."))); +} + +#[test] +fn claude_root_output_stays_unset_without_a_completed_turn() { + let registry = Registry::default_agents(); + let mut translator = registry.create("claude-code", "no-turn-session"); + let ctx = SessionCtx { + session_id: "no-turn-session".into(), + config: None, + }; + let event = |name: &str, ts_ms: i64, payload: Value| Envelope { + source: "claude-code".into(), + source_version: None, + plugin_version: None, + session_id: "no-turn-session".into(), + event: name.into(), + ts_ms, + managed_run_id: None, + payload, + route: None, + config: None, + capture: None, + }; + + let mut ops = Vec::new(); + for event in [ + event( + "SessionStart", + 1, + json!({"cwd":"/workspace/demo", "source":"startup", "model":"claude-test"}), + ), + event( + "UserPromptSubmit", + 2, + json!({"cwd":"/workspace/demo", "prompt":"interrupted"}), + ), + event("SessionEnd", 3, json!({"cwd":"/workspace/demo"})), + ] { + ops.extend(translator.handle(&event, &ctx).unwrap()); + } + + let rows = reduce(ops); + let root = rows + .values() + .find(|row| row.name == "Claude Code: demo") + .expect("root span"); + assert_eq!( + root.output, None, + "a session with no completed turn has no outcome to record" + ); +} + #[test] fn claude_subagent_routing_tolerates_malformed_optional_metadata() { let registry = Registry::default_agents(); diff --git a/bt-daemon/tests/codex_translator.rs b/bt-daemon/tests/codex_translator.rs index c094db2..eb26ae5 100644 --- a/bt-daemon/tests/codex_translator.rs +++ b/bt-daemon/tests/codex_translator.rs @@ -267,6 +267,45 @@ fn codex_happy_path_builds_session_turn_llm_tool_tree() { ); } +#[test] +fn codex_root_records_last_turn_output_on_stop() { + let tmp = tempfile::tempdir().unwrap(); + let transcript = tmp.path().join("rollout.jsonl"); + write_transcript(&transcript); + let tpath = transcript.to_str().unwrap(); + + let reg = Registry::default_agents(); + let mut tr = reg.create("codex", "sess-outcome"); + let ctx = SessionCtx { + session_id: "sess-outcome".into(), + config: None, + }; + + let mut ops = Vec::new(); + ops.extend( + tr.handle( + &envelope("sess-outcome", "SessionStart", tpath, json!({ "source": "startup" })), + &ctx, + ) + .unwrap(), + ); + ops.extend( + tr.handle(&envelope("sess-outcome", "Stop", tpath, json!({})), &ctx) + .unwrap(), + ); + ops.extend(tr.flush(&ctx).unwrap()); + + let rows = reduce(ops); + let turn = find(&rows, SpanType::Task, "turn: t1"); + assert_eq!(turn.output, Some(json!("Here are the files."))); + let root = find(&rows, SpanType::Task, "codex: myapp"); + assert_eq!( + root.output, + Some(json!("Here are the files.")), + "the session outcome must land on the root span" + ); +} + #[test] fn codex_root_preserves_canonical_source_across_lifecycle_events() { let tmp = tempfile::tempdir().unwrap(); diff --git a/bt-daemon/tests/pi_translator.rs b/bt-daemon/tests/pi_translator.rs index 64bf0ac..b9d878f 100644 --- a/bt-daemon/tests/pi_translator.rs +++ b/bt-daemon/tests/pi_translator.rs @@ -226,6 +226,104 @@ fn pi_builds_turn_llm_tool_compaction_and_shutdown_spans() { .all(|r| r.end_ms.is_some())); } +#[test] +fn pi_turn_and_root_carry_last_assistant_output() { + let registry = Registry::default_agents(); + let mut translator = registry.create("pi", "pi-session"); + let ctx = SessionCtx { + session_id: "pi-session".into(), + config: None, + }; + let events = vec![ + event("session_start", 1, json!({"reason":"new"})), + event("before_agent_start", 2, json!({"prompt":"do it"})), + event( + "context", + 3, + json!({"messages":[{"role":"user","content":"do it"}]}), + ), + event( + "message_end", + 4, + json!({"message":{"role":"assistant","provider":"openai","model":"gpt-5","content":[{"type":"text","text":"all done"}],"usage":{"input":3,"output":1,"totalTokens":4}}}), + ), + event("agent_end", 5, json!({"messages":[]})), + event("before_agent_start", 6, json!({"prompt":"again"})), + event( + "context", + 7, + json!({"messages":[{"role":"user","content":"again"}]}), + ), + event( + "message_end", + 8, + json!({"message":{"role":"assistant","provider":"openai","model":"gpt-5","content":[{"type":"text","text":"done again"}],"usage":{"input":3,"output":1,"totalTokens":4}}}), + ), + event("agent_end", 9, json!({"messages":[]})), + event("session_shutdown", 10, json!({"reason":"quit"})), + ]; + let mut ops = Vec::new(); + for event in events { + ops.extend(translator.handle(&event, &ctx).unwrap()); + } + let rows = reduce(ops); + let turn_one = rows.values().find(|r| r.name == "Turn 1").unwrap(); + assert_eq!( + turn_one.output, + Some(json!({"role":"assistant","content":"all done"})), + "a completed turn carries its last assistant message" + ); + let turn_two = rows.values().find(|r| r.name == "Turn 2").unwrap(); + assert_eq!( + turn_two.output, + Some(json!({"role":"assistant","content":"done again"})) + ); + let root = rows.values().find(|r| r.name == "Pi").unwrap(); + assert_eq!( + root.output, + Some(json!({"role":"assistant","content":"done again"})), + "the session outcome is the last completed turn's output" + ); +} + +#[test] +fn pi_errored_message_is_not_a_turn_or_root_outcome() { + let registry = Registry::default_agents(); + let mut translator = registry.create("pi", "pi-session"); + let ctx = SessionCtx { + session_id: "pi-session".into(), + config: None, + }; + let events = vec![ + event("session_start", 1, json!({"reason":"new"})), + event("before_agent_start", 2, json!({"prompt":"do it"})), + event( + "context", + 3, + json!({"messages":[{"role":"user","content":"do it"}]}), + ), + event( + "message_end", + 4, + json!({"message":{"role":"assistant","provider":"openai","model":"gpt-5","content":[{"type":"text","text":""}],"stopReason":"error","errorMessage":"provider exploded","usage":{"input":3,"output":1,"totalTokens":4}}}), + ), + event("agent_end", 5, json!({"messages":[]})), + event("session_shutdown", 6, json!({"reason":"quit"})), + ]; + let mut ops = Vec::new(); + for event in events { + ops.extend(translator.handle(&event, &ctx).unwrap()); + } + let rows = reduce(ops); + let turn = rows.values().find(|r| r.name == "Turn 1").unwrap(); + assert_eq!( + turn.output, None, + "an errored message is not a completed outcome" + ); + let root = rows.values().find(|r| r.name == "Pi").unwrap(); + assert_eq!(root.output, None); +} + #[test] fn pi_additional_metadata_reaches_roots_without_overriding_session_fields() { let registry = Registry::default_agents();