Re: spurious recursion reported?

[Maynard J. <may...@us...>]

On 12/05/2012 05:13 PM, Maynard Johnson wrote:
> On 12/05/2012 10:30 AM, David Flater wrote:
>> Thanks for any help in explaining the following behavior or confirming it as
>> a bug.
>>
>> I am attaching a simple test program of two functions.  Main calls leaffn;
>> leaffn runs for a while then returns; program exits without drama.
>>
>> Perf and gprof report, as expected, that main calls leaffn, and that's the
>> end of it, aside from interrupts:
> David,
> Thanks for reporting this problem. I can also reproduce the problem on Intel/RHEL 6.3 with a 2.6.32-279.14.1 kernel.  It's evidently an issue with just operf, because when I used "legacy oprofile" (i.e., opcontrol) to collect the callgraph profile for val2, then opreport gives expected results.  Funny this is happening now, because I'm pretty sure it wasn't behaving like this when I first implemented the callgraph option for operf.  The development was done mostly on RHEL 6.1, so maybe something changed in recent kernels that operf is not handling correctly now. This may take some time to debug.  :-/

David,
Sorry it took so long to get back to this.  I *finally* got a final answer from the kernel folks I reported this to.  It wasn't a very satisfactory answer -- they think it's working as designed.  No problem. As long as I know that, I can make a simple change in operf to adjust.  I opened https://sourceforge.net/p/oprofile/bugs/256/ to fix this.

-Maynard
> 
> -Maynard
> 
>>
>>   [From perf report]
>>     99.30%     val2  val2               [.] leaffn                
>>                |
>>                --- leaffn
>>                    main
>>                    __libc_start_main
>>
>>   [From gprof]
>>     index % time    self  children    called     name
>>                     2.11    0.00       1/1           main [2]
>>     [1]    100.0    2.11    0.00       1         leaffn [1]
>>     -----------------------------------------------
>>                                                      <spontaneous>
>>     [2]    100.0    0.00    2.11                 main [2]
>>                     2.11    0.00       1/1           leaffn [1]
>>     -----------------------------------------------
>>
>> But OProfile (operf + opreport) seems to think that leaffn is RECURSIVE:
>>
>>   [From opreport -c]
>>     samples  %        image name               symbol name
>>     ---------------------------------------------------------------------------
>>       4930     49.7779  val2                     leaffn
>>       4974     50.2221  val2                     main
>>     4930     99.0955  val2                     leaffn
>>       4930     49.7779  val2                     leaffn
>>       4930     49.7779  val2                     leaffn [self]
>>       42        0.4241  vmlinux                  apic_timer_interrupt
>>       2         0.0202  vmlinux                  ret_from_intr
>>     ---------------------------------------------------------------------------
>>
>> The fact that the number of samples is the same between the alleged recursion
>> and the [self] line is highly suspect.  I've been unable to locate a related
>> bug in the bug tracker, and the behavior reproduces with today's git version
>> of OProfile.
>>
>> Context:
>>     x86_64
>>     Linux mainline kernel version 3.6.7 with OProfile support enabled
>>     gcc version 4.7.2
>>     oprofile-0.9.8 and git version as of 2012-12-05
>>
>> Build:
>>     gcc -std=gnu99 -O2 -g -fno-omit-frame-pointer -o val2 val2.c
>>
>> Run:
>>     operf --lazy-conversion --vmlinux /usr/src/linux/vmlinux -e CPU_CLK_UNHALTED:1000000 -g ./val2
>>
>> Report:
>>     opreport -c > opreport-c.txt
>>     opreport -cgf | gprof2dot.py -w -f oprofile -o oprofile.dot
>>
>> Thanks,
>>
>>
>>
>> ------------------------------------------------------------------------------
>> LogMeIn Rescue: Anywhere, Anytime Remote support for IT. Free Trial
>> Remotely access PCs and mobile devices and provide instant support
>> Improve your efficiency, and focus on delivering more value-add services
>> Discover what IT Professionals Know. Rescue delivers
>> http://p.sf.net/sfu/logmein_12329d2d
>>
>>
>>
>> _______________________________________________
>> oprofile-list mailing list
>> opr...@li...
>> https://lists.sourceforge.net/lists/listinfo/oprofile-list
> 
> 
> ------------------------------------------------------------------------------
> LogMeIn Rescue: Anywhere, Anytime Remote support for IT. Free Trial
> Remotely access PCs and mobile devices and provide instant support
> Improve your efficiency, and focus on delivering more value-add services
> Discover what IT Professionals Know. Rescue delivers
> http://p.sf.net/sfu/logmein_12329d2d
> _______________________________________________
> oprofile-list mailing list
> opr...@li...
> https://lists.sourceforge.net/lists/listinfo/oprofile-list
>