Bug 157854 - opreport generating bogus reports
Summary: opreport generating bogus reports
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: oprofile
Version: rawhide
Hardware: i386
OS: Linux
medium
medium
Target Milestone: ---
Assignee: William Cohen
QA Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2005-05-16 14:36 UTC by Anthony Green
Modified: 2007-11-30 22:11 UTC (History)
1 user (show)

Fixed In Version: oprofile-0.9.2-3.fc6
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2006-12-21 16:47:25 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)

Description Anthony Green 2005-05-16 14:36:38 UTC
From Bugzilla Helper:
User-Agent: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.7.5) Gecko/20041111 Firefox/1.0

Description of problem:
I collected data with oprofile on an updated FC4test3 system, and ran oreport -l to get the following:

CPU: P4 / Xeon, speed 2399.74 MHz (estimated)
Counted GLOBAL_POWER_EVENTS events (time during which processor is not stopped) with a unit mask of 0x01 (mandatory) count 100000
samples  %        app name                 symbol name
475975   16.8211  libgcj.so.6.0.0          __do_global_ctors_aux
289367   10.2263  libgcj.so.6.0.0          java::lang::ClassLoader::setDefaultAssertionStatus(bool)
253928    8.9739  libgcj.so.6.0.0          java::lang::ClassLoader::definePackage(java::lang::String*, java::lang::String*, java::lang::String*, java::lang::String*, java::lang::String*, java::lang::String*, java::lang::String*, java::net::URL*)
227399    8.0364  no-vmlinux               (no symbols)
218493    7.7216  libc-2.3.5.so            memset
138539    4.8960  libc-2.3.5.so            memcpy
65380     2.3105  libgcj.so.6.0.0          _Jv_BytecodeVerifier::set_variable(int, _Jv_BytecodeVerifier::type)
60082     2.1233  libgcj.so.6.0.0          java::net::URI::unquote(java::lang::String*)
55660     1.9670  libgcj.so.6.0.0          rint
55020     1.9444  libgcj.so.6.0.0          java::lang::Class::desiredAssertionStatus()
52752     1.8643  libgcj.so.6.0.0          _Jv_BytecodeVerifier::branch_prepass()
49106     1.7354  libgcj.so.6.0.0          java::lang::Long::valueOf(java::lang::String*, int)
41880     1.4801  libgcj.so.6.0.0          java::net::NetworkInterface::__U3c_clinit__U3e_()
39999     1.4136  libgcj.so.6.0.0          java::net::URI::__U3c_clinit__U3e_()
35020     1.2376  libgcj.so.6.0.0          java::net::ServerSocket::getReuseAddress()
30886     1.0915  libgcj.so.6.0.0          _Jv_BytecodeVerifier::verify_fail(char*, int)


This report made no sense for the program I was running,  so I grabbed the latest oprofile sources from cvs, built them, and ran that opreport against the same data.  The output is completely different, and looks correct (see below).  It looks like the cvs sources have an important fix we need, since the current FC4 oprofile is pretty much useless.

CPU: P4 / Xeon, speed 2399.74 MHz (estimated)
Counted GLOBAL_POWER_EVENTS events (time during which processor is not stopped) with a unit mask of 0x01 (mandatory) count 100000
samples  %        app name                 symbol name
345520   12.2108  libgcj.so.6.0.0          _Jv_MonitorExit
270442    9.5575  libgcj.so.6.0.0          _Jv_MonitorEnter
227399    8.0364  no-vmlinux               (no symbols)
218493    7.7216  libc-2.3.5.so            memset
138539    4.8960  libc-2.3.5.so            memcpy
132851    4.6950  libgcj.so.6.0.0          GC_malloc_atomic
102237    3.6131  libgcj.so.6.0.0          GC_mark_from
93523     3.3051  libgcj.so.6.0.0          GC_gcj_malloc
73816     2.6087  libgcj.so.6.0.0          _Jv_NewPrimArray
68451     2.4191  libgcj.so.6.0.0          gnu::regexp::CharIndexedString::charAt(int)
59668     2.1087  libgcj.so.6.0.0          gnu::regexp::RE::getMatchImpl(gnu::regexp::CharIndexed*, int, int, java::lang::StringBuffer*)
58632     2.0721  libgcj.so.6.0.0          java::lang::Object::clone()
56053     1.9809  libgcj.so.6.0.0          java::lang::String::charAt(int)
55660     1.9670  libgcj.so.6.0.0          _Jv_LookupInterfaceMethodIdx
55000     1.9437  libgcj.so.6.0.0          _Jv_IsAssignableFrom(java::lang::Class*, java::lang::Class*)
52184     1.8442  libgcj.so.6.0.0          __i686.get_pc_thunk.bx
49690     1.7561  libgcj.so.6.0.0          _Jv_CheckCast
43327     1.5312  libgcj.so.6.0.0          gnu::regexp::RE::match(gnu::regexp::CharIndexed*, gnu::regexp::REMatch*)
39530     1.3970  libgcj.so.6.0.0          gnu::regexp::RETokenChar::match(gnu::regexp::CharIndexed*, gnu::regexp::REMatch*)
35873     1.2678  libgcj.so.6.0.0          gnu::regexp::REMatch::clear(int)
34821     1.2306  libgcj.so.6.0.0          gnu::regexp::RETokenOneOf::match(gnu::regexp::CharIndexed*, gnu::regexp::REMatch*)
34114     1.2056  libgcj.so.6.0.0          .plt
25645     0.9063  libgcj.so.6.0.0          java::lang::StringBuffer::append(wchar_t)
23938     0.8460  libgcj.so.6.0.0          gnu::regexp::REMatch::clone()
23411     0.8274  libgcj.so.6.0.0          GC_build_fl4
16517     0.5837  libgcj.so.6.0.0          java::lang::Object::getClass()
14565     0.5147  libgcj.so.6.0.0          _Jv_AllocObjectNoFinalizer
12708     0.4491  libgcj.so.6.0.0          java::lang::StringBuffer::ensureCapacity_unsynchronized(int)
12412     0.4386  oprofiled                (no symbols)
12208     0.4314  libgcj.so.6.0.0          java::lang::Class::isAssignableFrom(java::lang::Class*)





Version-Release number of selected component (if applicable):
oprofile-0.8.2-4

How reproducible:
Always

Steps to Reproduce:
1.Run oprofile on a gcj-built program (I don't know if this is gcj specific)
2.Look at the results.
3.
  

Additional info:

Comment 1 William Cohen 2005-05-25 21:49:09 UTC
Do you have a simple example gcj compiled program that will reproduce this problem?



Comment 2 Anthony Green 2005-06-08 04:41:42 UTC
Just use Eclipse on a FC4 system.

BTW, I never got email notification of your comment. Weird.


Comment 3 Andrew Haley 2005-06-08 09:19:58 UTC
I can confirm this.  The procedure is as simple as installing the Eclipse RPM,
starting Eclipse, and immediately quitting.


Comment 4 William Cohen 2006-09-18 19:02:58 UTC
Is this still a problem with the current 0.9.1 versions of oprofile in
FC5/FC6/rawhide?



Comment 5 William Cohen 2006-12-21 16:38:16 UTC
Followed the steps of running elcipse on an FC6 machine with oprofile
0.9.2-3.fc6 and got the resulting output. Does it look sane?

$ opreport  --long-filenames -l /usr/bin/gij -t 1
CPU: CPU with timer interrupt, speed 0 MHz (estimated)
Profiling through timer interrupt
samples  %        image name               symbol name
1478     13.4829  /usr/lib/libgcj.so.7rh.0.0 GC_mark_from
786       7.1702  /lib/libgcc_s-4.1.1-20061011.so.1 _Unwind_IteratePhdrCallback
521       4.7528  /lib/libc-2.5.so         memset
357       3.2567  /usr/lib/libz.so.1.2.3   inflate_fast
295       2.6911  /lib/libgcc_s-4.1.1-20061011.so.1 execute_cfa_program
227       2.0708  /lib/libc-2.5.so         memcpy
218       1.9887  /lib/libc-2.5.so         dl_iterate_phdr
207       1.8883  /lib/libgcc_s-4.1.1-20061011.so.1 uw_update_context_1
177       1.6147  /lib/libgcc_s-4.1.1-20061011.so.1 read_uleb128
165       1.5052  /usr/lib/libgcj.so.7rh.0.0 void
gnu::java::security::hash::MD5::transform(JArray<char>*, int)
149       1.3592  /lib/libgcc_s-4.1.1-20061011.so.1 uw_frame_state_for
137       1.2498  /usr/lib/libz.so.1.2.3   inflate_table
135       1.2315  /lib/libpthread-2.5.so   pthread_mutex_lock
134       1.2224  /lib/libpthread-2.5.so   __pthread_mutex_unlock_usercnt
131       1.1950  /usr/lib/libgcj.so.7rh.0.0 _Jv_MonitorEnter
127       1.1585  /usr/lib/libgcj.so.7rh.0.0 .plt
126       1.1494  /usr/lib/libgcj.so.7rh.0.0 __i686.get_pc_thunk.bx
122       1.1129  /usr/lib/libgcj.so.7rh.0.0 _Jv_MonitorExit
116       1.0582  /lib/libgobject-2.0.so.0.1200.3 (no symbols)
110       1.0035  /usr/lib/firefox-1.5.0.8/libmozjs.so (no symbols)


Comment 6 Andrew Haley 2006-12-21 16:41:03 UTC
That looks right to me.


Comment 7 Anthony Green 2006-12-21 16:47:25 UTC
(In reply to comment #6)
> That looks right to me.
> 

I agree.  Let's just close this bug.


Note You need to log in before you can comment on or make changes to this bug.