Skip to content

test: Make the "Trapped" signal handler signal-safe - #365

Merged
leongdl merged 1 commit into
OpenJobDescription:mainlinefrom
leongdl:fix/signal-safe-trapped-handler
Sep 3, 2026
Merged

test: Make the "Trapped" signal handler signal-safe#365
leongdl merged 1 commit into
OpenJobDescription:mainlinefrom
leongdl:fix/signal-safe-trapped-handler

Conversation

@leongdl

@leongdl leongdl commented Sep 3, 2026

Copy link
Copy Markdown
Contributor

Fixes: no GitHub issue; observed as an intermittent Code Quality failure, most recently on run 33807699249 (Python (macos-latest, 3.13)).

What was the problem/requirement? (What/Why)

test_notify_ends_process fails intermittently. On the run above it failed on macos-latest / 3.13 while every other leg of the same matrix passed on the same commit — all six Windows legs and macOS 3.14 included:

RuntimeError: reentrant call inside <_io.BufferedWriter name='<stdout>'>
Process pid 2878 exited with code: 1
assert 'Trapped' in ["Running command '/Users/runner/...", ..., 'Log from test 1', ...]

The four app_20s_run*.py support scripts print and flush stdout in their main loop:

for i in range(0, 20):
    print(f"Log from test {str(i)}")
    sys.stdout.flush()
    time.sleep(1)

and their signal handler does the same thing:

def hook(handle, frame):
    print("Trapped")
    sys.stdout.flush()
    sys.exit(1)

A signal handler runs on the main thread at an arbitrary bytecode boundary. When SIGTERM lands while the interpreter is inside the loop's sys.stdout.flush(), the handler re-enters the same BufferedWriter; CPython refuses, "Trapped" never reaches stdout, and the child exits non-zero. The test's assert "Trapped" in all_messages then fails.

Nothing in the package's own code is involved — this is the test's fixture racing itself.

What was the solution? (How)

The handler writes with os.write(1, ...), which is a direct unbuffered write(2) and cannot re-enter the buffer:

def hook(handle, frame):
    os.write(1, b"Trapped\n")
    sys.exit(1)

Ordering is unaffected: every print in these scripts is flushed on the very next line, so there is never buffered content for the handler's output to appear ahead of. The comment in the code records that, so the next reader does not "tidy" it back into a print.

All four copies are fixed, not just the one CI happened to hit. app_20s_run.py and app_20s_run_ignore_signal.py under both sessions_v0 and sessions_v1 were byte-identical in this handler (same md5), so the same flake was latent in every test that uses them — test_subprocess.py, test_runner_base.py, test_wrap_cancelation.py, test_windows_process_killer.py.

What is the impact of this change?

Test fixtures only. No src/ change, no behaviour change, no public interface change. It removes an intermittent CI failure whose only remedy today is a re-run.

How was this change tested?

Yes, unit tests have been run.

Reproduced deterministically first, rather than waiting for the flake. Giving the child a pipe that nobody drains parks its main loop inside a blocked sys.stdout.flush(), after which any SIGTERM is guaranteed to land inside the flush — no timing luck needed:

Target exit code Trapped present reentrant RuntimeError
current scripts 1 no yes
patched scripts 1 yes no

The first row matches CI's log verbatim, including the exit code. The second is the same probe against the fix, which is the check that the fix is what closed it rather than the probe having stopped working.

Worth recording, because it changed what this PR does: a first attempt at a reproduction found a different race — SIGTERM arriving before signal.signal() had run, giving rc=-15 with no handler installed at all, in 13 of 250 trials. That is real but not reachable from this test, which waits for "Log from test 0" before calling notify(), so the handler is always installed by then. It is deliberately not addressed here, and the probe was rewritten to target the mechanism CI actually reported.

Regression: test_subprocess.py, test_runner_base.py and test_wrap_cancelation.py give an identical result before and after — 6 failed, 189 passed, 12 skipped, 8 xfailed. Those 6 are the same pre-existing test_run_gracetime_when_process_ends_but_grandchild_uses_stdout parametrisations, which fail on this machine because it has no bare python on PATH. test_notify_ends_process passes both before and after locally, which is expected of a flake and is why the deterministic probe above is the load-bearing evidence rather than a green local run.

Was this change documented?

Yes — the handler carries a comment naming the RuntimeError, why write(2) cannot hit it, and why ordering is safe.

Is this a breaking change?

No. Test support files only.

Does this change impact security?

No. It replaces a buffered write to fd 1 with an unbuffered write to fd 1, in a test fixture.

Cross-port to openjd-rs

  • This change does not affect runtime behavior (docs / tests / tooling only)

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

`test_notify_ends_process` fails intermittently. Seen on
`Python (macos-latest, 3.13)` while every other leg of the same matrix passed on
the same commit, including all six Windows legs and macOS 3.14:

    RuntimeError: reentrant call inside <_io.BufferedWriter name='<stdout>'>
    Process pid 2878 exited with code: 1
    assert 'Trapped' in [...]

The four `app_20s_run*.py` support scripts print and flush stdout in their main
loop, and their signal handler does the same. When the signal lands while the
interpreter is inside the loop's `sys.stdout.flush()`, the handler re-enters the
same `BufferedWriter`, CPython raises, "Trapped" never reaches stdout, and the
child exits non-zero -- so the test's `assert "Trapped" in all_messages` fails.

The handler now writes with `os.write(1, ...)`, which is unbuffered and cannot
re-enter. Ordering is unaffected: every `print` in these scripts is flushed on
the next line, so nothing is sitting in the buffer for the handler's output to
appear ahead of.

Reproduced deterministically rather than by waiting for the flake. Giving the
child a pipe nobody drains parks its main loop inside a blocked
`sys.stdout.flush()`, after which any SIGTERM lands inside the flush. Against the
current scripts that yields exit 1, the reentrant `RuntimeError`, and no
"Trapped" -- matching CI. Against the patched scripts, "Trapped" is present and
there is no `RuntimeError`.

All four copies are fixed, not just the one CI happened to hit: `app_20s_run.py`
and `app_20s_run_ignore_signal.py` under both `sessions_v0` and `sessions_v1`
were byte-identical in this handler.

An earlier attempt at a reproduction found a *different* race -- SIGTERM arriving
before `signal.signal()` had run, giving rc=-15 with no handler at all. That one
is not reachable from this test, which waits for "Log from test 0" before calling
`notify()`, so it is deliberately not addressed here.

test_subprocess.py, test_runner_base.py and test_wrap_cancelation.py give an
identical result before and after (6 failed, 189 passed); those 6 are
pre-existing gracetime failures on a machine with no bare `python` on PATH.

Signed-off-by: David Leong <116610336+leongdl@users.noreply.github.com>
@leongdl
leongdl requested a review from a team as a code owner September 3, 2026 21:56
@leongdl
leongdl merged commit b3ee0b6 into OpenJobDescription:mainline Sep 3, 2026
31 checks passed
@leongdl
leongdl deleted the fix/signal-safe-trapped-handler branch September 3, 2026 22:58
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants