Skip to content

Python 3.14.8 swallows WatchedFileHandler reopen failures — file-sink suspend never engages #3551

Closed

Description

@mcdonc

Summary

TestLogFileSink::test_reopen_failure_suspends_sink_not_the_call_site fails deterministically on Python 3.14.8 (which CI's test-backend runs; local devenv is 3.14.7, where it passes). The failure is a real product regression: on 3.14.8, RotationSafeFileHandler's suspend-on-failure design never engages, because the stdlib now swallows reopen failures inside WatchedFileHandler.emit.

Observed

PR #3472's test-backend job, twice in a row (runs 37796009400, jobs 113375518546 and 113385368536), worker gw2, Python 3.14.8:

FAILED src/klangk/klangkd-tests/tests/test_logger.py::TestLogFileSink::test_reopen_failure_suspends_sink_not_the_call_site - assert False is True
 +  where False = <RotationSafeFileHandler /tmp/pytest-of-runner/pytest-0/popen-gw2/test_reopen_failure_suspends_s0/k.jsonl (INFO)>._sink_broken
1 failed, 8380 passed, 1 skipped in 459.37s

Cause

CPython 3.14.8 (backport of the gh-135683 companion change, Lib/logging/handlers.py) changed WatchedFileHandler.emit from

self.reopenIfNeeded()
logging.FileHandler.emit(self, record)

to

try:
    self.reopenIfNeeded()
except Exception:
    self.handleError(record)      # swallowed — no propagation
else:
    logging.FileHandler.emit(self, record)

RotationSafeFileHandler.emit (src/klangk/klangk/logger.py) relies on the reopen failure (IsADirectoryError when the path became a directory) propagating out of super().emit() into its own except Exception, which sets _sink_broken and emits the one-shot "file logging suspended" warning. On 3.14.8 that exception never leaves the stdlib, so:

  • _sink_broken is never set — file logging never suspends,
  • the one-shot warning is never emitted,
  • every subsequent record retries the failing reopen and routes through handleError, which (with logging.raiseExceptions, the default) prints a full traceback to stderr per record — noise plus silent data loss, exactly what the suspend design exists to prevent.

This affects any klangkd on Python ≥ 3.14.8 with a rotated/unwritable KLANGKD_LOG_FILE path, not just the test.

Fix direction

Stop relying on propagation from super().emit(): run self.reopenIfNeeded() explicitly inside RotationSafeFileHandler.emit's own try (before delegating to logging.FileHandler.emit), so a reopen failure reaches the handler's suspend path on every Python version. The call is idempotent — stdlib's own reopenIfNeeded inside WatchedFileHandler.emit becomes a no-op after ours succeeds, and on failure ours raises first.

A regression test should simulate the 3.14.8 swallow (monkeypatch WatchedFileHandler.emit to the 3.14.8 shape) and assert _sink_broken is still set — that pins the fix even on 3.14.7 toolchains.

Context

(Correction: this issue was originally filed with an inode-reuse-race theory for the test's unlink+mkdir setup. That theory was wrong — the handler holds the original fd open, which pins the old inode. The real cause is the 3.14.8 stdlib change above.)

Activity

  1. changed the title [-]Flaky test: test_reopen_failure_suspends_sink_not_the_call_site loses the inode-reuse race[/-] [+]Python 3.14.8 swallows WatchedFileHandler reopen failures — file-sink suspend never engages[/+] on Oct 8, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions