canbench_rs/lib.rs
1//! `canbench` is a tool for benchmarking canisters on the Internet Computer.
2//!
3//! ## Quickstart
4//!
5//! This example is also available to tinker with in the examples directory. See the [fibonacci example](https://github.com/dfinity/bench/tree/main/examples/fibonacci).
6//!
7//! ### 1. Install the `canbench` binary.
8//!
9//! The `canbench` is what runs your canister's benchmarks.
10//!
11//! ```bash
12//! cargo install canbench
13//! ```
14//!
15//! ### 2. Add optional dependency to `Cargo.toml`
16//!
17//! Typically you do not want your benchmarks to be part of your canister when deploying it to the Internet Computer.
18//! Therefore, we include `canbench` only as an optional dependency so that it's only included when running benchmarks.
19//! For more information about optional dependencies, you can read more about them [here](https://doc.rust-lang.org/cargo/reference/features.html#optional-dependencies).
20//!
21//! ```toml
22//! canbench-rs = { version = "x.y.z", optional = true }
23//! ```
24//!
25//! ### 3. Add a configuration to `canbench.yml`
26//!
27//! The `canbench.yml` configuration file tells `canbench` how to build and run you canister.
28//! Below is a typical configuration.
29//! Note that we're compiling the canister with the `canbench` feature so that the benchmarking logic is included in the Wasm.
30//!
31//! ```yml
32//! build_cmd:
33//! cargo build --release --target wasm32-unknown-unknown --locked --features canbench-rs
34//!
35//! wasm_path:
36//! ./target/wasm32-unknown-unknown/release/<YOUR_CANISTER>.wasm
37//! ```
38//! #### Init Args
39//!
40//! Init args can be specified using the `init_args` key in the configuration file:
41//! ```yml
42//! init_args:
43//! hex: 4449444c0001710568656c6c6f
44//! ```
45//!
46//! #### Stable Memory
47//!
48//! A file can be specified to be loaded in the canister's stable memory _after_ initialization.
49//!
50//! ```yml
51//! stable_memory:
52//! file:
53//! stable_memory.bin
54//! ```
55//!
56//! <div class="warning">Contents of the stable memory file are loaded <i>after</i> the call to the canister's init method.
57//! Therefore, changes made to stable memory in the init method would be overwritten.</div>
58//!
59//!
60//! #### Environment Variables
61//!
62//! A file can be specified from which environment variables are loaded into the canister. The file
63//! is a CSV with two columns: `name` and `value`, where `name` is the name of the environment
64//! variable, and `value` is the value of the environment variable.
65//! Leading and trailing whitespaces in `name` and `value` are ignored.
66//!
67//! ```yml
68//! env_vars:
69//! file: environment_variables.csv
70//! ```
71//!
72//!
73//! ### 4. Start benching! 🏋🏽
74//!
75//! Let's say we have a canister that exposes a `query` computing the fibonacci sequence of a given number.
76//! Here's what that query can look like:
77//!
78//! ```rust
79//! #[ic_cdk::query]
80//! fn fibonacci(n: u32) -> u32 {
81//! if n == 0 {
82//! return 0;
83//! } else if n == 1 {
84//! return 1;
85//! }
86//!
87//! let mut a = 0;
88//! let mut b = 1;
89//! let mut result = 0;
90//!
91//! for _ in 2..=n {
92//! result = a + b;
93//! a = b;
94//! b = result;
95//! }
96//!
97//! result
98//! }
99//! ```
100//!
101//! Now, let's add some benchmarks to this query:
102//!
103//! ```rust
104//! #[cfg(feature = "canbench-rs")]
105//! mod benches {
106//! use super::*;
107//! use canbench_rs::bench;
108//!
109//! # fn fibonacci(_: u32) -> u32 { 0 }
110//!
111//! #[bench]
112//! fn fibonacci_20() {
113//! // Prevent the compiler from optimizing the call and propagating constants.
114//! std::hint::black_box(fibonacci(std::hint::black_box(20)));
115//! }
116//!
117//! #[bench]
118//! fn fibonacci_45() {
119//! // Prevent the compiler from optimizing the call and propagating constants.
120//! std::hint::black_box(fibonacci(std::hint::black_box(45)));
121//! }
122//! }
123//! ```
124//!
125//! Run `canbench`. You'll see an output that looks similar to this:
126//!
127//! ```txt
128//! $ canbench
129//!
130//! ---------------------------------------------------
131//!
132//! Benchmark: fibonacci_20 (new)
133//! total:
134//! instructions: 2301 (new)
135//! heap_increase: 0 pages (new)
136//! stable_memory_increase: 0 pages (new)
137//!
138//! ---------------------------------------------------
139//!
140//! Benchmark: fibonacci_45 (new)
141//! total:
142//! instructions: 3088 (new)
143//! heap_increase: 0 pages (new)
144//! stable_memory_increase: 0 pages (new)
145//!
146//! ---------------------------------------------------
147//!
148//! Executed 2 of 2 benchmarks.
149//! ```
150//!
151//! ### 5. Track performance regressions
152//!
153//! Notice that `canbench` reported the above benchmarks as "new".
154//! `canbench` allows you to persist the results of these benchmarks.
155//! In subsequent runs, `canbench` reports the performance relative to the last persisted run.
156//!
157//! Let's first persist the results above by running `canbench` again, but with the `persist` flag:
158//!
159//! ```txt
160//! $ canbench --persist
161//! # optionally add `--csv` to generate a CSV report
162//! $ canbench --persist --csv
163//! ...
164//! ---------------------------------------------------
165//!
166//! Executed 2 of 2 benchmarks.
167//! Successfully persisted results to canbench_results.yml
168//! ```
169//!
170//! Now, if we run `canbench` again, `canbench` will run the benchmarks, and will additionally report that there were no changes detected in performance.
171//!
172//! ```txt
173//! $ canbench
174//! Finished release [optimized] target(s) in 0.34s
175//!
176//! ---------------------------------------------------
177//!
178//! Benchmark: fibonacci_20
179//! total:
180//! instructions: 2301 (no change)
181//! heap_increase: 0 pages (no change)
182//! stable_memory_increase: 0 pages (no change)
183//!
184//! ---------------------------------------------------
185//!
186//! Benchmark: fibonacci_45
187//! total:
188//! instructions: 3088 (no change)
189//! heap_increase: 0 pages (no change)
190//! stable_memory_increase: 0 pages (no change)
191//!
192//! ---------------------------------------------------
193//!
194//! Executed 2 of 2 benchmarks.
195//! ```
196//!
197//! Let's try swapping out our implementation of `fibonacci` with an implementation that's miserably inefficient.
198//! Replace the `fibonacci` function defined previously with the following:
199//!
200//! ```rust
201//! #[ic_cdk::query]
202//! fn fibonacci(n: u32) -> u32 {
203//! match n {
204//! 0 => 1,
205//! 1 => 1,
206//! _ => fibonacci(n - 1) + fibonacci(n - 2),
207//! }
208//! }
209//! ```
210//!
211//! And running `canbench` again, we see that it detects and reports a regression.
212//!
213//! ```txt
214//! $ canbench
215//!
216//! ---------------------------------------------------
217//!
218//! Benchmark: fibonacci_20
219//! total:
220//! instructions: 337.93 K (regressed by 14586.14%)
221//! heap_increase: 0 pages (no change)
222//! stable_memory_increase: 0 pages (no change)
223//!
224//! ---------------------------------------------------
225//!
226//! Benchmark: fibonacci_45
227//! total:
228//! instructions: 56.39 B (regressed by 1826095830.76%)
229//! heap_increase: 0 pages (no change)
230//! stable_memory_increase: 0 pages (no change)
231//!
232//! ---------------------------------------------------
233//!
234//! Executed 2 of 2 benchmarks.
235//! ```
236//!
237//! Apparently, the recursive implementation is many orders of magnitude more expensive than the iterative implementation 😱
238//! Good thing we found out before deploying this implementation to production.
239//!
240//! Notice that `fibonacci_45` took > 50B instructions, which is substantially more than the instruction limit given for a single message execution on the Internet Computer. `canbench` runs benchmarks in an environment that gives them up to 10T instructions.
241//!
242//! ## Additional Examples
243//!
244//! For the following examples, we'll be using the following canister code, which you can also find in the [examples](./examples/btreemap_vs_hashmap) directory.
245//! This canister defines a simple state as well as a `pre_upgrade` function that stores that state into stable memory.
246//!
247//! ```rust
248//! use candid::{CandidType, Encode};
249//! use ic_cdk::pre_upgrade;
250//! use std::cell::RefCell;
251//!
252//! #[derive(CandidType)]
253//! struct User {
254//! name: String,
255//! }
256//!
257//! #[derive(Default, CandidType)]
258//! struct State {
259//! users: std::collections::BTreeMap<u64, User>,
260//! }
261//!
262//! thread_local! {
263//! static STATE: RefCell<State> = RefCell::new(State::default());
264//! }
265//!
266//! #[pre_upgrade]
267//! fn pre_upgrade() {
268//! // Serialize state.
269//! let bytes = STATE.with(|s| Encode!(s).unwrap());
270//!
271//! // Write to stable memory.
272//! ic_cdk::stable::StableWriter::default()
273//! .write(&bytes)
274//! .unwrap();
275//! }
276//! ```
277//!
278//! ### Excluding setup code
279//!
280//! Let's say we want to benchmark how long it takes to run the `pre_upgrade` function. We can define the following benchmark:
281//!
282//! ```rust
283//! #[cfg(feature = "canbench-rs")]
284//! mod benches {
285//! use super::*;
286//! use canbench_rs::bench;
287//!
288//! # fn initialize_state() {}
289//! # fn pre_upgrade() {}
290//!
291//! #[bench]
292//! fn pre_upgrade_bench() {
293//! // Some function that fills the state with lots of data.
294//! initialize_state();
295//!
296//! pre_upgrade();
297//! }
298//! }
299//! ```
300//!
301//! The problem with the above benchmark is that it's benchmarking both the `pre_upgrade` call _and_ the initialization of the state.
302//! What if we're only interested in benchmarking the `pre_upgrade` call?
303//! To address this, we can use the `#[bench(raw)]` macro to specify exactly which code we'd like to benchmark.
304//!
305//! ```rust
306//! #[cfg(feature = "canbench-rs")]
307//! mod benches {
308//! use super::*;
309//! use canbench_rs::bench;
310//!
311//! # fn initialize_state() {}
312//! # fn pre_upgrade() {}
313//!
314//! #[bench(raw)]
315//! fn pre_upgrade_bench() -> canbench_rs::BenchResult {
316//! // Some function that fills the state with lots of data.
317//! initialize_state();
318//!
319//! // Only benchmark the pre_upgrade. Initializing the state isn't
320//! // included in the results of our benchmark.
321//! canbench_rs::bench_fn(pre_upgrade)
322//! }
323//! }
324//! ```
325//!
326//! Running `canbench` on the example above will benchmark only the code wrapped in `canbench_rs::bench_fn`, which in this case is the call to `pre_upgrade`.
327//!
328//! ```txt
329//! $ canbench pre_upgrade_bench
330//!
331//! ---------------------------------------------------
332//!
333//! Benchmark: pre_upgrade_bench (new)
334//! total:
335//! instructions: 717.10 M (new)
336//! heap_increase: 519 pages (new)
337//! stable_memory_increase: 184 pages (new)
338//!
339//! ---------------------------------------------------
340//!
341//! Executed 1 of 1 benchmarks.
342//! ```
343//!
344//! ### Granular Benchmarking
345//!
346//! Building on the example above, the `pre_upgrade` function does two steps:
347//!
348//! 1. Serialize the state
349//! 2. Write to stable memory
350//!
351//! Suppose we're interested in understanding, within `pre_upgrade`, the resources spent in each of these steps.
352//! `canbench` allows you to do more granular benchmarking using the `canbench_rs::bench_scope` function.
353//! Here's how we can modify our `pre_upgrade` function:
354//!
355//!
356//! ```rust
357//! # use candid::{Encode, CandidType};
358//! # use ic_cdk::pre_upgrade;
359//! # use std::cell::RefCell;
360//! #
361//! # #[derive(CandidType)]
362//! # struct User {
363//! # name: String,
364//! # }
365//! #
366//! # #[derive(Default, CandidType)]
367//! # struct State {
368//! # users: std::collections::BTreeMap<u64, User>,
369//! # }
370//! #
371//! # thread_local! {
372//! # static STATE: RefCell<State> = RefCell::new(State::default());
373//! # }
374//!
375//! #[pre_upgrade]
376//! fn pre_upgrade() {
377//! // Serialize state.
378//! let bytes = {
379//! #[cfg(feature = "canbench-rs")]
380//! let _p = canbench_rs::bench_scope("serialize_state");
381//! STATE.with(|s| Encode!(s).unwrap())
382//! };
383//!
384//! // Write to stable memory.
385//! #[cfg(feature = "canbench-rs")]
386//! let _p = canbench_rs::bench_scope("writing_to_stable_memory");
387//! ic_cdk::stable::StableWriter::default()
388//! .write(&bytes)
389//! .unwrap();
390//! }
391//! ```
392//!
393//! In the code above, we've asked `canbench` to profile each of these steps separately.
394//! Running `canbench` now, each of these steps are reported.
395//!
396//! ```txt
397//! $ canbench pre_upgrade_bench
398//!
399//! ---------------------------------------------------
400//!
401//! Benchmark: pre_upgrade_bench (new)
402//! total:
403//! instructions: 717.11 M (new)
404//! heap_increase: 519 pages (new)
405//! stable_memory_increase: 184 pages (new)
406//!
407//! serialize_state (profiling):
408//! instructions: 717.10 M (new)
409//! heap_increase: 519 pages (new)
410//! stable_memory_increase: 0 pages (new)
411//!
412//! writing_to_stable_memory (profiling):
413//! instructions: 502 (new)
414//! heap_increase: 0 pages (new)
415//! stable_memory_increase: 184 pages (new)
416//!
417//! ---------------------------------------------------
418//!
419//! Executed 1 of 1 benchmarks.
420//! ```
421//!
422//! ### Debugging
423//!
424//! The `ic_cdk::eprintln!()` macro facilitates tracing canister and benchmark execution.
425//! Output is displayed on the console when `canbench` is executed with
426//! the `--show-canister-output` option.
427//!
428//! ```rust
429//! # #[cfg(feature = "canbench-rs")]
430//! # mod benches {
431//! # use super::*;
432//! # use canbench_rs::bench;
433//! #
434//! #[bench]
435//! fn bench_with_debug_print() {
436//! // Run `canbench --show-canister-output` to see the output.
437//! ic_cdk::eprintln!("Hello from {}!", env!("CARGO_PKG_NAME"));
438//! }
439//! # }
440//! ```
441//!
442//! Example output:
443//!
444//! ```bash
445//! $ canbench bench_with_debug_print --show-canister-output
446//! [...]
447//! 2021-05-06 19:17:10.000000003 UTC: [Canister lxzze-o7777-77777-aaaaa-cai] Hello from example!
448//! [...]
449//! ```
450//!
451//! Refer to the [Internet Computer specification](https://internetcomputer.org/docs/references/ic-interface-spec#debugging-aids) for more details.
452//!
453//! ### Preventing Compiler Optimizations
454//!
455//! If benchmark results appear suspiciously low and remain consistent
456//! despite increased benchmarked function complexity, the `std::hint::black_box`
457//! function helps prevent compiler optimizations.
458//!
459//! ```rust
460//! # #[cfg(feature = "canbench-rs")]
461//! # mod benches {
462//! # use super::*;
463//! # use canbench_rs::bench;
464//! #
465//! #[bench]
466//! fn fibonacci_20() {
467//! // Prevent the compiler from optimizing the call and propagating constants.
468//! std::hint::black_box(fibonacci(std::hint::black_box(20)));
469//! }
470//! # }
471//! ```
472//!
473//! Note that passing constant values as function arguments can also
474//! trigger compiler optimizations. If the actual code uses
475//! variables (not constants), both the arguments and the result
476//! of the benchmarked function must be wrapped in `black_box` calls.
477//!
478//! Refer to the [Rust documentation](https://doc.rust-lang.org/std/hint/fn.black_box.html)
479//! for more details.
480//!
481pub use canbench_rs_macros::bench;
482use candid::CandidType;
483use serde::{Deserialize, Serialize};
484use std::{cell::RefCell, collections::BTreeMap};
485
486thread_local! {
487 static SCOPES: RefCell<BTreeMap<&'static str, Vec<MeasurementInternal>>> =
488 const { RefCell::new(BTreeMap::new()) };
489}
490
491/// The results of a benchmark.
492/// This type is in a public API.
493#[derive(Debug, PartialEq, Serialize, Deserialize, CandidType, Default)]
494pub struct BenchResult {
495 /// A measurement for the entire duration of the benchmark.
496 pub total: Measurement,
497
498 /// Measurements for scopes.
499 #[serde(default)]
500 pub scopes: BTreeMap<String, Measurement>,
501}
502
503/// The internal representation of the benchmark result.
504/// This type is not deserialized, therefore fields are not `Option`.
505#[derive(Debug, PartialEq, Default)]
506struct BenchResultInternal {
507 /// A measurement for the entire duration of the benchmark.
508 pub total: MeasurementInternal,
509
510 /// Measurements for scopes.
511 pub scopes: BTreeMap<String, MeasurementInternal>,
512}
513
514impl From<BenchResultInternal> for BenchResult {
515 fn from(r: BenchResultInternal) -> Self {
516 Self {
517 total: Measurement::from(r.total),
518 scopes: r
519 .scopes
520 .into_iter()
521 .map(|(k, v)| (k, Measurement::from(v)))
522 .collect(),
523 }
524 }
525}
526
527/// A benchmark measurement containing various stats.
528/// This type is in a public API.
529#[derive(Debug, PartialEq, Serialize, Deserialize, CandidType, Clone, Default)]
530pub struct Measurement {
531 /// The number of calls made during the measurement.
532 #[serde(default)]
533 pub calls: u64,
534
535 /// The number of instructions.
536 #[serde(default)]
537 pub instructions: u64,
538
539 /// The increase in heap (measured in pages).
540 #[serde(default)]
541 pub heap_increase: u64,
542
543 /// The increase in stable memory (measured in pages).
544 #[serde(default)]
545 pub stable_memory_increase: u64,
546}
547
548#[test]
549fn public_api_of_measurement_should_not_change() {
550 // If you have to modify this test, it's likely you broke the public API of `Measurement`.
551 // Avoid making such changes unless absolutely necessary — doing so requires a major version bump.
552 //
553 // This test checks that the `Measurement` struct:
554 // - Exists
555 // - Has all expected public fields
556 // - Fields have the expected names and types
557
558 let m = Measurement {
559 calls: 0_u64,
560 instructions: 0_u64,
561 heap_increase: 0_u64,
562 stable_memory_increase: 0_u64,
563 };
564
565 // Ensure field access works and types match expectations
566 let _: u64 = m.calls;
567 let _: u64 = m.instructions;
568 let _: u64 = m.heap_increase;
569 let _: u64 = m.stable_memory_increase;
570}
571
572/// The internal representation of a measurement.
573#[derive(Debug, PartialEq, Clone, Default)]
574struct MeasurementInternal {
575 /// Instruction counter at the start of measurement.
576 /// Not in public API, because it is not supposed to be compared to other measurements.
577 /// Used internally to correctly calculate instructions of overlapping or nested scopes.
578 start_instructions: u64,
579
580 /// The number of calls made during the measurement.
581 pub calls: u64,
582
583 /// The number of instructions.
584 pub instructions: u64,
585
586 /// The increase in heap (measured in pages).
587 pub heap_increase: u64,
588
589 /// The increase in stable memory (measured in pages).
590 pub stable_memory_increase: u64,
591}
592
593impl From<MeasurementInternal> for Measurement {
594 fn from(m: MeasurementInternal) -> Self {
595 Self {
596 calls: m.calls,
597 instructions: m.instructions,
598 heap_increase: m.heap_increase,
599 stable_memory_increase: m.stable_memory_increase,
600 }
601 }
602}
603
604/// Benchmarks the given function.
605pub fn bench_fn<R>(f: impl FnOnce() -> R) -> BenchResult {
606 reset();
607
608 let is_tracing_enabled = TRACING_BUFFER.with_borrow(|p| !p.is_empty());
609
610 if !is_tracing_enabled {
611 let start_heap = heap_size();
612 let start_stable_memory = ic_cdk::api::stable_size();
613 let start_instructions = instruction_count();
614 f();
615 let instructions = instruction_count() - start_instructions;
616 let stable_memory_increase = ic_cdk::api::stable_size() - start_stable_memory;
617 let heap_increase = heap_size() - start_heap;
618
619 let total = MeasurementInternal {
620 start_instructions,
621 calls: 1,
622 instructions,
623 heap_increase,
624 stable_memory_increase,
625 }
626 .into();
627 let scopes: std::collections::BTreeMap<_, _> = get_scopes_measurements()
628 .into_iter()
629 .map(|(k, v)| (k.to_string(), v))
630 .collect();
631
632 BenchResult { total, scopes }
633 } else {
634 // The first 4 bytes are a flag to indicate if tracing is enabled. It will be read by the
635 // tracing function (instrumented code) to decide whether to trace or not.
636 let tracing_started_flag_address = TRACING_BUFFER.with_borrow_mut(|p| p.as_mut_ptr());
637 unsafe {
638 // Ideally, we'd like to reverse the following 2 statements, but it might be possible
639 // for the compiler not to inline `ic_cdk::api::performance_counter` which would be
640 // problematic as `performance_counter` would be traced itself. Perhaps we can call
641 // ic0.performance_counter directly.
642 INSTRUCTIONS_START = ic_cdk::api::performance_counter(0) as i64;
643 *tracing_started_flag_address = 1;
644 }
645 f();
646 unsafe {
647 *tracing_started_flag_address = 0;
648 INSTRUCTIONS_END = ic_cdk::api::performance_counter(0) as i64;
649 }
650
651 // Only the traces are meaningful, and it's written to `TRACING_BUFFER` and will be
652 // collected in the tracing query method.
653 BenchResult::default()
654 }
655}
656
657/// Benchmarks the scope this function is declared in.
658///
659/// NOTE: It's important to assign this function, otherwise benchmarking won't work correctly.
660///
661/// # Correct Usage
662///
663/// ```
664/// fn my_func() {
665/// let _p = canbench_rs::bench_scope("my_scope");
666/// // Do something.
667/// }
668/// ```
669///
670/// # Incorrect Usages
671///
672/// ```
673/// fn my_func() {
674/// let _ = canbench_rs::bench_scope("my_scope"); // Doesn't capture the scope.
675/// // Do something.
676/// }
677/// ```
678///
679/// ```
680/// fn my_func() {
681/// canbench_rs::bench_scope("my_scope"); // Doesn't capture the scope.
682/// // Do something.
683/// }
684/// ```
685#[must_use]
686pub fn bench_scope(name: &'static str) -> BenchScope {
687 BenchScope::new(name)
688}
689
690/// An object used for benchmarking a specific scope.
691pub struct BenchScope {
692 name: &'static str,
693 start_instructions: u64,
694 start_stable_memory: u64,
695 start_heap: u64,
696}
697
698impl BenchScope {
699 fn new(name: &'static str) -> Self {
700 let start_heap = heap_size();
701 let start_stable_memory = ic_cdk::api::stable_size();
702 let start_instructions = instruction_count();
703
704 Self {
705 name,
706 start_instructions,
707 start_stable_memory,
708 start_heap,
709 }
710 }
711}
712
713impl Drop for BenchScope {
714 fn drop(&mut self) {
715 SCOPES.with(|p| {
716 let mut p = p.borrow_mut();
717 let start_instructions = self.start_instructions;
718 let stable_memory_increase = ic_cdk::api::stable_size() - self.start_stable_memory;
719 let heap_increase = heap_size() - self.start_heap;
720 let instructions = instruction_count() - self.start_instructions;
721 p.entry(self.name).or_default().push(MeasurementInternal {
722 start_instructions,
723 calls: 1,
724 instructions,
725 heap_increase,
726 stable_memory_increase,
727 });
728 });
729 }
730}
731
732// Clears all scope data.
733fn reset() {
734 SCOPES.with(|p| p.borrow_mut().clear());
735}
736
737// Returns the measurements for any declared scopes, aggregated by the scope name.
738fn get_scopes_measurements() -> BTreeMap<&'static str, Measurement> {
739 fn sum_non_overlapping(measurements: &[MeasurementInternal]) -> MeasurementInternal {
740 #[derive(Debug)]
741 struct Interval {
742 start: u64,
743 end: u64,
744 measurement: MeasurementInternal,
745 }
746
747 let mut intervals: Vec<Interval> = measurements
748 .iter()
749 .map(|m| Interval {
750 start: m.start_instructions,
751 end: m.start_instructions + m.instructions,
752 measurement: m.clone(),
753 })
754 .collect();
755
756 intervals.sort_by_key(|i| i.start);
757
758 let mut total = MeasurementInternal::default();
759 let mut current_start = 0;
760 let mut current_end = 0;
761 let mut group_measurements: Vec<MeasurementInternal> = Vec::new();
762
763 for i in intervals {
764 if i.start < current_end {
765 current_end = current_end.max(i.end);
766 group_measurements.push(i.measurement);
767 } else {
768 if current_end > current_start {
769 total.instructions += current_end - current_start;
770 for m in &group_measurements {
771 total.calls += m.calls;
772 total.heap_increase += m.heap_increase;
773 total.stable_memory_increase += m.stable_memory_increase;
774 }
775 }
776 current_start = i.start;
777 current_end = i.end;
778 group_measurements.clear();
779 group_measurements.push(i.measurement);
780 }
781 }
782
783 // Final group
784 if current_end > current_start {
785 total.instructions += current_end - current_start;
786 for m in &group_measurements {
787 total.calls += m.calls;
788 total.heap_increase += m.heap_increase;
789 total.stable_memory_increase += m.stable_memory_increase;
790 }
791 }
792
793 total
794 }
795
796 SCOPES.with(|p| {
797 p.borrow()
798 .iter()
799 .map(|(&scope, measurements)| {
800 (scope, Measurement::from(sum_non_overlapping(measurements)))
801 })
802 .collect()
803 })
804}
805
806fn instruction_count() -> u64 {
807 #[cfg(target_arch = "wasm32")]
808 {
809 ic_cdk::api::performance_counter(0)
810 }
811
812 #[cfg(not(target_arch = "wasm32"))]
813 {
814 // Consider using cpu time here.
815 0
816 }
817}
818
819fn heap_size() -> u64 {
820 #[cfg(target_arch = "wasm32")]
821 {
822 core::arch::wasm32::memory_size(0) as u64
823 }
824
825 #[cfg(not(target_arch = "wasm32"))]
826 {
827 0
828 }
829}
830
831thread_local! {
832 static TRACING_BUFFER: RefCell<Vec<u8>> = const { RefCell::new(Vec::new()) };
833}
834
835static mut INSTRUCTIONS_START: i64 = 0;
836static mut INSTRUCTIONS_END: i64 = 0;
837const NUM_BYTES_ENABLED_FLAG: usize = 4;
838const NUM_BYTES_NUM_ENTRIES: usize = 8;
839const MAX_NUM_LOG_ENTRIES: usize = 100_000_000;
840const NUM_BYTES_FUNC_ID: usize = 4;
841const NUM_BYTES_INSTRUCTION_COUNTER: usize = 8;
842const BUFFER_SIZE: usize = NUM_BYTES_ENABLED_FLAG
843 + NUM_BYTES_NUM_ENTRIES
844 + MAX_NUM_LOG_ENTRIES * (NUM_BYTES_FUNC_ID + NUM_BYTES_INSTRUCTION_COUNTER);
845const LOGS_START_OFFSET: usize = NUM_BYTES_ENABLED_FLAG + NUM_BYTES_NUM_ENTRIES;
846const MAX_NUM_LOG_ENTRIES_IN_RESPONSE: usize = 131_000;
847
848#[export_name = "__prepare_tracing"]
849fn prepare_tracing() -> i32 {
850 TRACING_BUFFER.with_borrow_mut(|b| {
851 *b = vec![0; BUFFER_SIZE];
852 b.as_ptr() as i32
853 })
854}
855
856pub fn get_traces(bench_instructions: u64) -> Result<Vec<(i32, i64)>, String> {
857 TRACING_BUFFER.with_borrow(|b| {
858 if b[0] == 1 {
859 panic!("Tracing is still enabled.");
860 }
861 let num_entries = i64::from_le_bytes(
862 b[NUM_BYTES_ENABLED_FLAG..(NUM_BYTES_ENABLED_FLAG + NUM_BYTES_NUM_ENTRIES)]
863 .try_into()
864 .unwrap(),
865 );
866 if num_entries > MAX_NUM_LOG_ENTRIES as i64 {
867 return Err(format!(
868 "There are {num_entries} log entries which is more than \
869 {MAX_NUM_LOG_ENTRIES}, as we can currently support",
870 ));
871 }
872 let instructions_start = unsafe { INSTRUCTIONS_START };
873 let mut traces = vec![(i32::MAX, 0)];
874 for i in 0..num_entries {
875 let log_start_address = i as usize
876 * (NUM_BYTES_FUNC_ID + NUM_BYTES_INSTRUCTION_COUNTER)
877 + LOGS_START_OFFSET;
878 let func_id = i32::from_le_bytes(
879 b[log_start_address..log_start_address + NUM_BYTES_FUNC_ID]
880 .try_into()
881 .unwrap(),
882 );
883 let instruction_counter = i64::from_le_bytes(
884 b[log_start_address + NUM_BYTES_FUNC_ID
885 ..log_start_address + NUM_BYTES_FUNC_ID + NUM_BYTES_INSTRUCTION_COUNTER]
886 .try_into()
887 .unwrap(),
888 );
889 traces.push((func_id, instruction_counter - instructions_start));
890 }
891 traces.push((i32::MIN, unsafe { INSTRUCTIONS_END - instructions_start }));
892 let traces = adjust_traces_for_overhead(traces, bench_instructions);
893 // TODO(EXC-2020): consider using compression.
894 let traces = truncate_traces(traces);
895 Ok(traces)
896 })
897}
898
899fn adjust_traces_for_overhead(traces: Vec<(i32, i64)>, bench_instructions: u64) -> Vec<(i32, i64)> {
900 let num_logs = traces.len() - 2;
901 let overhead = (traces[num_logs].1 as f64 - bench_instructions as f64) / (num_logs as f64);
902 traces
903 .into_iter()
904 .enumerate()
905 .map(|(i, (id, count))| {
906 if i <= num_logs {
907 (id, count - (overhead * i as f64) as i64)
908 } else {
909 (id, count - (overhead * num_logs as f64) as i64)
910 }
911 })
912 .collect()
913}
914
915fn truncate_traces(traces: Vec<(i32, i64)>) -> Vec<(i32, i64)> {
916 if traces.len() <= MAX_NUM_LOG_ENTRIES_IN_RESPONSE {
917 return traces;
918 }
919
920 let mut num_traces_by_depth = BTreeMap::new();
921
922 let mut depth = 0;
923 for (func_id, _) in traces.iter() {
924 if *func_id >= 0 {
925 depth += 1;
926 *num_traces_by_depth.entry(depth).or_insert(0) += 1;
927 } else {
928 depth -= 1;
929 }
930 }
931 assert_eq!(depth, 0, "Traces are not balanced.");
932 let mut depth_to_truncate = 0;
933 let mut cumulative_traces = 0;
934 for (depth, num_traces) in num_traces_by_depth.iter() {
935 cumulative_traces += num_traces;
936 if cumulative_traces <= MAX_NUM_LOG_ENTRIES_IN_RESPONSE {
937 depth_to_truncate = *depth;
938 } else {
939 break;
940 }
941 }
942
943 let truncated: Vec<_> = traces
944 .into_iter()
945 .scan(0, |depth, (func_id, instruction_counter)| {
946 if func_id >= 0 {
947 *depth += 1;
948 Some((*depth, func_id, instruction_counter))
949 } else {
950 *depth -= 1;
951 Some((*depth + 1, func_id, instruction_counter))
952 }
953 })
954 .filter(|(depth, _, _)| *depth <= depth_to_truncate)
955 .map(|(_, func_id, instruction_counter)| (func_id, instruction_counter))
956 .collect();
957
958 truncated
959}