Sometimes, silly small things about code I write just delight me. There are lots of ways to time things in R. 1 Tools like
microbenchmark are great for profiling code, but what I do all the time is log how long database queries that are scheduled to run each night are taking.
It is really easy to use calls to
difftime when working interactively, but I didn’t want to pepper all of my code with the same log statements all over the place. So instead, I wrote a function.
Almost all of
timing is straightforward to even a novice R user. I record what time it is using
Sys.time, do a little formatting work to make things look the way I want for reading logs, and pass in an optional message.
The form of
timing was easy for me to sketch out: 2
The thing I needed to learn when I wrote
timing a few years back was how to fill in
# Call my function here.
Did you know that you can pass a function as an argument in another function in R? I had been using
*apply with its
FUN argument all over the place, but never really thought about it until I wrote
timing. Of course in R you can pass a function name, and I even know how to pass arguments to that function– just like
apply, just declare a function with the magical
... and pass that along to the fucntion being passed in.
So from there, it was clear to see how I’d want my function declartion to look. It would definitely have the form
function(f, ..., msg = ''), where
f was some function and
... were the arguments for that function. What I didn’t know was how to properly call that function. Normally, I’d write something like
mean(...), but I don’t know what
f is in this case!
As it turns out, the first thing I tried worked, much to my surprise. R actually makes this super easy– you can just write
f will be replaced with whatever the argument is to
f! This just tickles me. It’s stupid elegant to my eyes.
Now I can monitor the run time of any function by wrapping it in
timing. For example:
And here’s an example of the output from a job that ran this morning:
tictocis new to me, but I’m glad it is. I would have probably never written the code in this post if it existed, and then I would be sad and this blog post wouldn’t exist. ↩︎
Yes, I realize that having the calls to
start_timetechnically add those calls to the stack of stuff being timed and both of those things could occur after function execution. For my purposes, the timing does not have to be nearly that precise and the timing of those functions will contribute virtually nothing. So I opted for what I think is the clearer style of code as well as ensuring that live monitoring would inform me of what’s currently running. ↩︎