From 1246450e1fc92c4bc364521683a432acef6169dc Mon Sep 17 00:00:00 2001 From: David Anthoff Date: Thu, 24 Sep 2026 12:56:16 -0700 Subject: [PATCH] Make gc_between_testitems opt-in instead of on for multi-process runs `execute_testrun` used to run `GC.gc(true)` after every test item whenever a run used more than one test process, to match ReTestItems. Measured on JuliaWorkspaces.jl CI it did not pay for itself: the test phase was slower in 15 of 18 legs (1.26x at the median), process RSS was unchanged, and on 7 GB macOS arm64 runners each full collection took 40-75 s under memory pressure, turning 12-minute jobs into timeouts. It now defaults to off; callers can still pass `gc_between_testitems=true`, which helps suites whose items hold memory that only a finalizer releases. Updates the comments that stated the old default, adds a test item that pins the new default for a two-process run, and a changelog entry. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 1 + src/state.jl | 2 +- src/testitemcontroller.jl | 12 ++-- test/test_worker_lifecycle.jl | 56 ++++++++++++++++++- .../TestItemServer/src/TestItemServer.jl | 4 +- 5 files changed, 64 insertions(+), 11 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 32d7fab..ed7eeaa 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -37,6 +37,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Changed +- `execute_testrun` no longer runs a full `GC.gc()` after every test item by default; pass `gc_between_testitems=true` to opt in. A run started over JSON-RPC, which cannot set it, now always runs without it. It used to be on whenever a run used more than one test process, as in ReTestItems, but it did not pay for itself. Across 18 CI legs of JuliaWorkspaces.jl it made the test phase slower in 15, by 1.26× at the median, and left process RSS unchanged (median 2.84 vs 2.95 GB): what grows is live data such as compiled code, which no collection frees, and Julia collects real garbage on its own. Under memory pressure it was ruinous — on 7 GB macOS arm64 runners each full collection took 40–75 s, and a 2-process Julia 1.12 run timed out after 80 minutes at 677 of 1170 items that finishes in 12 minutes without it. It can still help a suite whose items hold memory outside the Julia heap that only a finalizer releases (large C buffers, mmaps, handles, child processes). - Failures a test process can carry on past are now reported instead of being swallowed. The process was given a single error handler, and that handler always ends in `exit(1)`, so anything not worth dying for had to be discarded — which is why clearing coverage data between items had a bare `catch` with a `# TODO Call global error handler` in it, and why losing a setup's captured output showed up as an empty string. `TestItemServer.serve` now also accepts a non-fatal handler, used by those sites and by the watchdog. In the same vein, a test process that dies before it can connect no longer discards the output it produced while starting — the usual explanation for why it died — and the two internal-consistency assertions in the controller now attach an exception so their crash reports carry a backtrace pointing at the code that broke the invariant rather than at the logger. - **Breaking (JSONRPC):** every test item notification — `testItemStarted`, `testItemPassed`, `testItemFailed`, `testItemErrored`, `testItemSkipped` and `appendOutput` — now carries `testEnvId` alongside `testItemId`, and clients must identify an item by the pair. A test item id is scoped to its package, so the same package checked out into two folders mints the same id from both; a client keying on the id alone collapses them, reporting one item's results twice while the other never resolves. The in-process callbacks have always received `test_env_id` and `TestRunState.test_items` is already keyed this way — it was only the JSONRPC layer that dropped it. - Load setup modules via `using` by default ([2b187ad1](https://github.com/julia-vscode/TestItemControllers.jl/commit/2b187ad1)) diff --git a/src/state.jl b/src/state.jl index 89dbe61..846de59 100644 --- a/src/state.jl +++ b/src/state.jl @@ -125,7 +125,7 @@ mutable struct TestRunState reported_items::Set{String} # testitem_ids for which a terminal callback was emitted # Worker lifecycle policy for this run, sent on to each process in ConfigureTestRun. # `gc_between_testitems` is resolved from the caller's request in `execute_testrun` - # (default: on whenever the run uses more than one process). + # (default: off). gc_between_testitems::Bool memory_threshold::Union{Nothing,Float64} # Stop the run at the first failing or errored work unit. Decided on the reactor rather diff --git a/src/testitemcontroller.jl b/src/testitemcontroller.jl index 877e3a4..e978864 100644 --- a/src/testitemcontroller.jl +++ b/src/testitemcontroller.jl @@ -3208,12 +3208,12 @@ function execute_testrun( proc_count_by_env[k] = n_procs end - # Collecting between items only pays for itself when memory is contended, which in - # practice means more than one test process — so that is the default, matching - # ReTestItems' `gc_between_testitems`. - tr.gc_between_testitems = gc_between_testitems === nothing ? - sum(values(proc_count_by_env), init=0) > 1 : - gc_between_testitems + # Collecting between items is opt-in. A full collection after every item made the test + # phase slower in most CI runs we measured, did not lower process RSS (what grows is live + # compiled code and caches, which no collection frees), and under memory pressure each + # collection can take tens of seconds. It helps a suite whose items hold memory outside + # the Julia heap that only a finalizer releases: C buffers, mmaps, handles, processes. + tr.gc_between_testitems = something(gc_between_testitems, false) # Resolve log_level from the first work unit log_level = !isempty(work_units) ? first(work_units).log_level : :Info diff --git a/test/test_worker_lifecycle.jl b/test/test_worker_lifecycle.jl index a680247..096031c 100644 --- a/test/test_worker_lifecycle.jl +++ b/test/test_worker_lifecycle.jl @@ -1,6 +1,6 @@ @testitem "GC between test items does not deadlock the test process" setup=[TestHelpers] begin - # Regression test for a deadlock that shipped with the watchdog and sat on the common - # path: `gc_between_testitems` defaults on for multi-process runs. + # Regression test for a deadlock that shipped with the watchdog, at a time when + # `gc_between_testitems` defaulted on for multi-process runs and so sat on the common path. # # The watchdog thread runs a loop that neither allocates nor yields, paced by # `Libc.systemsleep` (a plain `ccall`). Without an explicit `GC.safepoint()` the thread @@ -43,6 +43,58 @@ end @test length(filter(e -> e.event == :passed, result.events)) == 1 end +@testitem "GC between test items is off by default, even for a multi-process run" setup=[TestHelpers] begin + # It used to default on whenever a run had more than one test process. That made CI + # slower and, under memory pressure, pathologically so, so it is now opt-in. + # + # No reactor and no test process: `execute_testrun` resolves the flag into the run's + # `TestRunState` — which `_configure_testrun!` sends on to every process — before it + # posts its request for processes, so the run can be inspected at that point and then + # released by hand. The request also confirms that the run asked for two processes. + using TestItemControllers: TestItemController, ControllerCallbacks, TestRunItem, + GetProcsForTestRunMsg, execute_testrun + + pkg_path = joinpath(TestHelpers.TESTDATA_DIR, "BasicPackage") + discovered = TestHelpers.discover_test_items(pkg_path) + items = filter(i -> i.label in ("add works", "greet works"), discovered.items) + @test length(items) == 2 + + test_env = TestHelpers.make_test_environment(; TestHelpers._env_kwargs(discovered)...) + work_units = [TestRunItem(i.id, test_env.id, nothing, :Info) for i in items] + + callbacks = ControllerCallbacks( + on_testitem_started = (run_id, item_id, test_env_id) -> nothing, + on_testitem_passed = (run_id, item_id, test_env_id, duration) -> nothing, + on_testitem_failed = (run_id, item_id, test_env_id, messages, duration) -> nothing, + on_testitem_errored = (run_id, item_id, test_env_id, messages, duration) -> nothing, + on_testitem_skipped = (run_id, item_id, test_env_id) -> nothing, + on_append_output = (run_id, item_id, test_env_id, output) -> nothing, + on_attach_debugger = (run_id, pipe_name) -> nothing, + ) + + # The resolved flag and the number of processes the run requested. + function resolve(; kwargs...) + controller = TestItemController(callbacks) + run_task = @async execute_testrun(controller, "gc-default", [test_env], items, + work_units, discovered.setups, 2, nothing; kwargs...) + + timedwait(() -> isready(controller.reactor_channel) || istaskdone(run_task), 30) + istaskdone(run_task) && fetch(run_task) # surface an error instead of hanging below + msg = take!(controller.reactor_channel) + @test msg isa GetProcsForTestRunMsg + tr = controller.test_runs["gc-default"] + resolved = (gc=tr.gc_between_testitems, n_procs=sum(values(msg.proc_count_by_env))) + + put!(tr.completion_channel, nothing) + TestHelpers.timed_wait(run_task, 30; label="execute_testrun after manual completion") + return resolved + end + + @test resolve() == (gc=false, n_procs=2) + # The check can see the flag when it is set, so the one above is not vacuous. + @test resolve(gc_between_testitems=true) == (gc=true, n_procs=2) +end + @testitem "A timed-out test item leaves hang diagnostics in its output" setup=[TestHelpers] begin # The point of the watchdog: an item killed for running too long should leave a stack # behind rather than a bare "timed out" line. The dump is written to a private file by a diff --git a/testprocess/TestItemServer/src/TestItemServer.jl b/testprocess/TestItemServer/src/TestItemServer.jl index 7c8ff9a..b7c15ec 100644 --- a/testprocess/TestItemServer/src/TestItemServer.jl +++ b/testprocess/TestItemServer/src/TestItemServer.jl @@ -74,8 +74,8 @@ mutable struct TestProcessState coverage_root_uris::Union{Nothing,Vector{String}} log_level::Base.CoreLogging.LogLevel - # Run a full `GC.gc()` after every test item. Defaulted by the controller, which turns - # it on whenever a run has more than one test process. + # Run a full `GC.gc()` after every test item. Opt-in: the controller leaves it off + # unless the caller asks for it. gc_between_testitems::Bool # Fraction of system memory (0..1) above which we stop after the current item so the # controller can recycle us. `nothing` disables the check.