lkml.org 
[lkml]   [2012]   [Mar]   [8]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [PATCH 0/2] perf: add sort by inclusive time functionality (v2)
On 3/8/12 7:31 AM, Frederic Weisbecker wrote:
> On Thu, Mar 08, 2012 at 08:29:01AM +0100, Ingo Molnar wrote:
>>
>> * Arun Sharma<asharma@fb.com> wrote:
>>
>>> This patch series refactors existing code a bit and adds sort by
>>> inclusive time (time spent in the function + callees).
>>>
>>> Sample command lines:
>>>
>>> # perf record -ag -- sleep 1
>>> # perf report -g graph,0.5,callee -n -s inclusive
>>
>> So I tried this out with:
>>
>> $ taskset 1 perf record -g git gc
>>
>> and got entries above 100% (in the TUI):
>>
>> $ perf report -g graph,0.5,callee -n -s inclusive
>>
>> + 321.11% 5628 [.] 0x392b609269
>> + 142.27% 3774 [.] create_delta
>> + 78.86% 1248 [.] lookup_object
>> + 40.54% 1348 [k] system_call_fastpath
>> [...]
>>
>> Is that expected?

Yes - this is the "known bug" I noted in the cover letter

The second column (samples) is still accurate and could be used for the
analysis.

>
> I think this happens because of this:
>
> - hists->stats.total_period += h->period;
> + if (!h->inclusive)
> + hists->stats.total_period += h->period;
>
> Which I'm not sure why it is needed btw.

Suppose the perf.data file had 1000 samples each with a period of 1e6
events. total_period would be 1e9 without -s inclusive. Further, let's
say the callchains had an average length of 10.

Now, after adding extra entries to the histogram, total_period would be
1e10, which screws up the percentages. I'd like to differentiate between
the hist entries that were in the event stream vs the ones added for
inclusive time computation. Desired end result: the total_period remains
unchanged at 1e9.

This is done via:

+ if (i != 0)
+ he->inclusive = 1;
+ else
+ orig_he = he;

Either (i != 0) is not a good enough test, or the inclusive bit is not
getting propagated properly after histogram collapsing/resorting. This
is the part I need to better understand and debug.

I tried to explain this problem in my first RFC message as well:

http://thread.gmane.org/gmane.linux.kernel/1262289

The problem Ingo is running into (and I've reproduced it on my end as
well) is that total_period is smaller than without -s inclusive i.e.
h->inclusive is 1 when it shouldn't be.

-Arun


\
 
 \ /
  Last update: 2012-03-08 19:53    [W:0.127 / U:0.020 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site