[LLVMdev] oprofile support?

Maurice Marks maurice.marks at gmail.com
Fri Oct 17 08:36:38 PDT 2014

I've been trying to get oprofile results for jitted code without success. I
built an 3.5.0 llvm with oprofile enabled, and tested it with lli on a
small test case. I built the latest oprofile from the git repository.

 Debugging I can see that lli is registering the listener and making the
oprofile calls to the libopagent api to specify the names and address
ranges of jit'd routines, and even the line number information. And the
oprofile agent is writing infomation to /tmp/.oprofile/jitdump. But
although oprofile counts lots of samples but doesnt attribute them to the
jit'd code. When execution finishes oprofile runs opjitconv to report the
jit counts but doesn't see how to attribute them so drops them on the floor.
Working with one of the primary oprofile developers, Maynard Johnson, we've
got a couple of theories:

1) oprofile jit code support doesn't actually work with MCJIT yet. Although
its supposed to work there are no examples we could find in recent web
history. Does anyone have a working example?
2) Using a small test case the jit'd code is on a small region of heap
memory. Because it isnt marked as anonymous (as it would be if it came from
an mmap/large malloc request) oprofile ignores the samples. I would have
though it would attribute those samples to lli which owns its heap. Perhaps
that's a bug?

My test case is this little  C program converted to IR and run with lli:


#include <stdio.h>
int fib_left(int);
int fib_right(int);
int fib_left(int i) {
   if (i < 2) return 1;
   return fib_left(i-1) + fib_right(i-2); }
int fib_right(int i) { if (i < 2) return 1;
return fib_left(i-1) + fib_right(i-2); }
int fib(int i) { if (i < 2) return 1;
return fib_left(i-1) + fib_right(i-2); }

int main() {
int i = 45; printf("fib(%d) == %d\n", i, fib(i)); }

$clang -g -S -emit-llvm -o loopy.ll loopy.c

$ operf -Vdebug -e CPU_CLK_UNHALTED:5000000 lli
-debug-only="oprofile-jit-event-listener" loopy.ll
Using samples dir /home/dad/oprofile_data/samples
Kernel profiling is not possible with current system config
Set /proc/sys/kernel/kptr_restrict to 0 to collect kernel samples.
Exec args are: lli -debug-only=oprofile-jit-event-listener loopy.ll
telling child to start app
app 47033 is running
parent says start app /usr/local/bin/lli
Forking read pid
going into waitpid on profiled app 47033
Successfully read header info for sample data
Converting operf data to oprofile sample data format
sample type is 43
operf: Profiler started
Connected to OProfile agent. <<< from the jit event listener code
Mapping 0x7f5ed6893014 to loopy.c:13 <<< adding debug line information in
the listener
Mapping 0x7f5ed689301f to loopy.c:13
Mapping 0x7f5ed6893032 to loopy.c:13
Mapping 0x7f5ed6893054 to loopy.c:14
Mapping 0x7f5ed6893079 to loopy.c:9
Mapping 0x7f5ed6893082 to loopy.c:9
Mapping 0x7f5ed689308e to loopy.c:10
Mapping 0x7f5ed68930a1 to loopy.c:10
Mapping 0x7f5ed68930b8 to loopy.c:10
Mapping 0x7f5ed68930d9 to loopy.c:5
Mapping 0x7f5ed68930e2 to loopy.c:5
Mapping 0x7f5ed68930ee to loopy.c:6
Mapping 0x7f5ed6893101 to loopy.c:6
Mapping 0x7f5ed6893118 to loopy.c:6
Mapping 0x7f5ed6893139 to loopy.c:7
Mapping 0x7f5ed6893142 to loopy.c:7
Mapping 0x7f5ed689314e to loopy.c:8
Mapping 0x7f5ed6893161 to loopy.c:8
Mapping 0x7f5ed6893178 to loopy.c:8
fib(45) == 1836311903
profiled app ended normally.
operf recording finished.
Total bytes recorded from perf events: 226136
operf-record process returned OK
operf_read: Total bytes received from operf_record process: 225952
Calling _do_jitdump_convert   <<<< oprofile converting jit sample
start time/end time is 1413559198/1413559208
opjitconv: Ending with rc = 2. This code is usually OK, but can be useful
for debugging purposes.
JIT dump processing complete.
operf-read process returned OK

Profiling done.

$ opreport
Using /home/dad/oprofile_data/samples/ for samples directory.
CPU: Intel Haswell microarchitecture, speed 3498 MHz (estimated)
Counted CPU_CLK_UNHALTED events (Clock cycles when not halted) with a unit
mask of 0x00 (No unit mask) count 5000000
  samples|      %|
     6949 100.000 lli
      samples|      %|
         6903 99.3380 ld-2.19.so
           23  0.3310 no-vmlinux
           10  0.1439 libLLVMCore.so
            8  0.1151 libLLVMCodeGen.so
            2  0.0288 libpthread-2.19.so
            1  0.0144 libLLVMAsmPrinter.so
            1  0.0144 libLLVMSelectionDAG.so
            1  0.0144 libLLVMTransformUtils.so

$ opreport -l `which lli`
Using /home/dad/oprofile_data/samples/ for samples directory.
CPU: Intel Haswell microarchitecture, speed 3498 MHz (estimated)
Counted CPU_CLK_UNHALTED events (Clock cycles when not halted) with a unit
mask of 0x00 (No unit mask) count 5000000
samples  %        image name               symbol name
38       57.5758  no-vmlinux               /no-vmlinux
2         3.0303  ld-2.19.so               _dl_lookup_symbol_x
2         3.0303  libLLVMCore.so
llvm::DenseMapBase<llvm::DenseMap<void const*, llvm::PassInfo const*,
llvm::DenseMapInfo<void const*> >, void const*, llvm::PassInfo const*,
llvm::DenseMapInfo<void const*> >::getHashValue(void const* const&)
2         3.0303  libLLVMCore.so           std::vector<llvm::PassInfo
const*, std::allocator<llvm::PassInfo const*> >::begin() const
1         1.5152  ld-2.19.so               _dl_check_map_versions
1         1.5152  ld-2.19.so               _dl_fixup
1         1.5152  ld-2.19.so               do_lookup_x
1         1.5152  libLLVMAsmParser.so
1         1.5152  libLLVMCodeGen.so        llvm::MachineFunction::getName()
1         1.5152  libLLVMCodeGen.so        llvm::MachineOperand::isReg()

>From this you can see that lli is calling the oprofile interface. Oprofile
is counting 6949 samples, but attributing 99% to ld-2.19.so. They are
actually the samples from the jit code execution.

Asking opreport to show the samples from lli it only sees the jit
compilation samples (<1% of the total). Asking for the samples from
ld-2.19.so shows the same info - just the compilation process.

Perhaps I'm missing something obvious so I wanted to ask the list if there
was anyone actively using oprofile with jit'd code so we can resolve the

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.llvm.org/pipermail/llvm-dev/attachments/20141017/5eb099f8/attachment.html>

More information about the llvm-dev mailing list