One info! line in a TLS destructor aborted the host on every session teardown #289

Merged
enricobuehler merged 1 commits from worktree-win-teardown-abort into main 2026-08-18 08:43:32 +00:00
Owner

A GameStream session ending killed the whole punktfunk-host process on Windows. The SCM restarted it ~6 s later, so in the field it reads as a mystery reconnect rather than a crash. Found while doing the on-glass pass for #288; every occurrence on .173 was a session teardown, on the canary and on a branch build alike.

Cause

HotThreadGuard is parked in a thread_local! so the last hot thread out reverts the process-wide session tuning. Its Drop is therefore a TLS destructor, and it called tracing::info!.

By then that thread's other thread-locals may already be gone — tracing_subscriber's registry is sharded-slab-backed and reads a thread_local! through LocalKey::with — so the event panicked with "cannot access a Thread Local Storage value during or after destruction". A panic that escapes a TLS destructor is fatal in Rust: fatal runtime error: thread local panicked on drop, aborting.

Why it went undiagnosed

The panic hook teed through tracing too, so it panicked the same way — and a panic raised while the hook is running is MustAbort::PanicInHook, where std deliberately does not format the message ("perhaps that is causing the panic"). The log got:

panicked at <loc>:
<blank>
thread panicked while processing panic. aborting.

That blank line is not corruption. It is the one string naming the cause, erased at exactly the moment it mattered.

The change

  • crates/pf-frame/src/session_tuning.rsuntune_process no longer logs. The revert is only FFI and stays inside the refcount lock, so it is still atomic against a session starting concurrently. The counterpart "applied" line in tune_process runs on a live thread and is kept.
  • crates/punktfunk-host/src/main.rs — the panic hook writes straight to the LogRing (a OnceLock + Mutex, so TLS-free) instead of through tracing. thread::current().name() and Backtrace::force_capture() were both verified safe during TLS destruction. This does not make a TLS-destructor panic survivable — Rust aborts on those regardless — but the message that names the cause now always lands.

Both sites carry a loud comment about the constraint, because the failure mode is invisible at the call site.

Evidence

Reproduced standalone first, against the same 1.96.0 toolchain: output byte-identical to the field log, blank line included. That harness also settles which half is load-bearing:

result
both defects abort, output identical to the field log
destructor logs, hook hardened still aborts — but prints the real AccessError
destructor silent, hook unhardened clean exit
both fixed clean exit

So hardening the hook alone is not a fix. Removing the destructor's log is.

On .173, before — a controlled Desktop session ended by client disconnect:

08:35:46.109 video stream stopped
panicked at .../thread/local.rs:428:25:
thread panicked while processing panic. aborting.
08:35:49.571 punktfunk-host 0.31.14308        <- SCM restart

windows session tuning applied present, reverted absent — that line is what panicked.

After: 3 teardown cycles, 0 panics, 0 restarts, host pid stable across all of them.

Gates

  • Windows .173: clippy --all-targets -p punktfunk-host -p pf-frame --features nvenc,amf-qsv -- -D warnings → 0, release build → 0. Non-vacuous (4 Checking|Compiling lines for the two crates).
  • Linux (punktfunk-rust-ci): fmt 0, clippy 0, pf-frame 10 tests, punktfunk-host log_capture 8 tests. Non-vacuous.

Two things left open, deliberately

No unit test. The natural guard — spawn a hot thread under a real Registry subscriber and let it exit — fails by aborting the test binary, killing every other test in it, and only on Windows. That seemed too hostile to add unprompted.

This is a latent class, not one bug. Any future tracing call reachable from a TLS destructor re-arms it. The structural cure is moving HotThreadGuard off TLS onto the hot threads' stacks — on_hot_thread() returning a guard — which touches ~12 boost_thread_priority call sites and risks a caller dropping it early. Bigger than this bug warrants; the constraint is documented at both sites instead.

A GameStream session ending killed the whole `punktfunk-host` process on Windows. The SCM restarted it ~6 s later, so in the field it reads as a mystery reconnect rather than a crash. Found while doing the on-glass pass for #288; every occurrence on .173 was a session teardown, on the canary and on a branch build alike. ## Cause `HotThreadGuard` is parked in a `thread_local!` so the last hot thread out reverts the process-wide session tuning. Its `Drop` is therefore a **TLS destructor**, and it called `tracing::info!`. By then that thread's *other* thread-locals may already be gone — `tracing_subscriber`'s registry is `sharded-slab`-backed and reads a `thread_local!` through `LocalKey::with` — so the event panicked with "cannot access a Thread Local Storage value during or after destruction". **A panic that escapes a TLS destructor is fatal in Rust**: `fatal runtime error: thread local panicked on drop, aborting`. ## Why it went undiagnosed The panic hook teed through `tracing` too, so it panicked the same way — and a panic raised while the hook is running is `MustAbort::PanicInHook`, where std *deliberately* does not format the message ("perhaps that is causing the panic"). The log got: ``` panicked at <loc>: <blank> thread panicked while processing panic. aborting. ``` That blank line is not corruption. It is the one string naming the cause, erased at exactly the moment it mattered. ## The change - **`crates/pf-frame/src/session_tuning.rs`** — `untune_process` no longer logs. The revert is only FFI and stays inside the refcount lock, so it is still atomic against a session starting concurrently. The counterpart "applied" line in `tune_process` runs on a live thread and is kept. - **`crates/punktfunk-host/src/main.rs`** — the panic hook writes straight to the `LogRing` (a `OnceLock` + `Mutex`, so TLS-free) instead of through `tracing`. `thread::current().name()` and `Backtrace::force_capture()` were both verified safe during TLS destruction. This does not make a TLS-destructor panic survivable — Rust aborts on those regardless — but the message that names the cause now always lands. Both sites carry a loud comment about the constraint, because the failure mode is invisible at the call site. ## Evidence Reproduced standalone first, against the same 1.96.0 toolchain: output byte-identical to the field log, blank line included. That harness also settles which half is load-bearing: | | result | |---|---| | both defects | **abort**, output identical to the field log | | destructor logs, hook hardened | **still aborts** — but prints the real `AccessError` | | destructor silent, hook unhardened | clean exit | | both fixed | clean exit | So hardening the hook alone is *not* a fix. Removing the destructor's log is. On .173, before — a controlled Desktop session ended by client disconnect: ``` 08:35:46.109 video stream stopped panicked at .../thread/local.rs:428:25: thread panicked while processing panic. aborting. 08:35:49.571 punktfunk-host 0.31.14308 <- SCM restart ``` `windows session tuning applied` present, `reverted` absent — that line is what panicked. After: **3 teardown cycles, 0 panics, 0 restarts**, host pid stable across all of them. ## Gates - **Windows .173**: `clippy --all-targets -p punktfunk-host -p pf-frame --features nvenc,amf-qsv -- -D warnings` → 0, release build → 0. Non-vacuous (4 `Checking|Compiling` lines for the two crates). - **Linux** (`punktfunk-rust-ci`): fmt 0, clippy 0, `pf-frame` 10 tests, `punktfunk-host log_capture` 8 tests. Non-vacuous. ## Two things left open, deliberately **No unit test.** The natural guard — spawn a hot thread under a real `Registry` subscriber and let it exit — fails by *aborting the test binary*, killing every other test in it, and only on Windows. That seemed too hostile to add unprompted. **This is a latent class, not one bug.** Any future `tracing` call reachable from a TLS destructor re-arms it. The structural cure is moving `HotThreadGuard` off TLS onto the hot threads' stacks — `on_hot_thread()` returning a guard — which touches ~12 `boost_thread_priority` call sites and risks a caller dropping it early. Bigger than this bug warrants; the constraint is documented at both sites instead.
enricobuehler added 1 commit 2026-08-18 08:42:58 +00:00
fix(host): one info! line in a TLS destructor aborted the host on every session teardown
ci / bun-nix (pull_request) Successful in 20s
ci / web (pull_request) Successful in 1m2s
ci / rust (pull_request) Successful in 5m58s
ci / rust-arm64 (pull_request) Successful in 7m18s
ci / docs-site (pull_request) Successful in 8m26s
android / android (pull_request) Successful in 14m11s
4cd35e15ca
A GameStream session ending killed the whole `punktfunk-host` process on Windows.
The SCM restarted it ~6 s later, so in the field it read as a mystery reconnect
rather than a crash. Four occurrences on .173, every one of them a session
teardown, on the canary and on a branch build alike.

`HotThreadGuard` is parked in a `thread_local!` so the last hot thread out
reverts the process-wide session tuning. Its `Drop` is therefore a **TLS
destructor**, and it called `tracing::info!`. By then this thread's other
thread-locals may already be gone — `tracing_subscriber`'s registry is
`sharded-slab`-backed and reads a `thread_local!` through `LocalKey::with` — so
the event panicked with "cannot access a Thread Local Storage value during or
after destruction". A panic that escapes a TLS destructor is fatal in Rust:
`fatal runtime error: thread local panicked on drop, aborting`.

The panic hook then hid the evidence. It teed through `tracing` too, so it
panicked the same way — and a panic raised while the hook runs is
`MustAbort::PanicInHook`, where std deliberately does not format the message
("perhaps that is causing the panic"). The log got `panicked at <loc>:`, a BLANK
line, and `thread panicked while processing panic. aborting.` The one string
naming the cause was erased at exactly the moment it mattered.

* `untune_process` no longer logs. The revert is only FFI and stays inside the
  refcount lock, so it is still atomic against a session starting concurrently.
  Its counterpart "applied" line runs on a live thread and is kept.
* The panic hook writes straight to the `LogRing` instead of through `tracing`.
  The ring is a `OnceLock` + `Mutex`, so it is TLS-free; `thread::current()` and
  `Backtrace::force_capture()` were both verified safe during TLS destruction.
  This does not make a TLS-destructor panic survivable — Rust aborts on those
  regardless — but the message that names the cause now always lands.

Reproduced standalone before fixing, against the same 1.96.0 toolchain, and the
output is byte-identical to the field log down to the blank line. That harness
also settles which half is load-bearing: destructor-logging alone aborts, hook
hardening alone still aborts (with a readable message), and removing the
destructor's log exits cleanly.
enricobuehler scheduled this pull request to auto merge when all checks succeed 2026-08-18 08:43:29 +00:00
enricobuehler merged commit b52733d287 into main 2026-08-18 08:43:32 +00:00
Sign in to join this conversation.
No Reviewers
No labels
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: unom/punktfunk#289