Re: Profiling code execution on amd64?

On 01/15/11 07:15, Garrett Cooper wrote:
> On Fri, Jan 14, 2011 at 10:10 PM, Steve Kargl
> <sgk_at_troutmask.apl.washington.edu>  wrote:
>> On Fri, Jan 14, 2011 at 03:40:46PM -0500, George Neville-Neil wrote:
>>>
>>> On Jan 13, 2011, at 23:05 , Steve Kargl wrote:
>>>
>>>> On Thu, Jan 13, 2011 at 10:08:30PM -0500, Ryan Stone wrote:
>>>>> I would suggest using hwpmc for profiling:
>>>>>
>>>>> # kldload hwpmc
>>>>> # pmcstat -S unhalted-cycles -O /tmp/samples.out ../penetration
>>>>> # pmcstat -R /tmp/samples.out -G /tmp/penetration.txt
>>>>>
>>>>>
>>>>> You can also get pmcstat to generate gprof-compatible output with -g,
>>>>> but I never use the mode so I'm really not sure what it gives you.  I
>>>>> think that you have to run gprof on the output or something, but don't
>>>>> hold me to that.
>>>>
>>>>
>>>> Thanks.  I'll give it a try, but my initial attempt seems to
>>>> indicate that one needs to be root to use hwpmc.
>>>>
>>>> laptop:kargl[210] pmcstat -S unhalted-cycles -O /tmp/samples.out ../penetration
>>>> pmcstat: ERROR: Cannot allocate system-mode pmc with specification
>>>> "unhalted-cycles": Operation not permitted
>>>>
>>>
>>> You only need to be root to profile the kernel or someone else's process.
>>>
>>> This tutorial might help:
>>>
>>> www.dcbsdcon.org/speakers/slides/neville-neil_dcbsdcon2009.pdf
>>>
>>
>> Thanks.  I'll look at the tutorial.  Meanwhile, should gprof
>> be removed from the base system because it appears broken?
>
> Instead of just removing things, why not determine why things are
> broken and try to fix them?
> -Garrett
>

gprof is not as badly broken as it seems 8-)

I have encountered the issue described by the original poster regularly 
over the last few years, using different versions of FreeBSD. The total 
time reported by gprof is often way shorter than the time reported by 
time. I have checked that the problem goes back to at least 7.3-RELEASE, 
and it occurs on both amd64 and i386.

I found that this problem is caused by neither the profile start-up code 
nor gprof knowing about dynamic linking. The start-up code calls 
profil() with etext as the upper limit of the address range to be 
profiled. This implies that all dynamically linked code will not be 
profiled, which explains the lost ticks in gprof.

A solution might be to teach both the profiling start-up code and gprof 
about dynamic linking, but I guess that is not that trivial ...

A good work-around is linking statically (-static). Also be aware that 
with dynamic linking and specifying -pg, a profiled (and static!) 
version is used only for the C library. So if e.g. the math library is 
needed -lm_p has to be specified explicitly instead of just -lm, or 
ticks will be lost. So specifying standard libraries with _p appended 
might already solve most of the problems.

I also remember (and just verified) that in the "good old days" (FreeBSD 
2.2.8) static linking took place automatically when profiling was 
requested, so the issues at hand might not even be new 8-)

Kind regards,

Hans Ottevanger

PS. Thanks for the link to your tutorial, George. I am very interested 
in hwpmc, and since documentation seems to be somewhat sparse, this 
really helps.