Android developer page: understanding traceview profiling example

Question

I am viewing this page: Profiling with Traceview and dmtracedump

In the "Profile Panel" section, it has the following text, which refers to the result of profiling the sample below the text:

The last column in the table shows the number of calls to this method plus the number of recursive calls. The last column shows the number of calls from the total number of calls made for this method. In this view, we see that there were 14 queries on LoadListener.nativeFinished (); looking at the timeline panel shows that one of these calls took an unusually long time.

I am confused by this description. First, the first two sentences in this quote seem to refer to the same column. So what is the last column? Secondly, I don’t understand where exactly in the “timeline” panel I have to look to see that it “shows that one of these calls took an unusually long time”.

Could you help me sort out this text.

Answer 1

Firstly, the same article states that:

Parents are shown with a purple background, and children with a yellow background

So LoadListener.nativeFinished is the parent function, and all trimmed lines below it are children or functions that the parent called.

Profile Panel

Here is the profile panel clip from the article:

The last column in the table shows the number of calls to this method plus the number of recursive calls.

The last column of the first row (parent) indicates the number of calls and recursive calls made for this function: 14 iterative and 0 recursive calls, separated by a plus sign (14 + 14).

I think the author of the article accidentally has a few words, and as a result, the following line is a bit confusing:

The last column shows the number of calls from the total number of calls made for this method.

In child rows with a yellow background below the parent, the last column does not actually indicate Calls + Rec. Pay attention to the change in notation - a fraction is used compared to the syntax of the plus symbol. In the case of LoadListener.tearDown, 14/14 indicates that LoadListener.tearDown is called by the parent function 14 times. The LoadListener.tearDown function was called a total of 14 times within this trace, so LoadListener.nativeFinished is the only function that called LoadListener.tearDown in this trace.

Let's look at another line. The last column of the (child) View.invalidate function has a value of 2413/2853. This does not mean that View.invalidate is called 2413 times iteratively and 2853 times recursively. Instead, this means that the parent function, LoadListener.nativeFinished, is called View.invalidate 2413 times.

Now take a look at line # 6 and you will see that View.invalidate is called 2853 times iteratively and 0 times recursively. Therefore, the parent function LoadListener.nativeFinished is the only function that has ever been called LoadListener.tearDown in this trace.

Timeline Panel

Here is the Timeline panel clip from the article:

From the same article

Thin lines below the first line indicate the degree (input to exit) of all calls to the selected method.

Pay attention to the thin pink braces similar to braces, which are located horizontally directly under the highlighted part of the main stream. Left braces are very short; they represent 13/14 calls to LoadListener.nativeFinished, which complete relatively quickly. The last bracket — the farthest to the right — is significantly longer than any of the others. This is a call to LoadListener.nativeFinished, which "took an unusually long time."