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