Skip to main content

systemprompt_cli/commands/infrastructure/logs/trace/
show.rs

1//! `infra logs trace show`: assemble and render a full execution trace.
2//!
3//! Defines the [`ShowArgs`] / [`TraceSections`] CLI surface, resolves the id to
4//! either an AI task trace or a log-event trace, and merges log, AI, MCP, and
5//! step events into a single time-ordered view.
6//!
7//! Copyright (c) systemprompt.io — Business Source License 1.1.
8//! See <https://systemprompt.io> for licensing details.
9
10use anyhow::Result;
11use chrono::{DateTime, Utc};
12use clap::Args;
13use std::sync::Arc;
14use systemprompt_identifiers::{TaskId, TraceId};
15use systemprompt_logging::{AiTraceService, CliService, TraceEvent, TraceQueryService};
16
17use super::ai_trace_display::{execute_ai_trace, filter_log_events};
18use super::display::{print_event, print_table};
19use super::json::build_json;
20use super::summary::{SummaryContext, print_summary};
21use super::{AiSummaryRow, McpSummaryRow, StepSummaryRow, TraceEventRow, TraceViewOutput};
22use crate::CliConfig;
23use crate::context::CommandContext;
24use crate::shared::{CommandOutput, render_result};
25
26#[derive(Debug, Args)]
27pub struct ShowArgs {
28    #[arg(help = "Trace ID or Task ID (can be partial)")]
29    pub id: String,
30
31    #[arg(long, help = "Show detailed metadata for each event")]
32    pub verbose: bool,
33
34    #[arg(long, help = "Output as JSON")]
35    pub json: bool,
36
37    #[command(flatten)]
38    pub sections: TraceSections,
39}
40
41#[derive(Debug, Clone, Copy, Args)]
42pub struct TraceSections {
43    #[arg(long, help = "Show execution steps")]
44    pub steps: bool,
45
46    #[arg(long, help = "Show AI requests in trace")]
47    pub ai: bool,
48
49    #[arg(long, help = "Show MCP tool calls in trace")]
50    pub mcp: bool,
51
52    #[arg(long, help = "Show artifacts")]
53    pub artifacts: bool,
54
55    #[arg(long, help = "Show all sections (steps, ai, mcp, artifacts)")]
56    pub all: bool,
57}
58
59#[derive(Debug)]
60pub struct TraceSummaries<'a> {
61    pub ai: &'a systemprompt_logging::AiRequestSummary,
62    pub mcp: &'a systemprompt_logging::McpExecutionSummary,
63    pub step: &'a systemprompt_logging::ExecutionStepSummary,
64}
65
66struct FormattedDisplayContext<'a> {
67    events: &'a [TraceEvent],
68    trace_id: &'a str,
69    task_id: Option<&'a TaskId>,
70    verbose: bool,
71    ai_summary: &'a systemprompt_logging::AiRequestSummary,
72    mcp_summary: &'a systemprompt_logging::McpExecutionSummary,
73    step_summary: &'a systemprompt_logging::ExecutionStepSummary,
74}
75
76pub(super) async fn execute(args: ShowArgs, ctx: &CommandContext) -> Result<CommandOutput> {
77    let pool = ctx.db_pool().await?.pool_arc()?;
78    execute_with_pool_inner(args, &pool, &ctx.cli).await
79}
80
81async fn execute_with_pool_inner(
82    args: ShowArgs,
83    pool: &Arc<sqlx::PgPool>,
84    config: &CliConfig,
85) -> Result<CommandOutput> {
86    let ai_service = AiTraceService::new(Arc::clone(pool));
87    if let Ok(task_id) = ai_service.resolve_task_id(&args.id).await {
88        return execute_ai_trace(&ai_service, &task_id, &args).await;
89    }
90
91    execute_trace_view(&args, pool, config).await
92}
93
94async fn execute_trace_view(
95    args: &ShowArgs,
96    pool: &Arc<sqlx::PgPool>,
97    config: &CliConfig,
98) -> Result<CommandOutput> {
99    let service = TraceQueryService::new(Arc::clone(pool));
100
101    let (
102        log_events,
103        ai_events,
104        mcp_events,
105        step_events,
106        ai_summary,
107        mcp_summary,
108        step_summary,
109        task_id,
110    ) = service
111        .get_all_trace_data(&TraceId::new(args.id.as_str()))
112        .await?;
113    let task_id: Option<TaskId> = task_id.map(TaskId::new);
114
115    let filtered_log_events = filter_log_events(log_events, args.verbose);
116
117    let mut events = filtered_log_events;
118    events.extend(ai_events);
119    events.extend(mcp_events);
120    events.extend(step_events);
121    events.sort_by_key(|e| e.timestamp);
122
123    let first_timestamp = events.first().map(|e| e.timestamp);
124    let last_timestamp = events.last().map(|e| e.timestamp);
125    let duration_ms = match (first_timestamp, last_timestamp) {
126        (Some(first), Some(last)) => Some((last - first).num_milliseconds()),
127        _ => None,
128    };
129
130    let summaries = TraceSummaries {
131        ai: &ai_summary,
132        mcp: &mcp_summary,
133        step: &step_summary,
134    };
135    let output = build_trace_output(&args.id, &events, &summaries, task_id.as_ref(), duration_ms);
136
137    let result = CommandOutput::card_value("Trace Details", &output);
138
139    if events.is_empty() {
140        if !args.json {
141            report_empty_trace(&args.id, &ai_summary, &mcp_summary);
142        }
143        return Ok(result.with_skip_render());
144    }
145
146    if args.json {
147        let json_result = build_json(&events, &args.id, &ai_summary, &mcp_summary, &step_summary);
148        render_result(&json_result, config);
149        return Ok(result.with_skip_render());
150    }
151
152    let display_ctx = FormattedDisplayContext {
153        events: &events,
154        trace_id: &args.id,
155        task_id: task_id.as_ref(),
156        verbose: args.verbose,
157        ai_summary: &ai_summary,
158        mcp_summary: &mcp_summary,
159        step_summary: &step_summary,
160    };
161    print_formatted(&display_ctx);
162
163    Ok(result.with_skip_render())
164}
165
166fn report_empty_trace(
167    trace_id: &str,
168    ai_summary: &systemprompt_logging::AiRequestSummary,
169    mcp_summary: &systemprompt_logging::McpExecutionSummary,
170) {
171    if ai_summary.request_count == 0 && mcp_summary.execution_count == 0 {
172        CliService::warning(&format!("No events found for trace: {}", trace_id));
173        CliService::info(
174            "Tip: The trace may take a moment to populate. Try again in a few seconds.",
175        );
176        return;
177    }
178
179    CliService::section(&format!("Trace: {}", trace_id));
180    CliService::info("No log events found, but trace has activity:");
181    if ai_summary.request_count > 0 {
182        CliService::key_value("AI Requests", &ai_summary.request_count.to_string());
183        CliService::key_value(
184            "Total Tokens",
185            &format!(
186                "{} in / {} out",
187                ai_summary.total_input_tokens, ai_summary.total_output_tokens
188            ),
189        );
190        let cost_dollars = f64::from(ai_summary.total_cost_microdollars as i32) / 1_000_000.0;
191        CliService::key_value("Cost", &format!("${:.6}", cost_dollars));
192    }
193    if mcp_summary.execution_count > 0 {
194        CliService::key_value("MCP Calls", &mcp_summary.execution_count.to_string());
195    }
196    CliService::info("Use --verbose to see all log entries, or --ai/--mcp for details");
197}
198
199fn print_formatted(ctx: &FormattedDisplayContext<'_>) {
200    CliService::section(&format!("Trace Flow: {}", ctx.trace_id));
201
202    let first_timestamp = ctx.events.first().map(|e| e.timestamp);
203    let last_timestamp = ctx.events.last().map(|e| e.timestamp);
204
205    if ctx.verbose {
206        let mut prev_timestamp: Option<DateTime<Utc>> = None;
207        for event in ctx.events {
208            print_event(event, ctx.verbose, prev_timestamp);
209            prev_timestamp = Some(event.timestamp);
210        }
211    } else {
212        print_table(ctx.events);
213    }
214
215    let summary_ctx = SummaryContext {
216        events: ctx.events,
217        first: first_timestamp,
218        last: last_timestamp,
219        task_id: ctx.task_id,
220        ai_summary: ctx.ai_summary,
221        mcp_summary: ctx.mcp_summary,
222        step_summary: ctx.step_summary,
223    };
224    print_summary(&summary_ctx);
225}
226
227pub fn build_trace_output(
228    trace_id: &str,
229    events: &[TraceEvent],
230    summaries: &TraceSummaries<'_>,
231    task_id: Option<&TaskId>,
232    duration_ms: Option<i64>,
233) -> TraceViewOutput {
234    let first_timestamp = events.first().map(|e| e.timestamp);
235
236    let event_rows: Vec<TraceEventRow> = events
237        .iter()
238        .map(|e| {
239            let delta_ms =
240                first_timestamp.map_or(0, |first| (e.timestamp - first).num_milliseconds());
241            TraceEventRow {
242                timestamp: e.timestamp.format("%Y-%m-%d %H:%M:%S%.3f").to_string(),
243                delta_ms,
244                event_type: e.event_type.clone(),
245                details: e.details.clone(),
246                latency_ms: None,
247            }
248        })
249        .collect();
250
251    let cost_dollars = f64::from(summaries.ai.total_cost_microdollars as i32) / 1_000_000.0;
252
253    let status = if summaries.step.failed > 0 {
254        "failed".to_owned()
255    } else if summaries.step.pending > 0 {
256        "in_progress".to_owned()
257    } else {
258        "completed".to_owned()
259    };
260
261    TraceViewOutput {
262        trace_id: TraceId::new(trace_id),
263        events: event_rows,
264        ai_summary: AiSummaryRow {
265            request_count: summaries.ai.request_count,
266            total_tokens: summaries.ai.total_input_tokens + summaries.ai.total_output_tokens,
267            input_tokens: summaries.ai.total_input_tokens,
268            output_tokens: summaries.ai.total_output_tokens,
269            cost_dollars,
270            total_latency_ms: summaries.ai.total_latency_ms,
271        },
272        mcp_summary: McpSummaryRow {
273            execution_count: summaries.mcp.execution_count,
274            total_execution_time_ms: summaries.mcp.total_execution_time_ms,
275        },
276        step_summary: StepSummaryRow {
277            total: summaries.step.total,
278            completed: summaries.step.completed,
279            failed: summaries.step.failed,
280            pending: summaries.step.pending,
281        },
282        task: task_id.map(|t| t.as_str().to_owned()),
283        duration_ms,
284        status,
285    }
286}