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, EndpointId};
11use std::{cell::RefCell, collections::HashMap};
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<HashMap<PerfKey, PerfSlot>> = RefCell::new(HashMap::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]
54pub fn perf_counter() -> u64 {
55    crate::cdk::api::performance_counter(1)
56}
57
58///
59/// PerfKey
60/// splitting up by Timer type to avoid confusing string comparisons
61///
62
63#[derive(Clone, Eq, Hash, Ord, PartialEq, PartialOrd)]
64pub enum PerfKey {
65    Endpoint(String),
66    Timer(String),
67}
68
69///
70/// PerfFrame
71/// Tracks an active endpoint scope and accumulated child instructions.
72///
73
74struct PerfFrame {
75    start: u64,
76    child_instructions: u64,
77}
78
79///
80/// PerfSlot
81///
82
83#[derive(Default)]
84struct PerfSlot {
85    count: u64,
86    total_instructions: u64,
87}
88
89impl PerfSlot {
90    const fn increment(&mut self, delta: u64) {
91        self.count = self.count.saturating_add(1);
92        self.total_instructions = self.total_instructions.saturating_add(delta);
93    }
94}
95
96///
97/// PerfEntry
98/// Aggregated perf counters keyed by kind (endpoint vs timer) and label.
99///
100
101#[derive(Clone)]
102pub struct PerfEntry {
103    pub key: PerfKey,
104    pub count: u64,
105    pub total_instructions: u64,
106}
107
108/// Record a counter under the provided key.
109pub fn record(key: PerfKey, delta: u64) {
110    PERF_TABLE.with(|table| {
111        let mut table = table.borrow_mut();
112        table.entry(key).or_default().increment(delta);
113    });
114}
115
116pub fn record_endpoint(endpoint: EndpointId, delta_instructions: u64) {
117    record(
118        PerfKey::Endpoint(endpoint.name.to_string()),
119        delta_instructions,
120    );
121}
122
123pub fn record_timer(label: &str, delta_instructions: u64) {
124    record(PerfKey::Timer(label.to_string()), delta_instructions);
125}
126
127/// Begin an endpoint scope and push it on the stack.
128pub(crate) fn enter_endpoint() {
129    enter_endpoint_at(perf_counter());
130}
131
132/// End the most recent endpoint scope and record exclusive instructions.
133pub(crate) fn exit_endpoint(call: EndpointCall) {
134    exit_endpoint_at(call.endpoint, perf_counter());
135}
136
137fn enter_endpoint_at(start: u64) {
138    PERF_STACK.with(|stack| {
139        let mut stack = stack.borrow_mut();
140
141        // If a previous call trapped, clear any stale frames.
142        if let Some(last) = stack.last()
143            && start < last.start
144        {
145            stack.clear();
146        }
147
148        stack.push(PerfFrame {
149            start,
150            child_instructions: 0,
151        });
152    });
153}
154
155fn exit_endpoint_at(endpoint: EndpointId, end: u64) {
156    PERF_STACK.with(|stack| {
157        let mut stack = stack.borrow_mut();
158        let Some(frame) = stack.pop() else {
159            record_endpoint(endpoint, end);
160            return;
161        };
162
163        let total = end.saturating_sub(frame.start);
164        let exclusive = total.saturating_sub(frame.child_instructions);
165
166        if let Some(parent) = stack.last_mut() {
167            parent.child_instructions = parent.child_instructions.saturating_add(total);
168        }
169
170        record_endpoint(endpoint, exclusive);
171    });
172}
173
174/// Snapshot all recorded perf counters, sorted by key.
175/// Entries are sorted by (kind, label).
176#[must_use]
177pub fn entries() -> Vec<PerfEntry> {
178    PERF_TABLE.with(|table| {
179        let table = table.borrow();
180
181        let mut out: Vec<PerfEntry> = table
182            .iter()
183            .map(|(key, slot)| PerfEntry {
184                key: key.clone(),
185                count: slot.count,
186                total_instructions: slot.total_instructions,
187            })
188            .collect();
189
190        out.sort_by(|a, b| a.key.cmp(&b.key));
191        out
192    })
193}
194
195///
196/// TESTS
197///
198
199#[cfg(test)]
200pub fn reset() {
201    PERF_TABLE.with(|t| t.borrow_mut().clear());
202    PERF_LAST.with(|last| *last.borrow_mut() = 0);
203    PERF_STACK.with(|stack| stack.borrow_mut().clear());
204}
205
206#[cfg(test)]
207mod tests {
208    use super::*;
209
210    fn checkpoint_at(now: u64) {
211        PERF_LAST.with(|last| *last.borrow_mut() = now);
212    }
213
214    fn entry_for(label: &str) -> PerfEntry {
215        entries()
216            .into_iter()
217            .find(|entry| matches!(&entry.key, PerfKey::Endpoint(l) if l == label))
218            .expect("expected perf entry to exist")
219    }
220
221    #[test]
222    fn nested_endpoints_record_exclusive_totals() {
223        reset();
224
225        enter_endpoint_at(100);
226        checkpoint_at(140);
227
228        enter_endpoint_at(200);
229        checkpoint_at(230);
230        exit_endpoint_at(EndpointId::new("child"), 260);
231
232        exit_endpoint_at(EndpointId::new("parent"), 300);
233
234        let parent = entry_for("parent");
235        let child = entry_for("child");
236
237        assert_eq!(child.count, 1);
238        assert_eq!(child.total_instructions, 60);
239        assert_eq!(parent.count, 1);
240        assert_eq!(parent.total_instructions, 140);
241    }
242}