hookshot uses Objective C runtime hooks to help you understand where your app is spending its time.
Dig into your application activity visually:
or drill in on stats:
$ bin/profile.py
Using /Users/robbywalker/Library/Application Support/iPhone Simulator/6.0/Applications/C1FB13C1-C230-4435-8A10-F7BED5A6B475/Documents/profile-23274
message calls ownTime avgOwn maxOwn total
AppDelegate.doSomethingExpensive 27 562.433ms 20.8309ms 21.1630ms 562.433ms
UIWebView.webView:decidePolicyForNavigationAction:request:frame:decisionListener: 2 19.480ms 9.7400ms 19.4440ms 20.110ms
UIWebView._webViewCommonInitWithWebView:scalesPageToFit:shouldEnableReachability: 1 11.725ms 11.7250ms 11.7250ms 12.780ms
AppDelegate.application:didFinishLaunchingWithOptions: 1 7.913ms 7.9130ms 7.9130ms 25.179ms
...
We'll say it again: hookshot uses undocumented Apple APIs. This is necessary for profiling and debugging, but will get your application rejected during App Store review if hookshot makes it in to production code. Follow the installation instructions to ensure hookshot is properly configured to be one big NOOP for release builds.
hookshot contains an instrumenting profiler. Contrary to its name, Apple's profiler in Instruments is actually a sampling profiler. We find both useful for different occasions. Specifically, we find hookshot most useful for:
-
Thread activity graphs with drill-in
-
Seeing accurate counts of calls
-
More precise per-call timings of messages
-
Measurement of messages with highly variable performance
hookshot also contains utilities for counting live instances of classes you care about and generic message instrumentation.
You can get hookshot in your project within about 5 minutes: step-by-step installation instructions
hookshot provides a whitelist based instrumenting profiler. You can use it to time critical parts of your code and identify bottlenecks.
Once you've installed hookshot in your project and run it, you can start exploring your data.
Early in your application's run, you can instrument any classes you want to measure performance of:
HOOKSHOT_PROFILE_CLASS([AppDelegate class]);
HOOKSHOT_PROFILE_CLASS([UIWebView class]);
HOOKSHOT_PROFILE_CLASS_EXCEPT([AnotherClass class],
[NSValue valueWithPointer:@selector(someFrequentlyCalledSelector)],
[NSValue valueWithPointer:@selector(anotherFrequentlyCalledSelector)])
You can omit messages you know are called frequently where you suspect profiling overhead will distort your results.
/bin/profile.py will analyze your latest profile data dump and summarize it:
$ bin/profile.py
Using /Users/robbywalker/Library/Application Support/iPhone Simulator/6.0/Applications/C1FB13C1-C230-4435-8A10-F7BED5A6B475/Documents/profile-23274
message calls ownTime avgOwn maxOwn total
AppDelegate.doSomethingExpensive 27 562.433ms 20.8309ms 21.1630ms 562.433ms
UIWebView.webView:decidePolicyForNavigationAction:request:frame:decisionListener: 2 19.480ms 9.7400ms 19.4440ms 20.110ms
UIWebView._webViewCommonInitWithWebView:scalesPageToFit:shouldEnableReachability: 1 11.725ms 11.7250ms 11.7250ms 12.780ms
AppDelegate.application:didFinishLaunchingWithOptions: 1 7.913ms 7.9130ms 7.9130ms 25.179ms
UIWebView.webView:didFinishLoadForFrame: 1 3.458ms 3.4580ms 3.4580ms 3.473ms
UIWebView._updateViewSettings 3 2.327ms 0.7757ms 1.7870ms 2.430ms
AppDelegate.applicationDidBecomeActive: 2 1.825ms 0.9125ms 1.8250ms 522.812ms
UIWebView._updateRequest 3 0.548ms 0.1827ms 0.5250ms 0.548ms
UIWebView.initWithCoder: 1 0.448ms 0.4480ms 0.4480ms 14.090ms
UIWebView.webView:decidePolicyForMIMEType:request:frame:decisionListener: 1 0.335ms 0.3350ms 0.3350ms 0.335ms
UIWebView._edgeExpressionInContainer:vertical:max: 4 0.289ms 0.0722ms 0.0990ms 0.397ms
...
We can see here that our example expensive method is, in fact, expensive.
A summary of your command line options is always available with bin/profile.py -h but we'll cover the most interesting ones here.
The summary is pulled from the latest profile file to be written by your Simulator. You can also run on a device and extract the Applications' data directory to your Desktop. The rest works automatically.
You can override the default smart-find functionality if you want:
bin/profile.py <pid>
will find a dump file (in the Simulator directory or recursively from your Desktop) called profile-<pid> and use that.
bin/profile.py --server
Once the server is running, open localhost:8020 to view a graphical representation of thread activity.
Hovering over a bar will show what call it represents. Clicking on any given call will replace that call by the timings of any other instrumented methods it called.
We have found this extremely useful for finding subtle performance bugs caused by thread interactions. For example, it will become obvious if and when the main thread is blocking on other threads and why.
You can sort profiled messages by --ownTime (the default), --calls count, --average time per call,
--total time per call, or --max time for a single call.
For example:
$ bin/profile.py --total
Using /Users/robbywalker/Library/Application Support/iPhone Simulator/6.0/Applications/C1FB13C1-C230-4435-8A10-F7BED5A6B475/Documents/profile-23274
message calls ownTime avgOwn maxOwn total
AppDelegate.doSomethingExpensive 27 562.433ms 20.8309ms 21.1630ms 562.433ms
AppDelegate.applicationDidBecomeActive: 2 1.825ms 0.9125ms 1.8250ms 522.812ms
AppDelegate.application:didFinishLaunchingWithOptions: 1 7.913ms 7.9130ms 7.9130ms 25.179ms
UIWebView.webView:decidePolicyForNavigationAction:request:frame:decisionListener: 2 19.480ms 9.7400ms 19.4440ms 20.110ms
UIWebView.initWithCoder: 1 0.448ms 0.4480ms 0.4480ms 14.090ms
...
You can filter by thread:
$ bin/profile.py --thread WebThread
Using /Users/robbywalker/Library/Application Support/iPhone Simulator/6.0/Applications/C1FB13C1-C230-4435-8A10-F7BED5A6B475/Documents/profile-23274
message calls ownTime avgOwn maxOwn total
UIWebView.webView:resource:canAuthenticateAgainstProtectionSpace:forDataSource: 3 0.055ms 0.0183ms 0.0280ms 0.055ms
by message regex:
$ bin/profile.py --message '.*did'
Using /Users/robbywalker/Library/Application Support/iPhone Simulator/6.0/Applications/C1FB13C1-C230-4435-8A10-F7BED5A6B475/Documents/profile-23274
message calls ownTime avgOwn maxOwn total
AppDelegate.application:didFinishLaunchingWithOptions: 1 7.913ms 7.9130ms 7.9130ms 25.179ms
UIWebView.webView:didFinishLoadForFrame: 1 3.458ms 3.4580ms 3.4580ms 3.473ms
UIWebView._didMoveFromWindow:toWindow: 1 0.212ms 0.2120ms 0.2120ms 0.261ms
UIWebView.nsis_valueOfVariable:didChangeInEngine: 4 0.130ms 0.0325ms 0.0400ms 0.232ms
UIWebView.webView:resource:didFinishLoadingFromDataSource: 12 0.100ms 0.0083ms 0.0140ms 0.100ms
UIWebView.webView:didStartProvisionalLoadForFrame: 1 0.062ms 0.0620ms 0.0620ms 0.587ms
UIWebView.view:didSetFrame:oldFrame: 2 0.056ms 0.0280ms 0.0370ms 2.029ms
UIWebView.webView:didFirstLayoutInFrame: 2 0.023ms 0.0115ms 0.0130ms 0.023ms
UIWebView.webView:didReceiveServerRedirectForProvisionalLoadForFrame: 1 0.018ms 0.0180ms 0.0180ms 0.026ms
UIWebView.webView:didClearWindowObject:forFrame: 1 0.016ms 0.0160ms 0.0160ms 0.016ms
UIWebView.webView:didReceiveTitle:forFrame: 1 0.015ms 0.0150ms 0.0150ms 0.015ms
UIWebView.webView:didCommitLoadForFrame: 1 0.010ms 0.0100ms 0.0100ms 0.010ms
UIWebView.didMoveToSuperview 1 0.004ms 0.0040ms 0.0040ms 0.004ms
UIWebView.didAddSubview: 1 0.004ms 0.0040ms 0.0040ms 0.004ms
UIWebView.didMoveToWindow 1 0.003ms 0.0030ms 0.0030ms 0.003ms
or by class:
$ bin/profile.py --class 'AppDelegate'
Using /Users/robbywalker/Library/Application Support/iPhone Simulator/6.0/Applications/C1FB13C1-C230-4435-8A10-F7BED5A6B475/Documents/profile-23274
message calls ownTime avgOwn maxOwn total
AppDelegate.doSomethingExpensive 27 562.433ms 20.8309ms 21.1630ms 562.433ms
AppDelegate.application:didFinishLaunchingWithOptions: 1 7.913ms 7.9130ms 7.9130ms 25.179ms
AppDelegate.applicationDidBecomeActive: 2 1.825ms 0.9125ms 1.8250ms 522.812ms
AppDelegate.isKindOfClass: 4 0.020ms 0.0050ms 0.0060ms 0.020ms
AppDelegate.allocWithZone: 1 0.018ms 0.0180ms 0.0180ms 0.018ms
AppDelegate.setWindow: 1 0.010ms 0.0100ms 0.0100ms 0.010ms
AppDelegate.init 1 0.009ms 0.0090ms 0.0090ms 0.009ms
AppDelegate.window 2 0.006ms 0.0030ms 0.0030ms 0.006ms
AppDelegate.setViewController: 1 0.005ms 0.0050ms 0.0050ms 0.005ms
AppDelegate.viewController 1 0.004ms 0.0040ms 0.0040ms 0.004ms
You can use hookshot to track how many instances of a given class are live.
HOOKSHOT_COUNT_INSTANCES(cls);
It's best to install this hook in your AppDelegate initialize or in the initialize of the class you want to count instances of.
This will result in log messages like:
HookshotDemo[25220:11303] UIImage: 8 (after dealloc)
You can also instance count for C++ classes, but only if they have no super class. You also can't configure this part at runtime - it'll be on when hookshot is built in (Debug builds) and off otherwise.
When you define your class, instead of
class ClassName {
...
}write
HOOKSHOT_COUNTED_CPP_CLASS(X) {
...
}In your implementation file, at the top, add:
HOOKSHOT_COUNTED_CPP_CLASS_IMPLEMENTATION_PREAMBLE(ClassName)
The above features are built on top of a generic capability for instance message instrumentation defined in Classes/CCInstanceMessageInstrumentation.h
We'd love to hear what (non-production!) uses you find for it.
-
hookshot can not instrument messages with templated C++ response types. hookshot will automatically detect these messages and not instrument them, and warn you about them in logs.
-
hookshot crashes when instrumenting messages with varargs. hookshot cannot detect these messages and ignore them, so you will have to use
PROFILE_CLASS_EXCEPTorPREVENT_INSTRUMENTATIONto work around this.
We know there is a lot more that can be done to build great tools so we can all write more performant applications.
We're always happy to receive pull requests!
Copyright 2012 The hookshot Authors.
Published under The Apache License, see LICENSE