I recently wanted to measure the speed of something I was doing in an iOS application. I searched for the best way to do this and found two basic approaches.
The first approach is to use date arithmetic. Something like:
NSDate * start = [[NSDate alloc] init];
[NSThread sleepForTimeInterval:1.0]; // Thing to be measured.
NSDate * stop = [[NSDate alloc] init];
NSLog(@”Thing took %f sec”, [stop timeIntervalSinceDate:start]);
Another way to write the same code would be:
NSTimeInterval start = [NSDate timeIntervalSinceReferenceDate];
[NSThread sleepForTimeInterval:1.0]; // Thing to be measured.
NSTimeInterval stop = [NSDate timeIntervalSinceReferenceDate];
NSLog(@”Thing took %f sec”, stop - start);
The problem with the date arithmetic approach is that it uses NSTimeInterval. NSTimeInterval expresses time in seconds with at best “sub-millisecond resolution”, whatever that is. This means that unless you are timing things that execute in many tens, hundreds, or thousands of milliseconds, you won’t get very useful measurements using this approach.
The next approach is to use
mach_absolute_time, which offers the precision I am looking for. Apple has a Technical Q&A on this approach:
QA1398. The problem with QA1398 is that it shows you how to perform the measurement but not how to build a reusable performance timer.
I set out to write a performance timer in Objective-C that would do the job in a simple and reusable way. The class is called PerfTimer.
Here’s the PerfTimer.h file:
//
// PerfTimer.h
//
// No copyright. No rights reserved.
//
#import <Foundation/Foundation.h>
// PerfTimer interface.
@interface PerfTimer : NSObject
// Starts or restarts the perf timer.
- (void)start;
// Captures the perf timer.
- (void)capture;
// Returns the elapsed time in nanoseconds of the last capture.
- (UInt64)nsElapsed;
// Returns the elapsed time in milliseconds of the last capture.
- (UInt32)msElapsed;
// Returns a string representation of the last capture.
- (NSString *)stringWithElapsedTime;
@end
Here’s the PerfTimer.m file:
//
// PerfTimer.m
//
// No copyright. No rights reserved.
//
#import “PerfTimer.h”
#include <mach/mach.h>
#include <mach/mach_time.h>
// PerfTimer implementation.
@implementation PerfTimer
{
@private
// The absolute to nanosecond conversion factor.
volatile long double factor_;
// The started absolute time.
volatile UInt64 started_;
// The capture absolute time.
volatile UInt64 capture_;
}
// Class initializer.
- (id)init
{
// Initialize superclass.
self = [super init];
// Handle errors.
if (!self)
{
return nil;
}
// Precalculate the absolute time to nanosecond conversion factor as it
// only needs to be done once.
mach_timebase_info_data_t info;
mach_timebase_info(&info);
factor_ = ((long double)info.numer) / ((long double)info.denom);
// Done.
return self;
}
// Starts or restarts the perf timer.
- (void)start;
{
started_ = mach_absolute_time();
capture_ = 0ULL;
}
// Captures the perf timer.
- (void)capture
{
// Get the capture time.
UInt64 capture = mach_absolute_time();
// If the timer was started, set capture time; otherwise, ignore the call.
if (started_)
{
capture_ = capture;
}
}
// Returns the elapsed time in nanoseconds.
- (UInt64)nsElapsed
{
if (!started_ || !capture_)
{
return 0LL;
}
return (UInt64)roundl((long double)(capture_ - started_) * factor_);
}
// Returns the elapsed time in milliseconds.
- (UInt32)msElapsed
{
if (!started_ || !capture_)
{
return 0LL;
}
return (UInt32)roundl((long double)(capture_ - started_) * factor_ / 1000000.0L);
}
// Returns a string containing a representation of the elapsed time.
- (NSString *)stringWithElapsedTime
{
// Allocate a number formatter and initialize it with the decimal style.
NSNumberFormatter * formatter = [[NSNumberFormatter alloc] init];
[formatter setNumberStyle:NSNumberFormatterDecimalStyle];
// Obtain the elapsed ns.
UInt64 nsElapsed = [self nsElapsed];
// Format the elapsed ns. This will always be returned.
NSString * nsElapsedString = [formatter stringFromNumber:[NSNumber numberWithLongLong:nsElapsed]];
// If the elapsed ns is < 1 ms, just return the elapsed ns.
if (nsElapsed < 1000000ULL)
{
return [NSString stringWithFormat:@"[%@ ns]“, nsElapsedString];
}
// Format the elapsed ms.
NSString * msElapsedString = [formatter stringFromNumber:[NSNumber numberWithLong:[self msElapsed]]];
// Done.
return [NSString stringWithFormat:@"[%@ ms] [%@ ns]“, msElapsedString, nsElapsedString];
}
@end
Here’s an example of how to use it:
// Allocate and initialize the perf timer.
PerfTimer * perfTimer = [[PerfTimer alloc] init];
// Measure sleeping 1/2 second.
[perfTimer start];
[NSThread sleepForTimeInterval:0.5];
[perfTimer capture];
NSLog(@" Sleep 1/2 second: %@", [perfTimer stringWithElapsedTime]);
// Measure sleeping 1 second.
[perfTimer start];
[NSThread sleepForTimeInterval:1.0];
[perfTimer capture];
NSLog(@" Sleep 1 second: %@", [perfTimer stringWithElapsedTime]);
// Measure sleeping 4.6 seconds.
[perfTimer start];
[NSThread sleepForTimeInterval:4.6];
[perfTimer capture];
NSLog(@" Sleep 4.6 seconds: %@", [perfTimer stringWithElapsedTime]);
Here’s the output:
PerfTimer[15551:707] Sleep 1/2 second: [501 ms] [500,621,412 ns]
PerfTimer[15551:707] Sleep 1 second: [1,001 ms] [1,000,748,801 ns]
PerfTimer[15551:707] Sleep 4.6 seconds: [4,601 ms] [4,601,025,431 ns]
One of the useful things about this class is that you can allocate one instance of it and use it over and over again to measure segments of your code by calling -start / -capture around the segments to be measured.
It’s also useful in cases where it will be called serially by different threads. An example of this would be allocating and starting a PerfTimer in the main part of a method and then subsequently calling capture on it in a block that is executed when an asynchronous operation completes.
Here’s an example:
// Allocate and initialize the perf timer.
PerfTimer * urlPerfTimer = [[PerfTimer alloc] init];
// Allocate and initalize the URL request.
NSURLRequest * urlRequest = [NSURLRequest requestWithURL:[NSURL URLWithString:@"http://google.com"]
cachePolicy:NSURLCacheStorageNotAllowed
timeoutInterval:60.0];
// Perform the URL request asynchronously using an NSURLConnection.
[urlPerfTimer start];
[NSURLConnection sendAsynchronousRequest:urlRequest
queue:_operationQueue
completionHandler:^(NSURLResponse * urlResponse, NSData * data, NSError * error)
{
if (!error)
{
[urlPerfTimer capture];
NSLog(@"Google took: %@", [urlPerfTimer stringWithElapsedTime]);
}
}];
The result of this was:
PerfTimer[15700:4003] Google took: [167 ms] [166,984,916 ns]
(Which, BTW, is damn fast!)
As it is, this class is useful when the overhead of passing the -start and -capture messages to an instance of it is inconsequential relative to the time it takes to perform the thing being measured. On my system, an empty -start -capture pair measures out at ~50 ns.
Here’s an example:
[perfTimer start];
[perfTimer capture];
NSLog(@"Empty start/capture: %@", [perfTimer stringWithElapsedTime]);
[perfTimer start];
[perfTimer capture];
NSLog(@"Empty start/capture: %@", [perfTimer stringWithElapsedTime]);
[perfTimer start];
[perfTimer capture];
NSLog(@"Empty start/capture: %@", [perfTimer stringWithElapsedTime]);
[perfTimer start];
[perfTimer capture];
NSLog(@"Empty start/capture: %@", [perfTimer stringWithElapsedTime]);
The output of this code is:
PerfTimer[19189:403] Empty start/capture: [45 ns]
PerfTimer[19189:403] Empty start/capture: [53 ns]
PerfTimer[19189:403] Empty start/capture: [55 ns]
PerfTimer[19189:403] Empty start/capture: [45 ns]
The overhead of passing -start and -capture messages to an instance of PerfTimer biases its results. Measuring this overhead and calibrating the results the class returns should improve its accuracy.
Happy coding!
Brian