From c3cc1f003eee82dabe6853635be3d96d5f84a2e5 Mon Sep 17 00:00:00 2001 From: Alberto Mengali Date: Wed, 30 Sep 2026 15:23:21 +0200 Subject: [PATCH 1/3] Report a failed test process spawn to the reactor `start` spawns the test process before its own error handler. When the spawn fails, for example because the program in `juliaCmd` does not exist, the error escapes to the `@async` task in `_launch_julia_process!`, and its `catch` only logs it. The reactor gets no message, so the process stays in ProcessStarting, its test run never completes, and a shutdown waits the full grace period for the process. The `catch` now also posts `TestProcessIOErrorMsg(ps.id, :fatal)`, as the other error paths in this file do. The existing fatal IO error path then errors the queued test items and removes the process. --- CHANGELOG.md | 2 ++ src/testitemcontroller.jl | 4 ++++ test/test_process_crash.jl | 20 ++++++++++++++++++++ 3 files changed, 26 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 72da68e..97f88bf 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,6 +9,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed +- A test run now completes when the controller cannot spawn a test process, for example because the program in `juliaCmd` does not exist or `juliaCmd` holds a command with arguments such as `julia +1.12`. The controller now errors the queued test items and removes the process. The spawn error only went to the log, so the process stayed in the starting state, its test items stayed pending, and a shutdown waited the full grace period for it. + - On Julia 1.12 and later, a garbage collection in a test process no longer has to wait for the hang watchdog to wake up. The watchdog paces itself with a plain OS sleep, and that `ccall` kept its thread GC-unsafe for the full 50 ms poll interval, so every stop-the-world collection stalled until the sleep ended: 25–50 ms of extra time-to-safepoint per GC on Windows and 50–190 ms on GitHub's macOS runners, none of it counted in the GC time reported for a test item. The sleep now runs in a GC-safe region (`@ccall gc_safe=true`), which brings that delay to zero. On Windows it goes through libuv's `uv_sleep` rather than Win32 `Sleep`, because `@ccall` cannot express the `stdcall` convention `Sleep` needs on 32-bit Windows. Older Julia versions keep the previous sleep. - A test item that uses a `@testmodule` now runs with its own file path, so `@__DIR__` and `@__FILE__` inside it resolve against its own directory and its top-level frames are attributed to its own file. The test process evaluated the `@testmodule` into the same local that holds the test item's path, so the item's body was then handed the *setup's* path — an item in `test/sub/` declaring a setup defined in `test/` loaded `joinpath(@__DIR__, "data", …)` relative to `test/`, and a failure in it was reported at the setup's file. Only the first item to evaluate a given `@testmodule` on a process was affected, because later items reuse the already-evaluated module and never take that branch, which is why this presented as order- and scheduling-dependent. The working directory was always correct, so a bare relative path was unaffected. `TestItemRunner.jl`'s in-process runner never had this bug. diff --git a/src/testitemcontroller.jl b/src/testitemcontroller.jl index 55b252d..84496a7 100644 --- a/src/testitemcontroller.jl +++ b/src/testitemcontroller.jl @@ -2618,6 +2618,10 @@ function _launch_julia_process!(c::TestItemController, ps::TestProcessState) julia_version, launch_token) catch err @error "Error in test process IO" testprocess_id=ps.id exception=(err, catch_backtrace()) + # `start` sends no message to the reactor for an error that occurs before its own + # error handler, for example when it cannot spawn `juliaCmd`. Without this message, + # the process stays in ProcessStarting and its test run does not complete. + try put!(c.reactor_channel, TestProcessIOErrorMsg(ps.id, :fatal)) catch end end push!(ps.process_tasks, t) end diff --git a/test/test_process_crash.jl b/test/test_process_crash.jl index 8d68b64..31209ce 100644 --- a/test/test_process_crash.jl +++ b/test/test_process_crash.jl @@ -188,6 +188,26 @@ end @test length(terminated) == 1 end +@testitem "A Julia command that cannot be spawned errors all test items" setup=[TestHelpers] begin + 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 + + julia_cmd = joinpath(pkg_path, "nonexistent", "julia") + + # At shutdown, the controller waits up to 30 s for a test process that it did not + # remove. A `shutdown_timeout` below that makes such a process fail the test. + result = TestHelpers.run_testrun(items, discovered.setups, discovered; julia_cmd, max_procs=2, timeout=60, shutdown_timeout=10) + + errored = filter(e -> e.event == :errored, result.events) + @test sort([e.testitem_id for e in errored]) == sort([i.id for i in items]) + + created = [e.id for e in result.process_events if e.event == :process_created] + terminated = [e.id for e in result.process_events if e.event == :process_terminated] + @test sort(terminated) == sort(created) +end + @testitem "The startup-crash warning only reads fields the exception has" begin using TestItemControllers: TestProcessCrashException From 87510b439a0fd59a981001cbe8b5be1108a2f5b3 Mon Sep 17 00:00:00 2001 From: David Anthoff Date: Fri, 2 Oct 2026 17:15:28 -0700 Subject: [PATCH 2/3] Treat a test process that cannot be spawned as a user error MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A `juliaCmd` that cannot be run is a configuration mistake, but it was logged with `@error`. Under the crash-reporting logger that VS Code installs, any `@error` sends a crash report and exits the test item controller, so the reactor message added in the previous commit never ran there. `start` now catches the `IOError` from the spawn itself, logs a warning, and posts the fatal IO error with a short reason such as "`…/julia`: no such file or directory (ENOENT)". The reason is built from the error code because the `IOError` message embeds the whole environment. The startup-crash path errors the queued test items with that reason instead of saying the process crashed. In `_launch_julia_process!`, which now only sees unexpected errors, the message is posted before the `@error` rather than after it. New test: one controller completes a run with a bad `juliaCmd` and then runs the same item with a working one. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 2 +- src/messages.jl | 5 ++- src/state.jl | 5 +++ src/testitemcontroller.jl | 18 ++++++++--- src/testprocess.jl | 28 ++++++++++++---- test/test_process_crash.jl | 66 +++++++++++++++++++++++++++++++++++++- 6 files changed, 111 insertions(+), 13 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 97f88bf..287d287 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,7 +9,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed -- A test run now completes when the controller cannot spawn a test process, for example because the program in `juliaCmd` does not exist or `juliaCmd` holds a command with arguments such as `julia +1.12`. The controller now errors the queued test items and removes the process. The spawn error only went to the log, so the process stayed in the starting state, its test items stayed pending, and a shutdown waited the full grace period for it. +- A test run now completes when the controller cannot spawn a test process, for example because the program in `juliaCmd` does not exist or `juliaCmd` holds a command with arguments such as `julia +1.12`. The controller now errors the queued test items with the cause ("Could not start the test process for test item '…': `…`: no such file or directory (ENOENT)") and removes the process. The spawn error only went to the log, so the process stayed in the starting state, its test items stayed pending, and a shutdown waited the full grace period for it. It was also logged as an error, which under VS Code's crash-reporting logger ended the test item controller and filed a crash report for what is a configuration mistake; it is now a warning, and the controller runs later test runs normally. - On Julia 1.12 and later, a garbage collection in a test process no longer has to wait for the hang watchdog to wake up. The watchdog paces itself with a plain OS sleep, and that `ccall` kept its thread GC-unsafe for the full 50 ms poll interval, so every stop-the-world collection stalled until the sleep ended: 25–50 ms of extra time-to-safepoint per GC on Windows and 50–190 ms on GitHub's macOS runners, none of it counted in the GC time reported for a test item. The sleep now runs in a GC-safe region (`@ccall gc_safe=true`), which brings that delay to zero. On Windows it goes through libuv's `uv_sleep` rather than Win32 `Sleep`, because `@ccall` cannot express the `stdcall` convention `Sleep` needs on 32-bit Windows. Older Julia versions keep the previous sleep. diff --git a/src/messages.jl b/src/messages.jl index 1b7ed44..a8e0cb6 100644 --- a/src/messages.jl +++ b/src/messages.jl @@ -185,8 +185,11 @@ struct TestProcessIOErrorMsg <: ReactorMessage error_type::Symbol # :restart or :fatal exit_code::Union{Nothing,Int} term_signal::Union{Nothing,Int} + # Set when the process could not be started at all; see `TestProcessState.launch_failure`. + reason::Union{Nothing,String} end -TestProcessIOErrorMsg(id::String, error_type::Symbol) = TestProcessIOErrorMsg(id, error_type, nothing, nothing) +TestProcessIOErrorMsg(id::String, error_type::Symbol) = TestProcessIOErrorMsg(id, error_type, nothing, nothing, nothing) +TestProcessIOErrorMsg(id::String, error_type::Symbol, exit_code, term_signal) = TestProcessIOErrorMsg(id, error_type, exit_code, term_signal, nothing) struct ActivationFailedMsg <: ReactorMessage testprocess_id::String diff --git a/src/state.jl b/src/state.jl index 8b2fdf2..0714f22 100644 --- a/src/state.jl +++ b/src/state.jl @@ -42,6 +42,10 @@ mutable struct TestProcessState # Exit info captured when the OS process dies (set in _launch_julia_process! catch) last_exit_code::Union{Nothing,Int} last_term_signal::Union{Nothing,Int} + # Why the controller could not start this process at all (e.g. `juliaCmd` does not + # exist), worded for the user. Set from `TestProcessIOErrorMsg`; when present, the + # queued test items are errored with it instead of being told the process crashed. + launch_failure::Union{Nothing,String} # Last time anything was heard from this process, on each of its two independent # channels: the JSON-RPC socket that carries every result, and the stdout/stderr pipes # that carry captured output. Diagnostics only — nothing branches on these. They exist @@ -84,6 +88,7 @@ function TestProcessState(id::String, env::ProcessEnv; Dict{Tuple{String,String},@NamedTuple{output::String, duration::Union{Nothing,Float64}}}(), # loaded_setups nothing, # last_exit_code nothing, # last_term_signal + nothing, # launch_failure nothing, # last_message_at nothing, # last_output_at ) diff --git a/src/testitemcontroller.jl b/src/testitemcontroller.jl index 84496a7..01f0a3b 100644 --- a/src/testitemcontroller.jl +++ b/src/testitemcontroller.jl @@ -1651,7 +1651,12 @@ function _handle_termination_during_run!(c::TestItemController, msg::TestProcess process_was_running = ps !== nothing && state(ps.fsm) in (ProcessRunning, ProcessIdle) if !process_was_running # True startup crash — process never ran any item. Error all queued items. - @info "Test process '$(terminated_proc_id)' crashed during startup, erroring $(length(items_to_redistribute)) queued item(s)" + launch_failure = ps === nothing ? nothing : ps.launch_failure + if launch_failure !== nothing + @info "Test process '$(terminated_proc_id)' could not be started ($(launch_failure)), erroring $(length(items_to_redistribute)) queued item(s)" + else + @info "Test process '$(terminated_proc_id)' crashed during startup, erroring $(length(items_to_redistribute)) queued item(s)" + end for testitem_id in items_to_redistribute item = _item_for_env(tr, test_env_id, testitem_id) work_key = (testitem_id, test_env_id) @@ -1665,6 +1670,8 @@ function _handle_termination_during_run!(c::TestItemController, msg::TestProcess test_env_id, TestMessage[ TestMessage( + launch_failure !== nothing ? + "Could not start the test process for test item '$(item.label)': $(launch_failure)" : "Test process crashed before running test item '$(item.label)'", nothing, nothing, @@ -2230,6 +2237,7 @@ function handle!(c::TestItemController, msg::TestProcessIOErrorMsg) # Store exit info on the process state so downstream handlers can access it. ps.last_exit_code = msg.exit_code ps.last_term_signal = msg.term_signal + msg.reason !== nothing && (ps.launch_failure = msg.reason) _kill_julia_process!(ps) @@ -2617,11 +2625,13 @@ function _launch_julia_process!(c::TestItemController, ps::TestProcessState) c.error_handler_file, c.crash_reporting_pipename, julia_version, launch_token) catch err - @error "Error in test process IO" testprocess_id=ps.id exception=(err, catch_backtrace()) # `start` sends no message to the reactor for an error that occurs before its own - # error handler, for example when it cannot spawn `juliaCmd`. Without this message, - # the process stays in ProcessStarting and its test run does not complete. + # error handler (a failed spawn is reported there; this is anything else, e.g. + # `Sockets.listen`). Without this message, the process stays in ProcessStarting and + # its test run does not complete. Posted before the `@error`, which under the + # crash-reporting logger ends the controller. try put!(c.reactor_channel, TestProcessIOErrorMsg(ps.id, :fatal)) catch end + @error "Error in test process IO" testprocess_id=ps.id exception=(err, catch_backtrace()) end push!(ps.process_tasks, t) end diff --git a/src/testprocess.jl b/src/testprocess.jl index f89b3dc..25ec903 100644 --- a/src/testprocess.jl +++ b/src/testprocess.jl @@ -414,13 +414,29 @@ function start(testprocess_id, reactor_channel, ps::TestProcessState, env::Proce cmd_args = `$(env.juliaCmd) $(jlArgs) --startup-file=no --history-file=no --depwarn=no $coverage_arg $testserver_script $pipe_name $(debug_pipe_name) $(error_handler_file...) $(crash_reporting_pipename...)` @info "Launching Julia test server process" testprocess_id pipe_name @debug "Full launch command" testprocess_id cmd=string(cmd_args) testserver_script mode=env.mode - jl_process = open( - pipeline( - Cmd(cmd_args, detach=false, env=jlEnv), - stdout = pipe_out, - stderr = pipe_out + jl_process = try + open( + pipeline( + Cmd(cmd_args, detach=false, env=jlEnv), + stdout = pipe_out, + stderr = pipe_out + ) ) - ) + catch err + err isa Base.IOError || rethrow() + # A `juliaCmd` that cannot be run is the user's configuration, not a fault in + # the controller: say why on the test items and stay up. An `@error` here + # would take the whole controller down under the crash-reporting logger. The + # reason is built from the error code because `err.msg` embeds the entire + # environment of the command. + reason = "`$(env.juliaCmd)`: $(Base.struverror(err.code)) ($(Base.uverrorname(err.code)))" + if occursin(' ', env.juliaCmd) && !isfile(env.juliaCmd) + reason *= ". `juliaCmd` is run as a single program; pass arguments such as `+1.12` in `juliaArgs`" + end + @warn "Could not start Julia test process" testprocess_id reason + put!(reactor_channel, TestProcessIOErrorMsg(testprocess_id, :fatal, nothing, nothing, reason)) + return + end proc_kill_registration = CancellationTokens.register(token) do @info "Killing test process due to cancellation" testprocess_id diff --git a/test/test_process_crash.jl b/test/test_process_crash.jl index 31209ce..788e25c 100644 --- a/test/test_process_crash.jl +++ b/test/test_process_crash.jl @@ -189,6 +189,9 @@ end end @testitem "A Julia command that cannot be spawned errors all test items" setup=[TestHelpers] begin + using Logging: with_logger, Warn, Error + using Test: TestLogger + 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) @@ -198,16 +201,77 @@ end # At shutdown, the controller waits up to 30 s for a test process that it did not # remove. A `shutdown_timeout` below that makes such a process fail the test. - result = TestHelpers.run_testrun(items, discovered.setups, discovered; julia_cmd, max_procs=2, timeout=60, shutdown_timeout=10) + logger = TestLogger(min_level=Warn) + result = with_logger(logger) do + TestHelpers.run_testrun(items, discovered.setups, discovered; julia_cmd, max_procs=2, timeout=60, shutdown_timeout=10) + end errored = filter(e -> e.event == :errored, result.events) @test sort([e.testitem_id for e in errored]) == sort([i.id for i in items]) + # The user is told why, not that the process crashed. + @test all(errored) do e + any(m -> occursin("Could not start the test process", m.message) && occursin("ENOENT", m.message), e.messages) + end + + # A misconfigured `juliaCmd` is a user error. Under the crash-reporting logger VS Code + # installs, anything logged at `Error` ends the controller and files a crash report. + @test !any(r -> r.level >= Error, logger.logs) + created = [e.id for e in result.process_events if e.event == :process_created] terminated = [e.id for e in result.process_events if e.event == :process_terminated] @test sort(terminated) == sort(created) end +@testitem "The controller runs test items again after a Julia command could not be spawned" setup=[TestHelpers] begin + using TestItemControllers: TestItemController, TestRunItem, execute_testrun, shutdown, ControllerCallbacks + import UUIDs + + pkg_path = joinpath(TestHelpers.TESTDATA_DIR, "BasicPackage") + discovered = TestHelpers.discover_test_items(pkg_path) + items = filter(i -> i.label == "add works", discovered.items) + @test length(items) == 1 + + events = NamedTuple[] + events_lock = ReentrantLock() + push_event!(e) = lock(() -> push!(events, e), events_lock) + + callbacks = ControllerCallbacks( + on_testitem_started = (run_id, item_id, test_env_id) -> nothing, + on_testitem_passed = (run_id, item_id, test_env_id, duration) -> push_event!((event=:passed, testrun_id=run_id)), + on_testitem_failed = (run_id, item_id, test_env_id, messages, duration) -> push_event!((event=:failed, testrun_id=run_id)), + on_testitem_errored = (run_id, item_id, test_env_id, messages, duration) -> push_event!((event=:errored, testrun_id=run_id)), + 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, + ) + + controller = TestItemController(callbacks; log_level=:Debug) + controller_task = @async try + run(controller) + catch err + @error "Controller error" exception=(err, catch_backtrace()) + end + + env_kwargs = TestHelpers._env_kwargs(discovered) + function run_once(test_env) + testrun_id = string(UUIDs.uuid4()) + work_units = [TestRunItem(item.id, test_env.id, nothing, :Debug) for item in items] + run_task = @async execute_testrun(controller, testrun_id, [test_env], items, work_units, discovered.setups, 1, nothing) + TestHelpers.timed_wait(run_task, 600; label="test run") + return lock(() -> [e.event for e in events if e.testrun_id == testrun_id], events_lock) + end + + bad_env = TestHelpers.make_test_environment(; env_kwargs..., julia_cmd=joinpath(pkg_path, "nonexistent", "julia")) + @test run_once(bad_env) == [:errored] + + good_env = TestHelpers.make_test_environment(; env_kwargs...) + @test run_once(good_env) == [:passed] + + shutdown(controller) + TestHelpers.timed_wait(controller_task, 60; label="controller shutdown") +end + @testitem "The startup-crash warning only reads fields the exception has" begin using TestItemControllers: TestProcessCrashException From 3ea6e3e2a17462743a5331ce15e452ff18a18209 Mon Sep 17 00:00:00 2001 From: David Anthoff Date: Fri, 2 Oct 2026 23:31:29 -0700 Subject: [PATCH 3/3] Cover the juliaArgs hint and the startup-crash message in tests Codecov/patch on #125 was below target because no test reached the hint for a `juliaCmd` that holds arguments, nor the plain "crashed during startup" branch next to the new launch-failure one. Co-Authored-By: Claude Opus 5.5 --- test/test_process_crash.jl | 37 +++++++++++++++++++++++++++++++++++++ 1 file changed, 37 insertions(+) diff --git a/test/test_process_crash.jl b/test/test_process_crash.jl index 788e25c..035af6b 100644 --- a/test/test_process_crash.jl +++ b/test/test_process_crash.jl @@ -223,6 +223,43 @@ end @test sort(terminated) == sort(created) end +@testitem "A Julia command with arguments in it points the user at juliaArgs" setup=[TestHelpers] begin + pkg_path = joinpath(TestHelpers.TESTDATA_DIR, "BasicPackage") + discovered = TestHelpers.discover_test_items(pkg_path) + items = filter(i -> i.label == "add works", discovered.items) + @test length(items) == 1 + + # The controller runs the whole string as one program, so a juliaup channel written into + # `juliaCmd` cannot be spawned. + result = TestHelpers.run_testrun(items, discovered.setups, discovered; julia_cmd="julia +1.12", timeout=60, shutdown_timeout=10) + + errored = filter(e -> e.event == :errored, result.events) + @test length(errored) == 1 + @test !isempty(errored) && any(errored[1].messages) do m + occursin("Could not start the test process", m.message) && occursin("`juliaArgs`", m.message) + end +end + +@testitem "A Julia process that exits during startup errors its test items as crashed" setup=[TestHelpers] begin + pkg_path = joinpath(TestHelpers.TESTDATA_DIR, "BasicPackage") + discovered = TestHelpers.discover_test_items(pkg_path) + items = filter(i -> i.label == "add works", discovered.items) + @test length(items) == 1 + + # Julia rejects the unknown option and exits before it connects to the controller. The + # process was spawned, so this is a crash and not a failure to start it. + result = TestHelpers.run_testrun(items, discovered.setups, discovered; julia_args=["--no-such-option"], timeout=120, shutdown_timeout=10) + + errored = filter(e -> e.event == :errored, result.events) + @test length(errored) == 1 + @test !isempty(errored) && any(m -> occursin("Test process crashed before running test item", m.message), errored[1].messages) + @test !isempty(errored) && !any(m -> occursin("Could not start the test process", m.message), errored[1].messages) + + created = [e.id for e in result.process_events if e.event == :process_created] + terminated = [e.id for e in result.process_events if e.event == :process_terminated] + @test sort(terminated) == sort(created) +end + @testitem "The controller runs test items again after a Julia command could not be spawned" setup=[TestHelpers] begin using TestItemControllers: TestItemController, TestRunItem, execute_testrun, shutdown, ControllerCallbacks import UUIDs