From 62124363e4e5012a5ec17b56d8f7375bf86f8773 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Fri, 10 Oct 2025 18:28:44 +0200 Subject: [PATCH 01/21] Add progress indication and ETA status line. --- src/ParallelTestRunner.jl | 437 ++++++++++++++++++++++++-------------- test/basic.jl | 1 + test/runtests.jl | 2 + 3 files changed, 286 insertions(+), 154 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index 0684ce3..bc9c2d1 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -100,37 +100,21 @@ function test_IOContext(::Type{TestRecord}, io::IO, lock::ReentrantLock, name_al ) end +# Message types for the printer channel +# (:started, test_name, worker_id) +# (:finished, test_name, worker_id, record) +# (:errored, test_name, worker_id) +const printer_channel = Channel{Tuple}(100) + function print_header(::Type{TestRecord}, ctx::TestIOContext, testgroupheader, workerheader) printstyled(ctx.io, " "^(ctx.name_align + textwidth(testgroupheader) - 3), " | ") printstyled(ctx.io, " | ---------------- CPU ---------------- |\n", color = :white) printstyled(ctx.io, testgroupheader, color = :white) printstyled(ctx.io, lpad(workerheader, ctx.name_align - textwidth(testgroupheader) + 1), " | ", color = :white) - printstyled(ctx.io, "Time (s) | GC (s) | GC % | Alloc (MB) | RSS (MB) |\n", color = :white) + printstyled(ctx.io, "Time (s) | GC (s) | GC % | Alloc (MB) | RSS (MB) |\n", color = :white) return nothing end -function print_testworker_stats(test, wrkr, record::TestRecord, ctx::TestIOContext) - lock(ctx.lock) - return try - printstyled(ctx.io, test, color = :white) - printstyled(ctx.io, lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " | ", color = :white) - time_str = @sprintf("%7.2f", record.time) - printstyled(ctx.io, lpad(time_str, ctx.elapsed_align, " "), " | ", color = :white) - - gc_str = @sprintf("%5.2f", record.gctime) - printstyled(ctx.io, lpad(gc_str, ctx.gc_align, " "), " | ", color = :white) - percent_str = @sprintf("%4.1f", 100 * record.gctime / record.time) - printstyled(ctx.io, lpad(percent_str, ctx.percent_align, " "), " | ", color = :white) - alloc_str = @sprintf("%5.2f", record.bytes / 2^20) - printstyled(ctx.io, lpad(alloc_str, ctx.alloc_align, " "), " | ", color = :white) - - rss_str = @sprintf("%5.2f", record.rss / 2^20) - printstyled(ctx.io, lpad(rss_str, ctx.rss_align, " "), " |\n", color = :white) - finally - unlock(ctx.lock) - end -end - ## entry point @@ -142,8 +126,11 @@ function runtest(::Type{TestRecord}, f, name, init_code) @eval(mod, import ParallelTestRunner: Test, Random) @eval(mod, using .Test, .Random) + # Signal that this test has started let id = myid() - wait(@spawnat 1 print_testworker_started(name, id)) + @spawnat 1 begin + put!(printer_channel, (:started, name, id)) + end end Core.eval(mod, init_code) @@ -245,6 +232,12 @@ function addworkers(X; kwargs...) end addworker(; kwargs...) = addworkers(1; kwargs...)[1] +function recycle_worker(p) + rmprocs(p, waitfor = 30) + + return nothing +end + """ runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, custom_tests = Dict()) @@ -308,6 +301,10 @@ issues during long test runs. The memory limit is set based on system architectu function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, custom_tests::Dict{String, Expr}=Dict{String, Expr}(), init_code = :(), test_worker = Returns(nothing)) + # + # set-up + # + do_help, _ = extract_flag!(ARGS, "--help") if do_help println( @@ -409,6 +406,55 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # add workers addworkers(min(jobs, length(tests))) + t0 = time() + results = [] + tasks = Task[] + running_tests = Dict{String, Tuple{Int, Float64}}() # test => (worker, start_time) + + done = false + function stop_work() + if !done + done = true + for task in tasks + task == current_task() && continue + Base.istaskdone(task) && continue + try; schedule(task, InterruptException(); error=true); catch; end + end + end + end + + + # + # input + # + + # Keyboard monitor (for more reliable CTRL-C handling) + if isa(stdin, Base.TTY) + # NOTE: this should be the first task; we really want it to complete + pushfirst!(tasks, @async begin + term = REPL.Terminals.TTYTerminal("xterm", stdin, stdout, stderr) + REPL.Terminals.raw!(term, true) + try + while !done + c = read(term, Char) + if c == '\x3' + println("\nCaught interrupt, stopping...") + stop_work() + break + end + end + finally + REPL.Terminals.raw!(term, false) + end + end) + end + # TODO: we have to be _fast_ here, as Pkg.jl only gives us 4 seconds to clean up + + + # + # output + # + # pretty print information about gc and mem usage testgroupheader = "Test" workerheader = "(Worker)" @@ -431,165 +477,246 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, io_ctx = test_IOContext(RecordType, stdout, print_lock, name_align) print_header(RecordType, io_ctx, testgroupheader, workerheader) - global print_testworker_started = (name, wrkr) -> begin - if do_verbose - lock(print_lock) - try - printstyled(name, color = :white) - printstyled( - lpad("($wrkr)", name_align - textwidth(name) + 1, " "), " |", - " "^elapsed_align, "started at $(now())\n", color = :white - ) - finally - unlock(print_lock) + status_lines_visible = Ref(0) + function clear_status() + if status_lines_visible[] > 0 + for i in 1:status_lines_visible[] + width = displaysize(stdout)[2] + print(stdout, "\r", " "^width, "\r") + if i < status_lines_visible[] + print(stdout, "\033[1A") # Move up + end end + print(stdout, "\r") + status_lines_visible[] = 0 end end - function print_testworker_errored(name, wrkr) - lock(print_lock) - return try - printstyled(name, color = :red) - printstyled( - lpad("($wrkr)", name_align - textwidth(name) + 1, " "), " |", - " "^elapsed_align, " failed at $(now())\n", color = :red - ) - finally - unlock(print_lock) + function update_status() + isempty(running_tests) && return + completed = length(results) + total = completed + length(tests) + length(running_tests) + + # line 1: empty line + line1 = "" + + # line 2: running tests + test_list = sort(collect(running_tests), by = x -> x[2][2]) + status_parts = map(test_list) do (test, (wrkr, _)) + "$test ($wrkr)" + end + line2 = "Running: " * join(status_parts, ", ") + ## truncate + max_width = displaysize(stdout)[2] + if length(line2) > max_width + line2 = line2[1:max_width-3] * "..." end + + # line 3: progress + ETA + line3 = "Progress: $completed/$total tests completed" + if completed > 0 + elapsed_so_far = time() - t0 + avg_time_per_test = elapsed_so_far / completed + remaining_tests = length(tests) + length(running_tests) + eta_seconds = avg_time_per_test * remaining_tests + eta_mins = round(Int, eta_seconds / 60) + line3 *= " | ETA: ~$eta_mins min" + end + + # display + clear_status() + println(stdout, line1) + println(stdout, line2) + print(stdout, line3) + flush(stdout) + status_lines_visible[] = 3 end - # construct a testset to render the test results - o_ts = Test.DefaultTestSet("Overall") - # run tasks - results = [] - all_tasks = Task[] - try - # Monitor stdin and kill this task on ^C - # but don't do this on Windows, because it may deadlock in the kernel - t = current_task() - running_tests = Dict{String, DateTime}() - if !Sys.iswindows() && isa(stdin, Base.TTY) - stdin_monitor = @async begin - term = REPL.Terminals.TTYTerminal("xterm", stdin, stdout, stderr) - try - REPL.Terminals.raw!(term, true) - while true - c = read(term, Char) - if c == '\x3' - Base.throwto(t, InterruptException()) - break - elseif c == '?' - println("Currently running: ") - tests = sort(collect(running_tests), by = x -> x[2]) - foreach(tests) do (test, date) - println(test, " (running for ", round(now() - date, Minute), ")") - end + push!(tasks, @async begin + last_status_update = Ref(time()) + try + # XXX: it's possible this task doesn't run, not processing results, + # while the execution runners have exited... + while !done + got_message = false + while isready(printer_channel) + # Try to get a message from the channel (with timeout) + msg = take!(printer_channel) + got_message = true + msg_type = msg[1] + + if msg_type == :started + test_name, wrkr = msg[2], msg[3] + + # Optionally print verbose started message + if do_verbose + printstyled(test_name, color = :white) + printstyled( + lpad("($wrkr)", name_align - textwidth(test_name) + 1, " "), " |", + " "^elapsed_align, "started at $(now())\n", color = :white + ) + flush(stdout) end + + elseif msg_type == :finished + test_name, wrkr, record = msg[2], msg[3], msg[4] + + # Clear status lines before printing result + clear_status() + + # Print test result + printstyled(test_name, color = :white) + printstyled(stdout, lpad("($wrkr)", name_align - textwidth(test_name) + 1, " "), " | ", color = :white) + time_str = @sprintf("%7.2f", record.time) + printstyled(stdout, lpad(time_str, elapsed_align, " "), " | ", color = :white) + gc_str = @sprintf("%5.2f", record.gctime) + printstyled(stdout, lpad(gc_str, io_ctx.gc_align, " "), " | ", color = :white) + percent_str = @sprintf("%4.1f", 100 * record.gctime / record.time) + printstyled(stdout, lpad(percent_str, io_ctx.percent_align, " "), " | ", color = :white) + alloc_str = @sprintf("%5.2f", record.bytes / 2^20) + printstyled(stdout, lpad(alloc_str, io_ctx.alloc_align, " "), " | ", color = :white) + rss_str = @sprintf("%5.2f", record.rss / 2^20) + printstyled(stdout, lpad(rss_str, io_ctx.rss_align, " "), " |\n", color = :white) + flush(stdout) + + elseif msg_type == :errored + test_name, wrkr = msg[2], msg[3] + + # Clear status lines before printing error + clear_status() + + printstyled(test_name, color = :red) + printstyled( + lpad("($wrkr)", name_align - textwidth(test_name) + 1, " "), " |", + " "^elapsed_align, " failed at $(now())\n", color = :red + ) + flush(stdout) end - catch e - isa(e, InterruptException) || rethrow() - finally - REPL.Terminals.raw!(term, false) end + + # After a while, display a status line + if time() - t0 >= 5 && (got_message || (time() - last_status_update[] >= 1)) + update_status() + last_status_update[] = time() + end + sleep(0.1) + end + catch ex + isa(ex, InterruptException) || rethrow() + finally + if isempty(tests) && isempty(running_tests) + # XXX: only erase the status if we completed successfully. + # in other cases we'll have printed "caught interrupt" + clear_status() end end - @sync begin - function recycle_worker(p) - rmprocs(p, waitfor = 30) + end) - return nothing - end - for p in workers() - @async begin - push!(all_tasks, current_task()) - while length(tests) > 0 - test = popfirst!(tests) + # + # execution + # - # if a worker failed, spawn a new one - if p === nothing - p = addworkers(1)[1] - end + for p in workers() + push!(tasks, @async begin + while length(tests) > 0 && !done + # if a worker failed, spawn a new one + if p === nothing + p = addworkers(1)[1] + end - # some tests may need a special worker - wrkr = something(test_worker(test), p) + # get a test to run + test = popfirst!(tests) + wrkr = something(test_worker(test), p) + running_tests[test] = (wrkr, time()) - # run the test - running_tests[test] = now() - resp = try - remotecall_fetch(runtest, wrkr, RecordType, test_runners[test], test, init_code) - catch e - isa(e, InterruptException) && return - Any[e] - end - delete!(running_tests, test) - push!(results, (test, resp)) - - # act on the results - if resp isa AbstractTestRecord - print_testworker_stats(test, wrkr, resp::RecordType, io_ctx) - - if memory_usage(resp) > max_worker_rss - # the worker has reached the max-rss limit, recycle it - # so future tests start with a smaller working set - p = recycle_worker(p) - end - else - @assert resp[1] isa Exception - print_testworker_errored(test, wrkr) - do_quickfail && Base.throwto(t, InterruptException()) - - # the worker encountered some failure, recycle it - # so future tests get a fresh environment - p = recycle_worker(p) - end + # run the test + resp = try + remotecall_fetch(runtest, wrkr, RecordType, test_runners[test], test, init_code) + catch e + isa(e, InterruptException) && return + Any[e] + end + push!(results, (test, resp)) - # get rid of the custom worker - if wrkr != p - recycle_worker(wrkr) - end - end + # act on the results + if resp isa AbstractTestRecord + put!(printer_channel, (:finished, test, wrkr, resp::RecordType)) - if p !== nothing - recycle_worker(p) + if memory_usage(resp) > max_worker_rss + # the worker has reached the max-rss limit, recycle it + # so future tests start with a smaller working set + p = recycle_worker(p) end + else + @assert resp[1] isa Exception + put!(printer_channel, (:errored, test, wrkr)) + if do_quickfail + stop_work() + end + + # the worker encountered some failure, recycle it + # so future tests get a fresh environment + p = recycle_worker(p) end - end - end - catch e - isa(e, InterruptException) || rethrow() - # If the test suite was merely interrupted, still print the - # summary, which can be useful to diagnose what's going on - foreach( - task -> begin - istaskstarted(task) || return - istaskdone(task) && return - try - schedule(task, InterruptException(); error = true) - catch ex - @error "InterruptException" exception = ex, catch_backtrace() + + # get rid of the custom worker + if wrkr != p + recycle_worker(wrkr) end - end, all_tasks - ) - for t in all_tasks - # NOTE: we can't just wait, but need to discard the exception, - # because the throwto for --quickfail also kills the worker. - try - wait(t) - catch e - showerror(stderr, e) + + delete!(running_tests, test) + end + + if p !== nothing + recycle_worker(p) + end + end) + end + + + # + # finalization + # + + # monitor tasks for failure so that each one doesn't need a try/catch + stop_work() + try + while true + if any(istaskfailed, tasks) + println("\nCaught an error, stopping...") + break + elseif done || (isempty(tests) && isempty(running_tests)) + break end + sleep(1) end + catch err + # in case the sleep got interrupted + isa(err, InterruptException) || rethrow() finally - if @isdefined stdin_monitor - schedule(stdin_monitor, InterruptException(); error = true) + stop_work() + end + ## `wait()` to actually catch any exceptions + for task in tasks + try + wait(task) + catch err + # unwrap TaskFailedException + while isa(err, TaskFailedException) + err = current_exceptions(err.task)[1].exception + end + + isa(err, InterruptException) || rethrow() end end - t1 = time() + # construct a testset to render the test results + t1 = time() + o_ts = Test.DefaultTestSet("Overall") if VERSION < v"1.13.0-DEV.1037" + o_ts.time_start = t0 o_ts.time_end = t1 else + @atomic o_ts.time_start = t0 @atomic o_ts.time_end = t1 end with_testset(o_ts) do @@ -648,7 +775,9 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, end end end - for test in tests + + # mark remaining or running tests as interrupted + for test in [tests; collect(keys(running_tests))] (test in completed_tests) && continue fake = Test.DefaultTestSet(test) Test.record(fake, Test.Error(:test_interrupted, test, nothing, Base.ExceptionStack([(exception = "skipped", backtrace = [])]), LineNumberNode(1))) diff --git a/test/basic.jl b/test/basic.jl index 8a617b3..a57aa68 100644 --- a/test/basic.jl +++ b/test/basic.jl @@ -1 +1,2 @@ @test true +sleep(10) diff --git a/test/runtests.jl b/test/runtests.jl index ea9ba3f..f157a44 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -1,6 +1,8 @@ using ParallelTestRunner using Test, IOCapture +cd(@__DIR__) + @testset "ParallelTestRunner" verbose=true begin @testset "basic test" begin From 37dde5cf8c269ae2d37780440d420ff57192bff1 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Sat, 11 Oct 2025 08:11:40 +0200 Subject: [PATCH 02/21] Record every testset's timing information. --- src/ParallelTestRunner.jl | 55 +++++++++++++++++++++------------------ test/basic.jl | 1 - 2 files changed, 29 insertions(+), 27 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index bc9c2d1..0f78adc 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -126,13 +126,6 @@ function runtest(::Type{TestRecord}, f, name, init_code) @eval(mod, import ParallelTestRunner: Test, Random) @eval(mod, using .Test, .Random) - # Signal that this test has started - let id = myid() - @spawnat 1 begin - put!(printer_channel, (:started, name, id)) - end - end - Core.eval(mod, init_code) data = @eval mod begin GC.gc(true) @@ -627,16 +620,19 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # get a test to run test = popfirst!(tests) wrkr = something(test_worker(test), p) - running_tests[test] = (wrkr, time()) # run the test + test_t0 = time() + running_tests[test] = (wrkr, test_t0) + put!(printer_channel, (:started, test, wrkr)) resp = try remotecall_fetch(runtest, wrkr, RecordType, test_runners[test], test, init_code) catch e isa(e, InterruptException) && return Any[e] end - push!(results, (test, resp)) + test_t1 = time() + push!(results, (test, resp, test_t0, test_t1)) # act on the results if resp isa AbstractTestRecord @@ -711,27 +707,27 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # construct a testset to render the test results t1 = time() - o_ts = Test.DefaultTestSet("Overall") + o_ts = Test.DefaultTestSet("Overall"; verbose=do_verbose) if VERSION < v"1.13.0-DEV.1037" o_ts.time_start = t0 o_ts.time_end = t1 else - @atomic o_ts.time_start = t0 + #@atomic o_ts.time_start = t0 @atomic o_ts.time_end = t1 end with_testset(o_ts) do completed_tests = Set{String}() - for (testname, res) in results + for (testname, res, start, stop) in results if res isa AbstractTestRecord resp = res.test else resp = res[1] end push!(completed_tests, testname) - if isa(resp, Test.DefaultTestSet) - with_testset(resp) do - Test.record(o_ts, resp) - end + + # decode or fake a testset + testset = if isa(resp, Test.DefaultTestSet) + resp elseif isa(resp, Tuple{Int, Int}) fake = Test.DefaultTestSet(testname) for i in 1:resp[1] @@ -740,10 +736,9 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, for i in 1:resp[2] Test.record(fake, Test.Broken(:test, nothing)) end - with_testset(fake) do - Test.record(o_ts, fake) - end - elseif isa(resp, RemoteException) && isa(resp.captured.ex, Test.TestSetException) + fake + elseif isa(resp, RemoteException) && + isa(resp.captured.ex, Test.TestSetException) println("Worker $(resp.pid) failed running test $(testname):") Base.showerror(stdout, resp.captured) println() @@ -757,9 +752,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, for t in resp.captured.ex.errors_and_fails Test.record(fake, t) end - with_testset(fake) do - Test.record(o_ts, fake) - end + fake else if !isa(resp, Exception) resp = ErrorException(string("Unknown result type : ", typeof(resp))) @@ -770,9 +763,19 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # deserialization errors or something similar. Record this testset as Errored. fake = Test.DefaultTestSet(testname) Test.record(fake, Test.Error(:nontest_error, testname, nothing, Base.ExceptionStack([(exception = resp, backtrace = [])]), LineNumberNode(1))) - with_testset(fake) do - Test.record(o_ts, fake) - end + fake + end + + # record the testset + if VERSION < v"1.13.0-DEV.1037" + testset.time_start = start + testset.time_end = stop + else + #@atomic testset.time_start = start + @atomic testset.time_end = stop + end + with_testset(testset) do + Test.record(o_ts, testset) end end diff --git a/test/basic.jl b/test/basic.jl index a57aa68..8a617b3 100644 --- a/test/basic.jl +++ b/test/basic.jl @@ -1,2 +1 @@ @test true -sleep(10) From 407977e6e05fbeee9ae07582c846022896b142e7 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Sat, 11 Oct 2025 08:24:42 +0200 Subject: [PATCH 03/21] Factor out printing logic again. --- src/ParallelTestRunner.jl | 125 +++++++++++++++++++++++++------------- 1 file changed, 82 insertions(+), 43 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index 0f78adc..6de751d 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -76,6 +76,11 @@ function memory_usage(rec::TestRecord) return rec.rss end + +# +# overridable I/O context for pretty-printing +# + struct TestIOContext io::IO lock::ReentrantLock @@ -100,23 +105,77 @@ function test_IOContext(::Type{TestRecord}, io::IO, lock::ReentrantLock, name_al ) end -# Message types for the printer channel -# (:started, test_name, worker_id) -# (:finished, test_name, worker_id, record) -# (:errored, test_name, worker_id) -const printer_channel = Channel{Tuple}(100) - function print_header(::Type{TestRecord}, ctx::TestIOContext, testgroupheader, workerheader) - printstyled(ctx.io, " "^(ctx.name_align + textwidth(testgroupheader) - 3), " | ") - printstyled(ctx.io, " | ---------------- CPU ---------------- |\n", color = :white) - printstyled(ctx.io, testgroupheader, color = :white) - printstyled(ctx.io, lpad(workerheader, ctx.name_align - textwidth(testgroupheader) + 1), " | ", color = :white) - printstyled(ctx.io, "Time (s) | GC (s) | GC % | Alloc (MB) | RSS (MB) |\n", color = :white) - return nothing + lock(ctx.lock) + try + printstyled(ctx.io, " "^(ctx.name_align + textwidth(testgroupheader) - 3), " | ") + printstyled(ctx.io, " | ---------------- CPU ---------------- |\n", color = :white) + printstyled(ctx.io, testgroupheader, color = :white) + printstyled(ctx.io, lpad(workerheader, ctx.name_align - textwidth(testgroupheader) + 1), " | ", color = :white) + printstyled(ctx.io, "Time (s) | GC (s) | GC % | Alloc (MB) | RSS (MB) |\n", color = :white) + flush(ctx.io) + finally + unlock(ctx.lock) + end +end + +function print_test_started(::Type{TestRecord}, wrkr, test, ctx::TestIOContext) + lock(ctx.lock) + try + printstyled(test, color = :white) + printstyled( + lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " |", + " "^ctx.elapsed_align, "started at $(now())\n", color = :white + ) + flush(ctx.io) + finally + unlock(ctx.lock) + end +end + +function print_test_finished(test, wrkr, record::TestRecord, ctx::TestIOContext) + lock(ctx.lock) + try + printstyled(ctx.io, test, color = :white) + printstyled(ctx.io, lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " | ", color = :white) + time_str = @sprintf("%7.2f", record.time) + printstyled(ctx.io, lpad(time_str, ctx.elapsed_align, " "), " | ", color = :white) + + gc_str = @sprintf("%5.2f", record.gctime) + printstyled(ctx.io, lpad(gc_str, ctx.gc_align, " "), " | ", color = :white) + percent_str = @sprintf("%4.1f", 100 * record.gctime / record.time) + printstyled(ctx.io, lpad(percent_str, ctx.percent_align, " "), " | ", color = :white) + alloc_str = @sprintf("%5.2f", record.bytes / 2^20) + printstyled(ctx.io, lpad(alloc_str, ctx.alloc_align, " "), " | ", color = :white) + + rss_str = @sprintf("%5.2f", record.rss / 2^20) + printstyled(ctx.io, lpad(rss_str, ctx.rss_align, " "), " |\n", color = :white) + + flush(ctx.io) + finally + unlock(ctx.lock) + end +end + +function print_test_errorred(::Type{TestRecord}, wrkr, test, ctx::TestIOContext) + lock(ctx.lock) + try + printstyled(test, color = :red) + printstyled( + lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " |", + " "^ctx.elapsed_align, " failed at $(now())\n", color = :red + ) + + flush(ctx.io) + finally + unlock(ctx.lock) + end end -## entry point +# +# entry point +# function runtest(::Type{TestRecord}, f, name, init_code) function inner() @@ -524,6 +583,12 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, status_lines_visible[] = 3 end + # Message types for the printer channel + # (:started, test_name, worker_id) + # (:finished, test_name, worker_id, record) + # (:errored, test_name, worker_id) + printer_channel = Channel{Tuple}(100) + push!(tasks, @async begin last_status_update = Ref(time()) try @@ -542,47 +607,21 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # Optionally print verbose started message if do_verbose - printstyled(test_name, color = :white) - printstyled( - lpad("($wrkr)", name_align - textwidth(test_name) + 1, " "), " |", - " "^elapsed_align, "started at $(now())\n", color = :white - ) - flush(stdout) + clear_status() + print_test_started(RecordType, wrkr, test_name, io_ctx) end elseif msg_type == :finished test_name, wrkr, record = msg[2], msg[3], msg[4] - # Clear status lines before printing result clear_status() - - # Print test result - printstyled(test_name, color = :white) - printstyled(stdout, lpad("($wrkr)", name_align - textwidth(test_name) + 1, " "), " | ", color = :white) - time_str = @sprintf("%7.2f", record.time) - printstyled(stdout, lpad(time_str, elapsed_align, " "), " | ", color = :white) - gc_str = @sprintf("%5.2f", record.gctime) - printstyled(stdout, lpad(gc_str, io_ctx.gc_align, " "), " | ", color = :white) - percent_str = @sprintf("%4.1f", 100 * record.gctime / record.time) - printstyled(stdout, lpad(percent_str, io_ctx.percent_align, " "), " | ", color = :white) - alloc_str = @sprintf("%5.2f", record.bytes / 2^20) - printstyled(stdout, lpad(alloc_str, io_ctx.alloc_align, " "), " | ", color = :white) - rss_str = @sprintf("%5.2f", record.rss / 2^20) - printstyled(stdout, lpad(rss_str, io_ctx.rss_align, " "), " |\n", color = :white) - flush(stdout) + print_test_finished(test_name, wrkr, record, io_ctx) elseif msg_type == :errored test_name, wrkr = msg[2], msg[3] - # Clear status lines before printing error clear_status() - - printstyled(test_name, color = :red) - printstyled( - lpad("($wrkr)", name_align - textwidth(test_name) + 1, " "), " |", - " "^elapsed_align, " failed at $(now())\n", color = :red - ) - flush(stdout) + print_test_errorred(RecordType, wrkr, test_name, io_ctx) end end From 5e6ec5f8affe35f4ffe8ba829e5d4edd8b323915 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Sun, 12 Oct 2025 09:26:32 +0200 Subject: [PATCH 04/21] Only draw on a TTY. --- src/ParallelTestRunner.jl | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index 6de751d..e5769b0 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -544,6 +544,10 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, end end function update_status() + # only draw the status bar on actual terminals + stdout isa Base.TTY || return + + # only draw if we have something to show isempty(running_tests) && return completed = length(results) total = completed + length(tests) + length(running_tests) From ec9f8f0a98ccf8f3bf9a66917804fe8c31c2dd40 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Sun, 12 Oct 2025 12:29:06 +0200 Subject: [PATCH 05/21] Add io arguments to runtests instead of relying on IOCapture. --- Project.toml | 2 + src/ParallelTestRunner.jl | 137 +++++++++++++++++++++++--------------- test/Project.toml | 1 - test/runtests.jl | 82 +++++++++++++---------- 4 files changed, 132 insertions(+), 90 deletions(-) diff --git a/Project.toml b/Project.toml index e419024..f2c8bee 100644 --- a/Project.toml +++ b/Project.toml @@ -6,6 +6,7 @@ version = "0.1.2" [deps] Dates = "ade2ca70-3891-5945-98fb-dc099432e06a" Distributed = "8ba89e20-285c-5b6f-9357-94700520ee1b" +IOCapture = "b5f81e59-6552-4d32-b1f0-c071b021bf89" Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7" REPL = "3fa0cd96-eef1-5676-8a61-b3b8758bbffb" Random = "9a3f8284-a2c9-5f02-9a11-845980a1fd5c" @@ -14,6 +15,7 @@ Test = "8dfed614-e22c-5e08-85e1-65c5234f0b40" [compat] Dates = "1" Distributed = "1" +IOCapture = "0.2.5" Printf = "1" REPL = "1" Random = "1" diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index e5769b0..e618e96 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -9,6 +9,7 @@ using Printf: @sprintf using Base.Filesystem: path_separator import Test import Random +import IOCapture #Always set the max rss so that if tests add large global variables (which they do) we don't make the GC's life too hard if Sys.WORD_SIZE == 64 @@ -82,7 +83,8 @@ end # struct TestIOContext - io::IO + stdout::IO + stderr::IO lock::ReentrantLock name_align::Int elapsed_align::Int @@ -92,7 +94,7 @@ struct TestIOContext rss_align::Int end -function test_IOContext(::Type{TestRecord}, io::IO, lock::ReentrantLock, name_align::Int) +function test_IOContext(::Type{TestRecord}, stdout::IO, stderr::IO, lock::ReentrantLock, name_align::Int) elapsed_align = textwidth("Time (s)") gc_align = textwidth("GC (s)") percent_align = textwidth("GC %") @@ -100,7 +102,7 @@ function test_IOContext(::Type{TestRecord}, io::IO, lock::ReentrantLock, name_al rss_align = textwidth("RSS (MB)") return TestIOContext( - io, lock, name_align, elapsed_align, gc_align, percent_align, + stdout, stderr, lock, name_align, elapsed_align, gc_align, percent_align, alloc_align, rss_align ) end @@ -108,12 +110,12 @@ end function print_header(::Type{TestRecord}, ctx::TestIOContext, testgroupheader, workerheader) lock(ctx.lock) try - printstyled(ctx.io, " "^(ctx.name_align + textwidth(testgroupheader) - 3), " | ") - printstyled(ctx.io, " | ---------------- CPU ---------------- |\n", color = :white) - printstyled(ctx.io, testgroupheader, color = :white) - printstyled(ctx.io, lpad(workerheader, ctx.name_align - textwidth(testgroupheader) + 1), " | ", color = :white) - printstyled(ctx.io, "Time (s) | GC (s) | GC % | Alloc (MB) | RSS (MB) |\n", color = :white) - flush(ctx.io) + printstyled(ctx.stdout, " "^(ctx.name_align + textwidth(testgroupheader) - 3), " | ") + printstyled(ctx.stdout, " | ---------------- CPU ---------------- |\n", color = :white) + printstyled(ctx.stdout, testgroupheader, color = :white) + printstyled(ctx.stdout, lpad(workerheader, ctx.name_align - textwidth(testgroupheader) + 1), " | ", color = :white) + printstyled(ctx.stdout, "Time (s) | GC (s) | GC % | Alloc (MB) | RSS (MB) |\n", color = :white) + flush(ctx.stdout) finally unlock(ctx.lock) end @@ -122,12 +124,13 @@ end function print_test_started(::Type{TestRecord}, wrkr, test, ctx::TestIOContext) lock(ctx.lock) try - printstyled(test, color = :white) + printstyled(ctx.stdout, test, color = :white) printstyled( + ctx.stdout, lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " |", " "^ctx.elapsed_align, "started at $(now())\n", color = :white ) - flush(ctx.io) + flush(ctx.stdout) finally unlock(ctx.lock) end @@ -136,22 +139,22 @@ end function print_test_finished(test, wrkr, record::TestRecord, ctx::TestIOContext) lock(ctx.lock) try - printstyled(ctx.io, test, color = :white) - printstyled(ctx.io, lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " | ", color = :white) + printstyled(ctx.stdout, test, color = :white) + printstyled(ctx.stdout, lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " | ", color = :white) time_str = @sprintf("%7.2f", record.time) - printstyled(ctx.io, lpad(time_str, ctx.elapsed_align, " "), " | ", color = :white) + printstyled(ctx.stdout, lpad(time_str, ctx.elapsed_align, " "), " | ", color = :white) gc_str = @sprintf("%5.2f", record.gctime) - printstyled(ctx.io, lpad(gc_str, ctx.gc_align, " "), " | ", color = :white) + printstyled(ctx.stdout, lpad(gc_str, ctx.gc_align, " "), " | ", color = :white) percent_str = @sprintf("%4.1f", 100 * record.gctime / record.time) - printstyled(ctx.io, lpad(percent_str, ctx.percent_align, " "), " | ", color = :white) + printstyled(ctx.stdout, lpad(percent_str, ctx.percent_align, " "), " | ", color = :white) alloc_str = @sprintf("%5.2f", record.bytes / 2^20) - printstyled(ctx.io, lpad(alloc_str, ctx.alloc_align, " "), " | ", color = :white) + printstyled(ctx.stdout, lpad(alloc_str, ctx.alloc_align, " "), " | ", color = :white) rss_str = @sprintf("%5.2f", record.rss / 2^20) - printstyled(ctx.io, lpad(rss_str, ctx.rss_align, " "), " |\n", color = :white) + printstyled(ctx.stdout, lpad(rss_str, ctx.rss_align, " "), " |\n", color = :white) - flush(ctx.io) + flush(ctx.stdout) finally unlock(ctx.lock) end @@ -160,13 +163,14 @@ end function print_test_errorred(::Type{TestRecord}, wrkr, test, ctx::TestIOContext) lock(ctx.lock) try - printstyled(test, color = :red) + printstyled(ctx.stderr, test, color = :red) printstyled( + ctx.stderr, lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " |", " "^ctx.elapsed_align, " failed at $(now())\n", color = :red ) - flush(ctx.io) + flush(ctx.stderr) finally unlock(ctx.lock) end @@ -318,6 +322,7 @@ Several keyword arguments are also supported: - `--quickfail`: Stop the entire test run as soon as any test fails - `--jobs=N`: Use N worker processes (default: based on CPU threads and available memory) - `TESTS...`: Filter tests by name, matched using `startswith` +- `stdout` and `stderr`: I/O streams to write to (default: `Base.stdout` and `Base.stderr`) ## Behavior @@ -352,7 +357,7 @@ issues during long test runs. The memory limit is set based on system architectu """ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, custom_tests::Dict{String, Expr}=Dict{String, Expr}(), init_code = :(), - test_worker = Returns(nothing)) + test_worker = Returns(nothing), stdout = Base.stdout, stderr = Base.stderr) # # set-up # @@ -453,7 +458,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, if !set_jobs jobs = default_njobs() end - @info "Running $jobs tests in parallel. If this is too many, specify the `--jobs=N` argument to the tests, or set the `JULIA_CPU_THREADS` environment variable." + println(stdout, "Running $jobs tests in parallel. If this is too many, specify the `--jobs=N` argument to the tests, or set the `JULIA_CPU_THREADS` environment variable.") # add workers addworkers(min(jobs, length(tests))) @@ -490,7 +495,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, while !done c = read(term, Char) if c == '\x3' - println("\nCaught interrupt, stopping...") + println(stderr, "\nCaught interrupt, stopping...") stop_work() break end @@ -526,26 +531,26 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, stderr.lock = print_lock end - io_ctx = test_IOContext(RecordType, stdout, print_lock, name_align) + io_ctx = test_IOContext(RecordType, stdout, stderr, print_lock, name_align) print_header(RecordType, io_ctx, testgroupheader, workerheader) status_lines_visible = Ref(0) function clear_status() if status_lines_visible[] > 0 for i in 1:status_lines_visible[] - width = displaysize(stdout)[2] - print(stdout, "\r", " "^width, "\r") + width = displaysize(io_ctx.stdout)[2] + print(io_ctx.stdout, "\r", " "^width, "\r") if i < status_lines_visible[] - print(stdout, "\033[1A") # Move up + print(io_ctx.stdout, "\033[1A") # Move up end end - print(stdout, "\r") + print(io_ctx.stdout, "\r") status_lines_visible[] = 0 end end function update_status() # only draw the status bar on actual terminals - stdout isa Base.TTY || return + io_ctx.stdout isa Base.TTY || return # only draw if we have something to show isempty(running_tests) && return @@ -562,7 +567,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, end line2 = "Running: " * join(status_parts, ", ") ## truncate - max_width = displaysize(stdout)[2] + max_width = displaysize(io_ctx.stdout)[2] if length(line2) > max_width line2 = line2[1:max_width-3] * "..." end @@ -580,10 +585,10 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # display clear_status() - println(stdout, line1) - println(stdout, line2) - print(stdout, line3) - flush(stdout) + println(io_ctx.stdout, line1) + println(io_ctx.stdout, line2) + print(io_ctx.stdout, line3) + flush(io_ctx.stdout) status_lines_visible[] = 3 end @@ -721,7 +726,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, try while true if any(istaskfailed, tasks) - println("\nCaught an error, stopping...") + println(io_ctx.stderr, "\nCaught an error, stopping...") break elseif done || (isempty(tests) && isempty(running_tests)) break @@ -782,19 +787,23 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, fake elseif isa(resp, RemoteException) && isa(resp.captured.ex, Test.TestSetException) - println("Worker $(resp.pid) failed running test $(testname):") - Base.showerror(stdout, resp.captured) - println() + println(io_ctx.stderr, "Worker $(resp.pid) failed running test $(testname):") + Base.showerror(io_ctx.stderr, resp.captured) + println(io_ctx.stderr) + fake = Test.DefaultTestSet(testname) - for i in 1:resp.captured.ex.pass - Test.record(fake, Test.Pass(:test, nothing, nothing, nothing, nothing)) - end - for i in 1:resp.captured.ex.broken - Test.record(fake, Test.Broken(:test, nothing)) - end - for t in resp.captured.ex.errors_and_fails - Test.record(fake, t) + c = IOCapture.capture() do + for i in 1:resp.captured.ex.pass + Test.record(fake, Test.Pass(:test, nothing, nothing, nothing, nothing)) + end + for i in 1:resp.captured.ex.broken + Test.record(fake, Test.Broken(:test, nothing)) + end + for t in resp.captured.ex.errors_and_fails + Test.record(fake, t) + end end + print(io_ctx.stdout, c.output) fake else if !isa(resp, Exception) @@ -805,7 +814,10 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # the test runner itself had some problem, so we may have hit a segfault, # deserialization errors or something similar. Record this testset as Errored. fake = Test.DefaultTestSet(testname) - Test.record(fake, Test.Error(:nontest_error, testname, nothing, Base.ExceptionStack([(exception = resp, backtrace = [])]), LineNumberNode(1))) + c = IOCapture.capture() do + Test.record(fake, Test.Error(:nontest_error, testname, nothing, Base.ExceptionStack([(exception = resp, backtrace = [])]), LineNumberNode(1))) + end + print(io_ctx.stdout, c.output) fake end @@ -826,20 +838,37 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, for test in [tests; collect(keys(running_tests))] (test in completed_tests) && continue fake = Test.DefaultTestSet(test) - Test.record(fake, Test.Error(:test_interrupted, test, nothing, Base.ExceptionStack([(exception = "skipped", backtrace = [])]), LineNumberNode(1))) + c = IOCapture.capture() do + Test.record(fake, Test.Error(:test_interrupted, test, nothing, Base.ExceptionStack([(exception = "skipped", backtrace = [])]), LineNumberNode(1))) + end + print(io_ctx.stdout, c.output) with_testset(fake) do Test.record(o_ts, fake) end end end - println() - Test.print_test_results(o_ts, 1) + println(io_ctx.stdout) + if VERSION >= v"1.13.0-DEV.1033" + Test.print_test_results(io_ctx.stdout, o_ts, 1) + else + c = IOCapture.capture() do + Test.print_test_results(o_ts, 1) + end + print(io_ctx.stdout, c.output) + end if (VERSION >= v"1.13.0-DEV.1037" && !Test.anynonpass(o_ts)) || (VERSION < v"1.13.0-DEV.1037" && !o_ts.anynonpass) - println(" \033[32;1mSUCCESS\033[0m") + println(io_ctx.stdout, " \033[32;1mSUCCESS\033[0m") else - println(" \033[31;1mFAILURE\033[0m\n") - Test.print_test_errors(o_ts) + println(io_ctx.stderr, " \033[31;1mFAILURE\033[0m\n") + if VERSION >= v"1.13.0-DEV.1033" + Test.print_test_errors(io_ctx.stdout, o_ts) + else + c = IOCapture.capture() do + Test.print_test_errors(o_ts) + end + print(io_ctx.stdout, c.output) + end throw(Test.FallbackTestSetException("Test run finished with errors")) end return nothing diff --git a/test/Project.toml b/test/Project.toml index 72c588e..0c36332 100644 --- a/test/Project.toml +++ b/test/Project.toml @@ -1,3 +1,2 @@ [deps] -IOCapture = "b5f81e59-6552-4d32-b1f0-c071b021bf89" Test = "8dfed614-e22c-5e08-85e1-65c5234f0b40" diff --git a/test/runtests.jl b/test/runtests.jl index f157a44..8dac2bc 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -1,21 +1,24 @@ using ParallelTestRunner -using Test, IOCapture +using Test cd(@__DIR__) @testset "ParallelTestRunner" verbose=true begin @testset "basic test" begin + io = IOBuffer() + runtests(["--verbose"]; stdout=io, stderr=io) + str = String(take!(io)) + println() println("Showing the output of one test run:") println("-"^80) - c = IOCapture.capture(passthrough=true) do - runtests(["--verbose"]) - end + print(str) println("-"^80) println() - @test contains(c.output, r"basic .+ started at") - @test contains(c.output, "SUCCESS") + + @test contains(str, r"basic .+ started at") + @test contains(str, "SUCCESS") end @testset "custom tests and init code" begin @@ -33,12 +36,14 @@ end @test @should_also_be_defined() end ) - c = IOCapture.capture() do - runtests(["--verbose"]; init_code, custom_tests) - end - @test contains(c.output, r"basic .+ started at") - @test contains(c.output, r"custom .+ started at") - @test contains(c.output, "SUCCESS") + + io = IOBuffer() + runtests(["--verbose"]; init_code, custom_tests, stdout=io, stderr=io) + + str = String(take!(io)) + @test contains(str, r"basic .+ started at") + @test contains(str, r"custom .+ started at") + @test contains(str, "SUCCESS") end @testset "custom worker" begin @@ -56,13 +61,15 @@ end @test !haskey(ENV, "SPECIAL_ENV_VAR") end ) - c = IOCapture.capture() do - runtests(["--verbose"]; test_worker, custom_tests) - end - @test contains(c.output, r"basic .+ started at") - @test contains(c.output, r"needs env var .+ started at") - @test contains(c.output, r"doesn't need env var .+ started at") - @test contains(c.output, "SUCCESS") + + io = IOBuffer() + runtests(["--verbose"]; test_worker, custom_tests, stdout=io, stderr=io) + + str = String(take!(io)) + @test contains(str, r"basic .+ started at") + @test contains(str, r"needs env var .+ started at") + @test contains(str, r"doesn't need env var .+ started at") + @test contains(str, "SUCCESS") end @testset "failing test" begin @@ -71,15 +78,17 @@ end @test 1 == 2 end ) - c = IOCapture.capture(rethrow=Union{}) do - runtests(["--verbose"]; custom_tests) + + io = IOBuffer() + @test_throws Test.FallbackTestSetException("Test run finished with errors") begin + runtests(["--verbose"]; custom_tests, stdout=io, stderr=io) end - @test contains(c.output, r"basic .+ started at") - @test contains(c.output, r"failing test .+ failed at") - @test contains(c.output, "FAILURE") - @test contains(c.output, "1 == 2") - @test c.error - @test c.value == Test.FallbackTestSetException("Test run finished with errors") + + str = String(take!(io)) + @test contains(str, r"basic .+ started at") + @test contains(str, r"failing test .+ failed at") + @test contains(str, "FAILURE") + @test contains(str, "1 == 2") end @testset "throwing test" begin @@ -88,15 +97,18 @@ end error("This test throws an error") end ) - c = IOCapture.capture(rethrow=Union{}) do - runtests(["--verbose"]; custom_tests) + + io = IOBuffer() + @test_throws Test.FallbackTestSetException("Test run finished with errors") begin + runtests(["--verbose"]; custom_tests, stdout=io, stderr=io) end - @test contains(c.output, r"basic .+ started at") - @test contains(c.output, r"throwing test .+ failed at") - @test contains(c.output, "FAILURE") - @test contains(c.output, "Got exception outside of a @test") - @test c.error - @test c.value == Test.FallbackTestSetException("Test run finished with errors") + + str = String(take!(io)) + @test contains(str, r"basic .+ started at") + @test contains(str, r"throwing test .+ failed at") + @test contains(str, "FAILURE") + @test contains(str, "Got exception outside of a @test") + @test contains(str, "This test throws an error") end end From 8f3c92ce83580b1a5844935559fa3b8578eedc1e Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Sun, 12 Oct 2025 12:29:25 +0200 Subject: [PATCH 06/21] Protect against race between executor and monitor. --- src/ParallelTestRunner.jl | 16 +++++++++++----- 1 file changed, 11 insertions(+), 5 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index e618e96..a5f2491 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -467,6 +467,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, results = [] tasks = Task[] running_tests = Dict{String, Tuple{Int, Float64}}() # test => (worker, start_time) + test_lock = ReentrantLock() # to protect crucial access to tests and running_tests done = false function stop_work() @@ -666,12 +667,17 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, end # get a test to run - test = popfirst!(tests) - wrkr = something(test_worker(test), p) + test, wrkr, test_t0 = Base.@lock test_lock begin + test = popfirst!(tests) + wrkr = something(test_worker(test), p) + + test_t0 = time() + running_tests[test] = (wrkr, test_t0) + + test, wrkr, test_t0 + end # run the test - test_t0 = time() - running_tests[test] = (wrkr, test_t0) put!(printer_channel, (:started, test, wrkr)) resp = try remotecall_fetch(runtest, wrkr, RecordType, test_runners[test], test, init_code) @@ -728,7 +734,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, if any(istaskfailed, tasks) println(io_ctx.stderr, "\nCaught an error, stopping...") break - elseif done || (isempty(tests) && isempty(running_tests)) + elseif done || Base.@lock(test_lock, isempty(tests) && isempty(running_tests)) break end sleep(1) From ca7994fc6505b4fdf19ceaab3057cf6cd4f22910 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Sun, 12 Oct 2025 12:43:52 +0200 Subject: [PATCH 07/21] Improve tests. --- test/runtests.jl | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/test/runtests.jl b/test/runtests.jl index 8dac2bc..d9aa441 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -88,6 +88,7 @@ end @test contains(str, r"basic .+ started at") @test contains(str, r"failing test .+ failed at") @test contains(str, "FAILURE") + @test contains(str, "Test Failed") @test contains(str, "1 == 2") end @@ -107,7 +108,7 @@ end @test contains(str, r"basic .+ started at") @test contains(str, r"throwing test .+ failed at") @test contains(str, "FAILURE") - @test contains(str, "Got exception outside of a @test") + @test contains(str, "Error During Test") @test contains(str, "This test throws an error") end From 113b887fabbd2934a9bae1a84129b2bd9aaa0549 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 07:10:51 +0200 Subject: [PATCH 08/21] Capture and print test output separately. --- src/ParallelTestRunner.jl | 45 +++++++++++++++++++++++---------------- test/runtests.jl | 16 ++++++++++++++ 2 files changed, 43 insertions(+), 18 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index a5f2491..82caebd 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -67,6 +67,7 @@ abstract type AbstractTestRecord end struct TestRecord <: AbstractTestRecord test::Any + output::String time::Float64 bytes::UInt64 gctime::Float64 @@ -154,6 +155,10 @@ function print_test_finished(test, wrkr, record::TestRecord, ctx::TestIOContext) rss_str = @sprintf("%5.2f", record.rss / 2^20) printstyled(ctx.stdout, lpad(rss_str, ctx.rss_align, " "), " |\n", color = :white) + for line in eachline(IOBuffer(record.output)) + println(ctx.stdout, " "^(ctx.name_align + 2), "| ", line) + end + flush(ctx.stdout) finally unlock(ctx.lock) @@ -186,34 +191,39 @@ function runtest(::Type{TestRecord}, f, name, init_code) # generate a temporary module to execute the tests in mod_name = Symbol("Test", rand(1:100), "Main_", replace(name, '/' => '_')) mod = @eval(Main, module $mod_name end) - @eval(mod, import ParallelTestRunner: Test, Random) + @eval(mod, import ParallelTestRunner: Test, Random, IOCapture) @eval(mod, using .Test, .Random) Core.eval(mod, init_code) + data = @eval mod begin GC.gc(true) Random.seed!(1) - res = @timed @testset $name begin - $f + res = @timed IOCapture.capture() do + @testset $name begin + $f + end end - (; res.value, res.time, res.bytes, res.gctime) + captured = res.value + (; testset=captured.value, captured.output, res.time, res.bytes, res.gctime) end # process results rss = Sys.maxrss() if VERSION >= v"1.11.0-DEV.1529" - tc = Test.get_test_counts(data.value) + tc = Test.get_test_counts(data.testset) passes, fails, error, broken, c_passes, c_fails, c_errors, c_broken = tc.passes, tc.fails, tc.errors, tc.broken, tc.cumulative_passes, tc.cumulative_fails, tc.cumulative_errors, tc.cumulative_broken else passes, fails, errors, broken, c_passes, c_fails, c_errors, c_broken = - Test.get_test_counts(data.value) + Test.get_test_counts(data.testset) end - if data[1].anynonpass == false - data = ( - (passes + c_passes, broken + c_broken), + if !data.testset.anynonpass + data = (; + result=(passes + c_passes, broken + c_broken), + data.output, data.time, data.bytes, data.gctime, @@ -536,19 +546,18 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, print_header(RecordType, io_ctx, testgroupheader, workerheader) status_lines_visible = Ref(0) + function clear_status() if status_lines_visible[] > 0 - for i in 1:status_lines_visible[] - width = displaysize(io_ctx.stdout)[2] - print(io_ctx.stdout, "\r", " "^width, "\r") - if i < status_lines_visible[] - print(io_ctx.stdout, "\033[1A") # Move up - end + for i in 1:status_lines_visible[]-1 + print(io_ctx.stdout, "\033[1A") # Move up one line + print(io_ctx.stdout, "\033[2K") # Clear entire line end - print(io_ctx.stdout, "\r") + print(io_ctx.stdout, "\r") # Move to start of line status_lines_visible[] = 0 end end + function update_status() # only draw the status bar on actual terminals io_ctx.stdout isa Base.TTY || return @@ -636,7 +645,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, end # After a while, display a status line - if time() - t0 >= 5 && (got_message || (time() - last_status_update[] >= 1)) + if !done && time() - t0 >= 5 && (got_message || (time() - last_status_update[] >= 1)) update_status() last_status_update[] = time() end @@ -847,7 +856,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, c = IOCapture.capture() do Test.record(fake, Test.Error(:test_interrupted, test, nothing, Base.ExceptionStack([(exception = "skipped", backtrace = [])]), LineNumberNode(1))) end - print(io_ctx.stdout, c.output) + # don't print the output of interrupted tests, it's not useful with_testset(fake) do Test.record(o_ts, fake) end diff --git a/test/runtests.jl b/test/runtests.jl index d9aa441..0d885e7 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -112,4 +112,20 @@ end @test contains(str, "This test throws an error") end +@testset "test output" begin + custom_tests = Dict( + "output" => quote + println("This is some output from the test") + end + ) + + io = IOBuffer() + runtests(["--verbose"]; custom_tests, stdout=io, stderr=io) + + str = String(take!(io)) + @test contains(str, r"output .+ started at") + @test contains(str, r"This is some output from the test") + @test contains(str, "SUCCESS") +end + end From 964d0616777a7b86855b9a0acd5c00d5647ef835 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 07:11:07 +0200 Subject: [PATCH 09/21] Always for the printer task to finish. --- src/ParallelTestRunner.jl | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index 82caebd..7903f58 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -608,12 +608,12 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # (:errored, test_name, worker_id) printer_channel = Channel{Tuple}(100) - push!(tasks, @async begin + printer_task = @async begin last_status_update = Ref(time()) try # XXX: it's possible this task doesn't run, not processing results, # while the execution runners have exited... - while !done + while isopen(printer_channel) got_message = false while isready(printer_channel) # Try to get a message from the channel (with timeout) @@ -660,7 +660,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, clear_status() end end - end) + end # @@ -755,6 +755,8 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, stop_work() end ## `wait()` to actually catch any exceptions + close(printer_channel) + wait(printer_task) for task in tasks try wait(task) From 4d40b18b8d36855c6f19b6c53749d4f54935a227 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 07:59:22 +0200 Subject: [PATCH 10/21] Deemphasize started at. --- src/ParallelTestRunner.jl | 5 ++--- test/runtests.jl | 3 ++- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index 7903f58..0a61010 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -125,11 +125,10 @@ end function print_test_started(::Type{TestRecord}, wrkr, test, ctx::TestIOContext) lock(ctx.lock) try - printstyled(ctx.stdout, test, color = :white) + printstyled(ctx.stdout, test, lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " |", color = :white) printstyled( ctx.stdout, - lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " |", - " "^ctx.elapsed_align, "started at $(now())\n", color = :white + " "^ctx.elapsed_align, "started at $(now())\n", color = :light_black ) flush(ctx.stdout) finally diff --git a/test/runtests.jl b/test/runtests.jl index 0d885e7..42f9868 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -7,7 +7,8 @@ cd(@__DIR__) @testset "basic test" begin io = IOBuffer() - runtests(["--verbose"]; stdout=io, stderr=io) + io_color = IOContext(io, :color => true) + runtests(["--verbose"]; stdout=io_color, stderr=io_color) str = String(take!(io)) println() From 9730be14a02f0ac257eb33931b4d40a632fecdb4 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 08:01:03 +0200 Subject: [PATCH 11/21] Update src/ParallelTestRunner.jl MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: Mosè Giordano <765740+giordano@users.noreply.github.com> --- src/ParallelTestRunner.jl | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index 0a61010..86a4a4f 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -671,7 +671,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, while length(tests) > 0 && !done # if a worker failed, spawn a new one if p === nothing - p = addworkers(1)[1] + p = addworker() end # get a test to run From 53ff205a7206462967a7e1e14f516ce4d6eaa05b Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 08:41:50 +0200 Subject: [PATCH 12/21] Update src/ParallelTestRunner.jl MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: Mosè Giordano <765740+giordano@users.noreply.github.com> --- src/ParallelTestRunner.jl | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index 86a4a4f..8d32d8a 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -771,12 +771,18 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # construct a testset to render the test results t1 = time() - o_ts = Test.DefaultTestSet("Overall"; verbose=do_verbose) if VERSION < v"1.13.0-DEV.1037" + o_ts = Test.DefaultTestSet("Overall"; verbose=do_verbose) o_ts.time_start = t0 o_ts.time_end = t1 else - #@atomic o_ts.time_start = t0 + o_ts = if v"1.13.0-DEV.1037" <= VERSION < v"1.13.0-DEV.1297" + # There's a small range of commits in the v1.13 development series where there's + # no way to retroactively set the start time of the testset after it started. + Test.DefaultTestSet("Overall"; verbose=do_verbose) + else + Test.DefaultTestSet("Overall"; verbose=do_verbose, time_start=t0) + end @atomic o_ts.time_end = t1 end with_testset(o_ts) do From 13c70d260342191e6090890caf990902f1139616 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 09:02:43 +0200 Subject: [PATCH 13/21] Fixes and simplifications for nightly. --- src/ParallelTestRunner.jl | 142 ++++++++++++++++---------------------- 1 file changed, 60 insertions(+), 82 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index 8d32d8a..bd8a665 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -210,24 +210,6 @@ function runtest(::Type{TestRecord}, f, name, init_code) # process results rss = Sys.maxrss() - if VERSION >= v"1.11.0-DEV.1529" - tc = Test.get_test_counts(data.testset) - passes, fails, error, broken, c_passes, c_fails, c_errors, c_broken = - tc.passes, tc.fails, tc.errors, tc.broken, tc.cumulative_passes, - tc.cumulative_fails, tc.cumulative_errors, tc.cumulative_broken - else - passes, fails, errors, broken, c_passes, c_fails, c_errors, c_broken = - Test.get_test_counts(data.testset) - end - if !data.testset.anynonpass - data = (; - result=(passes + c_passes, broken + c_broken), - data.output, - data.time, - data.bytes, - data.gctime, - ) - end res = TestRecord(data..., rss) GC.gc(true) @@ -770,21 +752,34 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, end # construct a testset to render the test results - t1 = time() - if VERSION < v"1.13.0-DEV.1037" - o_ts = Test.DefaultTestSet("Overall"; verbose=do_verbose) - o_ts.time_start = t0 - o_ts.time_end = t1 - else - o_ts = if v"1.13.0-DEV.1037" <= VERSION < v"1.13.0-DEV.1297" - # There's a small range of commits in the v1.13 development series where there's - # no way to retroactively set the start time of the testset after it started. - Test.DefaultTestSet("Overall"; verbose=do_verbose) + function create_testset(name; start=nothing, stop=nothing, kwargs...) + if start === nothing + testset = Test.DefaultTestSet(name; kwargs...) + elseif VERSION >= v"1.13.0-DEV.1297" + testset = Test.DefaultTestSet(name; time_start=start, kwargs...) + elseif VERSION < v"1.13.0-DEV.1037" + testset = Test.DefaultTestSet(name; kwargs...) + testset.time_start = start else - Test.DefaultTestSet("Overall"; verbose=do_verbose, time_start=t0) + # no way to set time_start retroactively + testset = Test.DefaultTestSet(name; kwargs...) + end + + if stop !== nothing + if VERSION < v"1.13.0-DEV.1037" + testset.time_end = stop + elseif VERSION >= v"1.13.0-DEV.1297" + @atomic testset.time_end = stop + else + # if we can't set the start time, also don't set a stop one + # to avoid negative timings + end end - @atomic o_ts.time_end = t1 + + return testset end + t1 = time() + o_ts = create_testset("Overall"; start=t0, stop=t1, verbose=do_verbose) with_testset(o_ts) do completed_tests = Set{String}() for (testname, res, start, stop) in results @@ -796,61 +791,44 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, push!(completed_tests, testname) # decode or fake a testset - testset = if isa(resp, Test.DefaultTestSet) - resp - elseif isa(resp, Tuple{Int, Int}) - fake = Test.DefaultTestSet(testname) - for i in 1:resp[1] - Test.record(fake, Test.Pass(:test, nothing, nothing, nothing, nothing)) - end - for i in 1:resp[2] - Test.record(fake, Test.Broken(:test, nothing)) - end - fake - elseif isa(resp, RemoteException) && - isa(resp.captured.ex, Test.TestSetException) - println(io_ctx.stderr, "Worker $(resp.pid) failed running test $(testname):") - Base.showerror(io_ctx.stderr, resp.captured) - println(io_ctx.stderr) - - fake = Test.DefaultTestSet(testname) - c = IOCapture.capture() do - for i in 1:resp.captured.ex.pass - Test.record(fake, Test.Pass(:test, nothing, nothing, nothing, nothing)) + if isa(resp, Test.DefaultTestSet) + testset = resp + else + testset = create_testset(testname; start, stop) + if isa(resp, RemoteException) && + isa(resp.captured.ex, Test.TestSetException) + println(io_ctx.stderr, "Worker $(resp.pid) failed running test $(testname):") + Base.showerror(io_ctx.stderr, resp.captured) + println(io_ctx.stderr) + + c = IOCapture.capture() do + for i in 1:resp.captured.ex.pass + Test.record(testset, Test.Pass(:test, nothing, nothing, nothing, nothing)) + end + for i in 1:resp.captured.ex.broken + Test.record(testset, Test.Broken(:test, nothing)) + end + for t in resp.captured.ex.errors_and_fails + Test.record(testset, t) + end end - for i in 1:resp.captured.ex.broken - Test.record(fake, Test.Broken(:test, nothing)) + print(io_ctx.stdout, c.output) + else + if !isa(resp, Exception) + resp = ErrorException(string("Unknown result type : ", typeof(resp))) end - for t in resp.captured.ex.errors_and_fails - Test.record(fake, t) + # If this test raised an exception that is not a remote testset exception, + # i.e. not a RemoteException capturing a TestSetException that means + # the test runner itself had some problem, so we may have hit a segfault, + # deserialization errors or something similar. Record this testset as Errored. + c = IOCapture.capture() do + Test.record(testset, Test.Error(:nontest_error, testname, nothing, Base.ExceptionStack([(exception = resp, backtrace = [])]), LineNumberNode(1))) end + print(io_ctx.stdout, c.output) end - print(io_ctx.stdout, c.output) - fake - else - if !isa(resp, Exception) - resp = ErrorException(string("Unknown result type : ", typeof(resp))) - end - # If this test raised an exception that is not a remote testset exception, - # i.e. not a RemoteException capturing a TestSetException that means - # the test runner itself had some problem, so we may have hit a segfault, - # deserialization errors or something similar. Record this testset as Errored. - fake = Test.DefaultTestSet(testname) - c = IOCapture.capture() do - Test.record(fake, Test.Error(:nontest_error, testname, nothing, Base.ExceptionStack([(exception = resp, backtrace = [])]), LineNumberNode(1))) - end - print(io_ctx.stdout, c.output) - fake end # record the testset - if VERSION < v"1.13.0-DEV.1037" - testset.time_start = start - testset.time_end = stop - else - #@atomic testset.time_start = start - @atomic testset.time_end = stop - end with_testset(testset) do Test.record(o_ts, testset) end @@ -859,13 +837,13 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # mark remaining or running tests as interrupted for test in [tests; collect(keys(running_tests))] (test in completed_tests) && continue - fake = Test.DefaultTestSet(test) + testset = create_testset(test) c = IOCapture.capture() do - Test.record(fake, Test.Error(:test_interrupted, test, nothing, Base.ExceptionStack([(exception = "skipped", backtrace = [])]), LineNumberNode(1))) + Test.record(testset, Test.Error(:test_interrupted, test, nothing, Base.ExceptionStack([(exception = "skipped", backtrace = [])]), LineNumberNode(1))) end # don't print the output of interrupted tests, it's not useful - with_testset(fake) do - Test.record(o_ts, fake) + with_testset(testset) do + Test.record(o_ts, testset) end end end From f4b6f2f40941906d28ccd59c22bddad3547a7e55 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 10:02:25 +0200 Subject: [PATCH 14/21] Remove stale TODO. --- src/ParallelTestRunner.jl | 2 -- 1 file changed, 2 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index bd8a665..7289b35 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -592,8 +592,6 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, printer_task = @async begin last_status_update = Ref(time()) try - # XXX: it's possible this task doesn't run, not processing results, - # while the execution runners have exited... while isopen(printer_channel) got_message = false while isready(printer_channel) From 4d6aee68ec4d64f991517180c8eb3ab0faeb0b95 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 10:42:26 +0200 Subject: [PATCH 15/21] Improve output printing. --- src/ParallelTestRunner.jl | 110 +++++++++++++++++++++----------------- 1 file changed, 61 insertions(+), 49 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index 7289b35..f0482f4 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -111,11 +111,11 @@ end function print_header(::Type{TestRecord}, ctx::TestIOContext, testgroupheader, workerheader) lock(ctx.lock) try - printstyled(ctx.stdout, " "^(ctx.name_align + textwidth(testgroupheader) - 3), " | ") - printstyled(ctx.stdout, " | ---------------- CPU ---------------- |\n", color = :white) + printstyled(ctx.stdout, " "^(ctx.name_align + textwidth(testgroupheader) - 3), " │ ") + printstyled(ctx.stdout, " │ ──────────────── CPU ──────────────── │\n", color = :white) printstyled(ctx.stdout, testgroupheader, color = :white) - printstyled(ctx.stdout, lpad(workerheader, ctx.name_align - textwidth(testgroupheader) + 1), " | ", color = :white) - printstyled(ctx.stdout, "Time (s) | GC (s) | GC % | Alloc (MB) | RSS (MB) |\n", color = :white) + printstyled(ctx.stdout, lpad(workerheader, ctx.name_align - textwidth(testgroupheader) + 1), " │ ", color = :white) + printstyled(ctx.stdout, "Time (s) │ GC (s) │ GC % │ Alloc (MB) │ RSS (MB) │\n", color = :white) flush(ctx.stdout) finally unlock(ctx.lock) @@ -125,7 +125,7 @@ end function print_test_started(::Type{TestRecord}, wrkr, test, ctx::TestIOContext) lock(ctx.lock) try - printstyled(ctx.stdout, test, lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " |", color = :white) + printstyled(ctx.stdout, test, lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " │", color = :white) printstyled( ctx.stdout, " "^ctx.elapsed_align, "started at $(now())\n", color = :light_black @@ -140,23 +140,19 @@ function print_test_finished(test, wrkr, record::TestRecord, ctx::TestIOContext) lock(ctx.lock) try printstyled(ctx.stdout, test, color = :white) - printstyled(ctx.stdout, lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " | ", color = :white) + printstyled(ctx.stdout, lpad("($wrkr)", ctx.name_align - textwidth(test) + 1, " "), " │ ", color = :white) time_str = @sprintf("%7.2f", record.time) - printstyled(ctx.stdout, lpad(time_str, ctx.elapsed_align, " "), " | ", color = :white) + printstyled(ctx.stdout, lpad(time_str, ctx.elapsed_align, " "), " │ ", color = :white) gc_str = @sprintf("%5.2f", record.gctime) - printstyled(ctx.stdout, lpad(gc_str, ctx.gc_align, " "), " | ", color = :white) + printstyled(ctx.stdout, lpad(gc_str, ctx.gc_align, " "), " │ ", color = :white) percent_str = @sprintf("%4.1f", 100 * record.gctime / record.time) - printstyled(ctx.stdout, lpad(percent_str, ctx.percent_align, " "), " | ", color = :white) + printstyled(ctx.stdout, lpad(percent_str, ctx.percent_align, " "), " │ ", color = :white) alloc_str = @sprintf("%5.2f", record.bytes / 2^20) - printstyled(ctx.stdout, lpad(alloc_str, ctx.alloc_align, " "), " | ", color = :white) + printstyled(ctx.stdout, lpad(alloc_str, ctx.alloc_align, " "), " │ ", color = :white) rss_str = @sprintf("%5.2f", record.rss / 2^20) - printstyled(ctx.stdout, lpad(rss_str, ctx.rss_align, " "), " |\n", color = :white) - - for line in eachline(IOBuffer(record.output)) - println(ctx.stdout, " "^(ctx.name_align + 2), "| ", line) - end + printstyled(ctx.stdout, lpad(rss_str, ctx.rss_align, " "), " │\n", color = :white) flush(ctx.stdout) finally @@ -199,24 +195,24 @@ function runtest(::Type{TestRecord}, f, name, init_code) GC.gc(true) Random.seed!(1) - res = @timed IOCapture.capture() do + stats = @timed IOCapture.capture() do @testset $name begin $f end end - captured = res.value - (; testset=captured.value, captured.output, res.time, res.bytes, res.gctime) + captured = stats.value + (; testset=captured.value, captured.output, stats.time, stats.bytes, stats.gctime) end # process results rss = Sys.maxrss() - res = TestRecord(data..., rss) + record = TestRecord(data..., rss) GC.gc(true) - return res + return record end - res = @static if VERSION >= v"1.13.0-DEV.1044" + @static if VERSION >= v"1.13.0-DEV.1044" @with Test.TESTSET_PRINT_ENABLE => false begin inner() end @@ -229,7 +225,6 @@ function runtest(::Type{TestRecord}, f, name, init_code) Test.TESTSET_PRINT_ENABLE[] = old_print_setting end end - return res end # This is an internal function, not to be used by end users. The keyword @@ -667,26 +662,27 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # run the test put!(printer_channel, (:started, test, wrkr)) - resp = try + result = try remotecall_fetch(runtest, wrkr, RecordType, test_runners[test], test, init_code) - catch e - isa(e, InterruptException) && return - Any[e] + catch ex + isa(ex, InterruptException) && return + # XXX: also put this in a test record? + ex end test_t1 = time() - push!(results, (test, resp, test_t0, test_t1)) + push!(results, (test, result, test_t0, test_t1)) # act on the results - if resp isa AbstractTestRecord - put!(printer_channel, (:finished, test, wrkr, resp::RecordType)) + if result isa AbstractTestRecord + put!(printer_channel, (:finished, test, wrkr, result::RecordType)) - if memory_usage(resp) > max_worker_rss + if memory_usage(result) > max_worker_rss # the worker has reached the max-rss limit, recycle it # so future tests start with a smaller working set p = recycle_worker(p) end else - @assert resp[1] isa Exception + @assert result isa Exception put!(printer_channel, (:errored, test, wrkr)) if do_quickfail stop_work() @@ -749,6 +745,27 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, end end + # print the output generated by each testset + for (testname, result, start, stop) in results + if isa(result, AbstractTestRecord) && !isempty(result.output) + println(io_ctx.stdout, "\nOutput generated during execution of '$testname':") + lines = collect(eachline(IOBuffer(result.output))) + + for (i,line) in enumerate(lines) + prefix = if length(lines) == 1 + "[" + elseif i == 1 + "┌" + elseif i == length(lines) + "└" + else + "│" + end + println(io_ctx.stdout, prefix, " ", line) + end + end + end + # construct a testset to render the test results function create_testset(name; start=nothing, stop=nothing, kwargs...) if start === nothing @@ -780,47 +797,42 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, o_ts = create_testset("Overall"; start=t0, stop=t1, verbose=do_verbose) with_testset(o_ts) do completed_tests = Set{String}() - for (testname, res, start, stop) in results - if res isa AbstractTestRecord - resp = res.test - else - resp = res[1] - end + for (testname, result, start, stop) in results push!(completed_tests, testname) # decode or fake a testset - if isa(resp, Test.DefaultTestSet) - testset = resp + if isa(result, AbstractTestRecord) + testset = result.test else testset = create_testset(testname; start, stop) - if isa(resp, RemoteException) && - isa(resp.captured.ex, Test.TestSetException) - println(io_ctx.stderr, "Worker $(resp.pid) failed running test $(testname):") - Base.showerror(io_ctx.stderr, resp.captured) + if isa(result, RemoteException) && + isa(result.captured.ex, Test.TestSetException) + println(io_ctx.stderr, "Worker $(result.pid) failed running test $(testname):") + Base.showerror(io_ctx.stderr, result.captured) println(io_ctx.stderr) c = IOCapture.capture() do - for i in 1:resp.captured.ex.pass + for i in 1:result.captured.ex.pass Test.record(testset, Test.Pass(:test, nothing, nothing, nothing, nothing)) end - for i in 1:resp.captured.ex.broken + for i in 1:result.captured.ex.broken Test.record(testset, Test.Broken(:test, nothing)) end - for t in resp.captured.ex.errors_and_fails + for t in result.captured.ex.errors_and_fails Test.record(testset, t) end end print(io_ctx.stdout, c.output) else - if !isa(resp, Exception) - resp = ErrorException(string("Unknown result type : ", typeof(resp))) + if !isa(result, Exception) + result = ErrorException(string("Unknown result type : ", typeof(result))) end # If this test raised an exception that is not a remote testset exception, # i.e. not a RemoteException capturing a TestSetException that means # the test runner itself had some problem, so we may have hit a segfault, # deserialization errors or something similar. Record this testset as Errored. c = IOCapture.capture() do - Test.record(testset, Test.Error(:nontest_error, testname, nothing, Base.ExceptionStack([(exception = resp, backtrace = [])]), LineNumberNode(1))) + Test.record(testset, Test.Error(:nontest_error, testname, nothing, Base.ExceptionStack([(exception = result, backtrace = [])]), LineNumberNode(1))) end print(io_ctx.stdout, c.output) end From fdc79e188da5aa728bb031b380fb48dfac3cec67 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 11:50:51 +0200 Subject: [PATCH 16/21] Greatly improve test interrupt handling. --- Project.toml | 2 -- src/ParallelTestRunner.jl | 72 ++++++++++++++++----------------------- 2 files changed, 29 insertions(+), 45 deletions(-) diff --git a/Project.toml b/Project.toml index f2c8bee..b9a1e40 100644 --- a/Project.toml +++ b/Project.toml @@ -8,7 +8,6 @@ Dates = "ade2ca70-3891-5945-98fb-dc099432e06a" Distributed = "8ba89e20-285c-5b6f-9357-94700520ee1b" IOCapture = "b5f81e59-6552-4d32-b1f0-c071b021bf89" Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7" -REPL = "3fa0cd96-eef1-5676-8a61-b3b8758bbffb" Random = "9a3f8284-a2c9-5f02-9a11-845980a1fd5c" Test = "8dfed614-e22c-5e08-85e1-65c5234f0b40" @@ -17,7 +16,6 @@ Dates = "1" Distributed = "1" IOCapture = "0.2.5" Printf = "1" -REPL = "1" Random = "1" Test = "1" julia = "1.10" diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index f0482f4..f9fd730 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -4,7 +4,6 @@ export runtests, addworkers, addworker using Distributed using Dates -import REPL using Printf: @sprintf using Base.Filesystem: path_separator import Test @@ -423,9 +422,9 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # list tests, if requested if do_list - println("Available tests:") + println(stdout, "Available tests:") for test in sort(tests) - println(" - $test") + println(stdout, " - $test") end exit(0) end @@ -451,7 +450,6 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, t0 = time() results = [] - tasks = Task[] running_tests = Dict{String, Tuple{Int, Float64}}() # test => (worker, start_time) test_lock = ReentrantLock() # to protect crucial access to tests and running_tests @@ -459,7 +457,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, function stop_work() if !done done = true - for task in tasks + for task in worker_tasks task == current_task() && continue Base.istaskdone(task) && continue try; schedule(task, InterruptException(); error=true); catch; end @@ -468,33 +466,6 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, end - # - # input - # - - # Keyboard monitor (for more reliable CTRL-C handling) - if isa(stdin, Base.TTY) - # NOTE: this should be the first task; we really want it to complete - pushfirst!(tasks, @async begin - term = REPL.Terminals.TTYTerminal("xterm", stdin, stdout, stderr) - REPL.Terminals.raw!(term, true) - try - while !done - c = read(term, Char) - if c == '\x3' - println(stderr, "\nCaught interrupt, stopping...") - stop_work() - break - end - end - finally - REPL.Terminals.raw!(term, false) - end - end) - end - # TODO: we have to be _fast_ here, as Pkg.jl only gives us 4 seconds to clean up - - # # output # @@ -626,6 +597,13 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, sleep(0.1) end catch ex + if isa(ex, InterruptException) + # the printer should keep on running, + # but we need to signal other tasks to stop + stop_work() + else + rethrow() + end isa(ex, InterruptException) || rethrow() finally if isempty(tests) && isempty(running_tests) @@ -641,8 +619,9 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # execution # + worker_tasks = Task[] for p in workers() - push!(tasks, @async begin + push!(worker_tasks, @async begin while length(tests) > 0 && !done # if a worker failed, spawn a new one if p === nothing @@ -665,7 +644,13 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, result = try remotecall_fetch(runtest, wrkr, RecordType, test_runners[test], test, init_code) catch ex - isa(ex, InterruptException) && return + if isa(ex, InterruptException) + # the worker got interrupted, signal other tasks to stop + stop_work() + return + end + + # return any other exception as the result # XXX: also put this in a test record? ex end @@ -700,10 +685,6 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, delete!(running_tests, test) end - - if p !== nothing - recycle_worker(p) - end end) end @@ -712,10 +693,10 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # finalization # - # monitor tasks for failure so that each one doesn't need a try/catch + stop_work() + # monitor worker tasks for failure so that each one doesn't need a try/catch + stop_work() try while true - if any(istaskfailed, tasks) + if any(istaskfailed, worker_tasks) println(io_ctx.stderr, "\nCaught an error, stopping...") break elseif done || Base.@lock(test_lock, isempty(tests) && isempty(running_tests)) @@ -729,10 +710,13 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, finally stop_work() end - ## `wait()` to actually catch any exceptions + + # wait for the printer to finish so that all results have been printed close(printer_channel) wait(printer_task) - for task in tasks + + # wait for worker tasks to catch unhandled exceptions + for task in worker_tasks try wait(task) catch err @@ -744,6 +728,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, isa(err, InterruptException) || rethrow() end end + @async rmprocs(; waitfor=0) # print the output generated by each testset for (testname, result, start, stop) in results @@ -881,7 +866,8 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, end throw(Test.FallbackTestSetException("Test run finished with errors")) end - return nothing + + return end # runtests end # module ParallelTestRunner From 414e214331a6db32f15abc248d94b12eb290e8de Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 12:04:26 +0200 Subject: [PATCH 17/21] Improve error reporting. --- src/ParallelTestRunner.jl | 97 ++++++++++++++++++++------------------- test/runtests.jl | 20 ++++++++ 2 files changed, 70 insertions(+), 47 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index f9fd730..c613347 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -751,7 +751,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, end end - # construct a testset to render the test results + # construct a testset containing all results function create_testset(name; start=nothing, stop=nothing, kwargs...) if start === nothing testset = Test.DefaultTestSet(name; kwargs...) @@ -780,25 +780,21 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, end t1 = time() o_ts = create_testset("Overall"; start=t0, stop=t1, verbose=do_verbose) - with_testset(o_ts) do - completed_tests = Set{String}() - for (testname, result, start, stop) in results - push!(completed_tests, testname) - - # decode or fake a testset - if isa(result, AbstractTestRecord) - testset = result.test - else - testset = create_testset(testname; start, stop) - if isa(result, RemoteException) && - isa(result.captured.ex, Test.TestSetException) - println(io_ctx.stderr, "Worker $(result.pid) failed running test $(testname):") - Base.showerror(io_ctx.stderr, result.captured) - println(io_ctx.stderr) - - c = IOCapture.capture() do + function collect_results() + with_testset(o_ts) do + completed_tests = Set{String}() + for (testname, result, start, stop) in results + push!(completed_tests, testname) + + # decode or fake a testset + if isa(result, AbstractTestRecord) + testset = result.test + else + testset = create_testset(testname; start, stop) + if isa(result, RemoteException) && + isa(result.captured.ex, Test.TestSetException) for i in 1:result.captured.ex.pass - Test.record(testset, Test.Pass(:test, nothing, nothing, nothing, nothing)) + Test.record(testset, Test.Pass(:test, nothing, nothing, nothing, LineNumberNode(@__LINE__, @__FILE__))) end for i in 1:result.captured.ex.broken Test.record(testset, Test.Broken(:test, nothing)) @@ -806,42 +802,49 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, for t in result.captured.ex.errors_and_fails Test.record(testset, t) end + else + if !isa(result, Exception) + result = ErrorException(string("Unknown result type : ", typeof(result))) + end + # If this test raised an exception that is not a remote testset exception, + # i.e. not a RemoteException capturing a TestSetException that means + # the test runner itself had some problem, so we may have hit a segfault, + # deserialization errors or something similar. Record this testset as Errored. + Test.record(testset, Test.Error(:nontest_error, testname, nothing, Base.ExceptionStack(NamedTuple[(;exception = result, backtrace = [])]), LineNumberNode(1))) end - print(io_ctx.stdout, c.output) - else - if !isa(result, Exception) - result = ErrorException(string("Unknown result type : ", typeof(result))) - end - # If this test raised an exception that is not a remote testset exception, - # i.e. not a RemoteException capturing a TestSetException that means - # the test runner itself had some problem, so we may have hit a segfault, - # deserialization errors or something similar. Record this testset as Errored. - c = IOCapture.capture() do - Test.record(testset, Test.Error(:nontest_error, testname, nothing, Base.ExceptionStack([(exception = result, backtrace = [])]), LineNumberNode(1))) - end - print(io_ctx.stdout, c.output) end - end - # record the testset - with_testset(testset) do - Test.record(o_ts, testset) + with_testset(testset) do + Test.record(o_ts, testset) + end end - end - # mark remaining or running tests as interrupted - for test in [tests; collect(keys(running_tests))] - (test in completed_tests) && continue - testset = create_testset(test) - c = IOCapture.capture() do - Test.record(testset, Test.Error(:test_interrupted, test, nothing, Base.ExceptionStack([(exception = "skipped", backtrace = [])]), LineNumberNode(1))) - end - # don't print the output of interrupted tests, it's not useful - with_testset(testset) do - Test.record(o_ts, testset) + # mark remaining or running tests as interrupted + for test in [tests; collect(keys(running_tests))] + (test in completed_tests) && continue + testset = create_testset(test) + Test.record(testset, Test.Error(:test_interrupted, test, nothing, Base.ExceptionStack(NamedTuple[(;exception = "skipped", backtrace = [])]), LineNumberNode(1))) + with_testset(testset) do + Test.record(o_ts, testset) + end end end end + @static if VERSION >= v"1.13.0-DEV.1044" + @with Test.TESTSET_PRINT_ENABLE => false begin + collect_results() + end + else + old_print_setting = Test.TESTSET_PRINT_ENABLE[] + Test.TESTSET_PRINT_ENABLE[] = false + try + collect_results() + finally + Test.TESTSET_PRINT_ENABLE[] = old_print_setting + end + end + + # display the results println(io_ctx.stdout) if VERSION >= v"1.13.0-DEV.1033" Test.print_test_results(io_ctx.stdout, o_ts, 1) diff --git a/test/runtests.jl b/test/runtests.jl index 42f9868..edebd39 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -113,6 +113,26 @@ end @test contains(str, "This test throws an error") end +@testset "crashing test" begin + custom_tests = Dict( + "crash" => quote + abort() = ccall(:abort, Nothing, ()) + abort() + end + ) + + io = IOBuffer() + @test_throws Test.FallbackTestSetException("Test run finished with errors") begin + runtests(["--verbose"]; custom_tests, stdout=io, stderr=io) + end + + str = String(take!(io)) + @test contains(str, r"crash .+ started at") + @test contains(str, "FAILURE") + @test contains(str, "Error During Test") + @test contains(str, "ProcessExitedException") +end + @testset "test output" begin custom_tests = Dict( "output" => quote From 77ec0d89b666415598b97729c609e375125d90fa Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 13:30:44 +0200 Subject: [PATCH 18/21] Improve ETA. --- Project.toml | 2 ++ src/ParallelTestRunner.jl | 28 ++++++++++++++++++++-------- 2 files changed, 22 insertions(+), 8 deletions(-) diff --git a/Project.toml b/Project.toml index b9a1e40..c7d5e7d 100644 --- a/Project.toml +++ b/Project.toml @@ -9,6 +9,7 @@ Distributed = "8ba89e20-285c-5b6f-9357-94700520ee1b" IOCapture = "b5f81e59-6552-4d32-b1f0-c071b021bf89" Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7" Random = "9a3f8284-a2c9-5f02-9a11-845980a1fd5c" +Statistics = "10745b16-79ce-11e8-11f9-7d13ad32a3b2" Test = "8dfed614-e22c-5e08-85e1-65c5234f0b40" [compat] @@ -17,5 +18,6 @@ Distributed = "1" IOCapture = "0.2.5" Printf = "1" Random = "1" +Statistics = "1" Test = "1" julia = "1.10" diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index c613347..2c3f539 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -6,6 +6,7 @@ using Distributed using Dates using Printf: @sprintf using Base.Filesystem: path_separator +using Statistics import Test import Random import IOCapture @@ -416,9 +417,9 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, end end end - sort!(tests; by = (file) -> stat(joinpath(WORKDIR, file * ".jl")).size, rev = true) ## finalize unique!(tests) + Random.shuffle!(tests) # list tests, if requested if do_list @@ -443,9 +444,8 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, if !set_jobs jobs = default_njobs() end + jobs = clamp(jobs, 1, length(tests)) println(stdout, "Running $jobs tests in parallel. If this is too many, specify the `--jobs=N` argument to the tests, or set the `JULIA_CPU_THREADS` environment variable.") - - # add workers addworkers(min(jobs, length(tests))) t0 = time() @@ -532,11 +532,23 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # line 3: progress + ETA line3 = "Progress: $completed/$total tests completed" if completed > 0 - elapsed_so_far = time() - t0 - avg_time_per_test = elapsed_so_far / completed - remaining_tests = length(tests) + length(running_tests) - eta_seconds = avg_time_per_test * remaining_tests - eta_mins = round(Int, eta_seconds / 60) + # gather stats + durations_done = [end_time - start_time for (_, _, start_time, end_time) in results] + durations_running = [time() - start_time for (_, start_time) in values(running_tests)] + n_done = length(durations_done) + n_running = length(durations_running) + n_remaining = length(tests) + n_total = n_done + n_running + n_remaining + + # estimate per-test time (slightly pessimistic) + μ = mean(durations_done) + σ = length(durations_done) > 1 ? std(durations_done) : 0.0 + est_per_test = μ + 0.5σ + + # estimate remaining time + est_remaining = sum(durations_running) + n_remaining * est_per_test + eta_sec = est_remaining / jobs + eta_mins = round(Int, eta_sec / 60) line3 *= " | ETA: ~$eta_mins min" end From abf77eca93d1139682eb224a59365590efeedfdf Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 13:38:58 +0200 Subject: [PATCH 19/21] Retain color of test output. --- src/ParallelTestRunner.jl | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index 2c3f539..f60c53b 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -86,6 +86,7 @@ end struct TestIOContext stdout::IO stderr::IO + color::Bool lock::ReentrantLock name_align::Int elapsed_align::Int @@ -102,8 +103,10 @@ function test_IOContext(::Type{TestRecord}, stdout::IO, stderr::IO, lock::Reentr alloc_align = textwidth("Alloc (MB)") rss_align = textwidth("RSS (MB)") + color = get(stdout, :color, false) + return TestIOContext( - stdout, stderr, lock, name_align, elapsed_align, gc_align, percent_align, + stdout, stderr, color, lock, name_align, elapsed_align, gc_align, percent_align, alloc_align, rss_align ) end @@ -181,7 +184,7 @@ end # entry point # -function runtest(::Type{TestRecord}, f, name, init_code) +function runtest(::Type{TestRecord}, f, name, init_code, color) function inner() # generate a temporary module to execute the tests in mod_name = Symbol("Test", rand(1:100), "Main_", replace(name, '/' => '_')) @@ -195,7 +198,7 @@ function runtest(::Type{TestRecord}, f, name, init_code) GC.gc(true) Random.seed!(1) - stats = @timed IOCapture.capture() do + stats = @timed IOCapture.capture(; color=$color) do @testset $name begin $f end @@ -654,7 +657,8 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # run the test put!(printer_channel, (:started, test, wrkr)) result = try - remotecall_fetch(runtest, wrkr, RecordType, test_runners[test], test, init_code) + remotecall_fetch(runtest, wrkr, RecordType, test_runners[test], test, + init_code, io_ctx.color) catch ex if isa(ex, InterruptException) # the worker got interrupted, signal other tasks to stop From 0b893267045e485cdd49dc36a4573c056f82e8e7 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 14:14:54 +0200 Subject: [PATCH 20/21] Fix another race condition. --- src/ParallelTestRunner.jl | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index f60c53b..f1ce7c3 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -637,7 +637,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, worker_tasks = Task[] for p in workers() push!(worker_tasks, @async begin - while length(tests) > 0 && !done + while !done # if a worker failed, spawn a new one if p === nothing p = addworker() @@ -645,6 +645,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # get a test to run test, wrkr, test_t0 = Base.@lock test_lock begin + isempty(tests) && break test = popfirst!(tests) wrkr = something(test_worker(test), p) @@ -663,7 +664,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, if isa(ex, InterruptException) # the worker got interrupted, signal other tasks to stop stop_work() - return + break end # return any other exception as the result From bca6f6520db78a6911d930010ecde574e43cd44f Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Mon, 13 Oct 2025 14:15:09 +0200 Subject: [PATCH 21/21] Hopefully fix things by moving the import closer to the call. --- src/ParallelTestRunner.jl | 9 ++------- 1 file changed, 2 insertions(+), 7 deletions(-) diff --git a/src/ParallelTestRunner.jl b/src/ParallelTestRunner.jl index f1ce7c3..3501b6e 100644 --- a/src/ParallelTestRunner.jl +++ b/src/ParallelTestRunner.jl @@ -266,13 +266,7 @@ function addworkers(X; kwargs...) exeflags = exe[2:end] return withenv("JULIA_NUM_THREADS" => 1, "OPENBLAS_NUM_THREADS" => 1) do - procs = addprocs(X; exename, exeflags, kwargs...) - Distributed.remotecall_eval( - Main, procs, quote - import ParallelTestRunner - end - ) - procs + addprocs(X; exename, exeflags, kwargs...) end end addworker(; kwargs...) = addworkers(1; kwargs...)[1] @@ -658,6 +652,7 @@ function runtests(ARGS; testfilter = Returns(true), RecordType = TestRecord, # run the test put!(printer_channel, (:started, test, wrkr)) result = try + Distributed.remotecall_eval(Main, wrkr, :(import ParallelTestRunner)) remotecall_fetch(runtest, wrkr, RecordType, test_runners[test], test, init_code, io_ctx.color) catch ex