Time Profiler Instrument

February 17th, 2016

Filed under: Instruments | Be the first to comment!

In this article I cover the Time Profiler instrument and how to find slow spots in your code with it.

I’m using the version of Instruments that ships with Xcode 7. If you are using an earlier version of Xcode, some things may look different and some features may be unavailable. If you are new to Instruments, read my Getting Started with Instruments article.

Profiling Your Application

Take the following steps to profile your application with the Time Profiler instrument:

  1. Choose Product > Profile in Xcode to profile your project.
  2. A window with a list of templates opens in Instruments.
  3. Select the Time Profiler template from the list.
  4. Click the Choose button.
  5. Click the Record button to start profiling.

Examining the Results

When you pause profiling the Time Profiler instrument shows the call tree view in the detail view. The call tree view helps to find the slow spots in your code. Going to the display settings and selecting the Invert Call Tree and Hide System Libraries checkboxes makes finding your code in the call tree view easier. The following screenshot shows a typical call tree view when inverting the call tree:

TimeProfilerCallTree

For each function in the call tree view, Instruments tells you the running time in milliseconds and the percentage of running time. The Time Profiler instrument works by recording the call stack every millisecond. The Running Time column shows you the amount of time the function was in the call stack along with the percentage of time the function was in the call stack.

The Self column tells you the number of milliseconds the function is at the top of the call stack. When a function is at the top of the call stack, the application was in that function when Instruments recorded the sample. If a function has a high value in the Self column, that function is a prime candidate for optimization.

If you look at the screenshot of the call tree view, you’ll notice every function has a value of 0.0 in the Self column. What’s the slowest function in the list? The slowest code path is the second listing, the function Wordlist.load() -> (). When you invert the call tree, Instruments shows code paths, sorting them by running time from slowest to fastest.

What about the main listing? It has the highest running time, but the main function is the starting point of most Mac and iOS applications. It’s going to be on the call stack the whole time your application runs. In most Mac and iOS applications the main function has little code in it, usually a call to NSApplicationMain or UIApplicationMain. There’s not going to be any code for you to optimize in main so don’t worry about what its listing in the call tree view says.

Showing Alternate Graph Data

Initially the Time Profiler graph shows CPU usage. If you move the mouse cursor over the graph timeline, a tooltip pops up that shows the percentage of the CPU used at that moment. The Time Profiler instrument has two other pieces of graph data you can see. You can change the data in the graph using the set of three buttons next to the Add button in the toolbar.

TimeProfilerGraphSelectionButtons

Clicking the left button shows the CPU usage for each CPU core.

TimeProfilerCPUCoreGraph

If you move the mouse cursor over the graph timeline, tooltips pop up showing the percentage of each CPU core being used along with the total CPU usage. The CPU core view lets you see how well your application uses each CPU core. If one CPU core has a high usage percentage and the other cores have a low percentage, that’s a sign of a possible performance problem.

Clicking the right button shows the thread data.

TimeProfilerThreadGraph

The thread data graph has blue dots. Each blue dot represents a sample the Time Profiler instrument took during the trace. Clicking a blue dot opens a popover that shows the call stack for that particular sample.

In the screenshots of the CPU core data and thread data, Instruments shows all the cores and threads. If you want to focus on one CPU core or one thread, click the appropriate button above the graph and choose the CPU core or thread you want to see.

TimeProfilerCPUCoreAndThreadSelector

Comparing Call Trees

If you profile your application with the Time Profiler instrument multiple times, you can compare the call trees by choosing Instrument > Compare Call Trees. The following screenshot shows what the call tree view looks like when comparing two call trees:

TimeProfilerCompareCallTrees

Instead of showing the total running time, Instruments shows the difference in running time between the two runs along with a percentage of the difference. Functions with a higher running time have the percentage colored red, and functions with a lower running time have the percentage colored green. The difference in running time is from the perspective of the most recent run.

Above the call tree statistics are two menus. The left menu is initially set to Diff, which means Instruments shows the differences between the two call trees. You can also choose Merge, which merges the two call trees in one listing. The right menu lets you choose an Instruments run to compare. You’ll need at least three runs to use the right menu.

UPDATE

Apple removed the Compare Call Trees feature in Xcode 9. The Compare Call Trees menu item is disabled in Xcode 9 and is removed in Xcode 10.


Leave a Reply

Your email address will not be published. Required fields are marked *