Understanding the Instruments Time Profiler column headings

Question

I'm running an application through the profiler with a sampling rate of 1 ms, but I'm having trouble understanding what the column headers mean. The documentation seems to be lacking the definitions for most of the columns headings, though I managed to decipher Self, # Self and Self % from the answer here. This is what I have so far:

• Total Samples: The total number of (1 ms) samples where the program was in a given function
• Total Time: The total time spent in a function (corresponds to total samples using a 1ms sampling rate)
• Self: Explained in the linked question, but how does it differ from total time? I should be able to figure out the meaning of # Self and Self % from this.
• Total %: Total samples as a percentage of the total running time

The rest of the column headings seem to combinations of the above (perhaps due to the 1ms sampling rate) or are self-explanatory. For example, I have a function that takes 647621ms of total time (89.4%), but has a Self/# Self of 9. Does that mean the function is called often, but takes little time to execute? On the other hand, another function takes 15559ms of total time (2.1%) but Self/# Self is 13099, which would mean that it is called less often, but takes much longer to complete. Am I on the right track?

Answer 1

Recent versions of Instruments don't have a Total Samples column, but I'll explain the difference between total samples, total time, and self because it explains how the Time Profiler instrument works. The Time Profiler instrument records the call stack periodically, every millisecond by default. The Total Samples column tells you the number of samples a method was in the call stack. The Total Time column tells you the amount of time the method was in the call stack. The Self column tells you the number of samples a method was at the top of the call stack, which means your app was in the method when Instruments recorded the sample.

The Self column is much more important than the Total Samples and Total Time columns. Your main() function is going to have a high total samples count and high total time because main() is in the call stack the entire time your application is running. But spending time optimizing the main() function in a Cocoa/Cocoa Touch application is a waste of time because all main() does is launch the application. Focus on methods that have a high Self value.

Recent versions of Instruments have a Running Time column. Each listing in the column has two values: a time and a percentage. The time corresponds to the Total Time in your question. The percentage corresponds to the Total % in your question.

UPDATE

Let me answer the question on your function examples in the last paragraph. Your application isn't spending much time inside the function in your first example (I'll call it Function A) because its Self entry is only 9. That means there were only 9 samples where your application was inside Function A. The high total time means your application spent a lot of time inside functions that Function A calls. Function A is in the call stack often, but not at the top of the call stack often.

In your second example the application is spending more time in the function, Function B, because its Self entry is 13099. The application does not spend a lot of time in functions that Function B calls because the total time is much smaller. Function B is at the top of the call stack more often than A and in the call stack less often than A. If you had a performance issue in your application, Function B would be the function to examine for ways to improve its performance. Optimizing Function A would not help much because its Self entry is only 9.