Skip to main content

construct/observability/
log.rs

1use super::traits::{Observer, ObserverEvent, ObserverMetric};
2use std::any::Any;
3use tracing::info;
4
5/// Log-based observer — uses tracing, zero external deps
6pub struct LogObserver;
7
8impl LogObserver {
9    pub fn new() -> Self {
10        Self
11    }
12}
13
14impl Observer for LogObserver {
15    fn record_event(&self, event: &ObserverEvent) {
16        match event {
17            ObserverEvent::AgentStart { provider, model } => {
18                info!(provider = %provider, model = %model, "agent.start");
19            }
20            ObserverEvent::AgentEnd {
21                provider,
22                model,
23                duration,
24                tokens_used,
25                cost_usd,
26            } => {
27                let ms = u64::try_from(duration.as_millis()).unwrap_or(u64::MAX);
28                info!(provider = %provider, model = %model, duration_ms = ms, tokens = ?tokens_used, cost_usd = ?cost_usd, "agent.end");
29            }
30            ObserverEvent::ToolCallStart { tool, .. } => {
31                info!(tool = %tool, "tool.start");
32            }
33            ObserverEvent::ToolCall {
34                tool,
35                duration,
36                success,
37            } => {
38                let ms = u64::try_from(duration.as_millis()).unwrap_or(u64::MAX);
39                info!(tool = %tool, duration_ms = ms, success = success, "tool.call");
40            }
41            ObserverEvent::TurnComplete => {
42                info!("turn.complete");
43            }
44            ObserverEvent::ChannelMessage { channel, direction } => {
45                info!(channel = %channel, direction = %direction, "channel.message");
46            }
47            ObserverEvent::HeartbeatTick => {
48                info!("heartbeat.tick");
49            }
50            ObserverEvent::CacheHit {
51                cache_type,
52                tokens_saved,
53            } => {
54                info!(cache_type = %cache_type, tokens_saved = tokens_saved, "cache.hit");
55            }
56            ObserverEvent::CacheMiss { cache_type } => {
57                info!(cache_type = %cache_type, "cache.miss");
58            }
59            ObserverEvent::Error { component, message } => {
60                info!(component = %component, error = %message, "error");
61            }
62            ObserverEvent::LlmRequest {
63                provider,
64                model,
65                messages_count,
66            } => {
67                info!(
68                    provider = %provider,
69                    model = %model,
70                    messages_count = messages_count,
71                    "llm.request"
72                );
73            }
74            ObserverEvent::LlmResponse {
75                provider,
76                model,
77                duration,
78                success,
79                error_message,
80                input_tokens,
81                output_tokens,
82            } => {
83                let ms = u64::try_from(duration.as_millis()).unwrap_or(u64::MAX);
84                info!(
85                    provider = %provider,
86                    model = %model,
87                    duration_ms = ms,
88                    success = success,
89                    error = ?error_message,
90                    input_tokens = ?input_tokens,
91                    output_tokens = ?output_tokens,
92                    "llm.response"
93                );
94            }
95            ObserverEvent::HandStarted { hand_name } => {
96                info!(hand = %hand_name, "hand.started");
97            }
98            ObserverEvent::HandCompleted {
99                hand_name,
100                duration_ms,
101                findings_count,
102            } => {
103                info!(hand = %hand_name, duration_ms = duration_ms, findings = findings_count, "hand.completed");
104            }
105            ObserverEvent::HandFailed {
106                hand_name,
107                error,
108                duration_ms,
109            } => {
110                info!(hand = %hand_name, error = %error, duration_ms = duration_ms, "hand.failed");
111            }
112            ObserverEvent::DeploymentStarted { deploy_id } => {
113                info!(deploy_id = %deploy_id, "deployment.started");
114            }
115            ObserverEvent::DeploymentCompleted {
116                deploy_id,
117                commit_sha,
118            } => {
119                info!(deploy_id = %deploy_id, commit_sha = %commit_sha, "deployment.completed");
120            }
121            ObserverEvent::DeploymentFailed { deploy_id, reason } => {
122                info!(deploy_id = %deploy_id, reason = %reason, "deployment.failed");
123            }
124            ObserverEvent::RecoveryCompleted { deploy_id } => {
125                info!(deploy_id = %deploy_id, "recovery.completed");
126            }
127        }
128    }
129
130    fn record_metric(&self, metric: &ObserverMetric) {
131        match metric {
132            ObserverMetric::RequestLatency(d) => {
133                let ms = u64::try_from(d.as_millis()).unwrap_or(u64::MAX);
134                info!(latency_ms = ms, "metric.request_latency");
135            }
136            ObserverMetric::TokensUsed(t) => {
137                info!(tokens = t, "metric.tokens_used");
138            }
139            ObserverMetric::ActiveSessions(s) => {
140                info!(sessions = s, "metric.active_sessions");
141            }
142            ObserverMetric::QueueDepth(d) => {
143                info!(depth = d, "metric.queue_depth");
144            }
145            ObserverMetric::HandRunDuration {
146                hand_name,
147                duration,
148            } => {
149                let ms = u64::try_from(duration.as_millis()).unwrap_or(u64::MAX);
150                info!(hand = %hand_name, duration_ms = ms, "metric.hand_run_duration");
151            }
152            ObserverMetric::HandFindingsCount { hand_name, count } => {
153                info!(hand = %hand_name, count = count, "metric.hand_findings_count");
154            }
155            ObserverMetric::HandSuccessRate { hand_name, success } => {
156                info!(hand = %hand_name, success = success, "metric.hand_success_rate");
157            }
158            ObserverMetric::DeploymentLeadTime(d) => {
159                let ms = u64::try_from(d.as_millis()).unwrap_or(u64::MAX);
160                info!(lead_time_ms = ms, "metric.deployment_lead_time");
161            }
162            ObserverMetric::RecoveryTime(d) => {
163                let ms = u64::try_from(d.as_millis()).unwrap_or(u64::MAX);
164                info!(recovery_time_ms = ms, "metric.recovery_time");
165            }
166        }
167    }
168
169    fn name(&self) -> &str {
170        "log"
171    }
172
173    fn as_any(&self) -> &dyn Any {
174        self
175    }
176}
177
178#[cfg(test)]
179mod tests {
180    use super::*;
181    use std::time::Duration;
182
183    #[test]
184    fn log_observer_name() {
185        assert_eq!(LogObserver::new().name(), "log");
186    }
187
188    #[test]
189    fn log_observer_all_events_no_panic() {
190        let obs = LogObserver::new();
191        obs.record_event(&ObserverEvent::AgentStart {
192            provider: "openrouter".into(),
193            model: "claude-sonnet".into(),
194        });
195        obs.record_event(&ObserverEvent::AgentEnd {
196            provider: "openrouter".into(),
197            model: "claude-sonnet".into(),
198            duration: Duration::from_millis(500),
199            tokens_used: Some(100),
200            cost_usd: Some(0.0015),
201        });
202        obs.record_event(&ObserverEvent::AgentEnd {
203            provider: "openrouter".into(),
204            model: "claude-sonnet".into(),
205            duration: Duration::ZERO,
206            tokens_used: None,
207            cost_usd: None,
208        });
209        obs.record_event(&ObserverEvent::LlmResponse {
210            provider: "openrouter".into(),
211            model: "claude-sonnet".into(),
212            duration: Duration::from_millis(150),
213            success: true,
214            error_message: None,
215            input_tokens: Some(100),
216            output_tokens: Some(50),
217        });
218        obs.record_event(&ObserverEvent::LlmResponse {
219            provider: "openrouter".into(),
220            model: "claude-sonnet".into(),
221            duration: Duration::from_millis(200),
222            success: false,
223            error_message: Some("rate limited".into()),
224            input_tokens: None,
225            output_tokens: None,
226        });
227        obs.record_event(&ObserverEvent::ToolCall {
228            tool: "shell".into(),
229            duration: Duration::from_millis(10),
230            success: false,
231        });
232        obs.record_event(&ObserverEvent::ChannelMessage {
233            channel: "telegram".into(),
234            direction: "outbound".into(),
235        });
236        obs.record_event(&ObserverEvent::HeartbeatTick);
237        obs.record_event(&ObserverEvent::Error {
238            component: "provider".into(),
239            message: "timeout".into(),
240        });
241    }
242
243    #[test]
244    fn log_observer_all_metrics_no_panic() {
245        let obs = LogObserver::new();
246        obs.record_metric(&ObserverMetric::RequestLatency(Duration::from_secs(2)));
247        obs.record_metric(&ObserverMetric::TokensUsed(0));
248        obs.record_metric(&ObserverMetric::TokensUsed(u64::MAX));
249        obs.record_metric(&ObserverMetric::ActiveSessions(1));
250        obs.record_metric(&ObserverMetric::QueueDepth(999));
251    }
252
253    #[test]
254    fn log_observer_hand_events_no_panic() {
255        let obs = LogObserver::new();
256        obs.record_event(&ObserverEvent::HandStarted {
257            hand_name: "review".into(),
258        });
259        obs.record_event(&ObserverEvent::HandCompleted {
260            hand_name: "review".into(),
261            duration_ms: 1500,
262            findings_count: 3,
263        });
264        obs.record_event(&ObserverEvent::HandFailed {
265            hand_name: "review".into(),
266            error: "timeout".into(),
267            duration_ms: 5000,
268        });
269    }
270
271    #[test]
272    fn log_observer_hand_metrics_no_panic() {
273        let obs = LogObserver::new();
274        obs.record_metric(&ObserverMetric::HandRunDuration {
275            hand_name: "review".into(),
276            duration: Duration::from_millis(1500),
277        });
278        obs.record_metric(&ObserverMetric::HandFindingsCount {
279            hand_name: "review".into(),
280            count: 5,
281        });
282        obs.record_metric(&ObserverMetric::HandSuccessRate {
283            hand_name: "review".into(),
284            success: true,
285        });
286    }
287}