Re: ERROR: operf_read::convertPerfData

On Mon, Jun 1, 2015 at 3:28 AM, Michael Petlan <[email protected]> wrote:
> On Sat, 2015-05-30 at 15:23 -0700, Daniel Wilkerson wrote:
>> I'm running a vanilla Ubuntu 14.04 install.  I attempted to profile a
>> C++ program built using g++.  Other than being multi-threaded and
>> using 100G of RAM, it is a pretty normal program.  I assign some
>> environment vars and then say "operf" before the program line, like
>> this: "VAR=0 operf prog.  My program does not finish and I get the
>> error quoted below in appendix A.  I see the recommendation to
>> decrease my sampling rate, but is that really the cause of the SIGPIPE
>> ?  I must say, this is not a very informative message.
>>
>> I attempted to profile a much simpler program on an Ubuntu 14.04
>> machine that just did some arithmetic in a loop and
>> allocated/deallocated some arrays; no multithreading.  That doesn't
>> crash, but opreport just gives a "no samples found" error, quoted
>> immediately below.  Does my program stop too fast to be profiled?
>>
>> opreport --symbols oprofile_data
>> Using /home/dsw/ex_cc/oprofile_data/samples/ for samples directory.
>> error: no sample files found: profile specification too strict ?
>> make: *** [profile] Error 1
>>
>> Daniel
>>
>
> Hi,
>
> in order to narrow the problem a bit, please try:
>
> 1) Command `opreport --symbols` without the "oprofile_data" argument.
> The "oprofile_data" dir is used by default. If you want to specify some
> other dir, you'd need to use the proper option: "--session-dir=dir". By
> putting "oprofile_data" there without any switch, opreport thinks, that
> "./oprofile_data" is the name of the executed binary. Since there are no
> samples of the binary "./oprofile_data", you get the "no samples"
> message.

Ok, so that worked for the single-threaded toy program I wrote;
thanks.  However the large multithreaded program I ran it under
crashes *while* it is running; see below.

> 2) Check something about your environment:
>
> * ophelp -r
> --> You should see what how oprofile recognizes your HW (or HW support).
> It is "Intel Ivy Bridge microarchitecture" in my case.

$ ophelp -r
AMD64 family15h


> * perf stat ls
> --> You should not get too much of "<not supported>" there:
>  Performance counter stats for 'ls':
>
>           0.779068      task-clock (msec)         #    0.003 CPUs utilized
>                  2      context-switches          #    0.003 M/sec
>                  1      cpu-migrations            #    0.001 M/sec
>                282      page-faults               #    0.362 M/sec
>          2,562,134      cycles                    #    3.289 GHz
>          1,835,655      stalled-cycles-frontend   #   71.65% frontend cycles idle
>    <not supported>      stalled-cycles-backend
>          1,525,423      instructions              #    0.60  insns per cycle
>                                                   #    1.20  stalled cycles per insn
>            301,446      branches                  #  386.932 M/sec
>             12,960      branch-misses             #    4.30% of all branches
>
>        0.299236997 seconds time elapsed
>
> The "cycles", "branches" and "instructions" should be always supported.
> But it depends on your machine's HW as well.

$ perf stat ls
The program 'perf' is currently not installed.  You can install it by typing:
sudo apt-get install linux-tools-common

$ operf stat ls
operf: Profiler started
stat: cannot stat ‘ls’: No such file or directory
profiled app exited with the following status: 1

Profiling done.

$ which ls
/bin/ls

$ operf stat /bin/ls
operf: Profiler started
  File: ‘/bin/ls’
  Size: 110080     Blocks: 216        IO Block: 4096   regular file
Device: fc00h/64512d Inode: 173539458   Links: 1
Access: (0755/-rwxr-xr-x)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2015-06-01 14:59:46.501828326 -0700
Modify: 2014-03-24 00:35:39.000000000 -0700
Change: 2015-03-30 13:34:11.860790701 -0700
 Birth: -

Profiling done.

$ opreport --symbols
Using /home/dsw/oprofile_data/samples/ for samples directory.
warning: /no-vmlinux could not be found.
CPU: AMD64 family15h, speed 2.2e+06 MHz (estimated)
Counted CPU_CLK_UNHALTED events (CPU Clocks not Halted) with a unit
mask of 0x00 (No unit mask) count 100000
samples  %        image name               symbol name
42       77.7778  no-vmlinux               /no-vmlinux
6        11.1111  libc-2.19.so             /lib/x86_64-linux-gnu/libc-2.19.so
4         7.4074  ld-2.19.so               /lib/x86_64-linux-gnu/ld-2.19.so
1         1.8519  libdl-2.19.so            /lib/x86_64-linux-gnu/libdl-2.19.so
1         1.8519  stat                     /usr/bin/stat
dsw@ewok:~$

Is this what you wanted?


> * ocount ls
> Event counts (actual) for /usr/bin/ls:
>         Event                   Count                    % time counted
>         CPU_CLK_UNHALTED        2,201,299                100.00
>
> Ocount counts the event occurences. You can see, that CPU_CLK_UNHALTED event
> happened 2.2 million times.

$ ocount ls
<... output of ls ...>

Events were actively counted for 3232448 nanoseconds.
Event counts (actual) for /bin/ls:
Event                   Count                    % time counted
CPU_CLK_UNHALTED        3,125,846                100.00


> If you run the following:
>
> ophelp -d
>
> you'll get something like:
>
> CPU_CLK_UNHALTED:100000:0:1:1

$ ophelp -d
CPU_CLK_UNHALTED:100000:0:1:1


> The second value (100000) is the sample rate. It means that when ocount reports
> circa 2200k of events, you should get around 2200k/100k = 22 samples.
>
> So even /bin/ls should generate enough samples to be detected by opreport.
>
> * operf ls
> * opreport
>
> If the previous things work, try to run `ls` under operf, there should really be
> samples.

> Hope it helps.

I appreciate all of the detail above, and it does seem to work as you
suggest for ls, but below as you can see for my multithreaded program
I am getting a failure while it is running.  Should I do something to
"lower the sample rate" to prevent that crash?  Again, see "appendix
A" below.

Daniel

>> ---- appendix A
>>
>> ERROR: operf_read::convertPerfData quitting. Bad data read from pipe.
>> Closing read end of data pipe. operf-record process will stop with SIGPIPE (13).
>> Try lowering the sample frequency to avoid this error; e.g., double the 'count'
>> value in your event specification.
>>
>>
>>  * * * ATTENTION: The kernel lost 4260291 samples. * * *
>> Decrease the sampling rate to eliminate (or reduce) lost samples.
>>
>> WARNING: Lost samples detected! See
>> /data2/dsw/wyd_runs/runE700/oprofile_data/samples/operf.log for
>> details.
>> operf-record process killed by signal 13
>> Error running profiler
>> make[1]: *** [0.align] Error 2
>> make[1]: Leaving directory `/data2/dsw/wyd_runs/runE700'
>> make: *** [nohup/go1] Error 2
>> ^C
>> [1]+  Exit 2                  make go

------------------------------------------------------------------------------
_______________________________________________
oprofile-list mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/oprofile-list