myko/server/
entity_set_stats.rs

1//! Periodic-summary entity-`SET`/`DEL` instrumentation.
2//!
3//! Replaces the per-`set`/`del` `tracing::debug!("[entity] SET|DEL {} id={}", ...)`
4//! lines in [`ServerContext`], which fire tens of thousands of times per second
5//! under pulse-heavy workloads (e.g. comp-engine field/cap presence pulses) and
6//! dominate log I/O.
7//!
8//! The hot path increments a per-entity-type atomic counter (SET and DEL kept
9//! separate) via a DashMap entry lookup; a single dedicated thread emits one
10//! summary log line every `WINDOW_MS`. Quiet windows emit nothing.
11//!
12//! Mirrors the [`super::report_cache_stats`] pattern. To silence even the
13//! summary, set `RUST_LOG=myko::server::entity_set_stats=off`.
14
15use std::{
16    sync::{
17        OnceLock,
18        atomic::{AtomicU64, Ordering},
19    },
20    thread,
21    time::Duration,
22};
23
24use dashmap::DashMap;
25
26const WINDOW_MS: u64 = 1000;
27
28/// Per-entity-type counters for one window, SET and DEL tracked separately.
29#[derive(Default)]
30struct Counts {
31    set: AtomicU64,
32    del: AtomicU64,
33}
34
35fn counts() -> &'static DashMap<String, Counts> {
36    static C: OnceLock<DashMap<String, Counts>> = OnceLock::new();
37    C.get_or_init(DashMap::new)
38}
39
40/// Record a single entity `SET` for `entity_type`. Cheap: one DashMap lookup
41/// plus a relaxed atomic increment.
42#[inline]
43pub fn record_set(entity_type: &str) {
44    counts()
45        .entry(entity_type.to_string())
46        .or_default()
47        .set
48        .fetch_add(1, Ordering::Relaxed);
49}
50
51/// Record a single entity `DEL` for `entity_type`. Counted separately from
52/// `SET` so the summary distinguishes churn from removal.
53#[inline]
54pub fn record_del(entity_type: &str) {
55    counts()
56        .entry(entity_type.to_string())
57        .or_default()
58        .del
59        .fetch_add(1, Ordering::Relaxed);
60}
61
62/// Spawn the summary thread. Idempotent.
63pub fn start_periodic_logger() {
64    static STARTED: OnceLock<()> = OnceLock::new();
65    if STARTED.set(()).is_err() {
66        return;
67    }
68    let _ = thread::Builder::new()
69        .name("myko-entity-set-stats".to_string())
70        .spawn(run_loop)
71        .map_err(|e| {
72            tracing::warn!(
73                target: "myko::server::entity_set_stats",
74                "Failed to spawn entity_set_stats thread: {}", e
75            )
76        });
77}
78
79fn run_loop() {
80    loop {
81        thread::sleep(Duration::from_millis(WINDOW_MS));
82        let _ = std::panic::catch_unwind(std::panic::AssertUnwindSafe(emit_window));
83    }
84}
85
86fn emit_window() {
87    // (entity_type, sets, dels) for every type with activity this window.
88    let mut snap: Vec<(String, u64, u64)> = counts()
89        .iter()
90        .filter_map(|e| {
91            let sets = e.value().set.swap(0, Ordering::Relaxed);
92            let dels = e.value().del.swap(0, Ordering::Relaxed);
93            if sets == 0 && dels == 0 {
94                None
95            } else {
96                Some((e.key().clone(), sets, dels))
97            }
98        })
99        .collect();
100    if snap.is_empty() {
101        return;
102    }
103    // Highest combined volume first.
104    snap.sort_by_key(|b| std::cmp::Reverse(b.1 + b.2));
105    let set_total: u64 = snap.iter().map(|s| s.1).sum();
106    let del_total: u64 = snap.iter().map(|s| s.2).sum();
107    let detail = snap
108        .iter()
109        .map(|(et, s, d)| format!("{}=set:{} del:{}", et, s, d))
110        .collect::<Vec<_>>()
111        .join(", ");
112    tracing::debug!(
113        target: "myko::server::entity_set_stats",
114        "[entity] window={}ms set_total={} del_total={} [{}]",
115        WINDOW_MS,
116        set_total,
117        del_total,
118        detail,
119    );
120}
myko/server/entity_set_stats.rs

myko/server/
entity_set_stats.rs
