ixa/profiling/
mod.rs

1//! This module provides a lightweight, feature-gated profiling interface for simulations.
2//! It tracks event counts and measures elapsed time for named operations ("spans"), and can
3//! export the results to the console and to a JSON file together with execution statistics. It supports:
4//!
5//! - Event counting – track how often named events occur during a run.
6//! - Rate calculation – compute rates (events per second) since the first count.
7//! - Span timing – measure time intervals with automatic closing on drop.
8//! - Coverage – report how much of total runtime is covered by any span via a special
9//!   "Total Measured" span.
10//! - Computed statistics – define custom, derived metrics over collected data.
11//! - A default computed statistic, infection forecasting efficiency.
12//!
13//! Feature flag: all functionality is gated behind the `profiling` feature (enabled by default).
14//! When the feature is disabled, the public API remains available but becomes a no-op and gets
15//! optimized away by the compiler, so you can leave profiling calls in your code at zero cost.
16//!
17//! ## Example console output
18//! ```ignore
19//! Span Label                           Count          Duration  % runtime
20//! ----------------------------------------------------------------------
21//! load_synth_population                    1       950us 792ns      0.36%
22//! infection_attempt                     1035     6ms 33us 91ns      2.28%
23//! sample_setting                        1035     3ms 66us 52ns      1.16%
24//! get_contact                           1035   1ms 135us 202ns      0.43%
25//! schedule_next_forecasted_infection    1286  22ms 329us 102ns      8.44%
26//! Total Measured                        1385  23ms 897us 146ns      9.03%
27//!
28//! Event Label                     Count  Rate (per sec)
29//! -----------------------------------------------------
30//! property progression               36          136.05
31//! recovery                           27          102.04
32//! accepted infection attempt      1,035        3,911.50
33//! forecasted infection            1,286        4,860.09
34//!
35//! Infection Forecasting Efficiency: 80.48%
36//! ```
37//!
38//! ## API functions
39//! - `increment_named_count`
40//! - `open_span`
41//! - `close_span`
42//! - `print_profiling_data`
43//! - `print_named_counts`
44//! - `print_named_spans`
45//! - `print_computed_statistics`
46//! - `add_computed_statistic`
47//!
48//! All of the above functions are no-ops without the `profiling` feature.
49//!
50//! ## Basic usage
51//!
52//! Count an event:
53//! ```rust,ignore
54//! increment_named_count("forecasted infection");
55//! increment_named_count("accepted infection attempt");
56//! ```
57//!
58//! Time an operation:
59//! ```rust,ignore
60//! let span = open_span("forecast loop");
61//! // operation code here (algorithm, function call, etc.)
62//! close_span(span); // optional; dropping the span also closes it
63//! ```
64//!
65//! You can also rely on RAII to auto-close a span at the end of scope:
66//! ```rust,ignore
67//! fn complicated_function() {
68//!     let _span = open_span("complicated function");
69//!     // Complicated control flow here, maybe with lots of `return` points.
70//! } // `_span` goes out of scope, automatically closed.
71//! ```
72//!
73//! Printing results to the console:
74//! ```rust,ignore
75//! // Call after the simulation completes
76//! print_profiling_data();
77//! ```
78//! Prints spans, counts, and any computed statistics via the functions
79//! `print_named_spans()`, `print_named_counts()`, `print_computed_statistics()`,
80//! which you can use individually if you prefer.
81//!
82//! Writing results to JSON together with execution statistics:
83//! ```rust,ignore
84//! use ixa::Context; // your simulation context
85//! use crate::profiling::ProfilingContextExt;
86//!
87//! fn finalize(mut context: Context) {
88//!     // Ensure Params::profiling_data_path is set, and report options specify
89//!     // output_dir/file_prefix/overwrite. This writes a pretty JSON file with:
90//!     //   date_time, execution_statistics, named_counts, named_spans, computed_statistics
91//!     context.write_profiling_data();
92//! }
93//! ```
94//!
95//! Special names and coverage
96//! - Spans may overlap or nest. The sum of all individual span durations will not
97//!   generally equal total runtime. A special span named `"Total Measured"` is open
98//!   if and only if any other span is open. It tells you how much of the total running
99//!   time is covered by some span.
100//!
101//! ## Computed statistics
102//!
103//! You can register custom computed statistics that derive values from the current
104//! `ProfilingData`. Use `add_computed_statistic(label, description, computer, printer)`
105//! to add one. The relevant API is:
106//!
107//! ```rust, ignore
108//! // Not exactly as implemented for technical reasons.
109//! pub fn add_computed_statistic(
110//!     // The label used in the profiling JSON file
111//!     label: &'static str,
112//!     /// Description of the statistic. Used in the JSON report.
113//!     description: &'static str,
114//!     /// A function that takes a reference to the `ProfilingData` and computes a value
115//!     computer: CustomStatisticComputer,
116//!     /// A function that prints the computed value to the console.
117//!     printer: CustomStatisticPrinter,
118//! );
119//!
120//! pub type CustomStatisticComputer<T> =
121//!     Box<dyn (Fn(&ProfilingData) -> Option<T>) + Send + Sync>;
122//! pub type CustomStatisticPrinter<T> = Box<dyn (Fn(T)) + Send + Sync>;
123//!
124//! // The "computer" gets an immutable reference to all counts and spans and to the start time.
125//! pub fn add_computed_statistic<T: ComputableType>(
126//!     label: &'static str,
127//!     description: &'static str,
128//!     computer: CustomStatisticComputer<T>,
129//!     printer: CustomStatisticPrinter<T>,
130//! )
131//! ```
132//!
133//! The "computer" returns an option for cases when a statistic is only conditionally
134//! defined. The "printer" takes the computed value and prints it to the console.
135//!
136//! Computed statistics are printed by `print_computed_statistics()` and included in the
137//! JSON report under `computed_statistics` (with label, description, and value).
138//!
139//!
140//! Example of using `"forecasted infection"` and `"accepted infection attempt"`.
141//! ```rust,ignore
142//! context.add_plan(next_time, move |context| {
143//!     increment_named_count("forecasted infection");
144//!     if evaluate_forecast(context, person, forecasted_total_infectiousness) {
145//!         if let Some(setting_id) = context.get_setting_for_contact(person) {
146//!             if let Some(next_contact) = infection_attempt(context, person, setting_id) {
147//!                 increment_named_count("accepted infection attempt");
148//!                 context.infect_person(next_contact, Some(person), None, None);
149//!             }
150//!         }
151//!     }
152//!     schedule_next_forecasted_infection(context, person);
153//! });
154//! ```
155#![allow(dead_code)]
156#![allow(unused_imports)]
157
158mod computed_statistic;
159mod data;
160mod display;
161mod file;
162
163use std::path::Path;
164#[cfg(feature = "profiling")]
165use std::time::Instant;
166
167pub use computed_statistic::*;
168pub use data::*;
169pub use display::*;
170use file::write_profiling_data_to_file;
171
172use crate::{error, Context, ContextReportExt};
173
174#[cfg(test)]
175/// Publicly expose access to profiling data only for testing.
176pub fn get_profiling_data() -> std::sync::MutexGuard<'static, ProfilingData> {
177    profiling_data()
178}
179
180// "Magic" constants used in this module
181/// The distinguished total measured time label.
182#[cfg(feature = "profiling")]
183const TOTAL_MEASURED: &str = "Total Measured";
184#[cfg(feature = "profiling")]
185const NAMED_SPANS_HEADERS: &[&str] = &["Span Label", "Count", "Duration", "% runtime"];
186#[cfg(feature = "profiling")]
187const NAMED_COUNTS_HEADERS: &[&str] = &["Event Label", "Count", "Rate (per sec)"];
188
189pub struct Span {
190    #[cfg(feature = "profiling")]
191    label: &'static str,
192    #[cfg(feature = "profiling")]
193    start_time: Instant,
194}
195
196impl Span {
197    fn new(#[allow(unused_variables)] label: &'static str) -> Self {
198        Self {
199            #[cfg(feature = "profiling")]
200            label,
201            #[cfg(feature = "profiling")]
202            start_time: Instant::now(),
203        }
204    }
205}
206
207#[cfg(feature = "profiling")]
208impl Drop for Span {
209    fn drop(&mut self) {
210        let mut container = profiling_data();
211        container.close_span(self);
212    }
213}
214
215/// Writes the execution statistics for the context and all profiling data
216/// to a JSON file.
217pub trait ProfilingContextExt: ContextReportExt {
218    fn write_profiling_data(&mut self) {
219        let (mut prefix, directory, overwrite) = {
220            let report_options = self.report_options();
221            (
222                report_options.file_prefix.clone(),
223                report_options.output_dir.clone(),
224                report_options.overwrite,
225            )
226        };
227
228        let execution_statistics = self.get_execution_statistics();
229        // Default filename when not provided via parameters: write under report options
230        // using the current file prefix.
231        prefix.push_str("profiling.json");
232        let profiling_data_path = directory.join(prefix);
233        let profiling_data_path = Path::new(&profiling_data_path);
234
235        if !overwrite && profiling_data_path.exists() {
236            error!(
237                "profiling output file already exists: {}",
238                profiling_data_path.display()
239            );
240            return;
241        }
242
243        write_profiling_data_to_file(profiling_data_path, execution_statistics)
244            .expect("could not write profiling data to file");
245    }
246}
247impl ProfilingContextExt for Context {}