#![allow(clippy::cast_precision_loss)]
use std::time::Duration;
#[cfg(not(target_arch = "wasm32"))]
use std::time::Instant;
use humantime::format_duration;
use log::info;
#[cfg(feature = "profiling")]
use log::{debug, error};
use serde_derive::Serialize;
#[cfg(feature = "profiling")]
use sysinfo::{Pid, ProcessRefreshKind, ProcessesToUpdate, System};
#[cfg(target_arch = "wasm32")]
use wasm_bindgen::prelude::*;
#[cfg(target_arch = "wasm32")]
#[wasm_bindgen]
pub fn get_high_res_time() -> f64 {
use web_sys::js_sys::Reflect;
let global = web_sys::js_sys::global();
let performance = Reflect::get(&global, &"performance".into())
.ok()
.and_then(|v: JsValue| v.dyn_into::<web_sys::Performance>().ok());
match performance {
Some(perf) => perf.now(),
None => 0.0,
}
}
#[derive(Serialize)]
pub struct ExecutionStatistics {
pub max_memory_usage: u64,
pub max_plans_in_flight: u64,
pub max_plan_queue_memory_in_use: u64,
pub cpu_time: Duration,
pub wall_time: Duration,
}
#[cfg(feature = "profiling")]
#[cfg_attr(target_arch = "wasm32", allow(dead_code))]
const REFRESH_INTERVAL: Duration = Duration::from_secs(1);
#[cfg(feature = "profiling")]
#[cfg_attr(target_arch = "wasm32", allow(dead_code))]
pub(crate) struct ExecutionProfilingCollector {
#[cfg(not(target_arch = "wasm32"))]
start_time: Instant,
#[cfg(target_arch = "wasm32")]
start_time: f64,
#[cfg(not(target_arch = "wasm32"))]
last_refresh: Instant,
#[cfg(target_arch = "wasm32")]
last_refresh: f64,
start_cpu_time: u64,
max_memory_usage: u64,
system: System,
process_id: Option<Pid>,
}
#[cfg(feature = "profiling")]
impl ExecutionProfilingCollector {
pub fn new() -> ExecutionProfilingCollector {
let process_id = sysinfo::get_current_pid().ok();
#[cfg(target_arch = "wasm32")]
let now = get_high_res_time();
#[cfg(not(target_arch = "wasm32"))]
let now = Instant::now();
let mut new_stats = ExecutionProfilingCollector {
start_time: now,
last_refresh: now,
start_cpu_time: 0,
max_memory_usage: 0,
system: System::new(),
process_id,
};
if let Some(process_id) = process_id {
debug!("Process ID: {}", process_id);
let process_refresh_kind = ProcessRefreshKind::nothing().with_cpu().with_memory();
new_stats.update_system_info(process_refresh_kind);
let process = new_stats.system.process(process_id).unwrap();
new_stats.max_memory_usage = process.memory();
new_stats.start_cpu_time = process.accumulated_cpu_time();
}
new_stats
}
#[inline]
pub fn refresh(&mut self) {
#[cfg(not(target_arch = "wasm32"))]
if self.last_refresh.elapsed() >= REFRESH_INTERVAL {
self.poll_memory();
self.last_refresh = Instant::now();
}
}
#[cfg_attr(target_arch = "wasm32", allow(dead_code))]
fn poll_memory(&mut self) {
if let Some(pid) = self.process_id {
self.update_system_info(ProcessRefreshKind::nothing().with_memory());
let process = self.system.process(pid).unwrap();
self.max_memory_usage = self.max_memory_usage.max(process.memory());
}
}
#[allow(unused)]
pub fn cpu_time(&mut self) -> u64 {
if let Some(process_id) = self.process_id {
self.update_system_info(ProcessRefreshKind::nothing().with_cpu());
let process = self.system.process(process_id).unwrap();
process.accumulated_cpu_time() - self.start_cpu_time
} else {
0
}
}
#[inline]
fn update_system_info(&mut self, process_refresh_kind: ProcessRefreshKind) {
if let Some(pid) = self.process_id {
if self.system.refresh_processes_specifics(
ProcessesToUpdate::Some(&[pid]),
true,
process_refresh_kind,
) < 1
{
error!("could not refresh process statistics");
}
}
}
pub fn compute_final_statistics(&mut self) -> ExecutionStatistics {
let mut cpu_time_millis = 0;
if let Some(pid) = self.process_id {
self.update_system_info(ProcessRefreshKind::nothing().with_cpu().with_memory());
let process = self.system.process(pid).unwrap();
self.max_memory_usage = self.max_memory_usage.max(process.memory());
cpu_time_millis = process.accumulated_cpu_time() - self.start_cpu_time;
}
let cpu_time = Duration::from_millis(cpu_time_millis);
#[cfg(target_arch = "wasm32")]
let wall_time = get_high_res_time() - self.start_time;
#[cfg(not(target_arch = "wasm32"))]
let wall_time = self.start_time.elapsed();
#[cfg(target_arch = "wasm32")]
let wall_time = Duration::from_millis(wall_time as u64);
ExecutionStatistics {
max_memory_usage: self.max_memory_usage,
max_plans_in_flight: 0,
max_plan_queue_memory_in_use: 0,
cpu_time,
wall_time,
}
}
}
#[cfg(not(feature = "profiling"))]
pub(crate) struct ExecutionProfilingCollector {
#[cfg(not(target_arch = "wasm32"))]
start_time: Instant,
#[cfg(target_arch = "wasm32")]
start_time: f64,
}
#[cfg(not(feature = "profiling"))]
impl ExecutionProfilingCollector {
pub fn new() -> ExecutionProfilingCollector {
#[cfg(target_arch = "wasm32")]
let now = get_high_res_time();
#[cfg(not(target_arch = "wasm32"))]
let now = Instant::now();
ExecutionProfilingCollector { start_time: now }
}
#[inline]
pub fn refresh(&mut self) {}
pub fn compute_final_statistics(&mut self) -> ExecutionStatistics {
#[cfg(target_arch = "wasm32")]
let wall_time = get_high_res_time() - self.start_time;
#[cfg(not(target_arch = "wasm32"))]
let wall_time = self.start_time.elapsed();
#[cfg(target_arch = "wasm32")]
let wall_time = Duration::from_millis(wall_time as u64);
ExecutionStatistics {
max_memory_usage: 0,
max_plans_in_flight: 0,
max_plan_queue_memory_in_use: 0,
cpu_time: Duration::ZERO,
wall_time,
}
}
}
pub fn print_execution_statistics(summary: &ExecutionStatistics) {
println!("━━━━ Execution Summary ━━━━");
if summary.max_memory_usage == 0 {
println!("Memory and CPU statistics are not available on your platform.");
} else {
#[cfg(feature = "profiling")]
{
println!(
"{:<25}{}",
"Max memory usage:",
bytesize::ByteSize::b(summary.max_memory_usage)
);
println!(
"{:<25}{}",
"Max plans in flight:", summary.max_plans_in_flight
);
println!(
"{:<25}{}",
"Max plan queue memory:",
bytesize::ByteSize::b(summary.max_plan_queue_memory_in_use)
);
println!("{:<25}{}", "CPU time:", format_duration(summary.cpu_time));
}
}
println!("{:<25}{}", "Wall time:", format_duration(summary.wall_time));
}
pub fn log_execution_statistics(stats: &ExecutionStatistics) {
info!("Execution complete.");
if stats.max_memory_usage == 0 {
info!("Memory and CPU statistics are not available on your platform.");
} else {
#[cfg(feature = "profiling")]
{
info!(
"Max memory usage: {}",
bytesize::ByteSize::b(stats.max_memory_usage)
);
info!("Max plans in flight: {}", stats.max_plans_in_flight);
info!(
"Max plan queue memory: {}",
bytesize::ByteSize::b(stats.max_plan_queue_memory_in_use)
);
info!("CPU time: {}", format_duration(stats.cpu_time));
}
}
info!("Wall time: {}", format_duration(stats.wall_time));
}
#[cfg(all(test, feature = "profiling"))]
mod tests {
use std::thread;
use std::time::Duration;
use super::*;
#[test]
fn test_collector_initialization() {
let collector = ExecutionProfilingCollector::new();
assert!(collector.max_memory_usage > 0);
}
#[test]
fn test_refresh_respects_interval() {
let mut collector = ExecutionProfilingCollector::new();
let before = collector.max_memory_usage;
collector.refresh();
let after = collector.max_memory_usage;
assert_eq!(before, after);
thread::sleep(Duration::from_secs(2));
collector.refresh();
assert!(collector.max_memory_usage >= before);
}
#[test]
fn test_compute_final_statistics_structure() {
let mut collector = ExecutionProfilingCollector::new();
thread::sleep(Duration::from_millis(100));
let stats = collector.compute_final_statistics();
assert!(stats.max_memory_usage > 0);
assert_eq!(stats.max_plans_in_flight, 0);
assert_eq!(stats.max_plan_queue_memory_in_use, 0);
assert!(stats.wall_time > Duration::ZERO);
}
#[test]
fn test_cpu_time_increases_over_time() {
let mut collector = ExecutionProfilingCollector::new();
let start = Instant::now();
while start.elapsed().as_millis() < 30u128 {
std::hint::black_box(0); }
let cpu_time_1 = collector.cpu_time();
let start = Instant::now();
while start.elapsed().as_millis() < 50u128 {
std::hint::black_box(0); }
let cpu_time_2 = collector.cpu_time();
assert!(cpu_time_2 > cpu_time_1);
}
}