Skip to content

Commit 3b15a1d

Browse files
committed
stats: do not use at-timed, which kills perfs with while false; end
This is an heuristic to compile the bloc, which we don't need/want here.
1 parent 8ebd22e commit 3b15a1d

File tree

2 files changed

+44
-49
lines changed

2 files changed

+44
-49
lines changed

src/ReTest.jl

Lines changed: 8 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -199,28 +199,29 @@ function resolve!(mod::Module, ts::TestsetExpr, rx::Regex;
199199
end
200200

201201
# convert a TestsetExpr into an actually runnable testset
202-
function make_ts(ts::TestsetExpr, rx::Regex, chan)
202+
function make_ts(ts::TestsetExpr, rx::Regex, stats, chan)
203203
ts.run || return nothing
204204

205205
if isfinal(ts)
206206
body = ts.body
207207
else
208-
body = make_ts(ts.body, rx, chan)
208+
body = make_ts(ts.body, rx, stats, chan)
209209
end
210210
if ts.loops === nothing
211211
quote
212-
@testset $(ts.mod) $(isfinal(ts)) $rx $(ts.desc) $(ts.options) $chan $body
212+
@testset $(ts.mod) $(isfinal(ts)) $rx $(ts.desc) $(ts.options) $stats $chan $body
213213
end
214214
else
215215
loopvals = something(ts.loopvalues, ts.loops.args[2])
216216
quote
217-
@testset $(ts.mod) $(isfinal(ts)) $rx $(ts.desc) $(ts.options) $chan $(ts.loops.args[1]) $loopvals $body
217+
@testset $(ts.mod) $(isfinal(ts)) $rx $(ts.desc) $(ts.options) $stats $chan $(ts.loops.args[1]) $loopvals $body
218218
end
219219
end
220220
end
221221

222-
make_ts(x, rx, _) = x
223-
make_ts(ex::Expr, rx, chan) = Expr(ex.head, map(x -> make_ts(x, rx, chan), ex.args)...)
222+
make_ts(x, rx, _, _) = x
223+
make_ts(ex::Expr, rx, stats, chan) =
224+
Expr(ex.head, map(x -> make_ts(x, rx, stats, chan), ex.args)...)
224225

225226
# convert raw tests from InlineTest into TestsetExpr tests, and handle overwriting
226227
function updatetests!(mod::Module)
@@ -593,7 +594,7 @@ function retest(args::Union{Module,AbstractString,Regex}...;
593594
chan = (out=outchan, compute=computechan, preview=previewchan)
594595
remotecall_fetch(wrkr, mod, ts, regex, chan
595596
) do mod, ts, regex, chan
596-
mts = make_ts(ts, regex, chan)
597+
mts = make_ts(ts, regex, format.stats, chan)
597598
Core.eval(mod, mts)
598599
end
599600
catch e

src/testset.jl

Lines changed: 36 additions & 42 deletions
Original file line numberDiff line numberDiff line change
@@ -425,20 +425,22 @@ function get_testset_string(remove_last=false)
425425
end
426426

427427
# non-inline testset with regex filtering support
428-
macro testset(mod::String, isfinal::Bool, rx::Regex, desc::String, options, chan, body)
429-
Testset.testset_beginend(mod, isfinal, rx, desc, options, chan, body, __source__)
428+
macro testset(mod::String, isfinal::Bool, rx::Regex, desc::String, options,
429+
stats::Bool, chan, body)
430+
Testset.testset_beginend(mod, isfinal, rx, desc, options, stats, chan, body, __source__)
430431
end
431432

432-
macro testset(mod::String, isfinal::Bool, rx::Regex, desc::Union{String,Expr}, options, chan,
433-
loopiter, loopvals, body)
434-
Testset.testset_forloop(mod, isfinal, rx, desc, options, chan, loopiter, loopvals, body, __source__)
433+
macro testset(mod::String, isfinal::Bool, rx::Regex, desc::Union{String,Expr}, options,
434+
stats::Bool, chan, loopiter, loopvals, body)
435+
Testset.testset_forloop(mod, isfinal, rx, desc, options,
436+
stats, chan, loopiter, loopvals, body, __source__)
435437
end
436438

437439
"""
438440
Generate the code for a `@testset` with a `begin`/`end` argument
439441
"""
440442
function testset_beginend(mod::String, isfinal::Bool, rx::Regex, desc::String, options,
441-
chan, tests, source)
443+
stats::Bool, chan, tests, source)
442444
# Generate a block of code that initializes a new testset, adds
443445
# it to the task local storage, evaluates the test(s), before
444446
# finally removing the testset and giving it a chance to take
@@ -460,19 +462,12 @@ function testset_beginend(mod::String, isfinal::Bool, rx::Regex, desc::String, o
460462
# by wrapping the body in a function
461463
local RNG = default_rng()
462464
local oldrng = copy(RNG)
463-
local timed
464-
local rss
465-
local compile_time
466465
try
467466
# RNG is re-seeded with its own seed to ease reproduce a failed test
468467
Random.seed!(RNG.seed)
469-
rss = Sys.maxrss()
470-
compile_time = cumulative_compile_time_ns()
471468
let
472-
timed = @timed $(esc(tests))
469+
ts.timed = @stats $stats $(esc(tests))
473470
end
474-
rss = Sys.maxrss() - rss
475-
compile_time = cumulative_compile_time_ns() - compile_time
476471
catch err
477472
err isa InterruptException && rethrow()
478473
# something in the test block threw an error. Count that as an
@@ -482,8 +477,6 @@ function testset_beginend(mod::String, isfinal::Bool, rx::Regex, desc::String, o
482477
finally
483478
copy!(RNG, oldrng)
484479
pop_testset()
485-
@isdefined(timed) &&
486-
set_timed!(ts, timed, rss, compile_time)
487480
ret = finish(ts, $chan)
488481
end
489482
ret
@@ -501,9 +494,8 @@ end
501494
"""
502495
Generate the code for a `@testset` with a `for` loop argument
503496
"""
504-
function testset_forloop(mod::String, isfinal::Bool, rx::Regex, desc::Union{String,Expr}, options, chan,
505-
loopiter, loopvals,
506-
tests, source)
497+
function testset_forloop(mod::String, isfinal::Bool, rx::Regex, desc::Union{String,Expr},
498+
options, stats, chan, loopiter, loopvals, tests, source)
507499

508500
# Pull out the loop variables. We might need them for generating the
509501
# description and we'll definitely need them for generating the
@@ -519,8 +511,6 @@ function testset_forloop(mod::String, isfinal::Bool, rx::Regex, desc::Union{Stri
519511
# they can be handled properly by `finally` lowering.
520512
if !first_iteration
521513
pop_testset()
522-
timed !== nothing &&
523-
set_timed!(ts, timed, rss, compile_time)
524514
push!(arr, finish(ts, $chan))
525515
# it's 1000 times faster to copy from tmprng rather than calling Random.seed!
526516
copy!(RNG, tmprng)
@@ -532,14 +522,9 @@ function testset_forloop(mod::String, isfinal::Bool, rx::Regex, desc::Union{Stri
532522
push_testset(ts)
533523
first_iteration = false
534524
try
535-
rss = Sys.maxrss()
536-
compile_time = cumulative_compile_time_ns()
537-
timed = nothing
538525
let
539-
timed = @timed $(esc(tests))
526+
ts.timed = @stats $stats $(esc(tests))
540527
end
541-
rss = Sys.maxrss() - rss
542-
compile_time = cumulative_compile_time_ns() - compile_time
543528
catch err
544529
err isa InterruptException && rethrow()
545530
# Something in the test block threw an error. Count that as an
@@ -556,9 +541,6 @@ function testset_forloop(mod::String, isfinal::Bool, rx::Regex, desc::Union{Stri
556541
local oldrng = copy(RNG)
557542
Random.seed!(RNG.seed)
558543
local tmprng = copy(RNG)
559-
local timed
560-
local rss
561-
local compile_time
562544
try
563545
let
564546
$(Expr(:for, Expr(:block, [esc(v) for v in loopvars]...), blk))
@@ -567,8 +549,6 @@ function testset_forloop(mod::String, isfinal::Bool, rx::Regex, desc::Union{Stri
567549
# Handle `return` in test body
568550
if !first_iteration
569551
pop_testset()
570-
timed !== nothing &&
571-
set_timed!(ts, timed, rss, compile_time)
572552
push!(arr, finish(ts, $chan))
573553
end
574554
copy!(RNG, oldrng)
@@ -577,16 +557,6 @@ function testset_forloop(mod::String, isfinal::Bool, rx::Regex, desc::Union{Stri
577557
end
578558
end
579559

580-
function set_timed!(ts, timed, rss, compile_time)
581-
# on Julia < 1.5, @timed returns a Tuple; here we give the names as in
582-
# Julia 1.5+, but we filter out the `val` field, unused here
583-
ts.timed = (time = timed[2], bytes = timed[3], gctime = timed[4],
584-
rss = rss, compile_time = compile_time)
585-
# julia/test/runtests.jl uses timed.gcstats.total_time/10^9, which is equal to gctime
586-
# (timed[5] == timed.gcstats)
587-
ts
588-
end
589-
590560
function set_timed!(ts)
591561
if ts.overall
592562
foreach(get_timed!, ts.results)
@@ -600,6 +570,30 @@ end
600570

601571
get_timed!(ts) = isempty(ts.timed) ? set_timed!(ts) : ts
602572

573+
# adapted from @timed in Julia/base/timing.jl
574+
# also, @timed inserts a `while false; end` compiler heuristic, which destroys perfs here
575+
macro stats(yes, ex)
576+
quote
577+
if $yes
578+
local stats = Base.gc_num()
579+
local elapsedtime = time_ns()
580+
local rss = Sys.maxrss()
581+
local compile_time = cumulative_compile_time_ns()
582+
end
583+
local val = $(esc(ex))
584+
if $yes
585+
elapsedtime = time_ns() - elapsedtime
586+
local diff = Base.GC_Diff(Base.gc_num(), stats)
587+
rss = Sys.maxrss() - rss
588+
compile_time = cumulative_compile_time_ns() - compile_time
589+
(time=elapsedtime/1e9, bytes=diff.allocd, gctime=diff.total_time/1e9,
590+
rss = rss, compile_time = compile_time)
591+
else
592+
NamedTuple()
593+
end
594+
end
595+
end
596+
603597
cumulative_compile_time_ns() =
604598
isdefined(Base, :cumulative_compile_time_ns) ?
605599
Base.cumulative_compile_time_ns() :

0 commit comments

Comments
 (0)