Bug 151763

Summary:	gprof's estimate of runtime is way off
Product:	[Fedora] Fedora	Reporter:	Tom Lane <tgl>
Component:	binutils	Assignee:	Jakub Jelinek <jakub>
Status:	CLOSED INSUFFICIENT_DATA	QA Contact:
Severity:	medium	Docs Contact:
Priority:	medium
Version:	3	CC:	esigra, gentoo.riverrat, hhorak, ian, jan.kratochvil, mattdm, vapier
Target Milestone:	---
Target Release:	---
Hardware:	i386
OS:	Linux
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2008-02-07 01:29:28 UTC	Type:	---
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Tom Lane 2005-03-22 03:27:34 UTC

Description of problem:
I just finished a gprof run in which I know that the actual run time of the program was not more
than 160 seconds (because this is the elapsed wall clock time).  However gprof shows a breakdown
that adds up to 440 seconds.  The relative times assigned to functions look plausible, but I can't say 
that I have any faith in the results after noticing this...

Version-Release number of selected component (if applicable):
binutils-2.15.92.0.2-5

How reproducible:
At least with this particular test case (a Postgres benchmark query), I consistently get gprof totals that 
are nearly three times the actual wall-clock time.  I'm not sure if the effect will occur on other 
programs.  Have you seen anything similar?

Steps to Reproduce:
1.  Run a program compiled -pg, note wall clock time needed.
2.  gprof
3.  note total time claimed in gprof output.
  
Actual results:
gprof total >> wall clock

Expected results:
gprof total somewhat less than wall clock

Additional info:
This is an up-to-date FC3 system.  Ping me about any specific versions you want verified.

Comment 1 RiverRat 2005-07-20 14:27:45 UTC

This issue has been argued in detail, had the problem issolated, and a proposed
patch offered in the Gentoo bugzilla:

http://bugs.gentoo.org/show_bug.cgi?id=90090

It includes test programs demonstarting the profile timing problem as well as an
elf program to quickly query the system for the setting and see the wrong one
returned.  There is also a command line query to determine that your system is
wrong.  The problem is the kernel loads an incorrect value into the elf header
and gprof (and others) use that value for calculations to ill effect.

The hardware platform needs to be changed to all here.  It for sure effects
x86-64 & i386.  Looking over the code it appears to affect many other archs. Can
anyone confirm this?

Comment 2 Nicholas Miell 2005-07-26 02:08:24 UTC

This is actually a glibc bug.

profil/sprofil call setitimer with timer.it_value.tv_sec = 0,
timer.it_value.tv_usec = 1 and then assumes that the kernel will round that up
and deliver SIGPROF every 1/_SC_CLK_TCK of a second, which (afaict) isn't
guaranteed by anything. (The only real use of _SC_CLK_TCK in Linux (and POSIX,
afaict) is as the resolution of clock_t.)

This happens to work when the value of _SC_CLK_TCK matches the kernel internal
timer granularity, but falls over when the kernel is actually operating at a
different frequency (i.e. 2.6 kernels).

Comment 3 Nicholas Miell 2005-07-26 02:18:48 UTC

Or maybe the problem is in the Linux version of __profile_frequency(), which is
assuming that the AT_CLKTCK ELF auxv value has some relation to the kernel's
timer  frequency.

Comment 4 Tru Huynh 2005-09-29 17:38:30 UTC

confirmed in rhel4 update 1 (do I need to open a new ticket?)

Comment 5 Matthew Miller 2006-07-10 22:22:03 UTC

Fedora Core 3 is now maintained by the Fedora Legacy project for security
updates only. If this problem is a security issue, please reopen and
reassign to the Fedora Legacy product. If it is not a security issue and
hasn't been resolved in the current FC5 updates or in the FC6 test
release, reopen and change the version to match.

Thank you!

Comment 6 petrosyan 2008-02-07 01:29:28 UTC

Fedora Core 3 is not maintained anymore.

Setting status to "INSUFFICIENT_DATA". If you can reproduce this bug in the
current Fedora release please reopen this bug and assign it to the corresponding
Fedora version.