Skip to content

Commit

Permalink
feat: make duration macros more flexible
Browse files Browse the repository at this point in the history 
Changes:

 * Moves the duration macros into new module crate::macros
 * adds macros duration_info!, duration_debug!,
   duration_async_info!, and duration_async_debug!
 * duration! and duration_async! now use log-level TRACE by default.
 * adds an optional message string to each macro.
 * adds tests to ensure that each usage variant will compile.

In total, the caller can now:
 *  log duration to trace, debug, info log-levels
 *  include an optional descriptive message.
  • Loading branch information
@dan-da
dan-da committed Apr 9, 2024
1 parent 0869f4c commit e61ef78
Show file tree
Hide file tree
Showing 3 changed files with 212 additions and 31 deletions.
31 changes: 1 addition & 30 deletions src/lib.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ pub mod config_models;
pub mod connect_to_peers;
pub mod database;
pub mod locks;
pub mod macros;
pub mod main_loop;
pub mod mine_loop;
pub mod models;
Expand Down Expand Up @@ -289,36 +290,6 @@ where
(output, total_time)
}

#[macro_export]
macro_rules! log_duration {
($args: expr) => {{
let (output, duration) = $crate::time_fn_call(|| $args);
tracing::debug!(
"at {}:{}\n-- executed expression --\n{}\n -- duration: {} secs --",
file!(),
line!(),
stringify!($args),
duration
);
output
}};
}

#[macro_export]
macro_rules! log_duration_async {
($args: expr) => {{
let (output, duration) = $crate::time_fn_call_async({ $args }).await;
tracing::debug!(
"at {}:{}\n-- executed async expression --\n{}\n -- duration: {} secs --",
file!(),
line!(),
stringify!($args),
duration
);
output
}};
}

/// Converts a UTC millisecond timestamp (millis since 1970 UTC) into
/// a `DateTime<Local>`, ie local-time.
pub fn utc_timestamp_to_localtime<T>(timestamp: T) -> DateTime<Local>
Expand Down
210 changes: 210 additions & 0 deletions src/macros.rs
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,210 @@
/// executes an expression, times duration, and emits trace! message
///
/// The trace level is `tracing::Level::TRACE` by default.
///
/// Accepts arguments in 3 forms:
/// duration!(myfunc())
/// duration!(myfunc(), message)
/// duration!(myfunc(), message, trace_level)
#[allow(unused_macros)]
macro_rules! duration {
($target: expr, $message: expr, $lvl: expr) => {{
let (output, duration) = $crate::time_fn_call(|| $target);
let msg = format!(
"at {}:{}{}\n-- executed expression --\n{}\n -- duration: {} secs --",
file!(),
line!(),
if $message.len() > 0 {
format! {"\n{}", $message}
} else {
"".to_string()
},
stringify!($target),
duration
);
match $lvl {
tracing::Level::INFO => tracing::info!("{}", msg),
tracing::Level::TRACE => tracing::trace!("{}", msg),
tracing::Level::DEBUG => tracing::trace!("{}", msg),
tracing::Level::WARN => tracing::warn!("{}", msg),
tracing::Level::ERROR => tracing::error!("{}", msg),
}
output
}};
($target: expr, $message: expr) => {
$crate::macros::duration!($target, $message, tracing::Level::TRACE)
};
($target: expr) => {
$crate::macros::duration!($target, "", tracing::Level::TRACE)
};
}

/// executes an expression, times duration, and emits info! message
///
/// Accepts arguments in 2 forms:
/// duration!(myfunc())
/// duration!(myfunc(), message)
#[allow(unused_macros)]
macro_rules! duration_info {
($target: expr) => {
$crate::macros::duration!($target, "", tracing::Level::INFO)
};
($target: expr, $message: expr) => {
$crate::macros::duration!($target, $message, tracing::Level::INFO)
};
}

/// executes an expression, times duration, and emits debug! message
///
/// Accepts arguments in 2 forms:
/// duration!(myfunc())
/// duration!(myfunc(), message)
#[allow(unused_macros)]
macro_rules! duration_debug {
($target: expr) => {
$crate::macros::duration!($target, "", tracing::Level::DEBUG)
};
($target: expr, $message: expr) => {
$crate::macros::duration!($target, $message, tracing::Level::DEBUG)
};
}

/// executes an async expression, times duration, and emits trace! message
///
/// Accepts arguments in 3 forms:
/// duration!(myfunc())
/// duration!(myfunc(), message)
/// duration!(myfunc(), message, trace_level)
#[allow(unused_macros)]
macro_rules! duration_async {
($target: expr, $message: expr, $lvl: expr) => {{
let (output, duration) = $crate::time_fn_call_async({ $target }).await;
let msg = format!(
"at {}:{}{}\n-- executed expression --\n{}\n -- duration: {} secs --",
file!(),
line!(),
if $message.len() > 0 {
format! {"\n{}", $message}
} else {
"".to_string()
},
stringify!($target),
duration
);
match $lvl {
tracing::Level::INFO => tracing::info!("{}", msg),
tracing::Level::TRACE => tracing::trace!("{}", msg),
tracing::Level::DEBUG => tracing::trace!("{}", msg),
tracing::Level::WARN => tracing::warn!("{}", msg),
tracing::Level::ERROR => tracing::error!("{}", msg),
}
output
}};
($target: expr, $message: expr) => {
$crate::macros::duration_async!($target, $message, tracing::Level::TRACE)
};
($target: expr) => {
$crate::macros::duration_async!($target, "", tracing::Level::TRACE)
};
}

/// executes an async expression, times duration, and emits info! message
///
/// Accepts arguments in 2 forms:
/// duration!(myfunc())
/// duration!(myfunc(), message)
#[allow(unused_macros)]
macro_rules! duration_async_info {
($target: expr) => {
$crate::macros::duration_async!($target, "", tracing::Level::INFO)
};
($target: expr, $message: expr) => {
$crate::macros::duration_async!($target, $message, tracing::Level::INFO)
};
}

/// executes an async expression, times duration, and emits debug! message
///
/// Accepts arguments in 2 forms:
/// duration!(myfunc())
/// duration!(myfunc(), message)
#[allow(unused_macros)]
macro_rules! duration_async_debug {
($target: expr) => {
$crate::macros::duration_async!($target, "", tracing::Level::DEBUG)
};
($target: expr, $message: expr) => {
$crate::macros::duration_async!($target, $message, tracing::Level::DEBUG)
};
}

// These allow the macros to be used as
// use crate::macros::xxxxx;
//
// see: https://stackoverflow.com/a/67140319/10087197

#[allow(unused_imports)]
pub(crate) use duration;
#[allow(unused_imports)]
pub(crate) use duration_async;
#[allow(unused_imports)]
pub(crate) use duration_async_debug;
#[allow(unused_imports)]
pub(crate) use duration_async_info;
#[allow(unused_imports)]
pub(crate) use duration_debug;
#[allow(unused_imports)]
pub(crate) use duration_info;

#[cfg(test)]
mod test {

use super::*;
use tracing::Level;

fn fibonacci(n: u32) -> u32 {
match n {
0 => 1,
1 => 1,
_ => fibonacci(n - 1) + fibonacci(n - 2),
}
}

async fn fibonacci_async(n: u32) -> u32 {
match n {
0 => 1,
1 => 1,
_ => fibonacci(n - 1) + fibonacci(n - 2),
}
}

#[test]
fn duration_tests() {
duration!(fibonacci(1));
duration!(fibonacci(2), "fibonacci - 2".to_string());
duration!(fibonacci(3), "fibonacci - 3", Level::INFO);

duration_info!(fibonacci(4));
duration_info!(fibonacci(5), "fibonacci - 5");
duration_info!(fibonacci(6), "fibonacci - 6".to_string());

duration_debug!(fibonacci(7));
duration_debug!(fibonacci(8), "fibonacci - 8");
duration_debug!(fibonacci(9), "fibonacci - 9".to_string());
}

#[tokio::test]
async fn duration_async_tests() {
duration_async!(fibonacci_async(1));
duration_async!(fibonacci_async(2), "fibonacci_async - 2".to_string());
duration_async!(fibonacci_async(3), "fibonacci_async - 3", Level::INFO);

duration_async_info!(fibonacci_async(4));
duration_async_info!(fibonacci_async(5), "fibonacci_async - 5");
duration_async_info!(fibonacci_async(6), "fibonacci_async - 6".to_string());

duration_async_debug!(fibonacci_async(7));
duration_async_debug!(fibonacci_async(8), "fibonacci_async - 8");
duration_async_debug!(fibonacci_async(9), "fibonacci_async - 9".to_string());
}
}
2 changes: 1 addition & 1 deletion src/models/state/mod.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1186,7 +1186,7 @@ impl GlobalState {
Ok(())
}

crate::log_duration_async!(store_block_internal_worker(
crate::macros::duration_async_info!(store_block_internal_worker(
self,
new_block,
coinbase_utxo_info
Expand Down

0 comments on commit e61ef78

Please sign in to comment.