Add snoopl() to snoop time in LLVM optimization

Project.toml

@@ -4,15 +4,19 @@ author = ["Tim Holy <tim.holy@gmail.com>"]
 version = "2.1.2"
 
 [deps]
+CSV = "336ed68f-0bac-5ca0-87d4-7b16caf5d00b"
 Cthulhu = "f68482b8-f384-11e8-15f7-abe071a5a75f"
 OrderedCollections = "bac558e1-5e72-5ebc-8fee-abe8a469f55d"
 Pkg = "44cfe95a-1eb2-52ea-b672-e2afdf69b78f"
 Serialization = "9e88b42a-f829-5b0c-bbe9-9e923198166b"
 SnoopCompileCore = "e2b509da-e806-4183-be48-004708413034"
+YAML = "ddb6d928-2868-570f-bddf-ab3f9cf99eb6"
 
 [compat]
 Cthulhu = "1.2"
+CSV = "0.7"
 OrderedCollections = "1"
+YAML = "0.4"
 SnoopCompileCore = "~2.1.2"
 julia = "1"
 

SnoopCompileCore/src/SnoopCompileCore.jl

@@ -16,4 +16,8 @@ if VERSION >= v"1.6.0-DEV.154"
     include("snoopr.jl")
 end
 
+if VERSION >= v"1.6.0-DEV.1192"  # https://github.com/JuliaLang/julia/pull/37136
+    include("snoopl.jl")
+end
+
 end

SnoopCompileCore/src/snoopl.jl

@@ -0,0 +1,51 @@
+export @snoopl
+
+using Serialization
+
+"""
+```
+@snoopl "func_names.csv" "llvm_timings.yaml" begin
+    # Commands to execute, in a new process
+end
+```
+causes the julia compiler to emit the LLVM optimization times for
+of executing the commands to the files "func_names.csv" and "llvm_timings.yaml". These files
+can be used for the input to `SnoopCompile.read_snoopl("func_names.csv", "llvm_timings.yaml")`
+"""
+macro snoopl(flags, func_file, llvm_file, commands)
+    return :(snoopl($(esc(flags)), $(esc(func_file)), $(esc(llvm_file)), $(QuoteNode(commands))))
+end
+macro snoopl(func_file, llvm_file, commands)
+    return :(snoopl(String[], $(esc(func_file)), $(esc(llvm_file)), $(QuoteNode(commands))))
+end
+
+function snoopl(flags, func_file, llvm_file, commands)
+    println("Launching new julia process to run commands...")
+    # addprocs will run the unmodified version of julia, so we
+    # launch it as a command.
+    code_object = """
+            using Serialization
+            while !eof(stdin)
+                Core.eval(Main, deserialize(stdin))
+            end
+            """
+    process = open(`$(Base.julia_cmd()) $flags --eval $code_object`, stdout, write=true)
+    serialize(process, quote
+        let func_io = open($func_file, "w"), llvm_io = open($llvm_file, "w")
+            ccall(:jl_dump_emitted_mi_name, Nothing, (Ptr{Nothing},), func_io.handle)
+            ccall(:jl_dump_llvm_opt, Nothing, (Ptr{Nothing},), llvm_io.handle)
+            try
+                $commands
+            finally
+                ccall(:jl_dump_emitted_mi_name, Nothing, (Ptr{Nothing},), C_NULL)
+                ccall(:jl_dump_llvm_opt, Nothing, (Ptr{Nothing},), C_NULL)
+                close(func_io)
+                close(llvm_io)
+            end
+        end
+        exit()
+    end)
+    wait(process)
+    println("done.")
+    nothing
+end

src/SnoopCompile.jl

@@ -9,6 +9,7 @@ end
 
 using Core: MethodInstance, CodeInfo
 using Serialization, OrderedCollections
+import YAML,CSV  # For @snoopl
 
 # Parcel Regex
 const anonrex = r"#{1,2}\d+#{1,2}\d+"         # detect anonymous functions
@@ -24,6 +25,13 @@ if VERSION >= v"1.2.0-DEV.573"
     include("parcel_snoopi.jl")
 end
 
+# TODO(PR): It seems reasonable to me to leave this alaways available, since even if you're
+# using a version of julia that doesn't support `@snoopl`, it seems like it's still nice to
+# let you _read and reason about_ the results of a snoopl run?
+#if VERSION >= v"1.6.0-DEV.1192"  # https://github.com/JuliaLang/julia/pull/37136
+    include("parcel_snoopl.jl")
+#end
+
 if isdefined(SnoopCompileCore, Symbol("@snoopr"))
     include("invalidations.jl")
 end

src/parcel_snoopl.jl

@@ -0,0 +1,49 @@
+"""
+    times, info = SnoopCompile.read_snoopl("func_names.csv", "llvm_timings.yaml")
+
+Reads the log file produced by the compiler and returns the structured representations.
+"""
+function read_snoopl(func_csv_file, llvm_yaml_file; tmin_secs=0.0)
+    func_csv = CSV.File(func_csv_file, header=false, delim='\t', types=[String, String])
+    llvm_yaml = YAML.load_file(llvm_yaml_file)
+
+    jl_names = Dict(r[1] => r[2] for r in func_csv)
+
+    try_get_jl_name(name) = if name in keys(jl_names)
+        jl_names[name]
+        else
+            @warn "Couldn't find $name"
+            name
+        end
+
+    time_secs(llvm_module) = llvm_module["time_ns"] / 1e9
+
+    times = [
+        time_secs(llvm_module) => [
+            try_get_jl_name(name)
+            for (name,_) in llvm_module["before"]
+        ] for llvm_module in llvm_yaml
+        if time_secs(llvm_module) > tmin_secs
+    ]
+
+    info = Dict(
+        try_get_jl_name(name) => (;
+            before = (;
+                instructions = before_stats["instructions"],
+                basicblocks = before_stats["basicblocks"],
+            ),
+            after = (;
+                instructions = after_stats["instructions"],
+                basicblocks = after_stats["basicblocks"],
+            ),
+        )
+        for llvm_module in llvm_yaml
+        for (name, before_stats) in llvm_module["before"]
+        for (name, after_stats)  in llvm_module["after"]
+        if time_secs(llvm_module) > tmin_secs
+    )
+
+
+    # sort times so that the most costly items are displayed last
+    return (sort(times), info)
+end