Skip to content

Commit f3c2227

Browse files
Fix timev compilation time tracking and add tests (#46100)
1 parent 028e9ff commit f3c2227

File tree

2 files changed

+33
-1
lines changed

2 files changed

+33
-1
lines changed

base/timing.jl

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -353,9 +353,11 @@ macro timev(msg, ex)
353353
Experimental.@force_compile
354354
local stats = gc_num()
355355
local elapsedtime = time_ns()
356+
cumulative_compile_timing(true)
356357
local compile_elapsedtimes = cumulative_compile_time_ns()
357358
local val = @__tryfinally($(esc(ex)),
358359
(elapsedtime = time_ns() - elapsedtime;
360+
cumulative_compile_timing(false);
359361
compile_elapsedtimes = cumulative_compile_time_ns() .- compile_elapsedtimes)
360362
)
361363
local diff = GC_Diff(gc_num(), stats)

test/misc.jl

Lines changed: 31 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -366,7 +366,7 @@ macro capture_stdout(ex)
366366
end
367367
end
368368

369-
# compilation reports in @time
369+
# compilation reports in @time, @timev
370370
let f = gensym("f"), callf = gensym("callf"), call2f = gensym("call2f")
371371
@eval begin
372372
$f(::Real) = 1
@@ -397,6 +397,36 @@ let f = gensym("f"), callf = gensym("callf"), call2f = gensym("call2f")
397397
@test occursin("% of which was recompilation", out)
398398
end
399399
end
400+
let f = gensym("f"), callf = gensym("callf"), call2f = gensym("call2f")
401+
@eval begin
402+
$f(::Real) = 1
403+
$callf(container) = $f(container[1])
404+
$call2f(container) = $callf(container)
405+
c64 = [1.0]
406+
c32 = [1.0f0]
407+
cabs = AbstractFloat[1.0]
408+
409+
out = @capture_stdout @timev $call2f(c64)
410+
@test occursin("% compilation time", out)
411+
out = @capture_stdout @timev $call2f(c64)
412+
@test occursin("% compilation time", out) == false
413+
414+
out = @capture_stdout @timev $call2f(c32)
415+
@test occursin("% compilation time", out)
416+
out = @capture_stdout @timev $call2f(c32)
417+
@test occursin("% compilation time", out) == false
418+
419+
out = @capture_stdout @timev $call2f(cabs)
420+
@test occursin("% compilation time", out)
421+
out = @capture_stdout @timev $call2f(cabs)
422+
@test occursin("% compilation time", out) == false
423+
424+
$f(::Float64) = 2
425+
out = @capture_stdout @timev $call2f(c64)
426+
@test occursin("% compilation time:", out)
427+
@test occursin("% of which was recompilation", out)
428+
end
429+
end
400430

401431
# interactive utilities
402432

0 commit comments

Comments
 (0)