Mar 8 2012

A Timing Utility

Sundial with apple, found by the Loudoun Museum in Leesburg, VA Timing how long a block of code takes is a useful tool. Maybe you’re choosing between two different calls that do similar things and you’re wondering which one is faster. If one is faster, is it faster-enough to make any difference? The usual techniques involve using a profiler like Instruments, or calling a time function like gettimeofday() before and after your code and calculating the delta. Those of us on mach-based systems like iOS and OS X can use mach_absolute_time(), which is the finest-grained timepiece available on the system.

mach_absolute_time() returns a count. But you don’t know what units that count is in. How do you figure out the units? mach_timebase_info() will fill in a structure with the values you can use to scale mach_absolute_time()‘s counter, yielding nanoseconds – billionths of a second. If you want seconds, you can divide nanoseconds by the constant NSEC_PER_SEC (one billion). NSEC_PER_SEC is easier to read than making sure that a division by 100000000 has enough zeroes in it.

That’s all well and good, but kind of tedious. Wouldn’t it be great if you could say “yo, time this block for me”, then you put your interesting code in the block. Here is a little utility, based on some code from a couple of years ago that does just that.

So how do you use it? Say you were timing to see which takes longer, isEqual: or isEqualToString:. Put a loop that makes the call inside of a block, and time it:

Running gives you some timings:

% ./compare-time
isEqual: time: 0.635283
isEqualToString: time: 0.593058

As you’ll see in a later post, you can start making informed decisions from this test, and from other tests.

Edit: Advanced iOS Instructor Jonathan Blocksom has put the code into a gist: https://gist.github.com/2006587.

Have a passion for profiling and performance? Our Advanced Mac OS X and Advanced iOS Bootcamps feature sections on performance tuning and Apple’s Instruments performance tools.

8 Comments

  1. relikd

    or change the method to get rid of the extra logging line:

    void BNRTimeBlock (const char* ident, void (^block)(void)) {
    …
    printf (“[%s] time: %f\n”, ident, time);
    }

    usage:

    BNRTimeBlock(“myTest”, ^{
    // do something
    });

  2. Mark Dalrymple

    I don’t like that as much – you can’t aggregate timings across a couple of timing invocations because it locks you into always logging the result, which you might not always want to do.

  3. John Mclaughlin

    Thanks… I was this close (imagine my fingers almost touching) to doing this exact thing yesterday so i’m glad I stumbled upon this.

    I find this sort of caveman debugging quite useful

    Safe to say I’ve bookmarked this page…

  4. Mark Dalrymple

    Caveman debugging is totally underrated. I was amazed at the number of Industry Luminaries in Coders at Work who admitted to it.

  5. Mike Abdullah

    Any chance of throwing this up as a Gist on GitHub or something similar? Would be great for us for working with it.

  6. Marc Respass

    Mark, this has been incredibly helpful to me. I’ve been working through some code trying to improve the performance from the UI side. Our application is complex but I’ve been using BNRTimeBlock to narrow down exactly where the bottle necks are. Using this block, I’ve found that things are not where I sometimes think. Thanks a lot!

Leave a Comment

Join the discussion. Do not worry, your email address will not be published.

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <strike> <strong>