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 {}