| 1 | //! `codewhale metrics` — reads the audit log and session/task stores and prints |
| 2 | //! a human-readable usage rollup. |
| 3 | //! |
| 4 | //! Data sources: |
| 5 | //! - `~/.deepseek/audit.log` — one JSON line per event (approvals, credentials) |
| 6 | //! - `~/.deepseek/sessions/` — saved session JSON files (tool call history) |
| 7 | //! - `~/.deepseek/tasks/runtime/events/` — runtime thread JSONL event streams |
| 8 | |
| 9 | use std::collections::HashMap; |
| 10 | use std::path::{Path, PathBuf}; |
| 11 | |
| 12 | use anyhow::Result; |
| 13 | use chrono::{DateTime, Duration, Utc}; |
| 14 | use serde_json::Value; |
| 15 | |
| 16 | // ────────────────────────────────────────────────────────────────────────────── |
| 17 | // Public entry-point |
| 18 | // ────────────────────────────────────────────────────────────────────────────── |
| 19 | |
| 20 | /// Arguments accepted by `codewhale metrics`. |
| 21 | #[derive(Debug, Default)] |
| 22 | pub struct MetricsArgs { |
| 23 | /// Emit machine-readable JSON instead of human text. |
| 24 | pub json: bool, |
| 25 | /// Restrict to events newer than this cutoff (inclusive). |
| 26 | pub since: Option<DateTime<Utc>>, |
| 27 | } |
| 28 | |
| 29 | pub fn run(args: MetricsArgs) -> Result<()> { |
| 30 | let base = deepseek_home(); |
| 31 | |
| 32 | // Collect data from every source; treat missing files as empty. |
| 33 | let mut rollup = Rollup::default(); |
| 34 | read_audit_log(&base.join("audit.log"), args.since, &mut rollup); |
| 35 | read_session_files(&base.join("sessions"), args.since, &mut rollup); |
| 36 | read_runtime_events( |
| 37 | &base.join("tasks").join("runtime").join("events"), |
| 38 | args.since, |
| 39 | &mut rollup, |
| 40 | ); |
| 41 | |
| 42 | if args.json { |
| 43 | print_json(&rollup)?; |
| 44 | } else { |
| 45 | print_human(&rollup); |
| 46 | } |
| 47 | |
| 48 | Ok(()) |
| 49 | } |
| 50 | |
| 51 | // ────────────────────────────────────────────────────────────────────────────── |
| 52 | // Duration-string parser ("7d", "24h", "30m", "2h", "now-2h", "2h30m") |
| 53 | // ────────────────────────────────────────────────────────────────────────────── |
| 54 | |
| 55 | /// Parse a loose humantime-ish duration string into an absolute `DateTime<Utc>` |
| 56 | /// cutoff (i.e. `Utc::now() - duration`). |
| 57 | /// |
| 58 | /// Accepted forms: |
| 59 | /// - `7d` / `24h` / `30m` / `90s` |
| 60 | /// - `2h30m`, `1d12h` |
| 61 | /// - `now-2h` (leading `now-` is stripped before parsing) |
| 62 | pub fn parse_since(s: &str) -> Result<DateTime<Utc>> { |
| 63 | let s = s.trim().to_ascii_lowercase(); |
| 64 | let s = s.strip_prefix("now-").unwrap_or(&s); |
| 65 | let secs = parse_duration_secs(s)?; |
| 66 | Ok(Utc::now() - Duration::seconds(secs)) |
| 67 | } |
| 68 | |
| 69 | fn parse_duration_secs(s: &str) -> Result<i64> { |
| 70 | // Walk through the string accumulating numbers and consuming unit suffixes. |
| 71 | let mut total: i64 = 0; |
| 72 | let mut num_buf = String::new(); |
| 73 | |
| 74 | for ch in s.chars() { |
| 75 | match ch { |
| 76 | '0'..='9' => num_buf.push(ch), |
| 77 | 'd' | 'h' | 'm' | 's' => { |
| 78 | let n: i64 = num_buf |
| 79 | .parse() |
| 80 | .map_err(|_| anyhow::anyhow!("invalid duration component: {num_buf:?}"))?; |
| 81 | num_buf.clear(); |
| 82 | let factor = match ch { |
| 83 | 'd' => 86_400, |
| 84 | 'h' => 3_600, |
| 85 | 'm' => 60, |
| 86 | 's' => 1, |
| 87 | _ => unreachable!(), |
| 88 | }; |
| 89 | total += n * factor; |
| 90 | } |
| 91 | _ => anyhow::bail!("unrecognised character {ch:?} in duration {s:?}"), |
| 92 | } |
| 93 | } |
| 94 | |
| 95 | if !num_buf.is_empty() { |
| 96 | // Trailing bare number — treat as seconds. |
| 97 | let n: i64 = num_buf.parse()?; |
| 98 | total += n; |
| 99 | } |
| 100 | |
| 101 | if total == 0 { |
| 102 | anyhow::bail!("duration {s:?} resolved to zero seconds"); |
| 103 | } |
| 104 | |
| 105 | Ok(total) |
| 106 | } |
| 107 | |
| 108 | // ────────────────────────────────────────────────────────────────────────────── |
| 109 | // Rollup data model |
| 110 | // ────────────────────────────────────────────────────────────────────────────── |
| 111 | |
| 112 | /// Per-tool aggregated counters. |
| 113 | #[derive(Debug, Default, serde::Serialize)] |
| 114 | pub struct ToolStats { |
| 115 | pub calls: u64, |
| 116 | /// Calls that were auto-approved (no prompt required). |
| 117 | pub auto_approved: u64, |
| 118 | /// Calls that required a manual prompt. |
| 119 | pub prompted: u64, |
| 120 | /// Total elapsed ms (from events that carry this field). |
| 121 | pub total_elapsed_ms: u64, |
| 122 | /// Number of elapsed_ms samples included in `total_elapsed_ms`. |
| 123 | pub elapsed_samples: u64, |
| 124 | /// Successful calls (where we have result data). |
| 125 | pub successes: u64, |
| 126 | /// Failed calls. |
| 127 | pub failures: u64, |
| 128 | } |
| 129 | |
| 130 | impl ToolStats { |
| 131 | fn success_rate_pct(&self) -> Option<f64> { |
| 132 | let judged = self.successes + self.failures; |
| 133 | if judged == 0 { |
| 134 | None |
| 135 | } else { |
| 136 | Some(self.successes as f64 / judged as f64 * 100.0) |
| 137 | } |
| 138 | } |
| 139 | |
| 140 | fn avg_elapsed_ms(&self) -> Option<u64> { |
| 141 | self.total_elapsed_ms.checked_div(self.elapsed_samples) |
| 142 | } |
| 143 | } |
| 144 | |
| 145 | /// Compaction event stats. |
| 146 | #[derive(Debug, Default, serde::Serialize)] |
| 147 | pub struct CompactionStats { |
| 148 | pub events: u64, |
| 149 | /// Sum of `reduction_ratio` from events that carry it (0.0–1.0 each). |
| 150 | pub ratio_sum: f64, |
| 151 | pub ratio_samples: u64, |
| 152 | } |
| 153 | |
| 154 | impl CompactionStats { |
| 155 | fn avg_reduction_pct(&self) -> Option<f64> { |
| 156 | if self.ratio_samples == 0 { |
| 157 | None |
| 158 | } else { |
| 159 | Some(self.ratio_sum / self.ratio_samples as f64 * 100.0) |
| 160 | } |
| 161 | } |
| 162 | } |
| 163 | |
| 164 | /// Sub-agent spawn stats. |
| 165 | #[derive(Debug, Default, serde::Serialize)] |
| 166 | pub struct AgentStats { |
| 167 | pub spawns: u64, |
| 168 | pub successes: u64, |
| 169 | pub failures: u64, |
| 170 | } |
| 171 | |
| 172 | impl AgentStats { |
| 173 | fn success_rate_pct(&self) -> Option<f64> { |
| 174 | let judged = self.successes + self.failures; |
| 175 | if judged == 0 { |
| 176 | None |
| 177 | } else { |
| 178 | Some(self.successes as f64 / judged as f64 * 100.0) |
| 179 | } |
| 180 | } |
| 181 | } |
| 182 | |
| 183 | /// Capacity-controller / rate-limit intervention stats. |
| 184 | #[derive(Debug, Default, serde::Serialize)] |
| 185 | pub struct CapacityStats { |
| 186 | pub total: u64, |
| 187 | pub by_category: HashMap<String, u64>, |
| 188 | } |
| 189 | |
| 190 | /// Credential / session event stats (from audit log). |
| 191 | #[derive(Debug, Default, serde::Serialize)] |
| 192 | pub struct CredentialStats { |
| 193 | pub saves: u64, |
| 194 | pub clears: u64, |
| 195 | } |
| 196 | |
| 197 | /// Top-level rollup. |
| 198 | #[derive(Debug, Default, serde::Serialize)] |
| 199 | pub struct Rollup { |
| 200 | /// UTC timestamp of the earliest event we've seen. |
| 201 | pub earliest_ts: Option<DateTime<Utc>>, |
| 202 | /// UTC timestamp of the latest event we've seen. |
| 203 | pub latest_ts: Option<DateTime<Utc>>, |
| 204 | /// Per-tool stats keyed by tool name. |
| 205 | pub tools: HashMap<String, ToolStats>, |
| 206 | pub compaction: CompactionStats, |
| 207 | pub agents: AgentStats, |
| 208 | pub capacity: CapacityStats, |
| 209 | pub credentials: CredentialStats, |
| 210 | /// Total lines read across all sources. |
| 211 | pub total_lines: u64, |
| 212 | /// Lines successfully parsed. |
| 213 | pub parsed_lines: u64, |
| 214 | } |
| 215 | |
| 216 | impl Rollup { |
| 217 | fn touch_ts(&mut self, ts: &DateTime<Utc>) { |
| 218 | match self.earliest_ts { |
| 219 | None => self.earliest_ts = Some(*ts), |
| 220 | Some(ref cur) if ts < cur => self.earliest_ts = Some(*ts), |
| 221 | _ => {} |
| 222 | } |
| 223 | match self.latest_ts { |
| 224 | None => self.latest_ts = Some(*ts), |
| 225 | Some(ref cur) if ts > cur => self.latest_ts = Some(*ts), |
| 226 | _ => {} |
| 227 | } |
| 228 | } |
| 229 | |
| 230 | fn tool_mut(&mut self, name: &str) -> &mut ToolStats { |
| 231 | self.tools.entry(name.to_string()).or_default() |
| 232 | } |
| 233 | |
| 234 | fn total_tool_calls(&self) -> u64 { |
| 235 | self.tools.values().map(|t| t.calls).sum() |
| 236 | } |
| 237 | } |
| 238 | |
| 239 | // ────────────────────────────────────────────────────────────────────────────── |
| 240 | // Source readers |
| 241 | // ────────────────────────────────────────────────────────────────────────────── |
| 242 | |
| 243 | /// Read one-JSON-line-per-event audit log. |
| 244 | fn read_audit_log(path: &Path, since: Option<DateTime<Utc>>, rollup: &mut Rollup) { |
| 245 | let content = match std::fs::read_to_string(path) { |
| 246 | Ok(c) => c, |
| 247 | Err(e) if e.kind() == std::io::ErrorKind::NotFound => return, |
| 248 | Err(e) => { |
| 249 | tracing::trace!( |
| 250 | "metrics: could not read audit log {}: {}", |
| 251 | path.display(), |
| 252 | e |
| 253 | ); |
| 254 | return; |
| 255 | } |
| 256 | }; |
| 257 | |
| 258 | for raw_line in content.lines() { |
| 259 | rollup.total_lines += 1; |
| 260 | let line = raw_line.trim(); |
| 261 | if line.is_empty() { |
| 262 | continue; |
| 263 | } |
| 264 | |
| 265 | let v: Value = match serde_json::from_str(line) { |
| 266 | Ok(v) => v, |
| 267 | Err(e) => { |
| 268 | tracing::trace!("metrics: skipping malformed audit line: {e}"); |
| 269 | continue; |
| 270 | } |
| 271 | }; |
| 272 | |
| 273 | // Parse timestamp — field is "ts" in audit log. |
| 274 | let ts = parse_ts_field(&v, "ts"); |
| 275 | |
| 276 | if let Some(cutoff) = since { |
| 277 | match ts { |
| 278 | Some(t) if t < cutoff => continue, |
| 279 | _ => {} |
| 280 | } |
| 281 | } |
| 282 | |
| 283 | rollup.parsed_lines += 1; |
| 284 | if let Some(t) = &ts { |
| 285 | rollup.touch_ts(t); |
| 286 | } |
| 287 | |
| 288 | let event = v.get("event").and_then(|e| e.as_str()).unwrap_or(""); |
| 289 | |
| 290 | match event { |
| 291 | "tool.approval.auto_approve" => { |
| 292 | let tool_name = v |
| 293 | .pointer("/details/tool_name") |
| 294 | .and_then(|t| t.as_str()) |
| 295 | .unwrap_or("unknown"); |
| 296 | let stats = rollup.tool_mut(tool_name); |
| 297 | stats.calls += 1; |
| 298 | stats.auto_approved += 1; |
| 299 | } |
| 300 | "tool.approval.prompted" => { |
| 301 | let tool_name = v |
| 302 | .pointer("/details/tool_name") |
| 303 | .and_then(|t| t.as_str()) |
| 304 | .unwrap_or("unknown"); |
| 305 | let stats = rollup.tool_mut(tool_name); |
| 306 | stats.calls += 1; |
| 307 | stats.prompted += 1; |
| 308 | } |
| 309 | "tool.completed" | "tool.result" => { |
| 310 | let tool_name = v |
| 311 | .pointer("/details/tool_name") |
| 312 | .or_else(|| v.pointer("/payload/tool_name")) |
| 313 | .and_then(|t| t.as_str()) |
| 314 | .unwrap_or("unknown"); |
| 315 | let stats = rollup.tool_mut(tool_name); |
| 316 | stats.calls += 1; |
| 317 | |
| 318 | // Optional elapsed_ms |
| 319 | if let Some(ms) = v |
| 320 | .pointer("/details/elapsed_ms") |
| 321 | .or_else(|| v.pointer("/payload/elapsed_ms")) |
| 322 | .and_then(|v| v.as_u64()) |
| 323 | { |
| 324 | stats.total_elapsed_ms += ms; |
| 325 | stats.elapsed_samples += 1; |
| 326 | } |
| 327 | |
| 328 | // Success / failure |
| 329 | let success = v |
| 330 | .pointer("/details/success") |
| 331 | .or_else(|| v.pointer("/payload/success")) |
| 332 | .and_then(|b| b.as_bool()) |
| 333 | .unwrap_or(true); |
| 334 | if success { |
| 335 | stats.successes += 1; |
| 336 | } else { |
| 337 | stats.failures += 1; |
| 338 | } |
| 339 | } |
| 340 | "compaction.completed" | "context.compaction" => { |
| 341 | rollup.compaction.events += 1; |
| 342 | if let Some(ratio) = v |
| 343 | .pointer("/details/reduction_ratio") |
| 344 | .or_else(|| v.pointer("/payload/reduction_ratio")) |
| 345 | .and_then(|r| r.as_f64()) |
| 346 | { |
| 347 | rollup.compaction.ratio_sum += ratio; |
| 348 | rollup.compaction.ratio_samples += 1; |
| 349 | } |
| 350 | } |
| 351 | "agent.spawn" | "subagent.spawned" => { |
| 352 | rollup.agents.spawns += 1; |
| 353 | } |
| 354 | "agent.completed" | "subagent.completed" => { |
| 355 | let success = v |
| 356 | .pointer("/details/success") |
| 357 | .or_else(|| v.pointer("/payload/success")) |
| 358 | .and_then(|b| b.as_bool()) |
| 359 | .unwrap_or(true); |
| 360 | if success { |
| 361 | rollup.agents.successes += 1; |
| 362 | } else { |
| 363 | rollup.agents.failures += 1; |
| 364 | } |
| 365 | } |
| 366 | e if e.starts_with("capacity.") => { |
| 367 | rollup.capacity.total += 1; |
| 368 | let category = v |
| 369 | .pointer("/details/category") |
| 370 | .or_else(|| v.pointer("/payload/category")) |
| 371 | .and_then(|c| c.as_str()) |
| 372 | .unwrap_or(e.trim_start_matches("capacity.")); |
| 373 | *rollup |
| 374 | .capacity |
| 375 | .by_category |
| 376 | .entry(category.to_string()) |
| 377 | .or_insert(0) += 1; |
| 378 | } |
| 379 | "credential.save" => { |
| 380 | rollup.credentials.saves += 1; |
| 381 | } |
| 382 | "credential.clear" => { |
| 383 | rollup.credentials.clears += 1; |
| 384 | } |
| 385 | _ => { |
| 386 | // Unknown event — tracked in parsed_lines but otherwise ignored. |
| 387 | } |
| 388 | } |
| 389 | } |
| 390 | } |
| 391 | |
| 392 | /// Read session JSON files under `sessions/` (one per session). |
| 393 | /// These carry tool call history with optional elapsed_ms and result data. |
| 394 | fn read_session_files(sessions_dir: &Path, since: Option<DateTime<Utc>>, rollup: &mut Rollup) { |
| 395 | let rd = match std::fs::read_dir(sessions_dir) { |
| 396 | Ok(rd) => rd, |
| 397 | Err(e) if e.kind() == std::io::ErrorKind::NotFound => return, |
| 398 | Err(e) => { |
| 399 | tracing::trace!( |
| 400 | "metrics: could not list sessions dir {}: {}", |
| 401 | sessions_dir.display(), |
| 402 | e |
| 403 | ); |
| 404 | return; |
| 405 | } |
| 406 | }; |
| 407 | |
| 408 | for entry in rd.flatten() { |
| 409 | let path = entry.path(); |
| 410 | // Only look at .json files directly in sessions/; skip sub-dirs. |
| 411 | if path.is_dir() || path.extension().map(|e| e != "json").unwrap_or(true) { |
| 412 | continue; |
| 413 | } |
| 414 | read_session_file(&path, since, rollup); |
| 415 | } |
| 416 | } |
| 417 | |
| 418 | fn read_session_file(path: &Path, since: Option<DateTime<Utc>>, rollup: &mut Rollup) { |
| 419 | let content = match std::fs::read_to_string(path) { |
| 420 | Ok(c) => c, |
| 421 | Err(e) => { |
| 422 | tracing::trace!( |
| 423 | "metrics: could not read session file {}: {}", |
| 424 | path.display(), |
| 425 | e |
| 426 | ); |
| 427 | return; |
| 428 | } |
| 429 | }; |
| 430 | |
| 431 | rollup.total_lines += 1; |
| 432 | |
| 433 | let v: Value = match serde_json::from_str(&content) { |
| 434 | Ok(v) => v, |
| 435 | Err(e) => { |
| 436 | tracing::trace!( |
| 437 | "metrics: skipping malformed session file {}: {}", |
| 438 | path.display(), |
| 439 | e |
| 440 | ); |
| 441 | return; |
| 442 | } |
| 443 | }; |
| 444 | |
| 445 | rollup.parsed_lines += 1; |
| 446 | |
| 447 | // Session-level timestamp filter (check metadata.created_at or updated_at). |
| 448 | let session_ts = v |
| 449 | .pointer("/metadata/updated_at") |
| 450 | .or_else(|| v.pointer("/metadata/created_at")) |
| 451 | .and_then(|t| t.as_str()) |
| 452 | .and_then(|s| s.parse::<DateTime<Utc>>().ok()); |
| 453 | |
| 454 | if let Some(cutoff) = since |
| 455 | && let Some(ts) = &session_ts |
| 456 | && *ts < cutoff |
| 457 | { |
| 458 | return; |
| 459 | } |
| 460 | |
| 461 | if let Some(ts) = session_ts { |
| 462 | rollup.touch_ts(&ts); |
| 463 | } |
| 464 | |
| 465 | // Walk messages looking for tool_use calls with associated results. |
| 466 | let messages = match v.get("messages").and_then(|m| m.as_array()) { |
| 467 | Some(m) => m, |
| 468 | None => return, |
| 469 | }; |
| 470 | |
| 471 | // Build a map from tool_use_id → (tool_name, elapsed_ms_option, started_at_option). |
| 472 | let mut pending: HashMap<String, (String, Option<u64>)> = HashMap::new(); |
| 473 | |
| 474 | for msg in messages { |
| 475 | let role = msg.get("role").and_then(|r| r.as_str()).unwrap_or(""); |
| 476 | let content_arr = match msg.get("content").and_then(|c| c.as_array()) { |
| 477 | Some(c) => c, |
| 478 | None => continue, |
| 479 | }; |
| 480 | |
| 481 | for block in content_arr { |
| 482 | let block_type = block.get("type").and_then(|t| t.as_str()).unwrap_or(""); |
| 483 | match (role, block_type) { |
| 484 | ("assistant", "tool_use") => { |
| 485 | let id = block.get("id").and_then(|i| i.as_str()).unwrap_or(""); |
| 486 | let name = block |
| 487 | .get("name") |
| 488 | .and_then(|n| n.as_str()) |
| 489 | .unwrap_or("unknown"); |
| 490 | let elapsed_ms = block.get("elapsed_ms").and_then(|e| e.as_u64()); |
| 491 | if !id.is_empty() { |
| 492 | pending.insert(id.to_string(), (name.to_string(), elapsed_ms)); |
| 493 | } |
| 494 | } |
| 495 | ("user", "tool_result") => { |
| 496 | let id = block |
| 497 | .get("tool_use_id") |
| 498 | .and_then(|i| i.as_str()) |
| 499 | .unwrap_or(""); |
| 500 | if let Some((name, elapsed_ms)) = pending.remove(id) { |
| 501 | let stats = rollup.tool_mut(&name); |
| 502 | // Only count if not already counted via audit log (we don't de-dup, so |
| 503 | // session files may double-count approvals; that's acceptable — users who |
| 504 | // want precise counts should use --json and cross-reference). |
| 505 | stats.calls += 1; |
| 506 | if let Some(ms) = elapsed_ms { |
| 507 | stats.total_elapsed_ms += ms; |
| 508 | stats.elapsed_samples += 1; |
| 509 | } |
| 510 | // Tool result success: absence of "is_error": true |
| 511 | let is_error = block |
| 512 | .get("is_error") |
| 513 | .and_then(|e| e.as_bool()) |
| 514 | .unwrap_or(false); |
| 515 | if is_error { |
| 516 | stats.failures += 1; |
| 517 | } else { |
| 518 | stats.successes += 1; |
| 519 | } |
| 520 | } |
| 521 | } |
| 522 | _ => {} |
| 523 | } |
| 524 | } |
| 525 | } |
| 526 | |
| 527 | // Walk messages for compaction events embedded as special user messages. |
| 528 | for msg in messages { |
| 529 | if let Some(compaction) = msg |
| 530 | .get("compaction") |
| 531 | .or_else(|| msg.pointer("/metadata/compaction")) |
| 532 | { |
| 533 | rollup.compaction.events += 1; |
| 534 | if let Some(ratio) = compaction.get("reduction_ratio").and_then(|r| r.as_f64()) { |
| 535 | rollup.compaction.ratio_sum += ratio; |
| 536 | rollup.compaction.ratio_samples += 1; |
| 537 | } |
| 538 | } |
| 539 | } |
| 540 | } |
| 541 | |
| 542 | /// Read JSONL event streams from the tasks runtime events directory. |
| 543 | fn read_runtime_events(events_dir: &Path, since: Option<DateTime<Utc>>, rollup: &mut Rollup) { |
| 544 | let rd = match std::fs::read_dir(events_dir) { |
| 545 | Ok(rd) => rd, |
| 546 | Err(e) if e.kind() == std::io::ErrorKind::NotFound => return, |
| 547 | Err(e) => { |
| 548 | tracing::trace!( |
| 549 | "metrics: could not list events dir {}: {}", |
| 550 | events_dir.display(), |
| 551 | e |
| 552 | ); |
| 553 | return; |
| 554 | } |
| 555 | }; |
| 556 | |
| 557 | for entry in rd.flatten() { |
| 558 | let path = entry.path(); |
| 559 | if path.extension().map(|e| e != "jsonl").unwrap_or(true) { |
| 560 | continue; |
| 561 | } |
| 562 | read_events_jsonl(&path, since, rollup); |
| 563 | } |
| 564 | } |
| 565 | |
| 566 | fn read_events_jsonl(path: &Path, since: Option<DateTime<Utc>>, rollup: &mut Rollup) { |
| 567 | let content = match std::fs::read_to_string(path) { |
| 568 | Ok(c) => c, |
| 569 | Err(e) => { |
| 570 | tracing::trace!( |
| 571 | "metrics: could not read events file {}: {}", |
| 572 | path.display(), |
| 573 | e |
| 574 | ); |
| 575 | return; |
| 576 | } |
| 577 | }; |
| 578 | |
| 579 | for raw_line in content.lines() { |
| 580 | rollup.total_lines += 1; |
| 581 | let line = raw_line.trim(); |
| 582 | if line.is_empty() { |
| 583 | continue; |
| 584 | } |
| 585 | |
| 586 | let v: Value = match serde_json::from_str(line) { |
| 587 | Ok(v) => v, |
| 588 | Err(e) => { |
| 589 | tracing::trace!("metrics: skipping malformed event line: {e}"); |
| 590 | continue; |
| 591 | } |
| 592 | }; |
| 593 | |
| 594 | let ts = parse_ts_field(&v, "timestamp"); |
| 595 | |
| 596 | if let Some(cutoff) = since { |
| 597 | match ts { |
| 598 | Some(t) if t < cutoff => continue, |
| 599 | _ => {} |
| 600 | } |
| 601 | } |
| 602 | |
| 603 | rollup.parsed_lines += 1; |
| 604 | if let Some(t) = &ts { |
| 605 | rollup.touch_ts(t); |
| 606 | } |
| 607 | |
| 608 | let event = v.get("event").and_then(|e| e.as_str()).unwrap_or(""); |
| 609 | |
| 610 | match event { |
| 611 | "tool.started" | "tool.completed" | "tool.failed" => { |
| 612 | let tool_name = v |
| 613 | .pointer("/payload/tool_name") |
| 614 | .or_else(|| v.pointer("/payload/name")) |
| 615 | .and_then(|t| t.as_str()) |
| 616 | .unwrap_or("unknown"); |
| 617 | let stats = rollup.tool_mut(tool_name); |
| 618 | |
| 619 | if event == "tool.started" { |
| 620 | stats.calls += 1; |
| 621 | } else if event == "tool.completed" { |
| 622 | stats.successes += 1; |
| 623 | if let Some(ms) = v.pointer("/payload/elapsed_ms").and_then(|v| v.as_u64()) { |
| 624 | stats.total_elapsed_ms += ms; |
| 625 | stats.elapsed_samples += 1; |
| 626 | } |
| 627 | } else { |
| 628 | // tool.failed |
| 629 | stats.failures += 1; |
| 630 | } |
| 631 | } |
| 632 | "compaction.completed" => { |
| 633 | rollup.compaction.events += 1; |
| 634 | if let Some(ratio) = v |
| 635 | .pointer("/payload/reduction_ratio") |
| 636 | .and_then(|r| r.as_f64()) |
| 637 | { |
| 638 | rollup.compaction.ratio_sum += ratio; |
| 639 | rollup.compaction.ratio_samples += 1; |
| 640 | } |
| 641 | } |
| 642 | "agent.spawned" | "subagent.spawned" => { |
| 643 | rollup.agents.spawns += 1; |
| 644 | } |
| 645 | "agent.completed" | "subagent.completed" => { |
| 646 | let success = v |
| 647 | .pointer("/payload/success") |
| 648 | .and_then(|b| b.as_bool()) |
| 649 | .unwrap_or(true); |
| 650 | if success { |
| 651 | rollup.agents.successes += 1; |
| 652 | } else { |
| 653 | rollup.agents.failures += 1; |
| 654 | } |
| 655 | } |
| 656 | e if e.starts_with("capacity.") => { |
| 657 | rollup.capacity.total += 1; |
| 658 | let category = v |
| 659 | .pointer("/payload/category") |
| 660 | .and_then(|c| c.as_str()) |
| 661 | .unwrap_or(e.trim_start_matches("capacity.")); |
| 662 | *rollup |
| 663 | .capacity |
| 664 | .by_category |
| 665 | .entry(category.to_string()) |
| 666 | .or_insert(0) += 1; |
| 667 | } |
| 668 | _ => {} |
| 669 | } |
| 670 | } |
| 671 | } |
| 672 | |
| 673 | // ────────────────────────────────────────────────────────────────────────────── |
| 674 | // Output formatters |
| 675 | // ────────────────────────────────────────────────────────────────────────────── |
| 676 | |
| 677 | fn print_json(rollup: &Rollup) -> Result<()> { |
| 678 | println!("{}", serde_json::to_string_pretty(rollup)?); |
| 679 | Ok(()) |
| 680 | } |
| 681 | |
| 682 | fn print_human(rollup: &Rollup) { |
| 683 | // Period header |
| 684 | match (rollup.earliest_ts, rollup.latest_ts) { |
| 685 | (Some(start), Some(end)) => { |
| 686 | let days = (end - start).num_days(); |
| 687 | println!( |
| 688 | "Period: {} → {} ({} days)", |
| 689 | start.format("%Y-%m-%d"), |
| 690 | end.format("%Y-%m-%d"), |
| 691 | days |
| 692 | ); |
| 693 | } |
| 694 | (Some(start), None) | (None, Some(start)) => { |
| 695 | println!("Period: {} → (unknown)", start.format("%Y-%m-%d")); |
| 696 | } |
| 697 | (None, None) => { |
| 698 | println!("Period: (no data)"); |
| 699 | } |
| 700 | } |
| 701 | |
| 702 | // ── Tools ────────────────────────────────────────────────────────────── |
| 703 | let total_calls = rollup.total_tool_calls(); |
| 704 | if total_calls > 0 { |
| 705 | // Overall success rate from session-file data (where we have result info). |
| 706 | let total_ok: u64 = rollup.tools.values().map(|t| t.successes).sum(); |
| 707 | let total_judged: u64 = rollup |
| 708 | .tools |
| 709 | .values() |
| 710 | .map(|t| t.successes + t.failures) |
| 711 | .sum(); |
| 712 | let overall_rate = if total_judged > 0 { |
| 713 | format!( |
| 714 | "{:.1}% success", |
| 715 | total_ok as f64 / total_judged as f64 * 100.0 |
| 716 | ) |
| 717 | } else { |
| 718 | // Only approval events — show prompt breakdown. |
| 719 | let auto: u64 = rollup.tools.values().map(|t| t.auto_approved).sum(); |
| 720 | let prompted: u64 = rollup.tools.values().map(|t| t.prompted).sum(); |
| 721 | format!("{auto} auto-approved, {prompted} prompted") |
| 722 | }; |
| 723 | |
| 724 | println!( |
| 725 | "Tools: {:>6} calls ({})", |
| 726 | fmt_num(total_calls), |
| 727 | overall_rate |
| 728 | ); |
| 729 | |
| 730 | // Sort tools by call count descending, top 15. |
| 731 | let mut tools: Vec<(&String, &ToolStats)> = rollup.tools.iter().collect(); |
| 732 | tools.sort_by_key(|b| std::cmp::Reverse(b.1.calls)); |
| 733 | for (name, stats) in tools.iter().take(15) { |
| 734 | let rate_str = match stats.success_rate_pct() { |
| 735 | Some(pct) => format!("{pct:5.1}%"), |
| 736 | None => { |
| 737 | // Only approval data available — show auto/prompted breakdown. |
| 738 | let a = stats.auto_approved; |
| 739 | let p = stats.prompted; |
| 740 | if p == 0 { |
| 741 | format!("auto×{a} ") |
| 742 | } else { |
| 743 | format!("auto×{a}/prompted×{p}") |
| 744 | } |
| 745 | } |
| 746 | }; |
| 747 | let avg_str = match stats.avg_elapsed_ms() { |
| 748 | Some(ms) => format!(" avg {ms}ms"), |
| 749 | None => String::new(), |
| 750 | }; |
| 751 | println!( |
| 752 | " {name:<22} {:>6} {rate_str}{avg_str}", |
| 753 | fmt_num(stats.calls) |
| 754 | ); |
| 755 | } |
| 756 | if tools.len() > 15 { |
| 757 | println!(" … and {} more tools", tools.len() - 15); |
| 758 | } |
| 759 | } else { |
| 760 | println!("Tools: (no data)"); |
| 761 | } |
| 762 | |
| 763 | // ── Compaction ───────────────────────────────────────────────────────── |
| 764 | if rollup.compaction.events > 0 { |
| 765 | let avg_str = match rollup.compaction.avg_reduction_pct() { |
| 766 | Some(pct) => format!(", avg {pct:.0}% size reduction"), |
| 767 | None => String::new(), |
| 768 | }; |
| 769 | println!( |
| 770 | "Compaction: {} events{}", |
| 771 | fmt_num(rollup.compaction.events), |
| 772 | avg_str |
| 773 | ); |
| 774 | } else { |
| 775 | println!("Compaction: (no data)"); |
| 776 | } |
| 777 | |
| 778 | // ── Sub-agents ───────────────────────────────────────────────────────── |
| 779 | if rollup.agents.spawns > 0 { |
| 780 | let rate_str = match rollup.agents.success_rate_pct() { |
| 781 | Some(pct) => format!(", {pct:.1}% success"), |
| 782 | None => String::new(), |
| 783 | }; |
| 784 | println!( |
| 785 | "Sub-agents: {} spawns{}", |
| 786 | fmt_num(rollup.agents.spawns), |
| 787 | rate_str |
| 788 | ); |
| 789 | } else { |
| 790 | println!("Sub-agents: (no data)"); |
| 791 | } |
| 792 | |
| 793 | // ── Capacity interventions ───────────────────────────────────────────── |
| 794 | if rollup.capacity.total > 0 { |
| 795 | let cat_str: String = { |
| 796 | let mut cats: Vec<(&String, &u64)> = rollup.capacity.by_category.iter().collect(); |
| 797 | cats.sort_by(|a, b| b.1.cmp(a.1)); |
| 798 | cats.iter() |
| 799 | .map(|(k, v)| format!("{v} {k}")) |
| 800 | .collect::<Vec<_>>() |
| 801 | .join(", ") |
| 802 | }; |
| 803 | println!( |
| 804 | "Capacity interventions: {} ({})", |
| 805 | fmt_num(rollup.capacity.total), |
| 806 | cat_str |
| 807 | ); |
| 808 | } else { |
| 809 | println!("Capacity interventions: (no data)"); |
| 810 | } |
| 811 | |
| 812 | // ── Credentials ──────────────────────────────────────────────────────── |
| 813 | if rollup.credentials.saves > 0 || rollup.credentials.clears > 0 { |
| 814 | println!( |
| 815 | "Credentials: {} saves, {} clears", |
| 816 | rollup.credentials.saves, rollup.credentials.clears |
| 817 | ); |
| 818 | } |
| 819 | } |
| 820 | |
| 821 | // ────────────────────────────────────────────────────────────────────────────── |
| 822 | // Helpers |
| 823 | // ────────────────────────────────────────────────────────────────────────────── |
| 824 | |
| 825 | fn deepseek_home() -> PathBuf { |
| 826 | // This reader preserves the legacy DEEPSEEK_HOME/default-root precedence, |
| 827 | // but delegates every environment and platform-home decision to the shared |
| 828 | // runtime path authority. |
| 829 | codewhale_paths::codewhale_home_override() |
| 830 | .ok() |
| 831 | .flatten() |
| 832 | .or_else(codewhale_paths::legacy_deepseek_home_override) |
| 833 | .or_else(codewhale_paths::legacy_deepseek_home) |
| 834 | .unwrap_or_else(|| PathBuf::from(codewhale_paths::LEGACY_APP_DIR)) |
| 835 | } |
| 836 | |
| 837 | /// Parse a timestamp from a JSON value field (tries RFC3339). |
| 838 | fn parse_ts_field(v: &Value, field: &str) -> Option<DateTime<Utc>> { |
| 839 | v.get(field)?.as_str()?.parse::<DateTime<Utc>>().ok() |
| 840 | } |
| 841 | |
| 842 | /// Format a number with thousands separators. |
| 843 | fn fmt_num(n: u64) -> String { |
| 844 | let s = n.to_string(); |
| 845 | let mut result = String::with_capacity(s.len() + s.len() / 3); |
| 846 | for (i, ch) in s.chars().rev().enumerate() { |
| 847 | if i > 0 && i % 3 == 0 { |
| 848 | result.push(','); |
| 849 | } |
| 850 | result.push(ch); |
| 851 | } |
| 852 | result.chars().rev().collect() |
| 853 | } |
| 854 | |
| 855 | // ────────────────────────────────────────────────────────────────────────────── |
| 856 | // Tests |
| 857 | // ────────────────────────────────────────────────────────────────────────────── |
| 858 | |
| 859 | #[cfg(test)] |
| 860 | mod tests { |
| 861 | use super::*; |
| 862 | |
| 863 | // ── Duration parser ── |
| 864 | |
| 865 | #[test] |
| 866 | fn parse_since_7d() { |
| 867 | let cutoff = parse_since("7d").unwrap(); |
| 868 | let expected = Utc::now() - Duration::days(7); |
| 869 | // Allow ±2s for test execution time. |
| 870 | assert!((cutoff - expected).num_seconds().abs() < 2); |
| 871 | } |
| 872 | |
| 873 | #[test] |
| 874 | fn parse_since_24h() { |
| 875 | let cutoff = parse_since("24h").unwrap(); |
| 876 | let expected = Utc::now() - Duration::hours(24); |
| 877 | assert!((cutoff - expected).num_seconds().abs() < 2); |
| 878 | } |
| 879 | |
| 880 | #[test] |
| 881 | fn parse_since_30m() { |
| 882 | let cutoff = parse_since("30m").unwrap(); |
| 883 | let expected = Utc::now() - Duration::minutes(30); |
| 884 | assert!((cutoff - expected).num_seconds().abs() < 2); |
| 885 | } |
| 886 | |
| 887 | #[test] |
| 888 | fn parse_since_now_prefix() { |
| 889 | // "now-2h" should strip "now-" and parse "2h". |
| 890 | let cutoff = parse_since("now-2h").unwrap(); |
| 891 | let expected = Utc::now() - Duration::hours(2); |
| 892 | assert!((cutoff - expected).num_seconds().abs() < 2); |
| 893 | } |
| 894 | |
| 895 | #[test] |
| 896 | fn parse_since_compound() { |
| 897 | let cutoff = parse_since("2h30m").unwrap(); |
| 898 | let expected = Utc::now() - Duration::seconds(2 * 3600 + 30 * 60); |
| 899 | assert!((cutoff - expected).num_seconds().abs() < 2); |
| 900 | } |
| 901 | |
| 902 | #[test] |
| 903 | fn parse_since_compound_days_hours() { |
| 904 | let cutoff = parse_since("1d12h").unwrap(); |
| 905 | let expected = Utc::now() - Duration::seconds(36 * 3600); |
| 906 | assert!((cutoff - expected).num_seconds().abs() < 2); |
| 907 | } |
| 908 | |
| 909 | #[test] |
| 910 | fn parse_since_error_on_invalid() { |
| 911 | assert!(parse_since("xyz").is_err()); |
| 912 | assert!(parse_since("").is_err()); |
| 913 | } |
| 914 | |
| 915 | // ── fmt_num ── |
| 916 | |
| 917 | #[test] |
| 918 | fn fmt_num_zero() { |
| 919 | assert_eq!(fmt_num(0), "0"); |
| 920 | } |
| 921 | |
| 922 | #[test] |
| 923 | fn fmt_num_thousands() { |
| 924 | assert_eq!(fmt_num(1_000), "1,000"); |
| 925 | assert_eq!(fmt_num(12_453), "12,453"); |
| 926 | assert_eq!(fmt_num(1_000_000), "1,000,000"); |
| 927 | } |
| 928 | |
| 929 | // ── Rollup from audit log ── |
| 930 | |
| 931 | fn make_audit_line(event: &str, tool: &str, ts: &str) -> String { |
| 932 | format!( |
| 933 | r#"{{"details":{{"mode":"YOLO","session_id":null,"tool_name":"{tool}"}},"event":"{event}","ts":"{ts}"}}"# |
| 934 | ) |
| 935 | } |
| 936 | |
| 937 | #[test] |
| 938 | fn audit_log_empty_file() { |
| 939 | let mut rollup = Rollup::default(); |
| 940 | // Non-existent path — should not panic, rollup stays empty. |
| 941 | read_audit_log(Path::new("/nonexistent/audit.log"), None, &mut rollup); |
| 942 | assert_eq!(rollup.total_lines, 0); |
| 943 | } |
| 944 | |
| 945 | #[test] |
| 946 | fn audit_log_parses_auto_approve() { |
| 947 | use std::io::Write; |
| 948 | let mut tmp = tempfile::NamedTempFile::new().unwrap(); |
| 949 | let line1 = make_audit_line( |
| 950 | "tool.approval.auto_approve", |
| 951 | "exec_shell", |
| 952 | "2026-04-01T10:00:00+00:00", |
| 953 | ); |
| 954 | let line2 = make_audit_line( |
| 955 | "tool.approval.auto_approve", |
| 956 | "read_file", |
| 957 | "2026-04-02T10:00:00+00:00", |
| 958 | ); |
| 959 | writeln!(tmp, "{line1}").unwrap(); |
| 960 | writeln!(tmp, "{line2}").unwrap(); |
| 961 | |
| 962 | let mut rollup = Rollup::default(); |
| 963 | read_audit_log(tmp.path(), None, &mut rollup); |
| 964 | |
| 965 | assert_eq!(rollup.parsed_lines, 2); |
| 966 | assert_eq!(rollup.tools["exec_shell"].calls, 1); |
| 967 | assert_eq!(rollup.tools["exec_shell"].auto_approved, 1); |
| 968 | assert_eq!(rollup.tools["read_file"].calls, 1); |
| 969 | } |
| 970 | |
| 971 | #[test] |
| 972 | fn audit_log_skips_malformed_lines() { |
| 973 | use std::io::Write; |
| 974 | let mut tmp = tempfile::NamedTempFile::new().unwrap(); |
| 975 | writeln!(tmp, "not json at all").unwrap(); |
| 976 | writeln!( |
| 977 | tmp, |
| 978 | r#"{{"event":"credential.save","ts":"2026-04-01T10:00:00+00:00"}}"# |
| 979 | ) |
| 980 | .unwrap(); |
| 981 | |
| 982 | let mut rollup = Rollup::default(); |
| 983 | read_audit_log(tmp.path(), None, &mut rollup); |
| 984 | |
| 985 | // 2 lines total, 1 malformed skipped, 1 parsed. |
| 986 | assert_eq!(rollup.total_lines, 2); |
| 987 | assert_eq!(rollup.parsed_lines, 1); |
| 988 | assert_eq!(rollup.credentials.saves, 1); |
| 989 | } |
| 990 | |
| 991 | #[test] |
| 992 | fn audit_log_since_filter() { |
| 993 | use std::io::Write; |
| 994 | let mut tmp = tempfile::NamedTempFile::new().unwrap(); |
| 995 | let line_old = make_audit_line( |
| 996 | "tool.approval.auto_approve", |
| 997 | "exec_shell", |
| 998 | "2025-01-01T00:00:00+00:00", |
| 999 | ); |
| 1000 | let line_new = make_audit_line( |
| 1001 | "tool.approval.auto_approve", |
| 1002 | "read_file", |
| 1003 | "2026-04-01T00:00:00+00:00", |
| 1004 | ); |
| 1005 | writeln!(tmp, "{line_old}").unwrap(); |
| 1006 | writeln!(tmp, "{line_new}").unwrap(); |
| 1007 | |
| 1008 | let cutoff: DateTime<Utc> = "2026-01-01T00:00:00Z".parse().unwrap(); |
| 1009 | let mut rollup = Rollup::default(); |
| 1010 | read_audit_log(tmp.path(), Some(cutoff), &mut rollup); |
| 1011 | |
| 1012 | // Only the newer line should be counted. |
| 1013 | assert_eq!(rollup.parsed_lines, 1); |
| 1014 | assert!(!rollup.tools.contains_key("exec_shell")); |
| 1015 | assert_eq!(rollup.tools["read_file"].calls, 1); |
| 1016 | } |
| 1017 | |
| 1018 | #[test] |
| 1019 | fn total_tool_calls_sums_across_tools() { |
| 1020 | let mut rollup = Rollup::default(); |
| 1021 | rollup.tool_mut("read_file").calls = 4_012; |
| 1022 | rollup.tool_mut("exec_shell").calls = 1_118; |
| 1023 | assert_eq!(rollup.total_tool_calls(), 5_130); |
| 1024 | } |
| 1025 | } |
| 1026 |