RE: opcontrol does not create results

"Lentes, Bernd" <[email protected]>
Newsgroups gmane.linux.oprofile
Message-ID <[email protected]>
Micael wrote

> -----Original Message-----
> From: Michael Petlan [mailto:[email protected]]
> Sent: Thursday, March 26, 2015 6:13 PM
> To: Lentes, Bernd
> Subject: Re: opcontrol does not create results
>
> On Thu, 2015-03-26 at 17:01 +0100, Lentes, Bernd wrote:
> > Hi Michael,
> >
> > i managed to install the debuginfo package:
> >
> > idcc-devel:~ # rpm -qa|grep -i kernel
> > kernel-smp-2.6.16.60-0.103.1
> > kernel-debug-2.6.16.60-0.103.1
> > kernel-syms-2.6.16.60-0.103.1
> > kernel-smp-debuginfo-2.6.16.60-0.103.1
> > kernel-source-2.6.16.60-0.103.1
> >
> > Is this the right one ?
> >
>
> I am not very familiar with SUSE, but I suppose, that the kernel-smp-
> debuginfo is the right package.
> If the kernel-smp is the kernel package, then kernel-smp-debuginfo is a
> package with its debuginfo.
> It goes like that in RHEL, except that the kernel package is called kernel
> and then the debuginfo is called kernel-debuginfo.
>
> >
> > I'm running the kernel-smp:
> >
> > idcc-devel:~ # uname -r
> > 2.6.16.60-0.103.1-smp
> >
>
> Yes that's right. The debuginfo should match exactly the version and
> release of the kernel.
>
> >
> > But the output is not using the debuginfo, i assume:
> >
> > idcc-devel:~ # opreport -d
> >
> > warning: /ide_cd could not be found.
> > warning: /ide_core could not be found.
> > warning: /ip_conntrack could not be found.
> > warning: /ip_tables could not be found.
> > warning: /iptable_mangle could not be found.
> > warning: /virtio_net could not be found.
> > warning: /virtio_ring could not be found.
>
> ^^^--- These warnings tell you that debuginfo for some modules is
> missing, but it should not matter that much.
>
> > CPU: CPU with timer interrupt, speed 0 MHz (estimated) Profiling
> > through timer interrupt
> > warning: /boot/vmlinux-2.6.16.60-0.103.1-smp.gz is not in a usable
> binary format.
>
> ^^^--- This warning looks more serious, it means that opreport is
> probably not able to read the kernel's debuginfo.
>
> > vma      samples  %        image name               app name                 symbol
> name
> > 00000000 3732     93.3934  vmlinux-2.6.16.60-0.103.1-smp.gz vmlinux-
> 2.6.16.60-0.103.1-smp.gz (no symbols)
> >   00009d7d 3179     85.1822
> >   00034a4f 1         0.0268
> >   0003a885 539      14.4427
> >   0004724b 2         0.0536
> >   0004bbf2 2         0.0536
> >   0005f62d 4         0.1072
> >   00062d22 1         0.0268
> >   00083777 1         0.0268
> >   00163072 1         0.0268
> >   001c0f9e 1         0.0268
> >   001e053a 1         0.0268
> > 00000000 82        2.0521  vmlinux-2.6.16.60-0.103.1-smp.gz sshd
> (no symbols)
> >   0003a885 79       96.3415
> >   0014e614 1         1.2195
> >   00195b03 1         1.2195
> >   001d43bd 1         1.2195
> > 00000000 38        0.9510  vmlinux-2.6.16.60-0.103.1-smp.gz atop
> (no symbols)
> >   0000a5e5 1         2.6316
> >   0000ae1a 1         2.6316
> > ...
> >
> > or
> >
> > idcc-devel:~ # opreport -gl
> >
> > warning: /ide_cd could not be found.
> > warning: /ide_core could not be found.
> > warning: /ip_conntrack could not be found.
> > warning: /ip_tables could not be found.
> > warning: /iptable_mangle could not be found.
> > warning: /virtio_net could not be found.
> > warning: /virtio_ring could not be found.
> > CPU: CPU with timer interrupt, speed 0 MHz (estimated) Profiling
> > through timer interrupt
> > warning: /boot/vmlinux-2.6.16.60-0.103.1-smp.gz is not in a usable
> binary format.
> > samples  %        linenr info                 image name               app name
> symbol name
> > 3732     93.3934  (no location information)   vmlinux-2.6.16.60-0.103.1-
> smp.gz vmlinux-2.6.16.60-0.103.1-smp.gz (no symbols)
> > 82        2.0521  (no location information)   vmlinux-2.6.16.60-0.103.1-
> smp.gz sshd                     (no symbols)
> > 38        0.9510  (no location information)   vmlinux-2.6.16.60-0.103.1-
> smp.gz atop                     (no symbols)
> > 33        0.8258  (no location information)   vmlinux-2.6.16.60-0.103.1-
> smp.gz top                      (no symbols)
> > 24        0.6006  (no location information)   vmlinux-2.6.16.60-0.103.1-
> smp.gz bash                     (no symbols)
> > 11        0.2753  (no location information)   vmlinux-2.6.16.60-0.103.1-
> smp.gz ls                       (no symbols)
> > 7         0.1752  (no location information)   libz.so.1.2.3            atop
> (no symbols)
> > 7         0.1752  (no location information)   vmlinux-2.6.16.60-0.103.1-
> smp.gz hald-addon-storage       (no symbols)
> > 6         0.1502  (no location information)   ide_core                 hald-addon-
> storage       (no symbols)
> > 5         0.1251  (no location information)   vmlinux-2.6.16.60-0.103.1-
> smp.gz cat                      (no symbols)
> > 3         0.0751  (no location information)   vmlinux-2.6.16.60-0.103.1-
> smp.gz gawk                     (no symbols)
> > 3         0.0751  (no location information)   vmlinux-2.6.16.60-0.103.1-
> smp.gz mysqld                   (no symbols)
> > 3         0.0751  (no location information)   vmlinux-2.6.16.60-0.103.1-
> smp.gz nscd                     (no symbols)
>
> ^^^--- From this table the only obvious thing is that the 93% of the
> captured workload is done by kernel for kernel itself. That's a thing you
> probably already know...
>
> >
> >
> > The "no symbols" is a hint that the debuginfo is not used ?
>
> Yes. And the warning about the binary format is a similar hint.
>
> >
> > What can I do ?
>
>
> (1) Try to investigate what is contained in the debuginfo package.
>
> $ rpm -ql kernel-smp-debuginfo | egrep '\.debug$'
> [...]
> /usr/lib/debug/lib/modules/3.10.0-
> 229.el7.x86_64/kernel/sound/pci/snd-rme32.ko.debug
> /usr/lib/debug/lib/modules/3.10.0-
> 229.el7.x86_64/kernel/sound/pci/snd-rme96.ko.debug
> [...]
>
> There should be dozens of *.debug files. In RHEL this is how the kernel
> debuginfo looks like. But maybe in SUSE everything is packed in a *.gz
> file.
>
>
> (2) Make sure that you give the right path to oprofile when you do the
> profiling:
>
> In RHEL 7 it should look like this:
>
> $ opcontrol --setup --vmlinux /usr/lib/debug/lib/modules/3.10.0-
> 229.el7.x86_64/vmlinux
>
> Maybe you have specified this one "/boot/vmlinux-2.6.16.60-0.103.1-
> smp.gz" since opreport is trying to read it. That will never work I guess.
>
>
> (3) Make sure you're doing the profiling right. Following thing works for
> me:
>
> [root@RHEL-7 tmp]# opcontrol --deinit
> [root@RHEL-7 tmp]# opcontrol --reset
> [root@RHEL-7 tmp]# modprobe oprofile timer=1
> [root@RHEL-7 tmp]# opcontrol --init
> [root@RHEL-7 tmp]# opcontrol --setup --vmlinux
> /usr/lib/debug/lib/modules/3.10.0-229.el7.x86_64/vmlinux
> [root@RHEL-7 tmp]# opcontrol --start
>
> ## wait for a while here ##
>
> [root@RHEL-7 tmp]# opcontrol --stop
> Stopping profiling.
> [root@RHEL-7 tmp]# opcontrol --dump
> [root@RHEL-7 tmp]# opreport -gl
> CPU: CPU with timer interrupt, speed 3.6e+06 MHz (estimated) Profiling
> through timer interrupt
> samples  %        linenr info                 image name               app name
> symbol name
> 132504   94.8653  cpuidle.c:77                vmlinux                  vmlinux
> cpuidle_enter_state
> 944       0.6758  (no location information)   libxul.so;55128db3 (deleted)
> libxul.so;55128db3 (deleted) /usr/lib64/firefox/libxul.so;55128db3
> (deleted)
> 930       0.6658  (no location information)   libQtGui.so.4.8.5
> libQtGui.so.4.8.5        /usr/lib64/libQtGui.so.4.8.5
> 399       0.2857  (no location information)   libQtCore.so.4.8.5
> libQtCore.so.4.8.5       /usr/lib64/libQtCore.so.4.8.5
> 283       0.2026  (no location information)   libglib-2.0.so.0.4000.0  libglib-
> 2.0.so.0.4000.0  /usr/lib64/libglib-2.0.so.0.4000.0
> 272       0.1947  core.c:2036                 vmlinux                  vmlinux
> finish_task_switch
> 124       0.0888  file.c:704                  vmlinux                  vmlinux
> fget_light
> 121       0.0866  (no location information)   Xorg                     Xorg
> /usr/bin/Xorg
> 98        0.0702  tick-sched.c:918            vmlinux                  vmlinux
> tick_nohz_idle_exit
> [...]
>
> This is how it should look like. I have some "(no location information)"
> there too, but it's not the kernel's fault. I just don't have debuginfo for
> firefox... When I grep it for "vmlinux", the information will be more
> interesting:
>
> samples  %        linenr info                 image name               app name
> symbol name
> 132504   94.8653  cpuidle.c:77                vmlinux                  vmlinux
> cpuidle_enter_state
> 272       0.1947  core.c:2036                 vmlinux                  vmlinux
> finish_task_switch
> 124       0.0888  file.c:704                  vmlinux                  vmlinux
> fget_light
> 98        0.0702  tick-sched.c:918            vmlinux                  vmlinux
> tick_nohz_idle_exit
> 94        0.0673  cpuidle.c:236               vmlinux                  vmlinux
> poll_idle
> 84        0.0601  socket.c:1151               vmlinux                  vmlinux
> sock_poll
> 63        0.0451  file_table.c:304            vmlinux                  vmlinux                  fput
> 60        0.0430  wait.c:45                   vmlinux                  vmlinux
> remove_wait_queue
> 53        0.0379  tick-sched.c:788            vmlinux                  vmlinux
> tick_nohz_idle_enter
> 51        0.0365  softirq.c:214               vmlinux                  vmlinux
> __do_softirq
> 48        0.0344  core.c:3425                 vmlinux                  vmlinux
> __wake_up_sync_key
> 46        0.0329  af_unix.c:2162              vmlinux                  vmlinux
> unix_poll
> 40        0.0286  wait.c:23                   vmlinux                  vmlinux
> add_wait_queue
> 35        0.0251  copy_user_64.S:254          vmlinux                  vmlinux
> copy_user_enhanced_fast_string
> 31        0.0222  page_alloc.c:1881           vmlinux                  vmlinux
> get_page_from_freelist
> 29        0.0208  fault.c:1011                vmlinux                  vmlinux
> __do_page_fault
> 26        0.0186  select.c:401                vmlinux                  vmlinux
> do_select
> 26        0.0186  slub.c:3368                 vmlinux                  vmlinux                  kfree
> 26        0.0186  entry_64.S:418              vmlinux                  vmlinux
> system_call_after_swapgs
> 24        0.0172  select.c:221                vmlinux                  vmlinux
> __pollwait
> 22        0.0158  auditsc.c:1504              vmlinux                  vmlinux
> __audit_syscall_exit
> 22        0.0158  select.c:873                vmlinux                  vmlinux
> do_sys_poll
> 21        0.0150  core.c:3144                 vmlinux                  vmlinux
> __schedule
> 20        0.0143  auditsc.c:1456              vmlinux                  vmlinux
> __audit_syscall_entry
>
>
> Here I can see, that the most kernel samples were in
> cpuidle_enter_state In the fifth column I see the source and line number
> where I should search for the culprit.. You should be able to get similar
> results.
>
> You might want to save your results for further investigation:
>
> [root@RHEL-7 tmp]# opcontrol --save=my_own_profiling_take_1
>
> And unload the module...
>
> [root@RHEL-7 tmp]# opcontrol --deinit
>
>
> >
> >
> > Bernd
> >
>
> Hope it helps.
>
> Regards,
> Michael
>

Hi Michael,

thanks for your help and patience. I think we are coming closer to the solution. I found the debuginfo kernel.
But now I have another problem:

I followed your guidance. But when I issue an "opcontrol --start", I get the following message:

idcc-devel:~ # opcontrol --start
Using default event: CPU_CLK_UNHALTED:100000:0:1:1
Using 2.6+ OProfile kernel interface.
Reading module info.
Using log file /var/lib/oprofile/oprofiled.log
Daemon started.
Profiler running.
idcc-devel:~ #

I get no results for profiling:

idcc-devel:~ # opreport
opreport error: No sample file found: try running opcontrol --dump
or specify a session containing sample files

The appropriate folder is empty:

idcc-devel:~ # l /var/lib/oprofile/samples/current/
total 8
drwxr-xr-x 2 root root 4096 Mar 26 19:18 ./
drwxr-xr-x 7 root root 4096 Mar 26 19:18 ../
idcc-devel:~ #

I'm pretty sure that when I got the results i provided per e-mail, the " Using default event: CPU_CLK_UNHALTED:100000:0:1:1" didn't appear. Is that the reason that I don't get results ?
I think so. How can I get rid of it ?

Here is my configuration:

idcc-devel:~ # opcontrol --status
Daemon not running
Separate options: library kernel
vmlinux file: /usr/lib/debug/boot/vmlinux-2.6.16.60-0.103.1-smp.debug
Image filter: none
Call-graph depth: 0

idcc-devel:~ # cat .oprofile/daemonrc
NR_CHOSEN=0
SEPARATE_LIB=1
SEPARATE_KERNEL=1
SEPARATE_THREAD=0
SEPARATE_CPU=0
VMLINUX=/boot/vmlinux-2.6.16.60-0.103.1-smp.gz
IMAGE_FILTER=
CPU_BUF_SIZE=0
CALLGRAPH=0
idcc-devel:~ #

Bernd




Helmholtz Zentrum München
Deutsches Forschungszentrum für Gesundheit und Umwelt (GmbH)
Ingolstädter Landstr. 1
85764 Neuherberg
www.helmholtz-muenchen.de
Aufsichtsratsvorsitzende: MinDir´in Bärbel Brumme-Bothe
Geschäftsführer: Prof. Dr. Günther Wess, Dr. Nikolaus Blum, Dr. Alfons Enhsen
Registergericht: Amtsgericht München HRB 6466
USt-IdNr: DE 129521671
------------------------------------------------------------------------------
Dive into the World of Parallel Programming The Go Parallel Website, sponsored
by Intel and developed in partnership with Slashdot Media, is your hub for all
things parallel software development, from weekly thought leadership blogs to
news, videos, case studies, tutorials and more. Take a look and join the 
conversation now. http://goparallel.sourceforge.net/
_______________________________________________
oprofile-list mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/oprofile-list
lmpx.com only provides a reader for public news (NNTP) servers. It is not affiliated with the servers or forums shown here and is not responsible for the content of articles, which is written by their respective authors.