use std::time::Duration;
#[derive(Debug, Clone, PartialEq)]
pub enum TraceEntryKind {
Command {
command: String,
duration: Duration,
result: TraceResult,
},
Instant {
name: String,
},
}
#[derive(Debug, Clone, PartialEq)]
pub struct TraceEntry {
pub context: Option<String>,
pub kind: TraceEntryKind,
pub start_time_us: Option<u64>,
pub thread_id: Option<u64>,
}
#[derive(Debug, Clone, PartialEq)]
pub enum TraceResult {
Completed { success: bool },
Error { message: String },
}
impl TraceEntry {
pub fn is_success(&self) -> bool {
match &self.kind {
TraceEntryKind::Command { result, .. } => {
matches!(result, TraceResult::Completed { success: true })
}
TraceEntryKind::Instant { .. } => true,
}
}
}
fn parse_line(line: &str) -> Option<TraceEntry> {
let marker = "[wt-trace] ";
let marker_pos = line.find(marker)?;
let rest = &line[marker_pos + marker.len()..];
let mut context = None;
let mut command = None;
let mut event = None;
let mut duration = None;
let mut result = None;
let mut start_time_us = None;
let mut thread_id = None;
let mut remaining = rest;
while !remaining.is_empty() {
remaining = remaining.trim_start();
if remaining.is_empty() {
break;
}
let eq_pos = remaining.find('=')?;
let key = &remaining[..eq_pos];
remaining = &remaining[eq_pos + 1..];
let value = if remaining.starts_with('"') {
remaining = &remaining[1..];
let end_quote = remaining.find('"')?;
let val = &remaining[..end_quote];
remaining = &remaining[end_quote + 1..];
val
} else {
let end = remaining.find(' ').unwrap_or(remaining.len());
let val = &remaining[..end];
remaining = &remaining[end..];
val
};
match key {
"context" => context = Some(value.to_string()),
"cmd" => command = Some(value.to_string()),
"event" => event = Some(value.to_string()),
"dur_us" => {
let us: u64 = value.parse().ok()?;
duration = Some(Duration::from_micros(us));
}
"ok" => {
let success = value == "true";
result = Some(TraceResult::Completed { success });
}
"err" => {
result = Some(TraceResult::Error {
message: value.to_string(),
});
}
"ts" => {
start_time_us = value.parse().ok();
}
"tid" => {
thread_id = value.parse().ok();
}
_ => {} }
}
let kind = if let Some(event_name) = event {
TraceEntryKind::Instant { name: event_name }
} else {
TraceEntryKind::Command {
command: command?,
duration: duration?,
result: result?,
}
};
Some(TraceEntry {
context,
kind,
start_time_us,
thread_id,
})
}
pub fn parse_lines(input: &str) -> Vec<TraceEntry> {
input.lines().filter_map(parse_line).collect()
}
#[cfg(test)]
mod tests {
use super::*;
#[test]
fn test_parse_basic() {
let line = r#"[wt-trace] cmd="git status" dur_us=12300 ok=true"#;
let entry = parse_line(line).unwrap();
assert_eq!(entry.context, None);
let TraceEntryKind::Command {
command, duration, ..
} = &entry.kind
else {
panic!("expected command");
};
assert_eq!(command, "git status");
assert_eq!(*duration, Duration::from_micros(12300));
assert!(entry.is_success());
}
#[test]
fn test_parse_with_context() {
let line =
r#"[wt-trace] context=main cmd="git merge-base HEAD origin/main" dur_us=45200 ok=true"#;
let entry = parse_line(line).unwrap();
assert_eq!(entry.context, Some("main".to_string()));
let TraceEntryKind::Command { command, .. } = &entry.kind else {
panic!("expected command");
};
assert_eq!(command, "git merge-base HEAD origin/main");
}
#[test]
fn test_parse_error() {
let line = r#"[wt-trace] cmd="git rev-list" dur_us=100000 err="fatal: bad revision""#;
let entry = parse_line(line).unwrap();
assert!(!entry.is_success());
assert!(matches!(
&entry.kind,
TraceEntryKind::Command { result: TraceResult::Error { message }, .. } if message == "fatal: bad revision"
));
}
#[test]
fn test_parse_ok_false() {
let line = r#"[wt-trace] cmd="git diff" dur_us=5000 ok=false"#;
let entry = parse_line(line).unwrap();
assert!(!entry.is_success());
assert!(matches!(
&entry.kind,
TraceEntryKind::Command {
result: TraceResult::Completed { success: false },
..
}
));
}
#[test]
fn test_parse_non_trace_line() {
assert!(parse_line("some random log line").is_none());
assert!(parse_line("[other-tag] something").is_none());
}
#[test]
fn test_parse_with_log_prefix() {
let line = r#"[a] [wt-trace] cmd="git status" dur_us=5000 ok=true"#;
let entry = parse_line(line).unwrap();
assert!(matches!(
&entry.kind,
TraceEntryKind::Command { command, .. } if command == "git status"
));
}
#[test]
fn test_parse_unknown_keys_ignored() {
let line =
r#"[wt-trace] future_field=xyz cmd="git status" dur_us=5000 ok=true extra=ignored"#;
let entry = parse_line(line).unwrap();
assert!(matches!(
&entry.kind,
TraceEntryKind::Command { command, .. } if command == "git status"
));
assert!(entry.is_success());
}
#[test]
fn test_parse_trailing_whitespace() {
let line = "[wt-trace] cmd=\"git status\" dur_us=5000 ok=true ";
let entry = parse_line(line).unwrap();
assert!(matches!(
&entry.kind,
TraceEntryKind::Command { command, .. } if command == "git status"
));
}
#[test]
fn test_parse_lines() {
let input = r#"
DEBUG some other log
[wt-trace] cmd="git status" dur_us=10000 ok=true
more noise
[wt-trace] cmd="git diff" dur_us=20000 ok=true
"#;
let entries = parse_lines(input);
assert_eq!(entries.len(), 2);
assert!(matches!(
&entries[0].kind,
TraceEntryKind::Command { command, .. } if command == "git status"
));
assert!(matches!(
&entries[1].kind,
TraceEntryKind::Command { command, .. } if command == "git diff"
));
}
#[test]
fn test_parse_with_timestamp_and_thread_id() {
let line = r#"[wt-trace] ts=1736600000000000 tid=5 context=feature cmd="git status" dur_us=12300 ok=true"#;
let entry = parse_line(line).unwrap();
assert_eq!(entry.start_time_us, Some(1736600000000000));
assert_eq!(entry.thread_id, Some(5));
assert_eq!(entry.context, Some("feature".to_string()));
assert!(matches!(
&entry.kind,
TraceEntryKind::Command { command, .. } if command == "git status"
));
assert!(entry.is_success());
}
#[test]
fn test_parse_without_timestamp_and_thread_id() {
let line = r#"[wt-trace] cmd="git status" dur_us=12300 ok=true"#;
let entry = parse_line(line).unwrap();
assert_eq!(entry.start_time_us, None);
assert_eq!(entry.thread_id, None);
assert!(matches!(
&entry.kind,
TraceEntryKind::Command { command, .. } if command == "git status"
));
}
#[test]
fn test_parse_partial_new_fields() {
let line = r#"[wt-trace] ts=1736600000000000 cmd="git status" dur_us=12300 ok=true"#;
let entry = parse_line(line).unwrap();
assert_eq!(entry.start_time_us, Some(1736600000000000));
assert_eq!(entry.thread_id, None);
}
#[test]
fn test_parse_instant_event() {
let line = r#"[wt-trace] ts=1736600000000000 tid=3 event="Showed skeleton""#;
let entry = parse_line(line).unwrap();
assert_eq!(entry.start_time_us, Some(1736600000000000));
assert_eq!(entry.thread_id, Some(3));
let TraceEntryKind::Instant { name } = &entry.kind else {
panic!("expected instant event");
};
assert_eq!(name, "Showed skeleton");
assert!(entry.is_success()); }
#[test]
fn test_parse_instant_event_with_context() {
let line = r#"[wt-trace] ts=1736600000000000 tid=3 context=main event="Skeleton rendered""#;
let entry = parse_line(line).unwrap();
assert_eq!(entry.context, Some("main".to_string()));
assert!(matches!(
&entry.kind,
TraceEntryKind::Instant { name } if name == "Skeleton rendered"
));
}
#[test]
fn test_parse_instant_event_minimal() {
let line = r#"[wt-trace] event="Started""#;
let entry = parse_line(line).unwrap();
assert!(matches!(
&entry.kind,
TraceEntryKind::Instant { name } if name == "Started"
));
assert_eq!(entry.start_time_us, None);
assert_eq!(entry.thread_id, None);
}
#[test]
fn test_parse_lines_mixed() {
let input = r#"
[wt-trace] event="Started"
[wt-trace] cmd="git status" dur_us=10000 ok=true
[wt-trace] event="Showed skeleton"
[wt-trace] cmd="git diff" dur_us=20000 ok=true
[wt-trace] event="Done"
"#;
let entries = parse_lines(input);
assert_eq!(entries.len(), 5);
assert!(matches!(&entries[0].kind, TraceEntryKind::Instant { name } if name == "Started"));
assert!(
matches!(&entries[1].kind, TraceEntryKind::Command { command, .. } if command == "git status")
);
assert!(
matches!(&entries[2].kind, TraceEntryKind::Instant { name } if name == "Showed skeleton")
);
assert!(
matches!(&entries[3].kind, TraceEntryKind::Command { command, .. } if command == "git diff")
);
assert!(matches!(&entries[4].kind, TraceEntryKind::Instant { name } if name == "Done"));
}
}