Skip to content

Fix Ctrl-C being lost or crashing duct - #456

Open
asmacdo wants to merge 21 commits into
con:mainfrom
asmacdo:signal-test-handshake
Open

asmacdo wants to merge 21 commits into
con:mainfrom
asmacdo:signal-test-handshake

Conversation

@asmacdo

@asmacdo asmacdo commented Sep 30, 2026 •

Copy link
Copy Markdown
Member

This is 1/2 to fix the flaky CI. 2/2 is #457

CI failures expected this one exacerbates the problems fixed by 457.

Four ways duct could lose or mishandle a Ctrl-C, found while making the signal tests (flaky on macOS, #451, #439) stop depending on timing:

  • Taken by the wrong thread: a signal sent to a process is delivered to any one of its threads, but Python only runs the handler in the main thread. When one of duct's helper threads received the SIGINT, the main thread stayed asleep waiting for the command and nothing was forwarded until the command exited by itself. Duct now starts its threads with SIGINT blocked (start_thread), so only the main thread can receive it.
  • Crash on a late Ctrl-C: a Ctrl-C handled after the command had already exited raised ProcessLookupError; duct printed a traceback and exited 1 instead of finishing with the command's exit code. Now it logs a warning and finishes normally.
  • Lost during logging: a SIGINT arriving while duct was writing a log line ran the handler mid-write; its own log call raised RuntimeError: reentrant call, which escaped before the signal was forwarded. Now the handler forwards first; if the log line still can't go through logging, it is written straight to stderr (still honoring the log level), on its own line and labeled as such.
  • Lost at startup: the handler was installed after the command started, so a Ctrl-C in between killed duct and left the command running untracked. Now it is installed first: a Ctrl-C before the command starts means it is not started (exit 130); one during start-up is forwarded as soon as the pid is known.

Tests

  • test_signal_int / test_signal_kill run duct as a real subprocess (both duct and con-duct run) and signal only once it is ready (start_duct waits for duct's "is executing" line; signal_ignorer.py confirms each step), instead of sleeping. Reruns disabled for them. A failure now shows duct's stderr.
  • They run with --fail-time 0 and -1 only, the two values whose effect does not depend on how long the run took. The thresholds get their own test_fail_time_threshold, which is the only place a failed command's log removal is tested by run time.
  • New unit tests for SigIntHandler and start_thread (test/duct_main/test_signals.py), including one that checks every thread started during a run is started with SIGINT blocked, so a thread added later with a plain .start() fails the suite.
  • test_session_mode_behavior_difference: its marker process now outlives both duct runs; coverage made pypy duct slow enough on the Intel Mac runner that the old 10 s marker exited first.
  • Coverage now follows subprocesses (patch = ["subprocess", "execv"], which needs coverage>=7.10, now declared in tox) so moving tests out of process doesn't lose coverage: TOTAL 91.28% → 93.47% (py313), _signals.py 36% → 90%.

Verification

All local numbers are Linux, py3.13.

  • Wrong thread: traced with strace, a helper thread took the SIGINT in 3 of 3 unforwarded cases and the main thread in 447 of 447 normal ones. On an idle machine with the test suite's 10 ms sampling interval, 11 of 1000 first SIGINTs went unforwarded before the change and 0 of 1000 after. At duct's default 1 s sampling interval none did in 600 trials, so users were less exposed than the tests. The signal tests then passed 400 of 400 executions with no reruns.
  • During logging / at startup: signal tests under a 10% CPU cap (systemd-run --user --scope -p CPUQuota=10%) to mimic a slow runner: before, ~1 in 90 lost the Ctrl-C; after, 290/290 passed. An strace-based repro lost it in ~12% of trials before, 0/60 after.
  • CI: the signal and start_thread tests pass on every Linux and macOS job.

The zero-sample flakes in the same issues (test_spawn_children, test_session_modes) are fixed in #457; until that merges, an Intel Mac job here can still fail on them.

What is not fixed, and one side effect
  • A SIGINT that lands in the microseconds between the main thread's last check for signals and its blocking wait for the command is still not acted on until the wait returns. That is a CPython limitation of any signal.signal() plus blocking-call program; it was only reproduced by aiming a signal at that instant. A second Ctrl-C gets through, and the pair is handled as one press. Closing it would mean waking the main thread periodically for the whole run, which is not worth the cost.
  • Why the kernel sometimes hands the SIGINT to a helper thread, and why that depends on the sampling rate, is not established. It was only reproduced on Linux.
  • A Ctrl-C handled just after the command exits (the late case above) signals a pid that has already been reaped. Normally that is the logged warning, but in principle the system could already have given that pid number to a new, unrelated process, which would then receive the SIGINT. That needs the pid to be reused within microseconds, and any program that signals a child by pid has the same exposure.
  • Processes started by duct's helper threads inherit the blocked SIGINT. In practice that is the short-lived ps of the sampling thread, which a terminal Ctrl-C can no longer interrupt mid-run. The command itself is started by the main thread and its signal mask is unchanged.

🤖 Generated with Claude Code

asmacdo and others added 8 commits September 30, 2026 11:17
pytest-cov 7 dropped its own subprocess support; coverage's
`patch = subprocess` replaces it. e2e tests that run duct via the CLI
now count toward coverage (TOTAL 91.28% -> 92.28% on py313).

Co-Authored-By: Claude Code 2.1.285 / Claude Opus 5.5 <noreply@anthropic.com>
`duct` execs into `con-duct run`; exec skips exit handlers, so without
coverage's `execv` patch the shim's data is lost.

Co-Authored-By: Claude Code 2.1.285 / Claude Opus 5.5 <noreply@anthropic.com>
With parallel coverage each process writes .coverage.<host>.<pid>...;
pytest-cov combines them, but an aborted run leaves them behind.

Co-Authored-By: Claude Code 2.1.285 / Claude Opus 5.5 <noreply@anthropic.com>
Starts duct as a subprocess and returns once duct has logged that it is
executing, which happens right after its SIGINT handler is installed.
Lets signal tests synchronize on duct's readiness instead of sleeping.

Co-Authored-By: Claude Code 2.1.285 / Claude Opus 5.5 <noreply@anthropic.com>
A SIGINT that arrives while duct's main thread is writing to stderr runs
the handler mid-write; its own log call then raises a reentrant-write
RuntimeError, which escaped before os.kill ran, so the Ctrl-C was lost.
Act first, and drop the log message if it cannot be written.

Co-Authored-By: Claude Code 2.1.285 / Claude Opus 5.5 <noreply@anthropic.com>
Replaces sleep-then-signal in a multiprocessing child (racy under spawn,
the macOS default) with start_duct, and asserts duct's own exit code.
Reruns disabled: the test must pass without them.

Co-Authored-By: Claude Code 2.1.285 / Claude Opus 5.5 <noreply@anthropic.com>
A Ctrl-C between Popen and installing the handler raised KeyboardInterrupt
in duct and left the command running untracked. The handler is now
installed first and only counts SIGINTs until attached to the command: one
before Popen means the command is not started (exit 130), one during Popen
is forwarded as soon as the pid is known.

Co-Authored-By: Claude Code 2.1.285 / Claude Opus 5.5 <noreply@anthropic.com>
signal_ignorer.py now reports "ready" and each SIGINT it receives to a
file, so the test sends the next SIGINT only once the previous one was
forwarded (pending SIGINTs merge) instead of sleeping between them.
Reruns disabled: the test must pass without them.

Co-Authored-By: Claude Code 2.1.285 / Claude Opus 5.5 <noreply@anthropic.com>
@asmacdo asmacdo added the semver-patch Increment the patch version when merged label Sep 30, 2026
@codecov

codecov Bot commented Sep 30, 2026 •

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 98.27586% with 1 line in your changes missing coverage. Please review.
✅ Project coverage is 94.38%. Comparing base (7a25f42) to head (865f4b9).
⚠️ Report is 7 commits behind head on main.

Files with missing lines Patch % Lines
src/con_duct/_signals.py 97.72% 1 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##             main     #456      +/-   ##
==========================================
+ Coverage   92.03%   94.38%   +2.34%     
==========================================
  Files          15       15              
  Lines        1344     1389      +45     
  Branches      182      186       +4     
==========================================
+ Hits         1237     1311      +74     
+ Misses         71       48      -23     
+ Partials       36       30       -6     

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

The background marker lived 10 s, but on a slow runner (macos-15-intel
pypy, with coverage now measuring duct) the two duct runs before it is
checked took ~15 s, so it had exited. The test stops it in `finally`.

Co-Authored-By: Claude Code 2.1.285 / Claude Opus 5.5 <noreply@anthropic.com>
asmacdo and others added 8 commits October 1, 2026 14:53
Its lifetime is the cap on how long test_signal_kill may take from the
command starting to the third SIGINT. 10 s was the tightest cap among
the reworked tests; the others give up after 60 s. The test kills the
script long before either, so a passing run is no slower.

Co-Authored-By: Claude Code 2.1.286 / Claude Fable 5.1 <noreply@anthropic.com>
start_duct waits for duct's "is executing" line, which is logged at
INFO. With DUCT_LOG_LEVEL above INFO in the environment or a .env file
the line never comes and start_duct waits until the command exits.
Pass the level explicitly so the helper does not depend on the
developer's configuration.

Co-Authored-By: Claude Code 2.1.286 / Claude Fable 5.1 <noreply@anthropic.com>
start_duct pipes duct's stderr and nothing printed it, so "duct exited
before ..." gave no hint why. Include what duct wrote in start_duct's
RuntimeError and in _wait_for_lines' assertion message.

With it, a failing test_signal_kill shows the cause directly: a
ProcessLookupError traceback from SigIntHandler, raised inside
os.waitpid after the command had already exited.

Co-Authored-By: Claude Code 2.1.286 / Claude Fable 5.1 <noreply@anthropic.com>
pyproject.toml sets [tool.coverage.run] patch = ["subprocess", "execv"],
which coverage only understands from 7.10. Older versions warn
"Unrecognized option" and silently do not measure subprocesses (checked
with 7.9.2 and 7.10.0). Declare the floor next to pytest-cov so an old
environment fails at install time with a clear message.

Co-Authored-By: Claude Code 2.1.286 / Claude Fable 5.1 <noreply@anthropic.com>
Python runs a signal handler in the main thread at its next bytecode.
For duct that can be only after its wait for the command has returned:
when the signal's delivery did not wake the main thread, or when the
Ctrl-C lands while duct is finishing up. The handler then signalled a
pid that had already been reaped, and the ProcessLookupError escaped:
duct printed a traceback and exited 1 instead of finishing normally
with the command's exit code.

CI showed it as test_signal_kill taking exactly the command's lifetime
and duct exiting 1.

Catch it and warn: the user pressed Ctrl-C and it could not be acted
on, which they should see.

Co-Authored-By: Claude Code 2.1.286 / Claude Fable 5.1 <noreply@anthropic.com>
A signal sent to a process is delivered to any one of its threads that
does not block it, but Python only runs the handler in the main thread.
When the kernel handed a SIGINT to one of duct's other threads, the
main thread stayed asleep in its wait for the command, and the Ctrl-C
was not forwarded until the command exited by itself.

Traced with strace: in 3 of 3 such cases a worker thread took the
SIGINT, mid-run, while in 447 normal cases the main thread did. On an
idle Linux machine with the test suite's 10 ms sampling interval 11 of
1000 first SIGINTs went unforwarded; with this change 0 of 1000. At
duct's default 1 s sampling interval none did in 600 trials, so users
were less exposed than the tests.

A new thread inherits its creator's signal mask, so start_thread()
blocks SIGINT just around Thread.start(). This is the usual way to
steer signals in a threaded program, costs two system calls per thread
start and nothing while the command runs, and leaves the handler's
escalation (forward, forward, kill) as it was, since only the main
thread ever ran it. A test checks that every thread started during a
run goes through it.

Side effect: processes started by those threads inherit the block, so
the short-lived `ps` of the sampling thread cannot be interrupted by a
terminal Ctrl-C. The command is started by the main thread and its
mask is unchanged. Not tested on macOS.

What remains is a SIGINT landing in the microseconds between the main
thread's last check for signals and its blocking wait. That is a
CPython limitation of any signal.signal() plus blocking-call program;
a second Ctrl-C gets through and the pair is handled as one press.

Co-Authored-By: Claude Code 2.1.286 / Claude Fable 5.1 <noreply@anthropic.com>
Until now --fail-time was only tested through the signal tests'
parametrization, where "logs removed" silently depended on the
interrupted run finishing inside the threshold. Test the thresholds
directly, with a command that just fails: under the threshold (3, the
default, and 60) the logs are removed; a command that runs longer than
the threshold (1 s) keeps them. Only the first two assume anything
about speed, and only that `exit 1` takes less than 3 s.

Co-Authored-By: Claude Code 2.1.286 / Claude Fable 5.1 <noreply@anthropic.com>
test_signal_int and test_signal_kill ran with --fail-time unset, 0, 10,
-1 and -3.14, a list they have carried since --fail-time was added.
For the unset (3 s) and 10 cases the "logs removed" check depends on
the interrupted run finishing inside the threshold, which a slow
runner does not guarantee.

Keep the two values whose effect does not depend on how long the run
took: 0 always keeps a failed command's logs, a negative value never
does. The thresholds themselves are covered by
test_fail_time_threshold.

Co-Authored-By: Claude Code 2.1.286 / Claude Fable 5.1 <noreply@anthropic.com>
Comment thread src/con_duct/_signals.py Outdated
try:
lgr.log(level, msg)
except RuntimeError:
pass

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

not sure about this.... may be should sleep/retry but not just silently swallow them!

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe we could just force flush the log before kill?

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Agreed that silently dropping it is bad, but sleep/retry (or flushing first) can't work here: the handler runs on the main thread on top of the stderr write it interrupted, and that write holds the buffered writer's lock until the handler returns, so any retry would just wait on itself.

The signal itself was never lost (os.kill runs before the log call); only the message was. f40bba8 now writes it straight to fd 2 when this happens, still honoring the log level, on its own line and labeled as written directly, e.g.:

con-duct [INFO] (written directly: the signal interrupted a log write): Received SIGINT, passing to command

🤖 Generated with Claude Code

@asmacdo

asmacdo commented Oct 2, 2026 •

Copy link
Copy Markdown
Member Author

TODO: compare to datalad's runner, perhaps learn from them perhaps have some fixes to offer them (add skill to this repo)

https://github.com/datalad/datalad/tree/maint/datalad/runner

A signal that interrupts duct mid-write to stderr makes the handler's own
log call raise "reentrant call"; the message used to be dropped. Retrying
cannot help: the interrupted write holds the buffered writer and only
finishes after the handler returns. Write the message straight to fd 2
instead, still honoring the log level, on its own line and saying why it
looks different. A failed raw write is ignored so the handler never raises.

Co-Authored-By: Claude Code 2.1.295 / Claude Opus 5.5 <noreply@anthropic.com>
@asmacdo asmacdo changed the title Fix Ctrl-C being lost during logging or at startup Fix Ctrl-C being lost or crashing duct Oct 8, 2026
@asmacdo

asmacdo commented Oct 8, 2026

Copy link
Copy Markdown
Member Author

TODO: compare to datalad's runner, perhaps learn from them perhaps have some fixes to offer them

Compared against datalad's runner (maint @ 8cc0031).

Why datalad is different: it installs no signal handlers at all, so it has nothing to forward and nothing to log from signal context (no counterpart to the reentrant-write fixes here). A tty Ctrl-C reaches the child because the child shares datalad's process group; Python's default handler independently raises KeyboardInterrupt in datalad. It also never hits the problem start_thread solves here, by design rather than by sigmask: process.wait() runs in a worker thread, and the main thread polls a queue with a 0.2 s timeout instead of blocking in wait(). So whichever thread the kernel picks, the main thread acts on SIGINT within ~0.2 s.

Possibly worth borrowing for #459 (SIGTERM): its timeout path closes the child's stdin, terminate()s, waits 1 s, then kill()s, and closes stdout/stderr only after the child is reaped (closing them earlier SIGPIPEs the child or its helpers, exit 141).

Hypothetical datalad bug: since nothing cleans up on interrupt, a signal sent to datalad's pid alone orphans the child. Reproduced through the Python API (Runner().run(["sleep", N])): kill -INT → datalad exits 130, kill -TERM → exits 143, and in both cases sleep keeps running, reparented. Not yet checked through the datalad CLI, and I have not named a realistic sender that signals only datalad's pid (a tty, SLURM, and systemd all signal the whole group/cgroup), so it may not matter in practice. I have a reproducer if we take this upstream.

Generated by Claude Code

@asmacdo
asmacdo marked this pull request as ready for review October 8, 2026 23:00
Copilot AI balanced review requested due to automatic review settings October 8, 2026 23:00

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔵 Needs a closer look

It reworks core SIGINT/threading lifecycle behavior with platform-sensitive signal-mask and reentrancy handling, and the author explicitly expects CI failures until the stacked #457 merges, so it needs human verification.

0 open findings

What changed in this PR

This PR hardens duct's Ctrl-C (SIGINT) handling so a signal is never lost or turned into a crash, and rewrites the signal tests to synchronize on duct's readiness/progress instead of sleeping (removing the macOS/PyPy timing flakiness in #451/#439). It restructures SigIntHandler into an install-early-then-attach model, forces all duct worker threads to start with SIGINT blocked so only the main thread handles it, and makes handler logging fail-safe. This is part 1/2 of the flaky-CI fix (part 2 is #457).

Changes:

  • SigIntHandler now installs before the command starts (only counting SIGINTs until attach(pid)), forwards the signal before logging, logs a warning instead of crashing on a late Ctrl-C, and falls back to a raw fd-2 write when logging would raise a reentrant RuntimeError.
  • New start_thread() blocks SIGINT while starting each thread; every Thread.start() in _duct_main.py/_output.py is routed through it, enforced by a new test.
  • Signal tests run duct as a real subprocess and wait for duct's "is executing" line / command progress file; fail-time thresholds get a dedicated timing test; coverage now follows subprocesses (coverage>=7.10, patch).
File Description
src/​con_duct/​_signals.py Core fix: attach() model, forward-before-log, ProcessLookupError handling, start_thread, fail-safe _log.
src/​con_duct/​_duct_main.py Installs handler before command, early-SIGINT exit (130), uses attach() and start_thread.
src/​con_duct/​_output.py Starts TailPipe thread via start_thread.
test/​duct_main/​test_signals.py New unit tests for SigIntHandler, _log fallback, and the SIGINT-blocked-thread invariant.
test/​duct_main/​test_e2e.py Rewrites test_signal_int/test_signal_kill as readiness-synced subprocess tests; longer marker process.
test/​duct_main/​test_execution.py Removes old timing-based signal tests; adds test_fail_time_threshold.
test/​utils.py Adds start_duct/rest_of_stderr helpers and DUCT_READY regex.
test/​data/​signal_ignorer.py Reports "ready"/"SIGINT" progress to a file so tests can wait per step.
tox.ini, pyproject.toml, .gitignore coverage>=7.10, patch = ["subprocess","execv"], ignore .coverage.*.

🧠 Review effort: Balanced


💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

@yarikoptic
yarikoptic requested a review from leej3 October 9, 2026 18:35

@leej3 leej3 left a comment •

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It seems there is a bugging this implementation:
"attach() can forward one SIGINT twice if it arrives between assigning self.pid and checking sigcount. Block SIGINT around that handoff and pending-signal processing, restore the previous mask, and add a regression test."

Also, an install of util-linux on macOS CI allows the setsid cases to run.

leej3 and others added 2 commits October 12, 2026 10:48
A SIGINT that arrived between attach() setting self.pid and checking
sigcount was forwarded twice: once by the handler, which already saw the
pid, and once more by attach() acting on the now nonzero count. The
command got two SIGINTs for one Ctrl-C.

With SIGINT blocked in the main thread (and in every helper thread, via
start_thread), a signal in that window stays pending and is handled
once, after the mask is restored.

Split out of #2, which also enabled setsid on macOS CI.

Co-Authored-By: Codex Desktop 26.1007.21159 (runtime codex-cli 0.162.0-alpha.17.2) / gpt-6-astra <codex@openai.com>
Codex-Reasoning-Effort: low
Co-Authored-By: Claude Code 2.1.296 / Claude Opus 5.5 <noreply@anthropic.com>
start_thread() and attach() both blocked SIGINT and restored the old
mask with the same try/finally.

Co-Authored-By: Claude Code 2.1.296 / Claude Opus 5.5 <noreply@anthropic.com>
@asmacdo
asmacdo force-pushed the signal-test-handshake branch from a5bb5fc to 865f4b9 Compare October 12, 2026 15:49
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

semver-patch Increment the patch version when merged

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants