10

I have started using Kcachegrind for performance analysis. But I don't understand the GUI and the output graphs.

For example for this call graph

enter image description here SignatureIterator::iterate_parameters() I don't understand what is the 9.25% referring to ? the 5 198x means how many times SignatureIterator::iterate_parameters() called SignatureIterator::parse_type() ? What is the meaning of 100% in Symbol::byte_at(int) const ? What is an ELF Object ?

Note: In the official documentation http://kcachegrind.sourceforge.net/html/CallGraph.html, but still don't understand what is the caller distance to the function ?

1
  • The distance between function A calling function B is the number of sub-functions ine between A->C->T->B in this case the distance between A and B is 2.
    – Bionix1441
    Commented Jun 9, 2015 at 13:53

1 Answer 1

13

All visualizations in KCachegrind center around a currently selected function, which is Symbol::byte_at() here. Usually, the percentage number of the selected function is shown in relation to total cost (runtime/cycles what ever). However, if you enable the mode/tool button "Relative to parent", the percentage numbers in the call graph get "zoomed up" to show 100% for the selected function, to make it easier to see ratios of cost spent in other functions, relative to the selected one.

Let's assume the cost (ie. event type selected in KCachegrind) is time (in CPU cycles or millisecs - doesn't matter to percentages). This makes it perhaps easier to understand.

The percentages in call graphs always show the time spent in some given function while the selected function (Symbol::byte_at) was active, ie. the time both functions could be found on the call stack during runtime of the program. This works both in callee direction (downwards Symbol::byte_at()) and caller direction (upwards Symbol::byte_at()).

Downwards, that is easier to understand: while Symbol::byte_at() was active, 24.14% of that time the processor actually was executing code from Symbol::base(). The other time (100% - 24.14%), code from Symbol::byte_at() itself was running.

Upwards of the selected function, it maybe is a bit more tricky. For example, the 9.25% for SignatureIterator::iterate_parameters() means that during the time Symbol::byte_at() was active, 9.25% of that time it was indirectly called from SignatureIterator::iterate_parameters(). Similarly, Symbol::byte_at() was called 11.27% of the time it was running directly from SignatureIterator::parse_type(). That is, upwards of the selected function, percentages in direct parents of a function always add up to the exact percentage of that function, unless a function was left off from the visualization due to being below the visibility threshold (see context menu).

2
  • Excellent explanation, thank you. The only thing missing (and the one I do not fully grasp yet) is how the bar next to recursive calls. They don't seem to follow the explained pattern because their value is bigger than that of the selected function - which should be impossible in the above scheme.
    – stefanct
    Commented Sep 6, 2016 at 11:41
  • There are multiple false statements here that might be very confusing. E.g., upwards of the selected function, percentages in direct parents of a function always add up No, they do not. I urge the moderators to pay attention to this post.
    – yujaiyu
    Commented May 29, 2020 at 17:55

Not the answer you're looking for? Browse other questions tagged or ask your own question.