[LLVMdev] oprofile support? (original) (raw)

Kevin Modzelewski kmod at dropbox.com
Fri Oct 17 15:17:35 PDT 2014

I haven't gotten operf to work with JIT'd code, but opcontrol seems to work ok if you can accept its unreliability. We've since switched to using perf, and haven't looked back.

On Fri, Oct 17, 2014 at 8:36 AM, Maurice Marks <maurice.marks at gmail.com> wrote:

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: loopy.c: #include <stdio.h> int fibleft(int); int fibright(int); int fibleft(int i) { if (i < 2) return 1;_ _return fibleft(i-1) + fibright(i-2); }_ _int fibright(int i) { if (i < 2) return 1;_ _return fibleft(i-1) + fibright(i-2); }_ _int fib(int i) { if (i < 2) return 1;_ _return fibleft(i-1) + fibright(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 CPUCLKUNHALTED:5000000 lli_ _-debug-only="oprofile-jit-event-listener" loopy.ll_ _Using samples dir /home/dad/oprofiledata/samples_ _Kernel profiling is not possible with current system config_ _Set /proc/sys/kernel/kptrrestrict 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_ _operfread: Total bytes received from operfrecord process: 225952_ _Calling dojitdumpconvert <<<< oprofile converting jit sample_ _information_ _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/oprofiledata/samples/ for samples directory._ _CPU: Intel Haswell microarchitecture, speed 3498 MHz (estimated)_ _Counted CPUCLKUNHALTED events (Clock cycles when not halted) with a unit_ _mask of 0x00 (No unit mask) count 5000000_ _CPUCLKUNHALT...|_ _samples| %|_ _------------------_ _6949 100.000 lli_ _CPUCLKUNHALT...|_ _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/oprofiledata/samples/ for samples directory._ _CPU: Intel Haswell microarchitecture, speed 3498 MHz (estimated)_ _Counted CPUCLKUNHALTED 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 dllookupsymbolx_ _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 dlcheckmapversions 1 1.5152 ld-2.19.so dlfixup 1 1.5152 ld-2.19.so dolookupx 1 1.5152 libLLVMAsmParser.so llvm::LLLexer::ReadString(llvm::lltok::Kind) 1 1.5152 libLLVMCodeGen.so llvm::MachineFunction::getName() const 1 1.5152 libLLVMCodeGen.so llvm::MachineOperand::isReg() const .... 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 problem. thanks!

LLVM Developers mailing list LLVMdev at cs.uiuc.edu http://llvm.cs.uiuc.edu http://lists.cs.uiuc.edu/mailman/listinfo/llvmdev -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.llvm.org/pipermail/llvm-dev/attachments/20141017/d641b03e/attachment.html>

More information about the llvm-dev mailing list