Messages in this thread | | | Date | Mon, 12 Mar 2012 16:15:32 +0900 | From | Namhyung Kim <> | Subject | Re: [PATCH 0/2] perf: add sort by inclusive time functionality (v2) |
| |
Hi,
2012-03-09 3:49 AM, Arun Sharma wrote: > 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. >
I think it's because of the shared hist_entry. If a callchain is a subset of another, it will be marked as inclusive so that it cannot be contributed to total period. Say, there're two chains - X (a -> b -> c) and Y (a -> b), once __hists__add_entry_inclusive() was called on X, we have:
a -> b -> c a -> b (inclusive) a (inclusive)
And then, calling the function on Y should make:
a -> b a (inclusive)
However, since both callchains are in tree already they'll be shared and marked *inclusive*. Thus the total period will not increased at all for Y. Also I guess the reverse case - add Y first, and then X - will have the same result.
Thanks, Namhyung
| |