Skip to main content

lean_ctx/tools/
server_metrics.rs

1use std::sync::atomic::Ordering;
2
3use super::server::{CepComputedStats, CrpMode, LeanCtxServer, ToolCallRecord};
4use super::startup::auto_consolidate_knowledge;
5use super::{ctx_compress, ctx_share};
6
7impl LeanCtxServer {
8    /// Records a tool call's token savings without timing information.
9    pub async fn record_call(
10        &self,
11        tool: &str,
12        original: usize,
13        saved: usize,
14        mode: Option<String>,
15    ) {
16        self.record_call_with_timing(tool, original, saved, mode, 0)
17            .await;
18    }
19
20    /// Records a tool call like `record_call`, but includes an optional file path for observability.
21    pub async fn record_call_with_path(
22        &self,
23        tool: &str,
24        original: usize,
25        saved: usize,
26        mode: Option<String>,
27        path: Option<&str>,
28    ) {
29        self.record_call_with_timing_inner(tool, original, saved, mode, 0, path)
30            .await;
31    }
32
33    /// Records a tool call's token savings, duration, and emits events and stats.
34    pub async fn record_call_with_timing(
35        &self,
36        tool: &str,
37        original: usize,
38        saved: usize,
39        mode: Option<String>,
40        duration_ms: u64,
41    ) {
42        self.record_call_with_timing_inner(tool, original, saved, mode, duration_ms, None)
43            .await;
44    }
45
46    async fn record_call_with_timing_inner(
47        &self,
48        tool: &str,
49        original: usize,
50        saved: usize,
51        mode: Option<String>,
52        duration_ms: u64,
53        path: Option<&str>,
54    ) {
55        let ts = chrono::Local::now().format("%Y-%m-%d %H:%M:%S").to_string();
56        let mut calls = self.tool_calls.write().await;
57        calls.push(ToolCallRecord {
58            tool: tool.to_string(),
59            original_tokens: original,
60            saved_tokens: saved,
61            mode: mode.clone(),
62            duration_ms,
63            timestamp: ts.clone(),
64        });
65
66        const MAX_TOOL_CALL_RECORDS: usize = 500;
67        if calls.len() > MAX_TOOL_CALL_RECORDS {
68            let excess = calls.len() - MAX_TOOL_CALL_RECORDS;
69            calls.drain(..excess);
70        }
71
72        if duration_ms > 0 {
73            Self::append_tool_call_log(tool, duration_ms, original, saved, mode.as_deref(), &ts);
74        }
75
76        crate::core::events::emit_tool_call(
77            tool,
78            original as u64,
79            saved as u64,
80            mode.clone(),
81            duration_ms,
82            path.map(ToString::to_string),
83        );
84
85        let output_tokens = original.saturating_sub(saved);
86        crate::core::stats::record(tool, original, output_tokens);
87        // Shell output compression is measured (observed bytes in vs out), so it
88        // belongs in the verified ledger. Reads are ledgered via the heatmap
89        // chokepoint and ctx_search ledgers itself — only shell is added here
90        // to avoid double counting.
91        if tool == "ctx_shell" {
92            crate::core::savings_ledger::record_tool_event("ctx_shell", original, saved);
93        }
94
95        // MCP shell savings are measured (raw vs compressed output), so they are
96        // ledger-grade (GL #479 D2). ctx_search is intentionally NOT recorded
97        // here: its `original` carries the 2.5x counterfactual estimate — the
98        // search tool itself appends a raw-baseline ledger event instead.
99        if tool == "ctx_shell" {
100            crate::core::savings_ledger::record_tool_event(tool, original, output_tokens);
101        }
102
103        let mut session = self.session.write().await;
104        session.record_tool_call(saved as u64, original as u64);
105        if tool == "ctx_shell" {
106            session.record_command();
107        }
108        let pending_save = if session.should_save() {
109            session.prepare_save().ok()
110        } else {
111            None
112        };
113        drop(calls);
114        drop(session);
115
116        if let Some(prepared) = pending_save {
117            tokio::task::spawn_blocking(move || {
118                let _ = prepared.write_to_disk();
119            });
120        }
121
122        self.write_mcp_live_stats().await;
123    }
124
125    /// Increments the call counter and returns true if a checkpoint is due.
126    pub fn increment_and_check(&self) -> bool {
127        let count = self.call_count.fetch_add(1, Ordering::Relaxed) + 1;
128        let interval = Self::checkpoint_interval_effective();
129        interval > 0 && count.is_multiple_of(interval)
130    }
131
132    /// Generates a compressed context checkpoint with session state and multi-agent sync.
133    pub async fn auto_checkpoint(&self) -> Option<String> {
134        let cache = self.cache.read().await;
135        if cache.get_all_entries().is_empty() {
136            return None;
137        }
138        let complexity = crate::core::adaptive::classify_from_context(&cache);
139        let checkpoint = ctx_compress::handle(&cache, false, CrpMode::effective());
140        drop(cache);
141
142        let mut session = self.session.write().await;
143        let _ = session.save();
144        let session_summary = session.format_compact();
145        let has_insights = !session.findings.is_empty() || !session.decisions.is_empty();
146        let project_root = session.project_root.clone();
147        // Snapshot the session under the lock; persist the summary off the hot path.
148        let summary_candidate = crate::core::session_summary::build_candidate(&session);
149        drop(session);
150
151        if has_insights {
152            if let Some(ref root) = project_root {
153                let root = root.clone();
154                std::thread::spawn(move || {
155                    auto_consolidate_knowledge(&root);
156                });
157            }
158        }
159
160        // Periodically record a recallable AI session summary (#292), off-thread.
161        if let Some(ref root) = project_root {
162            let root = root.clone();
163            std::thread::spawn(move || {
164                let _ =
165                    crate::core::session_summary::maybe_record_periodic(&root, summary_candidate);
166            });
167        }
168
169        let multi_agent_block = self
170            .auto_multi_agent_checkpoint(project_root.as_ref())
171            .await;
172
173        self.record_call("ctx_compress", 0, 0, Some("auto".to_string()))
174            .await;
175
176        self.record_cep_snapshot().await;
177
178        if !crate::core::protocol::meta_visible() {
179            return None;
180        }
181
182        let doc_reminder = {
183            let session = self.session.read().await;
184            let calls = self.tool_calls.read().await;
185            Self::activity_nudge(&session, &calls)
186        };
187
188        Some(format!(
189            "{checkpoint}\n\n--- SESSION STATE ---\n{session_summary}\n\n{}{multi_agent_block}{doc_reminder}",
190            complexity.instruction_suffix()
191        ))
192    }
193
194    async fn auto_multi_agent_checkpoint(&self, project_root: Option<&String>) -> String {
195        let Some(root) = project_root else {
196            return String::new();
197        };
198
199        let registry = crate::core::agents::AgentRegistry::load_or_create();
200        let active = registry.list_active(Some(root));
201        if active.len() <= 1 {
202            return String::new();
203        }
204
205        let agent_id = self.agent_id.read().await;
206        let my_id = match agent_id.as_deref() {
207            Some(id) => id.to_string(),
208            None => return String::new(),
209        };
210        drop(agent_id);
211
212        let cache = self.cache.read().await;
213        let entries = cache.get_all_entries();
214        if !entries.is_empty() {
215            let mut by_access: Vec<_> = entries.iter().collect();
216            by_access.sort_by_key(|x| std::cmp::Reverse(x.1.read_count()));
217            let top_paths: Vec<&str> = by_access
218                .iter()
219                .take(5)
220                .map(|(key, _)| key.as_str())
221                .collect();
222            let paths_csv = top_paths.join(",");
223
224            let _ = ctx_share::handle(
225                "push",
226                Some(&my_id),
227                None,
228                Some(&paths_csv),
229                None,
230                &cache,
231                root,
232            );
233        }
234        drop(cache);
235
236        let pending_count = registry
237            .scratchpad
238            .iter()
239            .filter(|e| !e.read_by.contains(&my_id) && e.from_agent != my_id)
240            .count();
241
242        let shared_dir = crate::core::data_dir::lean_ctx_data_dir()
243            .unwrap_or_default()
244            .join("agents")
245            .join("shared");
246        let shared_count = if shared_dir.exists() {
247            std::fs::read_dir(&shared_dir).map_or(0, std::iter::Iterator::count)
248        } else {
249            0
250        };
251
252        let agent_names: Vec<String> = active
253            .iter()
254            .map(|a| {
255                let role = a.role.as_deref().unwrap_or(&a.agent_type);
256                format!("{role}({})", &a.agent_id[..8.min(a.agent_id.len())])
257            })
258            .collect();
259
260        format!(
261            "\n\n--- MULTI-AGENT SYNC ---\nAgents: {} | Pending msgs: {} | Shared contexts: {}\nAuto-shared top-5 cached files.\n--- END SYNC ---",
262            agent_names.join(", "),
263            pending_count,
264            shared_count,
265        )
266    }
267
268    /// Appends a tool call entry to the rotating `tool-calls.log` file.
269    pub fn append_tool_call_log(
270        tool: &str,
271        duration_ms: u64,
272        original: usize,
273        saved: usize,
274        mode: Option<&str>,
275        timestamp: &str,
276    ) {
277        const MAX_LOG_LINES: usize = 50;
278        if let Ok(dir) = crate::core::paths::state_dir() {
279            let log_path = dir.join("tool-calls.log");
280            let mode_str = mode.unwrap_or("-");
281            let slow = if duration_ms > 5000 { " **SLOW**" } else { "" };
282            let line = format!(
283                "{timestamp}\t{tool}\t{duration_ms}ms\torig={original}\tsaved={saved}\tmode={mode_str}{slow}\n"
284            );
285
286            let mut lines: Vec<String> = std::fs::read_to_string(&log_path)
287                .unwrap_or_default()
288                .lines()
289                .map(std::string::ToString::to_string)
290                .collect();
291
292            lines.push(line.trim_end().to_string());
293            if lines.len() > MAX_LOG_LINES {
294                lines.drain(0..lines.len() - MAX_LOG_LINES);
295            }
296
297            let _ = std::fs::write(&log_path, lines.join("\n") + "\n");
298        }
299    }
300
301    fn compute_cep_stats(
302        calls: &[ToolCallRecord],
303        stats: &crate::core::cache::CacheStats,
304        complexity: &crate::core::adaptive::TaskComplexity,
305    ) -> CepComputedStats {
306        let total_original: u64 = calls.iter().map(|c| c.original_tokens as u64).sum();
307        let total_saved: u64 = calls.iter().map(|c| c.saved_tokens as u64).sum();
308        let total_compressed = total_original.saturating_sub(total_saved);
309        let compression_rate = if total_original > 0 {
310            total_saved as f64 / total_original as f64
311        } else {
312            0.0
313        };
314
315        let modes_used: std::collections::HashSet<&str> =
316            calls.iter().filter_map(|c| c.mode.as_deref()).collect();
317        let mode_diversity = (modes_used.len() as f64 / 10.0).min(1.0);
318        let cache_util = stats.hit_rate() / 100.0;
319        // Output efficiency (#501): 1 - avg echo ratio. An agent that keeps
320        // re-quoting delivered content burns the input savings on output.
321        let output_efficiency = 1.0 - crate::core::output_echo::current_avg_ratio();
322        let cep_score = cache_util * 0.25
323            + mode_diversity * 0.15
324            + compression_rate * 0.45
325            + output_efficiency * 0.15;
326
327        let mut mode_counts: std::collections::HashMap<String, u64> =
328            std::collections::HashMap::new();
329        for call in calls {
330            if let Some(ref mode) = call.mode {
331                *mode_counts.entry(mode.clone()).or_insert(0) += 1;
332            }
333        }
334
335        CepComputedStats {
336            cep_score: (cep_score * 100.0).round() as u32,
337            cache_util: (cache_util * 100.0).round() as u32,
338            mode_diversity: (mode_diversity * 100.0).round() as u32,
339            compression_rate: (compression_rate * 100.0).round() as u32,
340            total_original,
341            total_compressed,
342            total_saved,
343            mode_counts,
344            complexity: format!("{complexity:?}"),
345            cache_hits: stats.cache_hits(),
346            total_reads: stats.total_reads(),
347            tool_call_count: calls.len() as u64,
348        }
349    }
350
351    async fn write_mcp_live_stats(&self) {
352        let count = self.call_count.load(Ordering::Relaxed);
353        if count > 1 && !count.is_multiple_of(5) {
354            return;
355        }
356
357        let cache = self.cache.read().await;
358        let calls = self.tool_calls.read().await;
359        let stats = cache.get_stats();
360        let complexity = crate::core::adaptive::classify_from_context(&cache);
361
362        let cs = Self::compute_cep_stats(&calls, stats, &complexity);
363        let started_at = calls
364            .first()
365            .map(|c| c.timestamp.clone())
366            .unwrap_or_default();
367
368        drop(cache);
369        drop(calls);
370
371        // Persist CEP on the live-stats cadence (first call + every 5th) so even
372        // short sessions register `sessions`/`total_cache_hits` instead of only
373        // recording on an `auto_checkpoint` that a brief workload may never reach.
374        // `record_cep_session` is delta-based and PID-guarded, so the extra call
375        // that coincides with a checkpoint is a no-op for the totals (#361).
376        crate::core::stats::record_cep_session(
377            cs.cep_score,
378            cs.cache_hits,
379            cs.total_reads,
380            cs.total_original,
381            cs.total_compressed,
382            &cs.mode_counts,
383            cs.tool_call_count,
384            &cs.complexity,
385        );
386
387        let live = serde_json::json!({
388            "cep_score": cs.cep_score,
389            "cache_utilization": cs.cache_util,
390            "mode_diversity": cs.mode_diversity,
391            "compression_rate": cs.compression_rate,
392            "task_complexity": cs.complexity,
393            "files_cached": cs.total_reads,
394            "total_reads": cs.total_reads,
395            "cache_hits": cs.cache_hits,
396            "tokens_saved": cs.total_saved,
397            "tokens_original": cs.total_original,
398            "tool_calls": cs.tool_call_count,
399            "started_at": started_at,
400            "updated_at": chrono::Local::now().to_rfc3339(),
401        });
402
403        if let Ok(dir) = crate::core::paths::state_dir() {
404            let _ = std::fs::write(dir.join("mcp-live.json"), live.to_string());
405        }
406    }
407
408    /// Persists a CEP (Cognitive Efficiency Protocol) score snapshot for analytics.
409    pub async fn record_cep_snapshot(&self) {
410        let cache = self.cache.read().await;
411        let calls = self.tool_calls.read().await;
412        let stats = cache.get_stats();
413        let complexity = crate::core::adaptive::classify_from_context(&cache);
414
415        let cs = Self::compute_cep_stats(&calls, stats, &complexity);
416
417        drop(cache);
418        drop(calls);
419
420        crate::core::stats::record_cep_session(
421            cs.cep_score,
422            cs.cache_hits,
423            cs.total_reads,
424            cs.total_original,
425            cs.total_compressed,
426            &cs.mode_counts,
427            cs.tool_call_count,
428            &cs.complexity,
429        );
430    }
431
432    fn activity_nudge(
433        session: &crate::core::session::SessionState,
434        calls: &[ToolCallRecord],
435    ) -> &'static str {
436        let last_doc_ts = session
437            .progress
438            .last()
439            .map(|p| p.timestamp)
440            .or_else(|| session.decisions.last().map(|d| d.timestamp))
441            .or_else(|| session.findings.last().map(|f| f.timestamp));
442
443        if let Some(ts) = last_doc_ts {
444            let age = chrono::Utc::now() - ts;
445            if age.num_minutes() < 8 {
446                return "";
447            }
448        }
449
450        let (weighted_score, significant_tools, shell_heavy, edit_heavy) =
451            Self::compute_activity_score(calls, last_doc_ts);
452
453        if weighted_score < 20 || significant_tools < 5 {
454            if session.stats.total_tool_calls >= 30
455                && session.decisions.is_empty()
456                && session.progress.is_empty()
457            {
458                return "\n[CHECKPOINT: please document current progress via ctx_session(action=\"task\") or ctx_knowledge(action=\"remember\")]";
459            }
460            return "";
461        }
462
463        if shell_heavy {
464            "\n[CHECKPOINT: multiple shell commands executed — any test results or findings worth persisting via ctx_knowledge(action=\"remember\")?]"
465        } else if edit_heavy {
466            "\n[CHECKPOINT: several files modified — document the architecture decision or pattern via ctx_knowledge(action=\"remember\")?]"
467        } else {
468            "\n[CHECKPOINT: significant work detected — consider persisting decisions via ctx_knowledge(action=\"remember\")]"
469        }
470    }
471
472    fn compute_activity_score(
473        calls: &[ToolCallRecord],
474        last_doc_ts: Option<chrono::DateTime<chrono::Utc>>,
475    ) -> (u32, u32, bool, bool) {
476        let mut weighted_score: u32 = 0;
477        let mut significant_tools: u32 = 0;
478        let mut shell_count: u32 = 0;
479        let mut edit_count: u32 = 0;
480
481        let since_doc: Vec<&ToolCallRecord> = if let Some(ts) = last_doc_ts {
482            let ts_str = ts.format("%Y-%m-%d %H:%M:%S").to_string();
483            calls.iter().filter(|c| c.timestamp > ts_str).collect()
484        } else {
485            calls.iter().collect()
486        };
487
488        for call in &since_doc {
489            let tool = call.tool.as_str();
490            let is_knowledge = tool == "ctx_knowledge" || tool == "ctx_session";
491            if is_knowledge {
492                weighted_score = 0;
493                significant_tools = 0;
494                shell_count = 0;
495                edit_count = 0;
496                continue;
497            }
498
499            let (weight, significant) = match tool {
500                "edit" | "write" | "str_replace" => {
501                    edit_count += 1;
502                    (4u32, true)
503                }
504                "ctx_shell" => {
505                    shell_count += 1;
506                    let is_test_or_build = call
507                        .mode
508                        .as_deref()
509                        .is_some_and(|m| m.contains("test") || m.contains("build"));
510                    if is_test_or_build {
511                        (3, true)
512                    } else {
513                        (2, true)
514                    }
515                }
516                "ctx_read" => {
517                    let is_cache_hit = call.saved_tokens > 0
518                        && call.original_tokens > 0
519                        && call.saved_tokens == call.original_tokens;
520                    if is_cache_hit {
521                        (0, false)
522                    } else {
523                        (1, false)
524                    }
525                }
526                _ => (1, false),
527            };
528
529            weighted_score = weighted_score.saturating_add(weight);
530            if significant {
531                significant_tools += 1;
532            }
533        }
534
535        let shell_heavy = shell_count >= 3 && shell_count > edit_count;
536        let edit_heavy = edit_count >= 3 && edit_count >= shell_count;
537
538        (weighted_score, significant_tools, shell_heavy, edit_heavy)
539    }
540}
541
542#[cfg(test)]
543mod activity_score_tests {
544    use super::*;
545
546    fn make_call(tool: &str, mode: Option<&str>) -> ToolCallRecord {
547        ToolCallRecord {
548            tool: tool.to_string(),
549            original_tokens: 100,
550            saved_tokens: 50,
551            mode: mode.map(String::from),
552            duration_ms: 10,
553            timestamp: "2026-01-01 12:00:00".to_string(),
554        }
555    }
556
557    fn make_cache_hit() -> ToolCallRecord {
558        ToolCallRecord {
559            tool: "ctx_read".to_string(),
560            original_tokens: 100,
561            saved_tokens: 100,
562            mode: Some("full".to_string()),
563            duration_ms: 1,
564            timestamp: "2026-01-01 12:00:00".to_string(),
565        }
566    }
567
568    #[test]
569    fn empty_calls_zero_score() {
570        let (score, sig, _, _) = LeanCtxServer::compute_activity_score(&[], None);
571        assert_eq!(score, 0);
572        assert_eq!(sig, 0);
573    }
574
575    #[test]
576    fn edits_have_highest_weight() {
577        let calls = vec![
578            make_call("edit", None),
579            make_call("edit", None),
580            make_call("edit", None),
581        ];
582        let (score, sig, _, edit_heavy) = LeanCtxServer::compute_activity_score(&calls, None);
583        assert_eq!(score, 12);
584        assert_eq!(sig, 3);
585        assert!(edit_heavy);
586    }
587
588    #[test]
589    fn shell_test_build_weight_three() {
590        let calls = vec![
591            make_call("ctx_shell", Some("test")),
592            make_call("ctx_shell", Some("build")),
593            make_call("ctx_shell", Some("test")),
594        ];
595        let (score, sig, shell_heavy, _) = LeanCtxServer::compute_activity_score(&calls, None);
596        assert_eq!(score, 9);
597        assert_eq!(sig, 3);
598        assert!(shell_heavy);
599    }
600
601    #[test]
602    fn cache_hits_zero_weight() {
603        let calls = vec![make_cache_hit(), make_cache_hit(), make_cache_hit()];
604        let (score, sig, _, _) = LeanCtxServer::compute_activity_score(&calls, None);
605        assert_eq!(score, 0);
606        assert_eq!(sig, 0);
607    }
608
609    #[test]
610    fn knowledge_call_resets_score() {
611        let calls = vec![
612            make_call("edit", None),
613            make_call("edit", None),
614            make_call("ctx_knowledge", None),
615            make_call("ctx_read", None),
616        ];
617        let (score, sig, _, _) = LeanCtxServer::compute_activity_score(&calls, None);
618        assert_eq!(score, 1);
619        assert_eq!(sig, 0);
620    }
621
622    #[test]
623    fn mixed_workflow_scoring() {
624        let calls = vec![
625            make_call("ctx_read", None),
626            make_call("ctx_read", None),
627            make_call("edit", None),
628            make_call("edit", None),
629            make_call("ctx_shell", Some("test output")),
630            make_call("ctx_shell", None),
631        ];
632        let (score, sig, _, _) = LeanCtxServer::compute_activity_score(&calls, None);
633        assert_eq!(score, 2 + 4 + 4 + 3 + 2);
634        assert_eq!(sig, 4);
635    }
636}