diff --git a/Cargo.lock b/Cargo.lock index 82ba6cf7e..8563496f1 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -320,6 +320,25 @@ dependencies = [ "windows-sys 0.61.0", ] +[[package]] +name = "context_manager" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "728d71fd281b0ea795f0515222004c2a95ae640dab7fd905b7f9a549a1f8fd66" +dependencies = [ + "context_manager_macro", +] + +[[package]] +name = "context_manager_macro" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8090038efdbf72a77e0b9355618143912186cf2335d9747920a2bd72b0b08ee5" +dependencies = [ + "quote", + "syn", +] + [[package]] name = "convert_case" version = "0.8.0" @@ -916,6 +935,7 @@ dependencies = [ "clap", "clap-markdown", "colored 3.1.1", + "context_manager", "csv", "derive_more", "dirs", diff --git a/Cargo.toml b/Cargo.toml index ec6c75eea..7b6634bba 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -36,6 +36,7 @@ documented = "0.9.2" dirs = "6.0.0" edit = "0.1.5" erased-serde = "0.4.10" +context_manager = "0.1.3" [dev-dependencies] assert_cmd = "2.2.2" diff --git a/src/lib.rs b/src/lib.rs index f3501fe43..bcfd1543f 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -42,6 +42,7 @@ pub mod region; pub mod settings; pub mod simulation; pub mod time_slice; +pub mod timeit; pub mod units; #[cfg(test)] diff --git a/src/simulation.rs b/src/simulation.rs index 99050a8ef..cf8080f2a 100644 --- a/src/simulation.rs +++ b/src/simulation.rs @@ -4,8 +4,10 @@ use crate::model::Model; use crate::output::DataWriter; use crate::process::ProcessMap; use crate::simulation::prices::{Prices, calculate_prices}; +use crate::timeit::TimingContext; use crate::units::Capacity; use anyhow::{Context, Result}; +use context_manager; use log::info; use std::path::Path; use std::rc::Rc; @@ -158,6 +160,7 @@ pub fn run(model: &Model, output_path: &Path, debug_model: bool) -> Result<()> { } // Run dispatch to get flows and prices for a milestone year +#[context_manager::wrap(TimingContext)] fn run_dispatch_for_year( model: &Model, assets: &[AssetRef], diff --git a/src/simulation/investment.rs b/src/simulation/investment.rs index dbe7267ff..89c2cb21f 100644 --- a/src/simulation/investment.rs +++ b/src/simulation/investment.rs @@ -8,8 +8,10 @@ use crate::output::DataWriter; use crate::region::RegionID; use crate::simulation::prices::Prices; use crate::time_slice::{TimeSliceID, TimeSliceInfo, TimeSliceLevel, TimeSliceSelection}; +use crate::timeit::TimingContext; use crate::units::{ActivityPerCapacity, Capacity, Dimensionless, Flow, FlowPerCapacity}; use anyhow::{Result, ensure}; +use context_manager; use indexmap::IndexMap; use itertools::Itertools; use log::{debug, warn}; @@ -43,6 +45,7 @@ pub type AllDemandMap = IndexMap<(CommodityID, RegionID, TimeSliceID), Flow>; /// /// The assets selected (including retained commissioned assets) for the given planning `year` or an /// error. +#[context_manager::wrap(TimingContext)] pub fn perform_agent_investment( model: &Model, year: u32, diff --git a/src/timeit.rs b/src/timeit.rs new file mode 100644 index 000000000..8bcc429b5 --- /dev/null +++ b/src/timeit.rs @@ -0,0 +1,26 @@ +//! Implement a context manager for timing the decorated function +use context_manager::{CallerContext, SyncWrapContext}; +use log::info; +use std::time::Instant; + +/// Context for time a function call +pub struct TimingContext { + start: Instant, +} + +impl SyncWrapContext for TimingContext { + fn new() -> Self { + Self { + start: Instant::now(), + } + } + + fn after(self, caller_context: &CallerContext, _result: &T) { + let elapsed = self.start.elapsed(); + info!( + "[Timer] '{}' completed in {:.3}ms", + caller_context.fn_name(), + elapsed.as_secs_f64() * 1000.0, + ); + } +}