harn_vm/stdlib/
tracing.rs

1use std::collections::BTreeMap;
2use std::rc::Rc;
3use std::sync::atomic::Ordering;
4
5use crate::value::{VmError, VmValue};
6use crate::vm::Vm;
7
8use super::logging::{vm_build_log_line, VmTraceContext, VM_MIN_LOG_LEVEL, VM_TRACE_STACK};
9
10/// Finish a span started by `trace_start`: computes the elapsed duration,
11/// pops the span from the thread-local trace stack if it is on top, and
12/// returns `(name, trace_id, span_id, duration_ms)` suitable for both the
13/// default `out`-buffered `trace_end` and the bridge-streaming override
14/// registered by the ACP runner.
15pub fn finish_span_from_args(args: &[VmValue]) -> Result<(String, String, String, i64), VmError> {
16    let span = match args.first() {
17        Some(VmValue::Dict(d)) => d,
18        _ => {
19            return Err(VmError::Thrown(VmValue::String(Rc::from(
20                "trace_end: argument must be a span dict from trace_start",
21            ))));
22        }
23    };
24    let end_ms = std::time::SystemTime::now()
25        .duration_since(std::time::UNIX_EPOCH)
26        .unwrap_or_default()
27        .as_millis() as i64;
28    let start_ms = span
29        .get("start_ms")
30        .and_then(|v| v.as_int())
31        .unwrap_or(end_ms);
32    let duration_ms = end_ms - start_ms;
33    let name = span.get("name").map(|v| v.display()).unwrap_or_default();
34    let trace_id = span
35        .get("trace_id")
36        .map(|v| v.display())
37        .unwrap_or_default();
38    let span_id = span.get("span_id").map(|v| v.display()).unwrap_or_default();
39
40    VM_TRACE_STACK.with(|stack| {
41        let mut s = stack.borrow_mut();
42        if let Some(top) = s.last() {
43            if top.span_id == span_id {
44                s.pop();
45            }
46        }
47    });
48
49    Ok((name, trace_id, span_id, duration_ms))
50}
51
52pub(crate) fn register_tracing_builtins(vm: &mut Vm) {
53    vm.register_builtin("trace_start", |args, _out| {
54        use rand::RngExt;
55        let name = args.first().map(|a| a.display()).unwrap_or_default();
56        let trace_id = VM_TRACE_STACK.with(|stack| {
57            stack
58                .borrow()
59                .last()
60                .map(|t| t.trace_id.clone())
61                .unwrap_or_else(|| {
62                    let val: u32 = rand::rng().random();
63                    format!("{val:08x}")
64                })
65        });
66        let span_id = {
67            let val: u32 = rand::rng().random();
68            format!("{val:08x}")
69        };
70        let start_ms = std::time::SystemTime::now()
71            .duration_since(std::time::UNIX_EPOCH)
72            .unwrap_or_default()
73            .as_millis() as i64;
74
75        VM_TRACE_STACK.with(|stack| {
76            stack.borrow_mut().push(VmTraceContext {
77                trace_id: trace_id.clone(),
78                span_id: span_id.clone(),
79            });
80        });
81
82        let mut span = BTreeMap::new();
83        span.insert("trace_id".to_string(), VmValue::String(Rc::from(trace_id)));
84        span.insert("span_id".to_string(), VmValue::String(Rc::from(span_id)));
85        span.insert("name".to_string(), VmValue::String(Rc::from(name)));
86        span.insert("start_ms".to_string(), VmValue::Int(start_ms));
87        Ok(VmValue::Dict(Rc::new(span)))
88    });
89
90    vm.register_builtin("trace_end", |args, out| {
91        let (name, trace_id, span_id, duration_ms) = finish_span_from_args(args)?;
92        let level_num = 1_u8;
93        if level_num >= VM_MIN_LOG_LEVEL.load(Ordering::Relaxed) {
94            let mut fields = BTreeMap::new();
95            fields.insert("trace_id".to_string(), VmValue::String(Rc::from(trace_id)));
96            fields.insert("span_id".to_string(), VmValue::String(Rc::from(span_id)));
97            fields.insert("name".to_string(), VmValue::String(Rc::from(name)));
98            fields.insert("duration_ms".to_string(), VmValue::Int(duration_ms));
99            let line = vm_build_log_line("info", "span_end", Some(&fields));
100            out.push_str(&line);
101        }
102        Ok(VmValue::Nil)
103    });
104
105    vm.register_builtin("trace_id", |_args, _out| {
106        let id = VM_TRACE_STACK.with(|stack| stack.borrow().last().map(|t| t.trace_id.clone()));
107        match id {
108            Some(trace_id) => Ok(VmValue::String(Rc::from(trace_id))),
109            None => Ok(VmValue::Nil),
110        }
111    });
112
113    vm.register_builtin("llm_info", |_args, _out| {
114        let provider = std::env::var("HARN_LLM_PROVIDER").unwrap_or_default();
115        let model = std::env::var("HARN_LLM_MODEL").unwrap_or_default();
116        let api_key_set = std::env::var("HARN_API_KEY")
117            .or_else(|_| std::env::var("OPENROUTER_API_KEY"))
118            .or_else(|_| std::env::var("ANTHROPIC_API_KEY"))
119            .is_ok();
120        let mut info = BTreeMap::new();
121        info.insert("provider".to_string(), VmValue::String(Rc::from(provider)));
122        info.insert("model".to_string(), VmValue::String(Rc::from(model)));
123        info.insert("api_key_set".to_string(), VmValue::Bool(api_key_set));
124        Ok(VmValue::Dict(Rc::new(info)))
125    });
126
127    vm.register_builtin("enable_tracing", |args, _out| {
128        let enabled = match args.first() {
129            Some(VmValue::Bool(b)) => *b,
130            _ => true,
131        };
132        crate::tracing::set_tracing_enabled(enabled);
133        Ok(VmValue::Nil)
134    });
135
136    vm.register_builtin("trace_spans", |_args, _out| {
137        let spans = crate::tracing::peek_spans();
138        let vm_spans: Vec<VmValue> = spans.iter().map(crate::tracing::span_to_vm_value).collect();
139        Ok(VmValue::List(Rc::new(vm_spans)))
140    });
141
142    vm.register_builtin("trace_summary", |_args, _out| {
143        Ok(VmValue::String(Rc::from(crate::tracing::format_summary())))
144    });
145
146    vm.register_builtin("llm_usage", |_args, _out| {
147        let (total_input, total_output, total_duration, call_count) =
148            crate::llm::peek_trace_summary();
149        let mut usage = BTreeMap::new();
150        usage.insert("input_tokens".to_string(), VmValue::Int(total_input));
151        usage.insert("output_tokens".to_string(), VmValue::Int(total_output));
152        usage.insert(
153            "total_duration_ms".to_string(),
154            VmValue::Int(total_duration),
155        );
156        usage.insert("call_count".to_string(), VmValue::Int(call_count));
157        usage.insert("total_calls".to_string(), VmValue::Int(call_count));
158        Ok(VmValue::Dict(Rc::new(usage)))
159    });
160}
harn_vm/stdlib/tracing.rs

harn_vm/stdlib/
tracing.rs
