WIP: instrument julia to get per-method-instance llvm optimization timings#31616
WIP: instrument julia to get per-method-instance llvm optimization timings#31616NHDaly wants to merge 17 commits intoJuliaLang:masterfrom
Conversation
…Types` && move trace into actual codegen block
|
This is the D script we're currently running to record the timings: julia*:::compile-start
{
self->ts = timestamp;
}
julia*:::compile-end
/timestamp - self->ts > 1000/
{
@timings[copyinstr(arg0)] = quantize((timestamp - self->ts)/1000); // microseconds
} |
src/jitlayers.cpp
Outdated
| object::OwningBinary<object::ObjectFile> JuliaOJIT::CompilerT::operator()(Module &M) | ||
| { | ||
| // Instrument the time spent in this block for this method instance | ||
| CompileTiming _c(M.getName().str()); |
There was a problem hiding this comment.
@JeffBezanson do you know where I can find the caller of this function in a context that would have the name of the method instance?
There was a problem hiding this comment.
Ah, okay, i put a breakpoint and got a stacktrace, and it gives me:
frame #2: 0x00000001001b5f45 libjulia.1.2.dylib`JuliaOJIT::CompilerT::operator(this=0x0000000105039938, M=0x000000011131b280)(llvm::Module&) at jitlayers.cpp:355 [opt]
frame #3: 0x00000001001b6c06 libjulia.1.2.dylib`llvm::orc::IRCompileLayer<llvm::orc::RTDyldObjectLinkingLayer, JuliaOJIT::CompilerT>::addModule(this=0x0000000105039930, M=<unavailable>, Resolver=std::__1::shared_ptr<llvm::JITSymbolResolver>::element_type @ 0x000000011131c810 strong=1 weak=1) at IRCompileLayer.h:57:48 [opt]
frame #4: 0x00000001001b6ab7 libjulia.1.2.dylib`JuliaOJIT::addModule(this=<unavailable>, M=unique_ptr<llvm::Module, std::__1::default_delete<llvm::Module> > @ 0x00007ffeefbfe630) at jitlayers.cpp:477:41 [opt]
frame #5: 0x00000001001b73a3 libjulia.1.2.dylib`jl_finalize_function(llvm::StringRef) [inlined] jl_add_to_ee(m=unique_ptr<llvm::Module, std::__1::default_delete<llvm::Module> > @ scalar) at jitlayers.cpp:702:25 [opt]
frame #6: 0x00000001001b738f libjulia.1.2.dylib`jl_finalize_function(F=<unavailable>) at jitlayers.cpp:710 [opt]
frame #7: 0x00000001001596e9 libjulia.1.2.dylib`getAddressForFunction(fname=<unavailable>) at codegen.cpp:1338:5 [opt]
frame #8: 0x0000000100159a77 libjulia.1.2.dylib`::jl_generate_fptr(output=0x000000010c443c10) at codegen.cpp:1432:39 [opt]
frame #9: 0x00000001000ddb01 libjulia.1.2.dylib`jl_compile_method_internal(mi=0x000000010c524350, world=25987) at gf.c:1795:5 [opt]
frame #10: 0x00000001000e02ab libjulia.1.2.dylib`jl_apply_generic(args=0x00007ffeefbfe790, nargs=2) at gf.c:2196:16 [opt]
But i'm surprised; isn't finalize happening after the optimization passes have finished? Why is the JL_TIMING(LLVM_OPT); block there?
|
I would love to have these kinds of instrumentation points, they are really useful for doing application specific probing and this just turned out to be an interesting test-bed to do this. Notes to self:
|
|
Pasting the updated script I've been using to get a .csv of timings:
#pragma D option strsize=10000
julia*:::compile-start
{
self->ts = timestamp;
}
julia*:::compile-end
{
@timings[copyinstr(arg0)] = max((timestamp - self->ts)/1000); // microseconds
}
END
{
printf("\n");
printf("\n---- DTRACE ----\n");
printa("%s\t%@d\n", @timings);
}Then I run it like this, and delete everything up to the $ sudo dtrace -s ~/src/julia/test.d -c '/Users/nathan.daly/src/julia/julia --project test-script.jl' > out.csv |
|
The one remaining question I have before sending this for review is how to fix the Makefile.
|
|
For those following along at home I prototyped a version that can be used to create and trigger probes from Julia functions https://github.com/vchuravy/UProbes.jl It's a tad bit more expensive than the C version (has to do a |
This is a WIP PR that adds Dtrace timings to julia to allow printing timing information per method instance.
This was pair-programmed with @vchuravy 😊
We're currently trying to measure the
llvmoptimization times, but long-term it'd be nice to do lots of different sections.Also,
dtracemight only work on macOS/solaris, but there's an equivalent tracing tool for linux that should work with the same configuration files.