9
votes

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 hereSignatureIterator::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

1 Answers

11
votes

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).