transition @timeit in Core.Compiler to use tracy instead (#49675)

Co-authored-by: Kristoffer Carlsson <[email protected]>
Co-authored-by: gbaraldi <[email protected]>
Co-authored-by: Cody Tapscott <[email protected]>

Author: 4 people

Compiler/src/Compiler.jl

@@ -120,6 +120,7 @@ function is_return_type(Core.@nospecialize(f))
     return false
 end
 
+include("profiling.jl")
 include("sort.jl")
 
 # We don't include some.jl, but this definition is still useful.

Compiler/src/inferencestate.jl

@@ -188,7 +188,7 @@ mutable struct LazyGenericDomtree{IsPostDom}
 end
 function get!(x::LazyGenericDomtree{IsPostDom}) where {IsPostDom}
     isdefined(x, :domtree) && return x.domtree
-    return @timeit "domtree 2" x.domtree = IsPostDom ?
+    return @zone "CC: DOMTREE_2" x.domtree = IsPostDom ?
         construct_postdomtree(x.ir) :
         construct_domtree(x.ir)
 end

Compiler/src/optimize.jl

@@ -982,7 +982,7 @@ end
 
 # run the optimization work
 function optimize(interp::AbstractInterpreter, opt::OptimizationState, caller::InferenceResult)
-    @timeit "optimizer" ir = run_passes_ipo_safe(opt.src, opt)
+    @zone "CC: OPTIMIZER" ir = run_passes_ipo_safe(opt.src, opt)
     ipo_dataflow_analysis!(interp, opt, ir, caller)
     finishopt!(interp, opt, ir)
     return nothing
@@ -992,7 +992,7 @@ const ALL_PASS_NAMES = String[]
 macro pass(name::String, expr)
     optimize_until = esc(:optimize_until)
     stage = esc(:__stage__)
-    macrocall = :(@timeit $name $(esc(expr)))
+    macrocall = :(@zone $name $(esc(expr)))
     macrocall.args[2] = __source__  # `@timeit` may want to use it
     push!(ALL_PASS_NAMES, name)
     quote
@@ -1017,20 +1017,20 @@ function run_passes_ipo_safe(
 
     __stage__ = 0  # used by @pass
     # NOTE: The pass name MUST be unique for `optimize_until::String` to work
-    @pass "convert"   ir = convert_to_ircode(ci, sv)
-    @pass "slot2reg"  ir = slot2reg(ir, ci, sv)
+    @pass "CC: CONVERT"   ir = convert_to_ircode(ci, sv)
+    @pass "CC: SLOT2REG"  ir = slot2reg(ir, ci, sv)
     # TODO: Domsorting can produce an updated domtree - no need to recompute here
-    @pass "compact 1" ir = compact!(ir)
-    @pass "inlining"  ir = ssa_inlining_pass!(ir, sv.inlining, ci.propagate_inbounds)
-    # @timeit "verify 2" verify_ir(ir)
-    @pass "compact 2" ir = compact!(ir)
-    @pass "SROA"      ir = sroa_pass!(ir, sv.inlining)
-    @pass "ADCE"      (ir, made_changes) = adce_pass!(ir, sv.inlining)
+    @pass "CC: COMPACT_1" ir = compact!(ir)
+    @pass "CC: INLINING"  ir = ssa_inlining_pass!(ir, sv.inlining, ci.propagate_inbounds)
+    # @zone "CC: VERIFY 2" verify_ir(ir)
+    @pass "CC: COMPACT_2" ir = compact!(ir)
+    @pass "CC: SROA"      ir = sroa_pass!(ir, sv.inlining)
+    @pass "CC: ADCE"      (ir, made_changes) = adce_pass!(ir, sv.inlining)
     if made_changes
-        @pass "compact 3" ir = compact!(ir, true)
+        @pass "CC: COMPACT_3" ir = compact!(ir, true)
     end
     if is_asserts()
-        @timeit "verify 3" begin
+        @zone "CC: VERIFY_3" begin
             verify_ir(ir, true, false, optimizer_lattice(sv.inlining.interp), sv.linfo)
             verify_linetable(ir.debuginfo, length(ir.stmts))
         end
@@ -1291,10 +1291,10 @@ end
 function slot2reg(ir::IRCode, ci::CodeInfo, sv::OptimizationState)
     # need `ci` for the slot metadata, IR for the code
     svdef = sv.linfo.def
-    @timeit "domtree 1" domtree = construct_domtree(ir)
+    @zone "CC: DOMTREE_1" domtree = construct_domtree(ir)
     defuse_insts = scan_slot_def_use(Int(ci.nargs), ci, ir.stmts.stmt)
     𝕃ₒ = optimizer_lattice(sv.inlining.interp)
-    @timeit "construct_ssa" ir = construct_ssa!(ci, ir, sv, domtree, defuse_insts, 𝕃ₒ) # consumes `ir`
+    @zone "CC: CONSTRUCT_SSA" ir = construct_ssa!(ci, ir, sv, domtree, defuse_insts, 𝕃ₒ) # consumes `ir`
     # NOTE now we have converted `ir` to the SSA form and eliminated slots
     # let's resize `argtypes` now and remove unnecessary types for the eliminated slots
     resize!(ir.argtypes, ci.nargs)

Compiler/src/profiling.jl

@@ -0,0 +1,33 @@
+const WITH_ITTAPI = ccall(:jl_ittapi_enabled, Cint, ()) != 0
+const WITH_TRACY = ccall(:jl_tracy_enabled, Cint, ()) != 0
+
+include("profiling/tracy.jl")
+include("profiling/ittapi.jl")
+
+if WITH_TRACY || WITH_ITTAPI
+    macro zone(name, ex::Expr)
+        srcloc = WITH_TRACY && Tracy.tracy_zone_create(name, ex, __source__)
+        tracy_begin_expr = WITH_TRACY ? :(ctx_tracy = Tracy.tracy_zone_begin($srcloc, true)) : :()
+        tracy_end_expr = WITH_TRACY ? :(Tracy.tracy_zone_end(ctx_tracy)) : :()
+
+        event = WITH_ITTAPI && ITTAPI.ittapi_zone_create(name, ex, __source__)
+        ittapi_begin_expr = WITH_ITTAPI ? :(ctx_ittapi = ITTAPI.ittapi_zone_begin($event, true)) : :()
+        ittapi_end_expr = WITH_ITTAPI ? :(ITTAPI.ittapi_zone_end(ctx_ittapi)) : :()
+
+        return quote
+            $tracy_begin_expr
+            $ittapi_begin_expr
+            $(Expr(:tryfinally,
+            :($(esc(ex))),
+                quote
+                    $tracy_end_expr
+                    $ittapi_end_expr
+                end
+        ))
+        end
+    end
+else
+    macro zone(name::String, ex::Expr)
+        esc(ex)
+    end
+end

Compiler/src/profiling/ittapi.jl

@@ -0,0 +1,18 @@
+# Stubs
+module ITTAPI
+
+import ..String, ..Expr, ..LineNumberNode, ..nothing
+
+function ittapi_zone_create(name::String, ex::Expr, linfo::LineNumberNode)
+    return nothing
+end
+
+function ittapi_zone_begin(loc, active)
+   return nothing
+end
+
+function ittapi_zone_end(ctx)
+    return nothing
+end
+
+end

Compiler/src/profiling/tracy.jl

@@ -0,0 +1,63 @@
+module Tracy
+
+import ..@noinline, ..@atomic, ..Cint, ..Vector, ..push!, ..unsafe_convert, ..esc,
+       ..pointer_from_objref, ..String, ..Ptr, ..UInt8, ..Cvoid,
+       ..Expr, ..LineNumberNode, ..Symbol, ..UInt32, ..C_NULL, ..(===)
+
+_strpointer(s::String) = ccall(:jl_string_ptr, Ptr{UInt8}, (Any,), s)
+
+mutable struct TracySrcLoc
+    @atomic zone_name::Ptr{UInt8}
+    @atomic function_name::Ptr{UInt8}
+    @atomic file::Ptr{UInt8}
+    const line::UInt32
+    const color::UInt32
+    # Roots
+    const zone_name_str::String
+    const function_name_sym::Symbol
+    const file_sym::Symbol
+end
+TracySrcLoc(zone_name::String, function_name::Symbol, file::Symbol, line::UInt32, color::UInt32) =
+    TracySrcLoc(C_NULL, C_NULL, C_NULL, line, color, zone_name, function_name, file)
+
+@noinline function reinit!(srcloc::TracySrcLoc)
+    @atomic :monotonic srcloc.file = unsafe_convert(Ptr{UInt8}, srcloc.file_sym)
+    @atomic :monotonic srcloc.function_name = unsafe_convert(Ptr{UInt8}, srcloc.function_name_sym)
+    @atomic :release srcloc.zone_name = _strpointer(srcloc.zone_name_str)
+end
+
+struct TracyZoneCtx
+    id::UInt32
+    active::Cint
+end
+
+const srclocs = Vector{TracySrcLoc}()
+
+function tracy_zone_create(name::String, ex::Expr, linfo::LineNumberNode)
+    # Intern strings
+    for loc in srclocs
+        if loc.zone_name_str === name
+            name = loc.zone_name_str
+            break
+        end
+    end
+    loc = TracySrcLoc(name, Symbol("unknown"), linfo.file, UInt32(linfo.line), UInt32(0))
+    # Also roots `loc` in `srclocs`
+    push!(srclocs, loc)
+    return loc
+end
+
+function tracy_zone_begin(loc, active)
+    if (@atomic :acquire loc.zone_name) === Ptr{UInt8}(0)
+        reinit!(loc)
+    end
+    # `loc` is rooted in the global `srclocs`
+    ptr = Ptr{TracySrcLoc}(pointer_from_objref(loc))
+    return ccall((:___tracy_emit_zone_begin, "libTracyClient"), TracyZoneCtx, (Ptr{TracySrcLoc}, Cint), ptr, active)
+end
+
+function tracy_zone_end(ctx)
+    ccall((:___tracy_emit_zone_end, "libTracyClient"), Cvoid, (TracyZoneCtx,), ctx)
+end
+
+end

Compiler/src/ssair/inlining.jl

@@ -73,10 +73,10 @@ add_inlining_edge!(et::InliningEdgeTracker, edge::MethodInstance) = add_inlining
 function ssa_inlining_pass!(ir::IRCode, state::InliningState, propagate_inbounds::Bool)
     # Go through the function, performing simple inlining (e.g. replacing call by constants
     # and analyzing legality of inlining).
-    @timeit "analysis" todo = assemble_inline_todo!(ir, state)
+    @zone "CC: ANALYSIS" todo = assemble_inline_todo!(ir, state)
     isempty(todo) && return ir
     # Do the actual inlining for every call we identified
-    @timeit "execution" ir = batch_inline!(ir, todo, propagate_inbounds, state.interp)
+    @zone "CC: EXECUTION" ir = batch_inline!(ir, todo, propagate_inbounds, state.interp)
     return ir
 end
 

Compiler/src/ssair/slot2ssa.jl

@@ -574,7 +574,7 @@ function construct_ssa!(ci::CodeInfo, ir::IRCode, sv::OptimizationState,
     for (; leave_block) in catch_entry_blocks
         new_phic_nodes[leave_block] = NewPhiCNode2[]
     end
-    @timeit "idf" for (idx, slot) in Iterators.enumerate(defuses)
+    @zone "CC: IDF" for (idx, slot) in Iterators.enumerate(defuses)
         # No uses => no need for phi nodes
         isempty(slot.uses) && continue
         # TODO: Restore this optimization
@@ -600,7 +600,7 @@ function construct_ssa!(ci::CodeInfo, ir::IRCode, sv::OptimizationState,
             continue
         end
 
-        @timeit "liveness" (live = compute_live_ins(cfg, slot))
+        @zone "CC: LIVENESS" (live = compute_live_ins(cfg, slot))
         for li in live.live_in_bbs
             push!(live_slots[li], idx)
             cidx = findfirst(x::TryCatchRegion->x.leave_block==li, catch_entry_blocks)
@@ -671,7 +671,7 @@ function construct_ssa!(ci::CodeInfo, ir::IRCode, sv::OptimizationState,
     worklist = Tuple{Int, Int, Vector{Pair{Any, Any}}}[(1, 0, initial_incoming_vals)]
     visited = BitSet()
     new_nodes = ir.new_nodes
-    @timeit "SSA Rename" while !isempty(worklist)
+    @zone "CC: SSA_RENAME" while !isempty(worklist)
         (item, pred, incoming_vals) = pop!(worklist)
         if sv.bb_vartables[item] === nothing
             continue
@@ -891,6 +891,6 @@ function construct_ssa!(ci::CodeInfo, ir::IRCode, sv::OptimizationState,
         local node = new_nodes.stmts[i]
         node[:stmt] = new_to_regular(renumber_ssa!(node[:stmt], ssavalmap), nstmts)
     end
-    @timeit "domsort" ir = domsort_ssa!(ir, domtree)
+    @zone "CC: DOMSORT" ir = domsort_ssa!(ir, domtree)
     return ir
 end

Compiler/src/utilities.jl

@@ -4,7 +4,7 @@
 # generic #
 ###########
 
-if !@isdefined(var"@timeit")
+if !@isdefined(var"@zone")
     # This is designed to allow inserting timers when loading a second copy
     # of inference for performing performance experiments.
     macro timeit(args...)

Compiler/test/inline.jl

@@ -1852,7 +1852,7 @@ multi_inlining1(a::Int, b::Int) = @noinline func_mul_int(a, b)
 let i::Int, continue_::Bool
     interp = Compiler.NativeInterpreter()
     # check if callsite `@noinline` annotation works
-    ir, = only(Base.code_ircode(multi_inlining1, (Int,Int); optimize_until="inlining", interp))
+    ir, = only(Base.code_ircode(multi_inlining1, (Int,Int); optimize_until="CC: INLINING", interp))
     i = findfirst(isinvoke(:func_mul_int), ir.stmts.stmt)
     @test i !== nothing
     # now delete the callsite flag, and see the second inlining pass can inline the call
@@ -1876,7 +1876,7 @@ multi_inlining2(a::Int, b::Int) = call_func_mul_int(a, b)
 let i::Int, continue_::Bool
     interp = Compiler.NativeInterpreter()
     # check if callsite `@noinline` annotation works
-    ir, = only(Base.code_ircode(multi_inlining2, (Int,Int); optimize_until="inlining", interp))
+    ir, = only(Base.code_ircode(multi_inlining2, (Int,Int); optimize_until="CC: INLINING", interp))
     i = findfirst(isinvoke(:func_mul_int), ir.stmts.stmt)
     @test i !== nothing
     # now delete the callsite flag, and see the second inlining pass can inline the call
@@ -2220,7 +2220,7 @@ struct Issue52644
 end
 issue52644(::DataType) = :DataType
 issue52644(::UnionAll) = :UnionAll
-let ir = Base.code_ircode((Issue52644,); optimize_until="inlining") do t
+let ir = Base.code_ircode((Issue52644,); optimize_until="CC: INLINING") do t
         issue52644(t.tuple)
     end |> only |> first
     ir.argtypes[1] = Tuple{}
@@ -2229,7 +2229,7 @@ let ir = Base.code_ircode((Issue52644,); optimize_until="inlining") do t
     @test irfunc(Issue52644(Tuple{<:Integer})) === :UnionAll
 end
 issue52644_single(x::DataType) = :DataType
-let ir = Base.code_ircode((Issue52644,); optimize_until="inlining") do t
+let ir = Base.code_ircode((Issue52644,); optimize_until="CC: INLINING") do t
         issue52644_single(t.tuple)
     end |> only |> first
     ir.argtypes[1] = Tuple{}