diagnostics: split into their own file
This commit is contained in:
92
crates/coremem/src/diagnostics.rs
Normal file
92
crates/coremem/src/diagnostics.rs
Normal file
@@ -0,0 +1,92 @@
|
|||||||
|
use std::sync::{Arc, Mutex};
|
||||||
|
use std::time::{Duration, Instant};
|
||||||
|
|
||||||
|
pub struct Diagnostics {
|
||||||
|
frames_completed: u64,
|
||||||
|
time_spent_stepping: Duration,
|
||||||
|
time_spent_on_stimuli: Duration,
|
||||||
|
time_spent_prepping_render: Duration,
|
||||||
|
time_spent_blocked_on_render: Duration,
|
||||||
|
time_spent_rendering: Duration,
|
||||||
|
start_time: Instant,
|
||||||
|
}
|
||||||
|
|
||||||
|
#[derive(Clone)]
|
||||||
|
pub struct SyncDiagnostics(Arc<Mutex<Diagnostics>>);
|
||||||
|
|
||||||
|
impl Diagnostics {
|
||||||
|
pub fn new() -> Self {
|
||||||
|
Self {
|
||||||
|
frames_completed: 0,
|
||||||
|
time_spent_stepping: Default::default(),
|
||||||
|
time_spent_on_stimuli: Default::default(),
|
||||||
|
time_spent_prepping_render: Default::default(),
|
||||||
|
time_spent_blocked_on_render: Default::default(),
|
||||||
|
time_spent_rendering: Default::default(),
|
||||||
|
start_time: Instant::now(),
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
pub fn format(&self) -> String {
|
||||||
|
let step_time = self.time_spent_stepping.as_secs_f64();
|
||||||
|
let stim_time = self.time_spent_on_stimuli.as_secs_f64();
|
||||||
|
let render_time = self.time_spent_rendering.as_secs_f64();
|
||||||
|
let render_prep_time = self.time_spent_prepping_render.as_secs_f64();
|
||||||
|
let block_time = self.time_spent_blocked_on_render.as_secs_f64();
|
||||||
|
let overall_time = self.start_time.elapsed().as_secs_f64();
|
||||||
|
let fps = (self.frames_completed as f64) / overall_time;
|
||||||
|
format!("fps: {:6.2} (sim: {:.1}s, stim: {:.1}s, [render: {:.1}s], blocked: {:.1}s, render_prep: {:.1}s, other: {:.1}s)",
|
||||||
|
fps,
|
||||||
|
step_time,
|
||||||
|
stim_time,
|
||||||
|
render_time,
|
||||||
|
block_time,
|
||||||
|
render_prep_time,
|
||||||
|
overall_time - step_time - stim_time - block_time - render_prep_time,
|
||||||
|
)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
impl SyncDiagnostics {
|
||||||
|
pub fn new() -> Self {
|
||||||
|
Self(Arc::new(Mutex::new(Diagnostics::new())))
|
||||||
|
}
|
||||||
|
pub fn format(&self) -> String {
|
||||||
|
self.0.lock().unwrap().format()
|
||||||
|
}
|
||||||
|
/// measure the duration of some arbitrary chunk of code.
|
||||||
|
/// used internally.
|
||||||
|
pub fn measure<F: FnOnce()>(f: F) -> Duration {
|
||||||
|
let start = Instant::now();
|
||||||
|
f();
|
||||||
|
start.elapsed()
|
||||||
|
}
|
||||||
|
|
||||||
|
/// record the duration of the sim step operation.
|
||||||
|
pub fn instrument_step<F: FnOnce()>(&self, frames: u64, f: F) {
|
||||||
|
let elapsed = Self::measure(f);
|
||||||
|
let mut me = self.0.lock().unwrap();
|
||||||
|
me.time_spent_stepping += elapsed;
|
||||||
|
me.frames_completed += frames as u64;
|
||||||
|
}
|
||||||
|
|
||||||
|
/// record the duration spent preparing for render (i.e. cloning stuff and moving it into a
|
||||||
|
/// render pool).
|
||||||
|
pub fn instrument_render_prep<F: FnOnce()>(&self, f: F) {
|
||||||
|
let elapsed = Self::measure(f);
|
||||||
|
self.0.lock().unwrap().time_spent_prepping_render += elapsed;
|
||||||
|
}
|
||||||
|
|
||||||
|
/// record the duration actually spent doing CPU render work
|
||||||
|
pub fn instrument_render_cpu_side<F: FnOnce()>(&self, f: F) {
|
||||||
|
let elapsed = Self::measure(f);
|
||||||
|
self.0.lock().unwrap().time_spent_rendering += elapsed;
|
||||||
|
}
|
||||||
|
|
||||||
|
/// record the duration spent blocking the simulation because the render queue is full.
|
||||||
|
pub fn instrument_render_blocked<F: FnOnce()>(&self, f: F) {
|
||||||
|
let elapsed = Self::measure(f);
|
||||||
|
self.0.lock().unwrap().time_spent_blocked_on_render += elapsed;
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
@@ -1,3 +1,4 @@
|
|||||||
|
use crate::diagnostics::SyncDiagnostics;
|
||||||
use crate::geom::{Coord, Index, Meters, Region};
|
use crate::geom::{Coord, Index, Meters, Region};
|
||||||
use crate::mat;
|
use crate::mat;
|
||||||
use crate::meas::{self, AbstractMeasurement};
|
use crate::meas::{self, AbstractMeasurement};
|
||||||
@@ -10,9 +11,9 @@ use crate::stim::{self, AbstractStimulus};
|
|||||||
use log::{info, trace};
|
use log::{info, trace};
|
||||||
use serde::{Deserialize, Serialize};
|
use serde::{Deserialize, Serialize};
|
||||||
use std::path::PathBuf;
|
use std::path::PathBuf;
|
||||||
use std::sync::{Arc, Mutex};
|
use std::sync::Arc;
|
||||||
use std::sync::mpsc::{sync_channel, SyncSender, Receiver};
|
use std::sync::mpsc::{sync_channel, SyncSender, Receiver};
|
||||||
use std::time::{Duration, Instant};
|
use std::time::Instant;
|
||||||
use threadpool::ThreadPool;
|
use threadpool::ThreadPool;
|
||||||
|
|
||||||
pub struct Driver<S> {
|
pub struct Driver<S> {
|
||||||
@@ -29,95 +30,6 @@ pub struct Driver<S> {
|
|||||||
last_diag_time: Instant,
|
last_diag_time: Instant,
|
||||||
}
|
}
|
||||||
|
|
||||||
struct Diagnostics {
|
|
||||||
frames_completed: u64,
|
|
||||||
time_spent_stepping: Duration,
|
|
||||||
time_spent_on_stimuli: Duration,
|
|
||||||
time_spent_prepping_render: Duration,
|
|
||||||
time_spent_blocked_on_render: Duration,
|
|
||||||
time_spent_rendering: Duration,
|
|
||||||
start_time: Instant,
|
|
||||||
}
|
|
||||||
|
|
||||||
#[derive(Clone)]
|
|
||||||
struct SyncDiagnostics(Arc<Mutex<Diagnostics>>);
|
|
||||||
|
|
||||||
impl Diagnostics {
|
|
||||||
fn new() -> Self {
|
|
||||||
Self {
|
|
||||||
frames_completed: 0,
|
|
||||||
time_spent_stepping: Default::default(),
|
|
||||||
time_spent_on_stimuli: Default::default(),
|
|
||||||
time_spent_prepping_render: Default::default(),
|
|
||||||
time_spent_blocked_on_render: Default::default(),
|
|
||||||
time_spent_rendering: Default::default(),
|
|
||||||
start_time: Instant::now(),
|
|
||||||
}
|
|
||||||
}
|
|
||||||
|
|
||||||
fn format(&self) -> String {
|
|
||||||
let step_time = self.time_spent_stepping.as_secs_f64();
|
|
||||||
let stim_time = self.time_spent_on_stimuli.as_secs_f64();
|
|
||||||
let render_time = self.time_spent_rendering.as_secs_f64();
|
|
||||||
let render_prep_time = self.time_spent_prepping_render.as_secs_f64();
|
|
||||||
let block_time = self.time_spent_blocked_on_render.as_secs_f64();
|
|
||||||
let overall_time = self.start_time.elapsed().as_secs_f64();
|
|
||||||
let fps = (self.frames_completed as f64) / overall_time;
|
|
||||||
format!("fps: {:6.2} (sim: {:.1}s, stim: {:.1}s, [render: {:.1}s], blocked: {:.1}s, render_prep: {:.1}s, other: {:.1}s)",
|
|
||||||
fps,
|
|
||||||
step_time,
|
|
||||||
stim_time,
|
|
||||||
render_time,
|
|
||||||
block_time,
|
|
||||||
render_prep_time,
|
|
||||||
overall_time - step_time - stim_time - block_time - render_prep_time,
|
|
||||||
)
|
|
||||||
}
|
|
||||||
}
|
|
||||||
|
|
||||||
impl SyncDiagnostics {
|
|
||||||
fn new() -> Self {
|
|
||||||
Self(Arc::new(Mutex::new(Diagnostics::new())))
|
|
||||||
}
|
|
||||||
fn format(&self) -> String {
|
|
||||||
self.0.lock().unwrap().format()
|
|
||||||
}
|
|
||||||
/// measure the duration of some arbitrary chunk of code.
|
|
||||||
/// used internally.
|
|
||||||
fn measure<F: FnOnce()>(f: F) -> Duration {
|
|
||||||
let start = Instant::now();
|
|
||||||
f();
|
|
||||||
start.elapsed()
|
|
||||||
}
|
|
||||||
|
|
||||||
/// record the duration of the sim step operation.
|
|
||||||
fn instrument_step<F: FnOnce()>(&self, frames: u64, f: F) {
|
|
||||||
let elapsed = Self::measure(f);
|
|
||||||
let mut me = self.0.lock().unwrap();
|
|
||||||
me.time_spent_stepping += elapsed;
|
|
||||||
me.frames_completed += frames as u64;
|
|
||||||
}
|
|
||||||
|
|
||||||
/// record the duration spent preparing for render (i.e. cloning stuff and moving it into a
|
|
||||||
/// render pool).
|
|
||||||
fn instrument_render_prep<F: FnOnce()>(&self, f: F) {
|
|
||||||
let elapsed = Self::measure(f);
|
|
||||||
self.0.lock().unwrap().time_spent_prepping_render += elapsed;
|
|
||||||
}
|
|
||||||
|
|
||||||
/// record the duration actually spent doing CPU render work
|
|
||||||
fn instrument_render_cpu_side<F: FnOnce()>(&self, f: F) {
|
|
||||||
let elapsed = Self::measure(f);
|
|
||||||
self.0.lock().unwrap().time_spent_rendering += elapsed;
|
|
||||||
}
|
|
||||||
|
|
||||||
/// record the duration spent blocking the simulation because the render queue is full.
|
|
||||||
fn instrument_render_blocked<F: FnOnce()>(&self, f: F) {
|
|
||||||
let elapsed = Self::measure(f);
|
|
||||||
self.0.lock().unwrap().time_spent_blocked_on_render += elapsed;
|
|
||||||
}
|
|
||||||
}
|
|
||||||
|
|
||||||
impl<S: AbstractSim> Driver<S> {
|
impl<S: AbstractSim> Driver<S> {
|
||||||
pub fn new(state: S) -> Self {
|
pub fn new(state: S) -> Self {
|
||||||
Self {
|
Self {
|
||||||
@@ -266,7 +178,6 @@ impl<S: AbstractSim + Clone + Default + Send + 'static> Driver<S> {
|
|||||||
});
|
});
|
||||||
trace!("step end");
|
trace!("step end");
|
||||||
if self.last_diag_time.elapsed().as_secs_f64() >= 5.0 {
|
if self.last_diag_time.elapsed().as_secs_f64() >= 5.0 {
|
||||||
// TODO: make this a method on the Diagnostics.
|
|
||||||
self.last_diag_time = Instant::now();
|
self.last_diag_time = Instant::now();
|
||||||
let step = self.state.step_no();
|
let step = self.state.step_no();
|
||||||
let diagstr = self.diag.format();
|
let diagstr = self.diag.format();
|
||||||
|
@@ -7,6 +7,7 @@
|
|||||||
|
|
||||||
use log::info;
|
use log::info;
|
||||||
|
|
||||||
|
mod diagnostics;
|
||||||
pub mod driver;
|
pub mod driver;
|
||||||
pub mod geom;
|
pub mod geom;
|
||||||
pub mod meas;
|
pub mod meas;
|
||||||
|
Reference in New Issue
Block a user