Skip to content

fix: bound the CEC subprocess reap, quieten three Sentry noise sources, and report the version to GA4 - #3269

Closed
vpetersson-bot wants to merge 7 commits into
Screenly:masterfrom
vpetersson-bot:fix/sentry-triage-findings
Closed

fix: bound the CEC subprocess reap, quieten three Sentry noise sources, and report the version to GA4#3269
vpetersson-bot wants to merge 7 commits into
Screenly:masterfrom
vpetersson-bot:fix/sentry-triage-findings

Conversation

@vpetersson-bot

@vpetersson-bot vpetersson-bot commented Aug 7, 2026

Copy link
Copy Markdown
Contributor

Issues Fixed

Fixes #3264, #3265, #3266, #3267, #3268 — found during the 2026-08-07 Sentry triage sweep, then reproduced and validated on six physical testbeds. Also fixes the GA4 "Version distribution" report, which has never worked.

What changed

diagnostics — bound the CEC subprocess reap (#3264)

subprocess.run(..., capture_output=True, timeout=N) burns its entire timeout when a descendant still holds the inherited stdout pipe, because communicate() keeps draining. New _run_bounded(): start_new_session=True + killpg(SIGKILL), output to temp files instead of pipes, a timeout on every wait, and deliberately not a context manager (Popen.__exit__ is one of the hazards).

Measured, fast-exiting child with a grandchild holding stdout: 0.07-0.12s versus 8.0s for subprocess.run, on all three architectures.

diagnostics — three distinct CEC states (#3267)

'CEC error' covered three different situations and reported the most common one as a fault. Now 'No CEC adapter' (libcec raised), 'No CEC display detected' (adapter works, no peer answered — the normal case for a plain monitor), 'CEC adapter unresponsive' (libcec hung and was killed), and 'CEC error' for genuinely unexpected.

upgrade_containers.sh — pass /dev/cec0 on pi2/pi3/pi3-64/pi4-64 (#3267, root cause)

The vchiq→cec0 rewrite only matched pi5 and x86|arm64, so every other Pi fell through the case and kept the vchiq node libcec cannot open on a vc4-kms kernel. A targeted Pi 5 fix (#2863) never extended. Guarded on [ -e /dev/cec0 ], leaving vchiq untouched otherwise, since compose refuses to start when a listed host node is missing.

viewer — three log/behaviour fixes (#3265, #3266, #3268)

telemetry — send the release version

The GA4 "Version distribution" report reads a version_name dimension that nothing has ever sent — not this payload, and not the pre-#2798 one either, whose Pi_Version was the hardware model. Hence ~3,700 devices as "(not reported)". Sourced from get_anthias_release() (pyproject.toml, ships in the image) rather than an env var, because missing env vars are the known failure mode here; verified resolving to 2026.7.3 inside anthias-anthias-celery-1.

Hardware validation — six boards

Board Stack Result
Pi 2 armhf / Qt5 / linuxfb #3266 before/after + false-positive hunt, #3268, #3264
Pi 3 A+ armv7l, 361 MB #3264 under real memory pressure; found #3267's hang
Pi 3-64 arm64 / Qt6 / eglfs #3264 in the real worker, #3267 A/B, guard inert
Pi 4 arm64 / Qt6 / eglfs #3267 with a real /dev/cec0; genuine D-state child
Pi 5 arm64 / Qt6 / Wayland #3265 induced for real, with a Sentry A/B
x86 x86_64 / Wayland negative control; redis-py bound

Rock Pi 4 was off-network throughout, so the generic arm64 image is not covered.

#3266 — before: 3 attempts / 6.02s / generic message. After: 1 attempt / 2.94s / distinct message. The false-positive risk was attacked directly and does not exist: with /dev/fb0 replaced by an unopenable node, Qt emitted two of the three signatures and the guard correctly declined, spending its full budget. Inert on eglfs and Wayland, with positive controls proving the code is live rather than dead.

#3264 — worst-case overrun +0.0027s. A genuine uninterruptible D-state child was produced on arm64 (O_DIRECT to the SD card, 98.7% D, wchan mmc_blk_rw_wait) and the reap still held, killpg reaping in 31.5ms. 40 real dispatches: fd delta 0, zombie delta 0, temp-file delta 0.

#3265 — induced for real on the Pi 5 with a second live cage: recovery at WARNING(30), give-up still ERROR(40), and a capturing-transport A/B showing ERROR→1 event, WARNING→0. Bounded-restart counter and cap unchanged.

#32681437-1824 lines/hour → 0 across boards, with the latch resetting in both directions.

#3267 — the decisive experiment, on the Pi 4 with the host's real /dev/cec0 passed into a throwaway container: cec.init() OK at 1187ms, Device(TV) OK at 1430ms, is_on() raises OSError: Power status not found'No CEC display detected' at 2910ms. Control with vchiq only → 'No CEC adapter' at 82ms. The two strings discriminate exactly as designed.

Claims corrected during validation — the testbeds refuted me five times

Recording these because the earlier commit messages in this branch asserted them:

  1. The mechanism story was wrong. "SoftTimeLimitExceeded re-enters an unbounded wait so the task sails past the hard limit" does not reproduce on CPython 3.13, which calls process.kill() before every wait() — 0.00s overshoot, agreed by three boards. The real win is the pipe-drain stall. The docstring now says so, and the root cause of ANTHIAS-A/9/B/31 remains open — this is a robustness and latency fix, not a proven cure.
  2. Display power is permanently 'CEC error' on mainline-KMS Pis: containers get /dev/vchiq but libcec needs /dev/cec0 #3267 did not land on two boards. libcec hangs on the vchiq-only Pi 2 and Pi 3 A+ rather than raising, so the 'No CEC adapter' branch was unreachable and operators saw the same 'CEC error'. Hence the 'CEC adapter unresponsive' state, and the passthrough fix.
  3. The first Viewer idle log spam evicts crash diagnostics from the volatile journal within ~8h on low-RAM boards #3268 fix left a 5× worse offender untouched — the not-displayable arm loops on a 0.5s wait, measured at 7155-7200 lines/hour on three boards.
  4. My own latch went permanently silent in the "empty → unavailable → empty" sequence.
  5. The _run_bounded docstring claimed init would reap orphans. Container PID 1 is the celery worker; a killed grandchild persists. Caught independently by three boards.

Also corrected: #3266 does not reduce Sentry event volume (2 events before and after); it improves grouping and cuts the black-screen delay. And it cannot fire on the handshake-timeout path, whose message carries no Qt output — so the "~21 min" saving does not apply there.

Known-unfixed, deliberately

Testing

1570 passed, 3 skipped (-m "not integration"), mypy clean across 169 files, ruff check + format clean.

Checklist

  • I have performed a self-review of my own code.
  • New and existing unit tests pass locally and on CI with my changes.
  • I have done an end-to-end test for Raspberry Pi devices.
  • I have tested my changes for x86 devices.
  • I added a documentation for the changes I have made (when necessary).

…celery

subprocess.run's timeout path reaps with an unbounded wait(), and its
bare except defers to Popen.__exit__ which does the same. Celery raises
its soft limit once; that signal interrupts the first waitpid, then
unwinding re-enters an unbounded wait with no second signal coming, so
the task blows the hard limit and the worker is SIGKILLed.

- run the child via Popen with start_new_session=True, output to temp
  files instead of pipes, and a timeout on every wait
- SIGKILL the whole process group on timeout so a grandchild cannot
  survive or stall the reap; give up rather than block if it persists
- distinguish "No CEC adapter" from "No CEC display detected" so a plain
  monitor without CEC stops being reported to operators as a fault
- leave True/False and the str|bool return alone: they are the v2 API's
  data values, not diagnostics

Fixes Screenly#3264. Addresses the tractable half of Screenly#3267.
Three separate log/behaviour fixes in the viewer:

- the Wayland headless-boot recovery logged its own success at ERROR,
  and the Sentry logging integration promotes ERROR to events, so every
  recovery filed an issue. Demoted to warning; the give-up-after-cap
  branch stays at ERROR (Screenly#3265)
- short-circuit the launch retry loop when the display device has
  vanished. The container's /dev is a start-time snapshot and
  wait_for_framebuffer runs once, so retrying cannot re-enumerate it —
  it just delays the container restart by 6.5-21 min of black screen.
  Conservative: needs a Qt no-screen signature AND /dev/fb0 absent, and
  never fires on wayland/eglfs (Screenly#3266)
- log the empty-playlist notice on transition instead of every poll, and
  drop the per-tick URL line to debug. Together these emitted ~1250
  lines/hour on an idle board into a ~15 MB volatile journal, evicting
  crash diagnostics within ~8 hours (Screenly#3268)
@vpetersson-bot
vpetersson-bot requested a review from a team as a code owner August 7, 2026 07:07
@vpetersson-bot vpetersson-bot self-assigned this Aug 7, 2026
@codecov

codecov Bot commented Aug 7, 2026

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 82.92683% with 7 lines in your changes missing coverage. Please review.
⚠️ Please upload report for BASE (master@82c5def). Learn more about missing BASE report.

Files with missing lines Patch % Lines
src/anthias_server/lib/diagnostics.py 81.08% 7 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff            @@
##             master    #3269   +/-   ##
=========================================
  Coverage          ?   90.65%           
=========================================
  Files             ?       76           
  Lines             ?     8467           
  Branches          ?      898           
=========================================
  Hits              ?     7676           
  Misses            ?      570           
  Partials          ?      221           

☔ 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.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

Testbed validation on the vchiq-only Pi 3 A+ refuted the assumption in
the previous commit: libcec there does not raise, it HANGS, so the
'No CEC adapter' branch is unreachable and the operator saw the same
'CEC error' as before. Behaviour differs by board — the Pi 3-64
fast-fails in ~70ms while this one blocks past the timeout.

- return 'CEC adapter unresponsive' when the probe had to be killed, so
  "no hardware" and "hardware wedged" are distinguishable
- record that vchiq-only Pi 1-4 boards therefore burn the full timeout
  every beat tick, and why skipping the doomed probe is not yet safe
Testbed measurement on the arm64 board: asset_loop's non-displayable
arm loops on a 0.5s wait, so ONE unreachable asset emitted ~7180
lines/hour — roughly 5x the idle-playlist rate the previous commit
fixed, and enough on its own to defeat the whole point of it.

- log once per distinct asset (keyed on asset_id:uri) instead of ~2
  lines/second, and clear the latch when a playable asset returns
- that arm also never cleared the empty-playlist latch; it does now
- unit tests for both latches, including that they reset rather than
  going permanently silent
- correct the _run_bounded docstring: container PID 1 is the celery
  worker, not an init that reaps, so a killed grandchild persists.
  Two independent testbeds caught this. Also record the two documented
  killpg escapes (setpgid, fast double-fork), neither reachable from
  the CEC scripts.
The vchiq -> cec0 rewrite in upgrade_containers.sh only matched pi5 and
x86|arm64, so every other Pi board fell through the case and kept the
/dev/vchiq node libcec cannot open on a vc4-kms kernel. That is the root
cause of display power never working on them, and of the bare
'CEC error' operators saw.

Measured on the pi4-64 testbed with /dev/cec0 passed into a throwaway
container: libcec opens the adapter (init 1.19s, Device 1.43s) and the
query completes in ~2.9s, versus an 82ms failure with vchiq only — or an
outright hang on the pi3-32, which is why the string was uninformative.

Guarded on [ -e /dev/cec0 ] and leaving vchiq untouched otherwise, since
compose refuses to start a container whose listed host node is missing.
/dev/cec1 deliberately not added: present on some of these boards and
not others, and not needed to read display power.

Refs Screenly#3267.
The GA4 "Version distribution" report reads a `version_name` dimension
that nothing has ever sent — not this payload, and not the pre-Screenly#2798 one
either, whose `Pi_Version` was the *hardware* model. So the report
showed ~3,700 devices as "(not reported)" and could never have worked.

- add `version_name` from get_anthias_release() (pyproject.toml, which
  ships in the image) rather than an env var, since missing env vars are
  the known failure mode for telemetry params. Verified inside
  anthias-anthias-celery-1 on the pi5 testbed: resolves to '2026.7.3'
  with no extra plumbing
- fall back to 'unknown' rather than '', so a device whose version
  lookup fails gets its own bucket instead of silently rejoining the
  "(not reported)" pile that hid this
- correct the docstring: the event was renamed `version` ->
  `device_active` in Screenly#2798 and the docstring still said `version`
Validation across armhf/arm64/x86 and linuxfb/eglfs/Wayland found five
things wrong with the earlier commits:

- the empty-playlist latch never reset in the not-displayable branch, so
  "empty -> unavailable asset -> empty" went permanently silent. That is
  the exact failure the latch exists to prevent
- move the no-CEC r.set() inside the SoftTimeLimitExceeded handler. It
  is not unbounded (redis-py 8.0.1 defaults socket_timeout=5) but the
  default Retry(retries=10) costs 58.83s measured, which blows the 30s
  soft limit; outside the try that escaped uncaught and filed a Sentry
  event on exactly the no-CEC boards
- add the 'Failed to open framebuffer' Qt signature, seen on armhf when
  the node exists but cannot be opened
- honour linuxfb's fb=/dev/fbN instead of hardcoding /dev/fb0
- rewrite the _run_bounded docstring to match measurement. The
  unbounded-wait-past-the-hard-limit story does NOT reproduce on CPython
  3.13 (0.00s overshoot, three boards agree); the real, large win is the
  pipe-drain stall, 0.07s vs 8.0s. A genuine D-state child was produced
  on arm64 and the reap still held in 31.5ms. So this is a robustness
  and latency fix, not a proven cure for the SIGKILL

Tests added for the gaps the boards flagged as uncovered: the
load_browser short-circuit and its false-positive counterpart, the
fb=/dev/fbN lookup, and the Screenly#3265 ERROR->WARNING demotion.
@vpetersson-bot vpetersson-bot changed the title fix: bound the CEC subprocess reap and quieten three Sentry noise sources fix: bound the CEC subprocess reap, quieten three Sentry noise sources, and report the version to GA4 Aug 7, 2026
@sonarqubecloud

sonarqubecloud Bot commented Aug 7, 2026

Copy link
Copy Markdown

@vpetersson-bot

Copy link
Copy Markdown
Contributor Author

Closing in favour of four focused PRs. This one had grown to 977 lines across 8 files and 5 issues, plus an unrelated telemetry fix — too much to review as a unit, and worse, it welded together changes with completely different risk profiles.

PR Contents Risk
#3272 diagnostics bounded CEC reap + distinct CEC states + the celery r.set move Medium — server library
#3271 Viewer: recovery log level, framebuffer short-circuit, idle log throttling Medium — changes viewer restart behaviour
#3270 telemetry version_name for the GA4 report Trivial — one outbound field
#3273 upgrade_containers.sh /dev/cec0 passthrough High — runs during real OTA upgrades

The split matters most for #3273. It is simultaneously the riskiest change here (a mistake means containers fail to start fleet-wide) and the least validated — I never ran an actual upgrade, only verified the sed and reasoned from the existing x86|arm64 precedent. Buried in this PR, that caveat was easy to miss behind pages of reap measurements. On its own it can be held, reviewed and reverted independently.

Verified lossless: every changed file is covered by exactly one of the four, and 7 of 8 are byte-identical to this branch. The eighth, celery_tasks.py, differs only in a comment I reworded so it no longer asserts a state that #3273 changes — the two can now merge in either order.

All the hardware validation carries over; it was per-issue anyway. Each PR body keeps the measurements relevant to it, plus the caveats — including that #3264's root cause remains open: bounding the reap fixes a real 8-second stall, but three boards refuted my original mechanism claim and the hard-limit SIGKILL was never reproduced.

No commits are lost — the branch fix/sentry-triage-findings remains if anything needs to be recovered from the combined history.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

get_display_power still SIGKILLs the celery worker despite the soft-limit guard

1 participant