From f3c22273d44ca9daedff3f72994e6ccf9c04c13e Mon Sep 17 00:00:00 2001 From: Ian Butterworth Date: Wed, 20 Jul 2022 11:51:39 -0400 Subject: [PATCH] Fix timev compilation time tracking and add tests (#46100) --- base/timing.jl | 2 ++ test/misc.jl | 32 +++++++++++++++++++++++++++++++- 2 files changed, 33 insertions(+), 1 deletion(-) diff --git a/base/timing.jl b/base/timing.jl index 02ed5fc5ae35c..7030fd53230ce 100644 --- a/base/timing.jl +++ b/base/timing.jl @@ -353,9 +353,11 @@ macro timev(msg, ex) Experimental.@force_compile local stats = gc_num() local elapsedtime = time_ns() + cumulative_compile_timing(true) local compile_elapsedtimes = cumulative_compile_time_ns() local val = @__tryfinally($(esc(ex)), (elapsedtime = time_ns() - elapsedtime; + cumulative_compile_timing(false); compile_elapsedtimes = cumulative_compile_time_ns() .- compile_elapsedtimes) ) local diff = GC_Diff(gc_num(), stats) diff --git a/test/misc.jl b/test/misc.jl index be5c8593351ff..bf4b4f2bb41e5 100644 --- a/test/misc.jl +++ b/test/misc.jl @@ -366,7 +366,7 @@ macro capture_stdout(ex) end end -# compilation reports in @time +# compilation reports in @time, @timev let f = gensym("f"), callf = gensym("callf"), call2f = gensym("call2f") @eval begin $f(::Real) = 1 @@ -397,6 +397,36 @@ let f = gensym("f"), callf = gensym("callf"), call2f = gensym("call2f") @test occursin("% of which was recompilation", out) end end +let f = gensym("f"), callf = gensym("callf"), call2f = gensym("call2f") + @eval begin + $f(::Real) = 1 + $callf(container) = $f(container[1]) + $call2f(container) = $callf(container) + c64 = [1.0] + c32 = [1.0f0] + cabs = AbstractFloat[1.0] + + out = @capture_stdout @timev $call2f(c64) + @test occursin("% compilation time", out) + out = @capture_stdout @timev $call2f(c64) + @test occursin("% compilation time", out) == false + + out = @capture_stdout @timev $call2f(c32) + @test occursin("% compilation time", out) + out = @capture_stdout @timev $call2f(c32) + @test occursin("% compilation time", out) == false + + out = @capture_stdout @timev $call2f(cabs) + @test occursin("% compilation time", out) + out = @capture_stdout @timev $call2f(cabs) + @test occursin("% compilation time", out) == false + + $f(::Float64) = 2 + out = @capture_stdout @timev $call2f(c64) + @test occursin("% compilation time:", out) + @test occursin("% of which was recompilation", out) + end +end # interactive utilities