How to log a method's execution time exactly in milliseconds?

Question

NSDate *methodStart = [NSDate date];

/* ... Do whatever you need to do ... */

NSDate *methodFinish = [NSDate date];
NSTimeInterval executionTime = [methodFinish timeIntervalSinceDate:methodStart];
NSLog(@"executionTime = %f", executionTime);

Swift:

let methodStart = NSDate()

/* ... Do whatever you need to do ... */

let methodFinish = NSDate()
let executionTime = methodFinish.timeIntervalSinceDate(methodStart)
print("Execution time: \(executionTime)")

Swift3:

let methodStart = Date()

/* ... Do whatever you need to do ... */

let methodFinish = Date()
let executionTime = methodFinish.timeIntervalSince(methodStart)
print("Execution time: \(executionTime)")

Easy to use and has sub-millisecond precision.

Here are two one-line macros that I use:

#define TICK   NSDate *startTime = [NSDate date]
#define TOCK   NSLog(@"Time: %f", -[startTime timeIntervalSinceNow])

Use it like this:

TICK;

/* ... Do Some Work Here ... */

TOCK;

For fine-grained timing on OS X, you should use mach_absolute_time( ) declared in <mach/mach_time.h>:

#include <mach/mach_time.h>
#include <stdint.h>

// Do some stuff to setup for timing
const uint64_t startTime = mach_absolute_time();
// Do some stuff that you want to time
const uint64_t endTime = mach_absolute_time();

// Time elapsed in Mach time units.
const uint64_t elapsedMTU = endTime - startTime;

// Get information for converting from MTU to nanoseconds
mach_timebase_info_data_t info;
if (mach_timebase_info(&info))
   handleErrorConditionIfYoureBeingCareful();

// Get elapsed time in nanoseconds:
const double elapsedNS = (double)elapsedMTU * (double)info.numer / (double)info.denom;

Of course the usual caveats about fine-grained measurements apply; you're probably best off invoking the routine under test many times, and averaging/taking a minimum/some other form of processing.

Additionally, please note that you may find it more useful to profile your application running using a tool like Shark. This won't give you exact timing information, but it will tell you what percentage of the application's time is being spent where, which is often more useful (but not always).

There is a convenient wrapper for mach_absolute_time() – it's a CACurrentMediaTime() function.

Unlike NSDate or CFAbsoluteTimeGetCurrent() offsets, mach_absolute_time() and CACurrentMediaTime() are based on the internal host clock, a precise, monatomic measure, and not subject to changes in the external time reference, such as those caused by time zones, daylight savings, or leap seconds.

---

ObjC

CFTimeInterval startTime = CACurrentMediaTime();
// Do your stuff here
CFTimeInterval endTime = CACurrentMediaTime();
NSLog(@"Total Runtime: %g s", endTime - startTime);

Swift

let startTime = CACurrentMediaTime()
// Do your stuff here
let endTime = CACurrentMediaTime()
print("Total Runtime: \(endTime - startTime) s")

In Swift, I'm using:

In my Macros.swift I just added

var startTime = NSDate()
func TICK(){ startTime =  NSDate() }
func TOCK(function: String = __FUNCTION__, file: String = __FILE__, line: Int = __LINE__){
    println("\(function) Time: \(startTime.timeIntervalSinceNow)\nLine:\(line) File: \(file)")
}

you can now just call anywhere

TICK()

// your code to be tracked

TOCK()

Swift 5.0

   var startTime = NSDate()
func TICK(){ startTime =  NSDate() }
func TOCK(function: String = #function, file: String = #file, line: Int = #line){
    print("\(function) Time: \(startTime.timeIntervalSinceNow)\nLine:\(line) File: \(file)")
}

• this code is based on Ron's code translate to Swift, he has the credits
• I'm using start date at global level, any suggestion to improve are welcome

I know this is an old one but even I found myself wandering past it again, so I thought I'd submit my own option here.

Best bet is to check out my blog post on this: Timing things in Objective-C: A stopwatch

Basically, I wrote a class that does stop watching in a very basic way but is encapsulated so that you only need to do the following:

[MMStopwatchARC start:@"My Timer"];
// your work here ...
[MMStopwatchARC stop:@"My Timer"];

And you end up with:

MyApp[4090:15203]  -> Stopwatch: [My Timer] runtime: [0.029]

in the log...

Again, check out my post for a little more or download it here: MMStopwatch.zip