[Inference] Mark timing with typeof(interp)

Allows consumers to separate native inference from inference coming
from a custom AbstractInterpreter.

Co-authored-by: Shuhei Kadowaki <[email protected]>

base/compiler/ssair/irinterp.jl

@@ -346,10 +346,10 @@ function ir_abstract_constant_propagation(interp::AbstractInterpreter, irsv::IRI
     irinterp = switch_to_irinterp(interp)
     if __measure_typeinf__[]
         inf_frame = Timings.InferenceFrameInfo(irsv.mi, irsv.world, VarState[], Any[], length(irsv.ir.argtypes))
-        Timings.enter_new_timer(inf_frame)
+        Timings.enter_new_timer(irinterp, inf_frame)
         ret = _ir_abstract_constant_propagation(irinterp, irsv)
         append!(inf_frame.slottypes, irsv.ir.argtypes)
-        Timings.exit_current_timer(inf_frame)
+        Timings.exit_current_timer(irinterp, inf_frame)
         return ret
     else
         return _ir_abstract_constant_propagation(irinterp, irsv)

base/compiler/typeinfer.jl

@@ -23,7 +23,7 @@ being used for this purpose alone.
 module Timings
 
 using Core.Compiler: -, +, :, Vector, length, first, empty!, push!, pop!, @inline,
-    @inbounds, copy, backtrace
+    @inbounds, copy, backtrace, AbstractInterpreter
 
 # What we record for any given frame we infer during type inference.
 struct InferenceFrameInfo
@@ -48,21 +48,22 @@ end
 _typeinf_identifier(frame::InferenceFrameInfo) = frame
 
 """
-    Core.Compiler.Timing(mi_info, start_time, ...)
+    Core.Compiler.Timing(interpT, mi_info, start_time, ...)
 
 Internal type containing the timing result for running type inference on a single
 MethodInstance.
 """
 struct Timing
+    interpT::DataType
     mi_info::InferenceFrameInfo
     start_time::UInt64
     cur_start_time::UInt64
     time::UInt64
     children::Core.Array{Timing,1}
     bt         # backtrace collected upon initial entry to typeinf
 end
-Timing(mi_info, start_time, cur_start_time, time, children) = Timing(mi_info, start_time, cur_start_time, time, children, nothing)
-Timing(mi_info, start_time) = Timing(mi_info, start_time, start_time, UInt64(0), Timing[])
+Timing(interpT, mi_info, start_time, cur_start_time, time, children) = Timing(interpT, mi_info, start_time, cur_start_time, time, children, nothing)
+Timing(interpT, mi_info, start_time) = Timing(interpT, mi_info, start_time, start_time, UInt64(0), Timing[])
 
 _time_ns() = ccall(:jl_hrtime, UInt64, ())  # Re-implemented here because Base not yet available.
 
@@ -88,6 +89,7 @@ start the ROOT() timer again. `ROOT()` measures all time spent _outside_ inferen
 function reset_timings()
     empty!(_timings)
     push!(_timings, Timing(
+        AbstractInterpreter,
         # The MethodInstance for ROOT(), and default empty values for other fields.
         InferenceFrameInfo(ROOTmi, 0x0, Core.Compiler.VarState[], Any[Core.Const(ROOT)], 1),
         _time_ns()))
@@ -108,6 +110,7 @@ reset_timings()
     # Add in accum_time ("modify" the immutable struct)
     @inbounds begin
         _timings[end] = Timing(
+            parent_timer.interpT,
             parent_timer.mi_info,
             parent_timer.start_time,
             parent_timer.cur_start_time,
@@ -119,15 +122,15 @@ reset_timings()
     return nothing
 end
 
-@inline function enter_new_timer(frame)
+@inline function enter_new_timer(interp::AbstractInterpreter, frame)
     # Very first thing, stop the active timer: get the current time and add in the
     # time since it was last started to its aggregate exclusive time.
     close_current_timer()
 
     mi_info = _typeinf_identifier(frame)
 
     # Start the new timer right before returning
-    push!(_timings, Timing(mi_info, UInt64(0)))
+    push!(_timings, Timing(typeof(interp), mi_info, UInt64(0)))
     len = length(_timings)
     new_timer = @inbounds _timings[len]
     # Set the current time _after_ appending the node, to try to exclude the
@@ -136,6 +139,7 @@ end
 
     @inbounds begin
         _timings[len] = Timing(
+            new_timer.interpT,
             new_timer.mi_info,
             start,
             start,
@@ -150,7 +154,7 @@ end
 # _expected_frame_ is not needed within this function; it is used in the `@assert`, to
 # assert that indeed we are always returning to a parent after finishing all of its
 # children (that is, asserting that inference proceeds via depth-first-search).
-@inline function exit_current_timer(_expected_frame_)
+@inline function exit_current_timer(interp, _expected_frame_)
     # Finish the new timer
     stop_time = _time_ns()
 
@@ -168,6 +172,7 @@ end
     accum_time = stop_time - new_timer.cur_start_time
     # Add in accum_time ("modify" the immutable struct)
     new_timer = Timing(
+        new_timer.interpT,
         new_timer.mi_info,
         new_timer.start_time,
         new_timer.cur_start_time,
@@ -182,6 +187,7 @@ end
     len = length(_timings)
     @inbounds begin
         _timings[len] = Timing(
+            parent_timer.interpT,
             parent_timer.mi_info,
             parent_timer.start_time,
             _time_ns(),
@@ -208,9 +214,9 @@ const __measure_typeinf__ = fill(false)
 function typeinf(interp::AbstractInterpreter, frame::InferenceState)
     interp = switch_from_irinterp(interp)
     if __measure_typeinf__[]
-        Timings.enter_new_timer(frame)
+        Timings.enter_new_timer(interp, frame)
         v = _typeinf(interp, frame)
-        Timings.exit_current_timer(frame)
+        Timings.exit_current_timer(interp, frame)
         return v
     else
         return _typeinf(interp, frame)

base/show.jl

@@ -1299,7 +1299,7 @@ function show(io::IO, mi_info::Core.Compiler.Timings.InferenceFrameInfo)
 end
 
 function show(io::IO, tinf::Core.Compiler.Timings.Timing)
-    print(io, "Core.Compiler.Timings.Timing(", tinf.mi_info, ") with ", length(tinf.children), " children")
+    print(io, "Core.Compiler.Timings.Timing(", tinf.interpT, ", ", tinf.mi_info, ") with ", length(tinf.children), " children")
 end
 
 function show_delim_array(io::IO, itr::Union{AbstractArray,SimpleVector}, op, delim, cl,

test/compiler/inference.jl

@@ -3769,7 +3769,7 @@ end
     timing1 = time_inference() do
         @eval M1.g(2, 3.0)
     end
-    @test occursin(r"Core.Compiler.Timings.Timing\(InferenceFrameInfo for Core.Compiler.Timings.ROOT\(\)\) with \d+ children", sprint(show, timing1))
+    @test occursin(r"Core.Compiler.Timings.Timing\(Core.Compiler.AbstractInterpreter, InferenceFrameInfo for Core.Compiler.Timings.ROOT\(\)\) with \d+ children", sprint(show, timing1))
     # The last two functions to be inferred should be `i` and `i2`, inferred at runtime with
     # their concrete types.
     @test sort([mi_info.mi.def.name for (time,mi_info) in flatten_times(timing1)[end-1:end]]) == [:i, :i2]