Elapsed time logger

Drop impl new time Instant

While working on the Rust Digger I wanted to be able to collect and display the elapsed time of the varous processes.

Partially I waned this to be able to profile the code and make improvements where it will make the most impact, and partially just to show it.

There are a number of code-profilers for Rust and at one point I am going to use them on the project, but after writing about Drop, the destructor of Rust structs I figured I'd like to see if I can use it to make it easier to implement this.

This is my first implementation:

examples/elapsed-time-logger/src/main.rs

struct ElapsedTimer {
    name: String,
    start: std::time::Instant,
}

impl Drop for ElapsedTimer {
    fn drop(&mut self) {
        let end = std::time::Instant::now();
        let elapsed = end - self.start;
        println!("ENDED {} {}", self.name, elapsed.as_millis());
    }
}

impl ElapsedTimer {
    pub fn new(name: &str) -> Self {
        let timer = Self {
            name: name.to_owned(),
            start: std::time::Instant::now(),
        };
        println!("START {}", timer.name);
        timer
    }
}
fn main() {
    println!("Start");
    do_something(100);
    println!("End");
}


fn do_something(millis: u64) {
    let _a = ElapsedTimer::new("do_something");
    std::thread::sleep(std::time::Duration::from_millis(millis))
}

Here in any function, or for that matter in any block I can create a variable (with a leading underscore as we won't really use the variable) to be an instance of the ElapsedTime struct. The new method of the crate (which would be called the constructor or initializer if we used the OOP lingo) stores the string we passed to it aling with the current time. It also prints to the screen that we "START" the function.

Then when the variable goes out of scope - when the code leaves the enclosing block - the drop method is called that checks the time again, computes the elapsed time and displays that with the word "ENDED" and the name we stored earlier.

Logging

Naturally instead of simply pritning to the screen we could use a logger crate to log the value or we could save it in some special file that can be later analyzed or displayed on a web page.

Other crates

Once I implemented this I thought I should publish it on Crates.io and I was wondering what should be the name.

function-timer seemed to be the obvious choice, but as you can see it already exists and if I am not mistaken it tries to solve the same problem in a nicer way. I am going to look into that crate later.

Author

Gabor Szabo (szabgab)

Gabor Szabo, the author of the Rust Maven web site maintains several Open source projects in Rust and while he still feels he has tons of new things to learn about Rust he already offers training courses in Rust and still teaches Python, Perl, git, GitHub, GitLab, CI, and testing.

Gabor Szabo