gprof errors due to loss of precision/add more digits

gprof errors due to loss of precision/add more digits

[wsnyder]

As background I support Verilator, which generates applications where there are often 10K+ functions. These create a relatively flat profile that runs through gprof. The gprof report is then post-analyzed to combine some of the 10K+ results into 10-ish groupings.  What users are finding is that the sum of percentages of the groupings in some cases is only accounting for roughly 40% of the program time.

This due to the gprof report. In that report, the sum of all of the various function's percentage column sums to only about 40%.  This is because there are many functions which print as in report as "0.00%", but really the number behind that might be up to e.g. "0.004%", and if we could sum all of those lost-to-truncation values we'd get 60% of the total program time.

If I edit gprof's hist.c to print e.g. 9 digits of precision then all of the "missing" time is now accounted for, proving it is a rounding issue.

1. Is there any existing way to have gprof print sym->hist_time, and/or more precision in the time or percentage columns, to avoid this loss of data due to this precision issue?

2. Would a patch to add a gprof flag to print sym->hist.time e.g. 9 digits of precision be potentially accepted?

3. Any other suggestions?

Thanks

P.S. Saw a thread about gprofng being under development - suggest that also (optionally?) print many more digits!

Re: gprof errors due to loss of precision/add more digits

[Ruud van der Pas]

Hi,

> P.S. Saw a thread about gprofng being under development -

It is actually ready to be tried. Although we’re still ironing out
some initial glitches, you should be able to use the latest oracle/gprofng-v3
branch on https://www.github.com/oracle/binutils-gdb

> suggest that also (optionally?) print many more digits!

Thanks very much for the suggestion!

I think this is a good idea to consider. There is going to be quite an
impact on the lay-out if we move away from the current fixed format,
but nothing dramatic, I think.

We will also need to see where this is having an impact, since we
not only show the function overview, but also source code and disassembly,
but it is definitely worth considering as a future enhancement.

Kind regards, Ruud

Re: gprof errors due to loss of precision/add more digits

[Vladimir Mezentsev]

On 9/10/21 4:26 AM, wsnyder@wsnyder.org wrote:
> As background I support Verilator, which generates applications where there are often 10K+ functions. These create a relatively flat profile that runs through gprof. The gprof report is then post-analyzed to combine some of the 10K+ results into 10-ish groupings.  What users are finding is that the sum of percentages of the groupings in some cases is only accounting for roughly 40% of the program time.

  Is the sum of the absolute time wrong too ?
If not, it means the calculation of percentages is wrong for group. It 
should not be a sum of percentages.


>
> This due to the gprof report. In that report, the sum of all of the various function's percentage column sums to only about 40%.  This is because there are many functions which print as in report as "0.00%", but really the number behind that might be up to e.g. "0.004%", and if we could sum all of those lost-to-truncation values we'd get 60% of the total program time.
>
> If I edit gprof's hist.c to print e.g. 9 digits of precision then all of the "missing" time is now accounted for, proving it is a rounding issue.
>
> 1. Is there any existing way to have gprof print sym->hist_time, and/or more precision in the time or percentage columns, to avoid this loss of data due to this precision issue?
>
> 2. Would a patch to add a gprof flag to print sym->hist.time e.g. 9 digits of precision be potentially accepted?
>
> 3. Any other suggestions?
>
> Thanks
>
> P.S. Saw a thread about gprofng being under development - suggest that also (optionally?) print many more digits!
>

Re: gprof errors due to loss of precision/add more digits

[wsnyder]

> Is the sum of the absolute time wrong too ?

It suffers the same problem with rounding, as obviously it is also only printing a few decimal places too.

This has the curious effect that if the runtime is more than 100 seconds it's more accurate for the downstream tool to use the line-item runtime and compute percentages from the runtime, and if the runtime is less than 100 seconds it's more accurate to use the line-item percentage and compute runtime from the percentage times total runtime.

September 10, 2021 1:02 PM, "Vladimir Mezentsev" <vladimir.mezentsev@oracle.com> wrote:

> On 9/10/21 4:26 AM, wsnyder@wsnyder.org wrote:
> 
>> As background I support Verilator, which generates applications where there are often 10K+
>> functions. These create a relatively flat profile that runs through gprof. The gprof report is then
>> post-analyzed to combine some of the 10K+ results into 10-ish groupings. What users are finding is
>> that the sum of percentages of the groupings in some cases is only accounting for roughly 40% of
>> the program time.
> 
> Is the sum of the absolute time wrong too ?
> If not, it means the calculation of percentages is wrong for group. It should not be a sum of
> percentages.
> 
>> This due to the gprof report. In that report, the sum of all of the various function's percentage
>> column sums to only about 40%. This is because there are many functions which print as in report as
>> "0.00%", but really the number behind that might be up to e.g. "0.004%", and if we could sum all of
>> those lost-to-truncation values we'd get 60% of the total program time.
>> 
>> If I edit gprof's hist.c to print e.g. 9 digits of precision then all of the "missing" time is now
>> accounted for, proving it is a rounding issue.
>> 
>> 1. Is there any existing way to have gprof print sym->hist_time, and/or more precision in the time
>> or percentage columns, to avoid this loss of data due to this precision issue?
>> 
>> 2. Would a patch to add a gprof flag to print sym->hist.time e.g. 9 digits of precision be
>> potentially accepted?
>> 
>> 3. Any other suggestions?
>> 
>> Thanks
>> 
>> P.S. Saw a thread about gprofng being under development - suggest that also (optionally?) print
>> many more digits!

Re: gprof errors due to loss of precision/add more digits

[Ruud van der Pas]

Hi,

> It suffers the same problem with rounding, as obviously it is also only printing a few decimal places too.

Thanks. That is indeed not surprising.

> This has the curious effect that if the runtime is more than 100 seconds it's more accurate for the downstream tool to use the line-item runtime and compute percentages from the runtime, and if the runtime is less than 100 seconds it's more accurate to use the line-item percentage and compute runtime from the percentage times total runtime.

These are interesting numerical effects indeed. 

This is definitely something for us to consider for gprofng to support.

We are going to evaluate how much work this is going to be and when we
might have it available. Obviously we have other things to work on, but
if we can provide some initial basic support for this, we’d like to do so.

We will also share our findings on this alias of course.

Kind regards, Ruud
 
> 
> September 10, 2021 1:02 PM, "Vladimir Mezentsev" <vladimir.mezentsev@oracle.com> wrote:
> 
>> On 9/10/21 4:26 AM, wsnyder@wsnyder.org wrote:
>> 
>>> As background I support Verilator, which generates applications where there are often 10K+
>>> functions. These create a relatively flat profile that runs through gprof. The gprof report is then
>>> post-analyzed to combine some of the 10K+ results into 10-ish groupings. What users are finding is
>>> that the sum of percentages of the groupings in some cases is only accounting for roughly 40% of
>>> the program time.
>> 
>> Is the sum of the absolute time wrong too ?
>> If not, it means the calculation of percentages is wrong for group. It should not be a sum of
>> percentages.
>> 
>>> This due to the gprof report. In that report, the sum of all of the various function's percentage
>>> column sums to only about 40%. This is because there are many functions which print as in report as
>>> "0.00%", but really the number behind that might be up to e.g. "0.004%", and if we could sum all of
>>> those lost-to-truncation values we'd get 60% of the total program time.
>>> 
>>> If I edit gprof's hist.c to print e.g. 9 digits of precision then all of the "missing" time is now
>>> accounted for, proving it is a rounding issue.
>>> 
>>> 1. Is there any existing way to have gprof print sym->hist_time, and/or more precision in the time
>>> or percentage columns, to avoid this loss of data due to this precision issue?
>>> 
>>> 2. Would a patch to add a gprof flag to print sym->hist.time e.g. 9 digits of precision be
>>> potentially accepted?
>>> 
>>> 3. Any other suggestions?
>>> 
>>> Thanks
>>> 
>>> P.S. Saw a thread about gprofng being under development - suggest that also (optionally?) print
>>> many more digits!
>