1
  2
  3
  4
  5
  6
  7
  8
  9
 10
 11
 12
 13
 14
 15
 16
 17
 18
 19
 20
 21
 22
 23
 24
 25
 26
 27
 28
 29
 30
 31
 32
 33
 34
 35
 36
 37
 38
 39
 40
 41
 42
 43
 44
 45
 46
 47
 48
 49
 50
 51
 52
 53
 54
 55
 56
 57
 58
 59
 60
 61
 62
 63
 64
 65
 66
 67
 68
 69
 70
 71
 72
 73
 74
 75
 76
 77
 78
 79
 80
 81
 82
 83
 84
 85
 86
 87
 88
 89
 90
 91
 92
 93
 94
 95
 96
 97
 98
 99
100

/// print the time that executing some expression took
/// but only when relevant according to log level.
///
/// The goal of this macro is to avoid doing useless
/// `Instant::now`.
///
/// Arguments:
/// - log level, optional (default is `Debug`)
/// - a category, optional (only if name is set)
/// - a name, optional (stringified expression is used by default)
/// - the expression whose duration we want to log depending on the level
///
/// Examples:
///
/// ```
/// #[macro_use] extern crate log;
/// #[macro_use] extern crate cli_log;
/// # fn do_stuff(arg: usize) -> Result<usize, String> {
/// #    Ok(arg)
/// # }
/// # fn main() -> Result<(), String> {
/// let result = time!(do_stuff(4));
/// let result = time!(Debug, do_stuff(3))?;
/// let result = time!("World creation", do_stuff(7));
/// let sum = time!(Debug, "summing", 2 + 2);
/// let sum = time!(Debug, "summing", 2 + 2);
/// let mult = time!("operations", "mult 4", 3 * 4);
/// let mult = time!(Info, "operations", "mult 4", 3 * 4);
/// # Ok(())
/// # }
/// ```
#[macro_export]
macro_rules! time {
    ($timed: expr $(,)?) => {{
        use log::Level::*;
        if log_enabled!(Debug) {
            let start = std::time::Instant::now();
            let value = $timed;
            log!(Debug, "{} took {:?}", stringify!($timed), start.elapsed());
            value
        } else {
            $timed
        }
    }};
    ($level: ident, $timed: expr $(,)?) => {{
        use log::Level::*;
        if log_enabled!($level) {
            let start = std::time::Instant::now();
            let value = $timed;
            log!($level, "{} took {:?}", stringify!($timed), start.elapsed());
            value
        } else {
            $timed
        }
    }};
    ($name: expr, $timed: expr $(,)?) => {{
        use log::Level::*;
        if log_enabled!(Debug) {
            let start = std::time::Instant::now();
            let value = $timed;
            log!(Debug, "{} took {:?}", $name, start.elapsed());
            value
        } else {
            $timed
        }
    }};
    ($level: ident, $name: expr, $timed: expr $(,)?) => {{
        use log::Level::*;
        if log_enabled!($level) {
            let start = std::time::Instant::now();
            let value = $timed;
            log!($level, "{} took {:?}", $name, start.elapsed());
            value
        } else {
            $timed
        }
    }};
    ($cat: expr, $name :expr,  $timed: expr $(,)?) => {{
        use log::Level::*;
        if log_enabled!(Debug) {
            let start = std::time::Instant::now();
            let value = $timed;
            log!(Debug, "{} on {:?} took {:?}", $cat, $name, start.elapsed());
            value
        } else {
            $timed
        }
    }};
    ($level: ident, $cat: expr, $name :expr,  $timed: expr $(,)?) => {{
        use log::Level::*;
        if log_enabled!($level) {
            let start = std::time::Instant::now();
            let value = $timed;
            log!($level, "{} on {:?} took {:?}", $cat, $name, start.elapsed());
            value
        } else {
            $timed
        }
    }};
}