ixa/
execution_stats.rs

1// Loss of precision is allowable in this module's use cases.
2#![allow(clippy::cast_precision_loss)]
3
4use bytesize::ByteSize;
5use humantime::format_duration;
6use log::{debug, error, info};
7use serde_derive::Serialize;
8use std::time::Duration;
9#[cfg(not(target_arch = "wasm32"))]
10use std::time::Instant;
11use sysinfo::{Pid, ProcessRefreshKind, ProcessesToUpdate, System};
12#[cfg(target_arch = "wasm32")]
13use wasm_bindgen::prelude::*;
14#[cfg(target_arch = "wasm32")]
15use web_sys::window;
16
17#[cfg_attr(target_arch = "wasm32", allow(dead_code))]
18/// How frequently we update the max memory used value.
19const REFRESH_INTERVAL: Duration = Duration::from_secs(1);
20
21#[cfg(target_arch = "wasm32")]
22#[wasm_bindgen]
23/// The `wasm` target does not support `std::time::Instant::now()`.
24pub fn get_high_res_time() -> f64 {
25    let perf = window().unwrap().performance().unwrap();
26    perf.now() // Returns time in milliseconds as f64
27}
28
29/// A container struct for computed final statistics. Note that if population size
30/// is zero, then the per person statistics are also zero, as they are meaningless.
31#[derive(Serialize)]
32pub struct ExecutionStatistics {
33    pub max_memory_usage: u64,
34    pub cpu_time: Duration,
35    pub wall_time: Duration,
36
37    // Per person stats
38    pub population: usize,
39    pub cpu_time_per_person: Duration,
40    pub wall_time_per_person: Duration,
41    pub memory_per_person: u64,
42}
43
44#[cfg_attr(target_arch = "wasm32", allow(dead_code))]
45pub(crate) struct ExecutionProfilingCollector {
46    /// Simulation start time, used to compute elapsed wall time for the simulation execution
47    #[cfg(not(target_arch = "wasm32"))]
48    start_time: Instant,
49    #[cfg(target_arch = "wasm32")]
50    start_time: f64,
51    /// We keep track of the last time we refreshed so that client code doesn't have to and can
52    /// just call `ExecutionProfilingCollector::refresh` in its event loop.
53    #[cfg(not(target_arch = "wasm32"))]
54    last_refresh: Instant,
55    #[cfg(target_arch = "wasm32")]
56    last_refresh: f64,
57    /// The accumulated CPU time of the process in CPU-milliseconds at simulation start, used
58    /// to compute the CPU time of the simulation execution
59    start_cpu_time: u64,
60    /// The maximum amount of real memory used by the process as reported by
61    /// `sysinfo::System::process::memory()`. This value is polled during execution to capture the
62    /// max.
63    max_memory_usage: u64,
64    /// A `sysinfo::System` for polling memory use
65    system: System,
66    /// Current process, set to `None` on unsupported platforms, wasm32 in particular
67    process_id: Option<Pid>,
68}
69
70impl ExecutionProfilingCollector {
71    pub fn new() -> ExecutionProfilingCollector {
72        let process_id = sysinfo::get_current_pid().ok();
73        #[cfg(target_arch = "wasm32")]
74        let now = get_high_res_time();
75        #[cfg(not(target_arch = "wasm32"))]
76        let now = Instant::now();
77
78        let mut new_stats = ExecutionProfilingCollector {
79            start_time: now,
80            last_refresh: now,
81            start_cpu_time: 0,
82            max_memory_usage: 0,
83            system: System::new(),
84            process_id,
85        };
86        // Only refreshable on supported platforms.
87        if let Some(process_id) = process_id {
88            debug!("Process ID: {}", process_id);
89            let process_refresh_kind = ProcessRefreshKind::nothing().with_cpu().with_memory();
90            new_stats.update_system_info(process_refresh_kind);
91
92            let process = new_stats.system.process(process_id).unwrap();
93
94            new_stats.max_memory_usage = process.memory();
95            new_stats.start_cpu_time = process.accumulated_cpu_time();
96        }
97
98        new_stats
99    }
100
101    /// If at least `REFRESH_INTERVAL` (1 second) has passed since the previous
102    /// refresh, memory usage is polled and updated. Call this method as frequently
103    /// as you like, as it takes care of limiting polling frequency itself.
104    #[inline]
105    pub fn refresh(&mut self) {
106        #[cfg(not(target_arch = "wasm32"))]
107        if self.last_refresh.elapsed() >= REFRESH_INTERVAL {
108            self.poll_memory();
109            self.last_refresh = Instant::now();
110        }
111    }
112
113    #[cfg_attr(target_arch = "wasm32", allow(dead_code))]
114    /// Updates maximum memory usage. This method should be called about once per second,
115    /// as it is a relatively expensive system call.
116    fn poll_memory(&mut self) {
117        if let Some(pid) = self.process_id {
118            // Only refreshes memory statistics
119            self.update_system_info(ProcessRefreshKind::nothing().with_memory());
120            let process = self.system.process(pid).unwrap();
121            self.max_memory_usage = self.max_memory_usage.max(process.memory());
122        }
123    }
124
125    /// Gives accumulated CPU time of the process in CPU-milliseconds since simulation start.
126    #[allow(unused)]
127    pub fn cpu_time(&mut self) -> u64 {
128        if let Some(process_id) = self.process_id {
129            // Only refresh cpu statistics
130            self.update_system_info(ProcessRefreshKind::nothing().with_cpu());
131
132            let process = self.system.process(process_id).unwrap();
133            process.accumulated_cpu_time() - self.start_cpu_time
134        } else {
135            0
136        }
137    }
138
139    /// Refreshes the internal `sysinfo::System` object for this process using the given
140    /// `ProcessRefreshKind`.
141    #[inline]
142    fn update_system_info(&mut self, process_refresh_kind: ProcessRefreshKind) {
143        if let Some(pid) = self.process_id {
144            if self.system.refresh_processes_specifics(
145                ProcessesToUpdate::Some(&[pid]),
146                true,
147                process_refresh_kind,
148            ) < 1
149            {
150                error!("could not refresh process statistics");
151            }
152        }
153    }
154
155    /// Computes the final summary statistics
156    pub fn compute_final_statistics(&mut self, population: usize) -> ExecutionStatistics {
157        let mut cpu_time_millis = 0;
158
159        if let Some(pid) = self.process_id {
160            // Update both memory and cpu statistics
161            self.update_system_info(ProcessRefreshKind::nothing().with_cpu().with_memory());
162            let process = self.system.process(pid).unwrap();
163
164            self.max_memory_usage = self.max_memory_usage.max(process.memory());
165            cpu_time_millis = process.accumulated_cpu_time() - self.start_cpu_time;
166        }
167
168        // Convert to `Duration`s in preparation for formatting
169        let cpu_time = Duration::from_millis(cpu_time_millis);
170        #[cfg(target_arch = "wasm32")]
171        let wall_time = get_high_res_time() - self.start_time;
172        #[cfg(not(target_arch = "wasm32"))]
173        let wall_time = self.start_time.elapsed();
174
175        // For the per person stats, it's not clear what scale this should be at. Duration can
176        // be constructed from seconds in `f64`, which is probably good enough for our purposes.
177        // For memory, we can just round to the nearest byte.
178
179        let cpu_time_per_person = if population > 0 {
180            Duration::from_secs_f64(cpu_time_millis as f64 / population as f64 / 1000.0)
181        } else {
182            Duration::new(0, 0)
183        };
184        let wall_time_per_person = if population > 0 {
185            #[cfg(not(target_arch = "wasm32"))]
186            let wall_time = wall_time.as_secs_f64();
187            #[cfg(target_arch = "wasm32")]
188            let wall_time = wall_time / 1000.0;
189            Duration::from_secs_f64(wall_time / population as f64)
190        } else {
191            Duration::new(0, 0)
192        };
193        let memory_per_person = if population > 0 {
194            self.max_memory_usage / population as u64
195        } else {
196            0
197        };
198
199        #[cfg(target_arch = "wasm32")]
200        let wall_time = Duration::from_millis(wall_time as u64);
201
202        ExecutionStatistics {
203            max_memory_usage: self.max_memory_usage,
204            cpu_time,
205            wall_time,
206
207            // Per person stats
208            population,
209            cpu_time_per_person,
210            wall_time_per_person,
211            memory_per_person,
212        }
213    }
214}
215
216/// Prints execution statistics to the console.
217///
218/// Use `ExecutionProfilingCollector::compute_final_statistics()` to construct `ExecutionStatistics`.
219pub fn print_execution_statistics(summary: &ExecutionStatistics) {
220    println!("━━━━ Execution Summary ━━━━");
221    if summary.max_memory_usage == 0 {
222        println!("Memory and CPU statistics are not available on your platform.");
223    } else {
224        println!(
225            "{:<25}{}",
226            "Max memory usage:",
227            ByteSize::b(summary.max_memory_usage)
228        );
229        println!("{:<25}{}", "CPU time:", format_duration(summary.cpu_time));
230    }
231
232    println!("{:<25}{}", "Wall time:", format_duration(summary.wall_time));
233
234    if summary.population > 0 {
235        println!("{:<25}{}", "Population:", summary.population);
236        if summary.max_memory_usage > 0 {
237            println!(
238                "{:<25}{}",
239                "Memory per person:",
240                ByteSize::b(summary.memory_per_person)
241            );
242            println!(
243                "{:<25}{}",
244                "CPU time per person:",
245                format_duration(summary.cpu_time_per_person)
246            );
247        }
248        println!(
249            "{:<25}{}",
250            "Wall time per person:",
251            format_duration(summary.wall_time_per_person)
252        );
253    }
254}
255
256/// Logs execution statistics with the logging system.
257///
258/// Use `ExecutionProfilingCollector::compute_final_statistics()` to construct `ExecutionStatistics`.
259pub fn log_execution_statistics(stats: &ExecutionStatistics) {
260    info!("Execution complete.");
261    if stats.max_memory_usage == 0 {
262        info!("Memory and CPU statistics are not available on your platform.");
263    } else {
264        info!("Max memory usage: {}", ByteSize::b(stats.max_memory_usage));
265        info!("CPU time: {}", format_duration(stats.cpu_time));
266    }
267    info!("Wall time: {}", format_duration(stats.wall_time));
268
269    if stats.population > 0 {
270        info!("Population: {}", stats.population);
271        if stats.max_memory_usage > 0 {
272            info!(
273                "Memory per person: {}",
274                ByteSize::b(stats.memory_per_person)
275            );
276            info!(
277                "CPU time per person: {}",
278                format_duration(stats.cpu_time_per_person)
279            );
280        }
281        info!(
282            "Wall time per person: {}",
283            format_duration(stats.wall_time_per_person)
284        );
285    }
286}
287
288#[cfg(test)]
289mod tests {
290    use super::*;
291    use std::{thread, time::Duration};
292
293    #[test]
294    fn test_collector_initialization() {
295        let collector = ExecutionProfilingCollector::new();
296
297        // Ensure that initial max memory usage is non-zero
298        assert!(collector.max_memory_usage > 0);
299    }
300
301    #[test]
302    fn test_refresh_respects_interval() {
303        let mut collector = ExecutionProfilingCollector::new();
304        let before = collector.max_memory_usage;
305
306        // Call refresh immediately — it should not poll
307        collector.refresh();
308        let after = collector.max_memory_usage;
309        assert_eq!(before, after);
310
311        // Sleep enough time to trigger refresh
312        thread::sleep(Duration::from_secs(2));
313        collector.refresh();
314        // Now memory usage should be refreshed — allow it to stay same or increase
315        assert!(collector.max_memory_usage >= before);
316    }
317
318    #[test]
319    fn test_compute_final_statistics_structure() {
320        let mut collector = ExecutionProfilingCollector::new();
321
322        thread::sleep(Duration::from_millis(100));
323        let stats = collector.compute_final_statistics(10);
324
325        // Fields should be non-zero
326        assert!(stats.max_memory_usage > 0);
327        assert!(stats.wall_time > Duration::ZERO);
328        assert_eq!(stats.population, 10);
329    }
330
331    #[test]
332    fn test_zero_population_results() {
333        let mut collector = ExecutionProfilingCollector::new();
334
335        let stats = collector.compute_final_statistics(0);
336
337        assert_eq!(stats.population, 0);
338        assert_eq!(stats.cpu_time_per_person, Duration::ZERO);
339        assert_eq!(stats.wall_time_per_person, Duration::ZERO);
340        assert_eq!(stats.memory_per_person, 0);
341    }
342
343    #[test]
344    fn test_cpu_time_increases_over_time() {
345        let mut collector = ExecutionProfilingCollector::new();
346
347        // Burn ~30ms CPU time. Likely will be < 30ms, as this thread will not have 100% of CPU
348        // during 30ms wall time.
349        let start = Instant::now();
350        while start.elapsed().as_millis() < 30u128 {
351            std::hint::black_box(0); // Prevent optimization
352        }
353
354        let cpu_time_1 = collector.cpu_time();
355
356        // Burn ~50ms CPU time
357        let start = Instant::now();
358        while start.elapsed().as_millis() < 50u128 {
359            std::hint::black_box(0); // Prevent optimization
360        }
361
362        let cpu_time_2 = collector.cpu_time();
363        assert!(cpu_time_2 > cpu_time_1);
364    }
365}