From 062fa0ad9380243b9d3d34c84131c049f823c79d Mon Sep 17 00:00:00 2001 From: Valentin Churavy Date: Mon, 17 Apr 2023 15:28:11 -0400 Subject: [PATCH] [Inference] Mark timing with typeof(interp) Allows consumers to separate native inference from inference coming from a custom AbstractInterpreter. Co-authored-by: Shuhei Kadowaki <40514306+aviatesk@users.noreply.github.com> --- base/compiler/ssair/irinterp.jl | 4 ++-- base/compiler/typeinfer.jl | 24 +++++++++++++++--------- base/show.jl | 2 +- test/compiler/inference.jl | 2 +- 4 files changed, 19 insertions(+), 13 deletions(-) diff --git a/base/compiler/ssair/irinterp.jl b/base/compiler/ssair/irinterp.jl index d171cceb842e94..b8955b7d20d70a 100644 --- a/base/compiler/ssair/irinterp.jl +++ b/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) diff --git a/base/compiler/typeinfer.jl b/base/compiler/typeinfer.jl index 1eec73d0435bd2..0839d087eb2fd4 100644 --- a/base/compiler/typeinfer.jl +++ b/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,12 +48,13 @@ 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 @@ -61,8 +62,8 @@ struct Timing 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,7 +122,7 @@ 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() @@ -127,7 +130,7 @@ end 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) diff --git a/base/show.jl b/base/show.jl index 36f7df54d00083..26d87ec7556fea 100644 --- a/base/show.jl +++ b/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, diff --git a/test/compiler/inference.jl b/test/compiler/inference.jl index 8e23ca27602413..1ab3bd871309fe 100644 --- a/test/compiler/inference.jl +++ b/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]