Skip to main content

canic_core/
perf.rs

1//! Cross-cutting performance instrumentation.
2//!
3//! This module provides instruction-count measurement primitives used
4//! across endpoints, ops, timers, and background tasks.
5//!
6//! It is intentionally crate-level infrastructure, not part of the
7//! domain layering (endpoints → ops → model).
8//! Instrumentation modules are layer-neutral and may be used anywhere.
9
10use crate::ids::{EndpointCall, EndpointCallKind};
11use std::{cell::RefCell, collections::BTreeMap};
12
13thread_local! {
14    /// Last snapshot used by the `perf!` macro.
15    #[cfg(not(test))]
16    pub static PERF_LAST: RefCell<u64> = RefCell::new(perf_counter());
17
18    // Unit tests run outside a canister context, so `perf_counter()` would trap.
19    #[cfg(test)]
20    pub static PERF_LAST: RefCell<u64> = const { RefCell::new(0) };
21
22    /// Aggregated perf counters keyed by kind (endpoint vs timer) and label.
23    static PERF_TABLE: RefCell<BTreeMap<PerfKey, PerfSlot>> = const { RefCell::new(BTreeMap::new()) };
24
25    /// Stack of active endpoint scopes for exclusive instruction accounting.
26    /// This is independent of `PERF_LAST`, which is only used by `perf!` checkpoints.
27    static PERF_STACK: RefCell<Vec<PerfFrame>> = const { RefCell::new(Vec::new()) };
28}
29
30/// Returns the **call-context instruction counter** for the current execution.
31///
32/// This value is obtained from `ic0.performance_counter(1)` and represents the
33/// total number of WebAssembly instructions executed by *this canister* within
34/// the **current call context**.
35///
36/// Key properties:
37/// - Monotonically increasing for the duration of the call context
38/// - Accumulates across `await` points and resumptions
39/// - Resets only when a new call context begins
40/// - Counts *only* instructions executed by this canister (not other canisters)
41///
42/// This counter is suitable for:
43/// - Endpoint-level performance accounting
44/// - Async workflows and timers
45/// - Regression detection and coarse-grained profiling
46///
47/// It is **not** a measure of cycle cost. Expensive inter-canister operations
48/// (e.g., canister creation) may have low instruction counts here but high cycle
49/// charges elsewhere.
50///
51/// For fine-grained, single-slice profiling (e.g., hot loops), use
52/// `ic0.performance_counter(0)` instead.
53#[must_use]
54#[cfg_attr(not(target_arch = "wasm32"), expect(clippy::missing_const_for_fn))]
55pub fn perf_counter() -> u64 {
56    #[cfg(target_arch = "wasm32")]
57    {
58        ic_cdk::api::performance_counter(1)
59    }
60
61    #[cfg(not(target_arch = "wasm32"))]
62    {
63        0
64    }
65}
66
67///
68/// PerfKey
69/// Splits perf counters by transport surface so metrics rows remain explicit.
70///
71
72#[derive(Clone, Eq, Hash, Ord, PartialEq, PartialOrd)]
73pub enum PerfKey {
74    Endpoint {
75        kind: EndpointCallKind,
76        name: String,
77    },
78    Checkpoint {
79        scope: String,
80        label: String,
81    },
82}
83
84///
85/// PerfFrame
86/// Tracks an active endpoint scope and accumulated child instructions.
87///
88
89struct PerfFrame {
90    start: u64,
91    child_instructions: u64,
92}
93
94///
95/// PerfSlot
96///
97
98#[derive(Default)]
99struct PerfSlot {
100    count: u64,
101    total_instructions: u64,
102}
103
104impl PerfSlot {
105    const fn increment(&mut self, delta: u64) {
106        self.count = self.count.saturating_add(1);
107        self.total_instructions = self.total_instructions.saturating_add(delta);
108    }
109}
110
111///
112/// PerfEntry
113/// Aggregated perf counters keyed by kind (endpoint vs timer) and label.
114///
115
116#[derive(Clone)]
117pub struct PerfEntry {
118    pub key: PerfKey,
119    pub count: u64,
120    pub total_instructions: u64,
121}
122
123/// Record a counter under the provided key.
124pub fn record(key: PerfKey, delta: u64) {
125    PERF_TABLE.with(|table| {
126        let mut table = table.borrow_mut();
127        table.entry(key).or_default().increment(delta);
128    });
129}
130
131pub fn record_endpoint_call(call: EndpointCall, delta_instructions: u64) {
132    record(
133        PerfKey::Endpoint {
134            kind: call.kind,
135            name: call.endpoint.name.to_string(),
136        },
137        delta_instructions,
138    );
139}
140
141pub fn record_checkpoint(scope: &str, label: &str, delta_instructions: u64) {
142    record(
143        PerfKey::Checkpoint {
144            scope: scope.to_string(),
145            label: label.to_string(),
146        },
147        delta_instructions,
148    );
149}
150
151/// Begin an endpoint scope and push it on the stack.
152pub(crate) fn enter_endpoint() {
153    enter_endpoint_at(perf_counter());
154}
155
156/// End the most recent endpoint scope and record exclusive instructions.
157pub(crate) fn exit_endpoint(call: EndpointCall) {
158    exit_endpoint_at(call, perf_counter());
159}
160
161fn enter_endpoint_at(start: u64) {
162    PERF_STACK.with(|stack| {
163        let mut stack = stack.borrow_mut();
164
165        // If a previous call trapped, clear any stale frames.
166        if let Some(last) = stack.last()
167            && start < last.start
168        {
169            stack.clear();
170        }
171
172        stack.push(PerfFrame {
173            start,
174            child_instructions: 0,
175        });
176    });
177}
178
179fn exit_endpoint_at(call: EndpointCall, end: u64) {
180    PERF_STACK.with(|stack| {
181        let mut stack = stack.borrow_mut();
182        let Some(frame) = stack.pop() else {
183            record_endpoint_call(call, end);
184            return;
185        };
186
187        let total = end.saturating_sub(frame.start);
188        let exclusive = total.saturating_sub(frame.child_instructions);
189
190        if let Some(parent) = stack.last_mut() {
191            parent.child_instructions = parent.child_instructions.saturating_add(total);
192        }
193
194        record_endpoint_call(call, exclusive);
195    });
196}
197
198/// Snapshot all recorded perf counters, sorted by key.
199/// Entries are sorted by (kind, label).
200#[must_use]
201pub fn entries() -> Vec<PerfEntry> {
202    PERF_TABLE.with(|table| {
203        let table = table.borrow();
204
205        let mut out: Vec<PerfEntry> = table
206            .iter()
207            .map(|(key, slot)| PerfEntry {
208                key: key.clone(),
209                count: slot.count,
210                total_instructions: slot.total_instructions,
211            })
212            .collect();
213
214        out.sort_by(|a, b| a.key.cmp(&b.key));
215        out
216    })
217}
218
219/// Read a key-ordered prefix without cloning arbitrarily large checkpoint labels.
220pub(crate) fn bounded_entries(limit: usize) -> Result<Vec<PerfEntry>, crate::InternalError> {
221    PERF_TABLE.with_borrow(|table| {
222        table
223            .iter()
224            .take(limit)
225            .map(|(key, slot)| {
226                let valid = match key {
227                    PerfKey::Endpoint { name, .. } => {
228                        name.len() <= crate::model::public_metrics::MAX_PUBLIC_METRIC_TEXT_BYTES
229                    }
230                    PerfKey::Checkpoint { scope, label } => {
231                        scope.len() <= crate::model::public_metrics::MAX_PUBLIC_METRIC_TEXT_BYTES
232                            && label.len()
233                                <= crate::model::public_metrics::MAX_PUBLIC_METRIC_TEXT_BYTES
234                    }
235                };
236                if !valid {
237                    return Err(crate::InternalError::invalid_input());
238                }
239                Ok(PerfEntry {
240                    key: key.clone(),
241                    count: slot.count,
242                    total_instructions: slot.total_instructions,
243                })
244            })
245            .collect()
246    })
247}
248
249// -----------------------------------------------------------------------------
250// Tests
251// -----------------------------------------------------------------------------
252
253#[cfg(test)]
254pub fn reset() {
255    PERF_TABLE.with(|t| t.borrow_mut().clear());
256    PERF_LAST.with(|last| *last.borrow_mut() = 0);
257    PERF_STACK.with(|stack| stack.borrow_mut().clear());
258}
259
260#[cfg(test)]
261mod tests {
262    use super::*;
263
264    fn checkpoint_at(now: u64) {
265        PERF_LAST.with(|last| *last.borrow_mut() = now);
266    }
267
268    fn call(name: &'static str, kind: EndpointCallKind) -> EndpointCall {
269        EndpointCall {
270            endpoint: crate::ids::EndpointId::new(name),
271            kind,
272        }
273    }
274
275    fn entry_for(kind: EndpointCallKind, label: &str) -> PerfEntry {
276        entries()
277            .into_iter()
278            .find(|entry| {
279                matches!(
280                    &entry.key,
281                    PerfKey::Endpoint {
282                        kind: entry_kind,
283                        name
284                    } if *entry_kind == kind && name == label
285                )
286            })
287            .expect("expected perf entry to exist")
288    }
289
290    fn checkpoint_entry_for(scope: &str, label: &str) -> PerfEntry {
291        entries()
292            .into_iter()
293            .find(|entry| {
294                matches!(
295                    &entry.key,
296                    PerfKey::Checkpoint {
297                        scope: entry_scope,
298                        label: entry_label,
299                    } if entry_scope == scope && entry_label == label
300                )
301            })
302            .expect("expected checkpoint perf entry to exist")
303    }
304
305    #[test]
306    fn nested_endpoints_record_exclusive_totals() {
307        reset();
308
309        enter_endpoint_at(100);
310        checkpoint_at(140);
311
312        enter_endpoint_at(200);
313        checkpoint_at(230);
314        exit_endpoint_at(call("child", EndpointCallKind::Query), 260);
315
316        exit_endpoint_at(call("parent", EndpointCallKind::Update), 300);
317
318        let parent = entry_for(EndpointCallKind::Update, "parent");
319        let child = entry_for(EndpointCallKind::Query, "child");
320
321        assert_eq!(child.count, 1);
322        assert_eq!(child.total_instructions, 60);
323        assert_eq!(parent.count, 1);
324        assert_eq!(parent.total_instructions, 140);
325    }
326
327    #[test]
328    fn endpoint_perf_keys_preserve_call_kind() {
329        reset();
330
331        record_endpoint_call(call("same_name", EndpointCallKind::Query), 10);
332        record_endpoint_call(call("same_name", EndpointCallKind::QueryComposite), 20);
333        record_endpoint_call(call("same_name", EndpointCallKind::Update), 30);
334
335        assert_eq!(
336            entry_for(EndpointCallKind::Query, "same_name").total_instructions,
337            10
338        );
339        assert_eq!(
340            entry_for(EndpointCallKind::QueryComposite, "same_name").total_instructions,
341            20
342        );
343        assert_eq!(
344            entry_for(EndpointCallKind::Update, "same_name").total_instructions,
345            30
346        );
347    }
348
349    #[test]
350    fn checkpoints_record_scope_and_label() {
351        reset();
352
353        record_checkpoint("workflow::bootstrap", "load_cfg", 120);
354        record_checkpoint("workflow::bootstrap", "load_cfg", 80);
355
356        let checkpoint = checkpoint_entry_for("workflow::bootstrap", "load_cfg");
357
358        assert_eq!(checkpoint.count, 2);
359        assert_eq!(checkpoint.total_instructions, 200);
360    }
361}