Add ccalls to enable dumping LLVM_OPT time per method instance.

Adds these functions to toggle the output:
  - ccall(:jl_dump_emitted_mi_name, Nothing, (Ptr{Nothing},), e_io.handle)
  - ccall(:jl_dump_llvm_opt, Nothing, (Ptr{Nothing},), l_io.handle)

This will then be controlled from SnoopCompileCore, via JuliaDebug/SnoopCompile.jl#135.

This logs a CSV file with mappings from C function name to Julia
MethodInstance name, and a YAML file with timings statistics about the
LLVM module being optimized, including:
 - Total time to optimize the llvm module
 - The `optlevel` used for the llvm module
 - The name of each function in the module, before and after
 - Number of instructions for each function, before and after
 - Number of basic blocks for each function, before and after

Co-Authored-By: Sacha Verweij <[email protected]>
Co-Authored-By: Valentin Churavy <[email protected]>

Author: 3 people

src/codegen.cpp

@@ -95,6 +95,13 @@ typedef Instruction TerminatorInst;
 #include "processor.h"
 #include "julia_assert.h"
 
+JL_STREAM *dump_emitted_mi_name_stream = NULL;
+extern "C" JL_DLLEXPORT
+void jl_dump_emitted_mi_name(void *s)
+{
+    dump_emitted_mi_name_stream = (JL_STREAM*)s;
+}
+
 extern "C" {
 
 #include "builtin_proto.h"
@@ -7149,6 +7156,16 @@ jl_compile_result_t jl_emit_code(
         "functions compiled with custom codegen params must not be cached");
     JL_TRY {
         std::tie(m, decls) = emit_function(li, src, jlrettype, params);
+        if (dump_emitted_mi_name_stream != NULL) {
+            jl_printf(dump_emitted_mi_name_stream, "%s\t", decls.specFunctionObject.c_str());
+            // NOTE: We print the Type Tuple without surrounding quotes, because the quotes
+            // break CSV parsing if there are any internal quotes in the Type name (e.g. in
+            // Symbol("...")). The \t delineator should be enough to ensure whitespace is
+            // handled correctly. (And we don't need to worry about any tabs in the printed
+            // string, because tabs are printed as "\t" by `show`.)
+            jl_static_show(dump_emitted_mi_name_stream, li->specTypes);
+            jl_printf(dump_emitted_mi_name_stream, "\n");
+        }
     }
     JL_CATCH {
         // Something failed! This is very, very bad.

src/jitlayers.cpp

@@ -38,6 +38,12 @@ void jl_dump_compiles(void *s)
 {
     dump_compiles_stream = (JL_STREAM*)s;
 }
+JL_STREAM *dump_llvm_opt_stream = NULL;
+extern "C" JL_DLLEXPORT
+void jl_dump_llvm_opt(void *s)
+{
+    dump_llvm_opt_stream = (JL_STREAM*)s;
+}
 
 static void jl_add_to_ee(std::unique_ptr<Module> m);
 static void jl_add_to_ee(std::unique_ptr<Module> &M, StringMap<std::unique_ptr<Module>*> &NewExports);
@@ -523,7 +529,36 @@ static void addPassesForOptLevel(legacy::PassManager &PM, TargetMachine &TM, raw
 
 CompilerResultT JuliaOJIT::CompilerT::operator()(Module &M)
 {
+    uint64_t start_time = 0;
+    if (dump_llvm_opt_stream != NULL) {
+        // Print LLVM function statistics _before_ optimization
+        // Print all the information about this invocation as a YAML object
+        jl_printf(dump_llvm_opt_stream, "- \n");
+        // We print the name and some statistics for each function in the module, both
+        // before optimization and again afterwards.
+        jl_printf(dump_llvm_opt_stream, "  before: \n");
+        for (auto &F : M.functions()) {
+            if (F.isDeclaration() || F.getName().startswith("jfptr_")) {
+                continue;
+            }
+            // Count number of Basic Blocks
+            int bbs = 0;
+            for (auto &B : F.getBasicBlockList()) {
+                std::ignore = B;
+                ++bbs;
+            }
+
+            // Each function is printed as a YAML object with several attributes
+            jl_printf(dump_llvm_opt_stream, "    \"%s\":\n", F.getName().str().c_str());
+            jl_printf(dump_llvm_opt_stream, "        instructions: %u\n", F.getInstructionCount());
+            jl_printf(dump_llvm_opt_stream, "        basicblocks: %u\n", bbs);
+        }
+
+        start_time = jl_hrtime();
+    }
+
     JL_TIMING(LLVM_OPT);
+
     int optlevel;
     if (jl_generating_output()) {
         optlevel = 0;
@@ -565,6 +600,32 @@ CompilerResultT JuliaOJIT::CompilerT::operator()(Module &M)
                                  "The module's content was printed above. Please file a bug report");
     }
 
+    uint64_t end_time = 0;
+    if (dump_llvm_opt_stream != NULL) {
+        end_time = jl_hrtime();
+        jl_printf(dump_llvm_opt_stream, "  time_ns: %" PRIu64 "\n", end_time - start_time);
+        jl_printf(dump_llvm_opt_stream, "  optlevel: %d\n", optlevel);
+
+        // Print LLVM function statistics _after_ optimization
+        jl_printf(dump_llvm_opt_stream, "  after: \n");
+        for (auto &F : M.functions()) {
+            if (F.isDeclaration() || F.getName().startswith("jfptr_")) {
+                continue;
+            }
+
+            // Count number of Basic Blocks
+            int bbs = 0;
+            for (auto &B : F.getBasicBlockList()) {
+                std::ignore = B;
+                ++bbs;
+            }
+
+            jl_printf(dump_llvm_opt_stream, "    \"%s\":\n", F.getName().str().c_str());
+            jl_printf(dump_llvm_opt_stream, "        instructions: %u\n", F.getInstructionCount());
+            jl_printf(dump_llvm_opt_stream, "        basicblocks: %u\n", bbs);
+        }
+    }
+
     return CompilerResultT(std::move(ObjBuffer));
 }