bvandeusenandClaude Opus 5
f23ab9f50e
CI / lint (push) Successful in 3s
CI / extension-version (push) Successful in 3s
Build images / sign-extension (push) Successful in 4s
Build images / build-agent (push) Successful in 7s
CI / frontend-build (push) Successful in 21s
CI / backend-lint-and-test (push) Successful in 33s
Build images / build-web (push) Successful in 2m4s
CI / integration (push) Successful in 2m11s
Build images / smoke-web (push) Successful in 1m3s
Build images / promote (push) Skipped
From the operator's first consolidated deploy, 2026-09-23. The app is serving
— showcase, thumbnails, a Patreon ingest tick, all five lanes in one
container — and this repeats in the log:
WARNING service roster: celery inspect failed; roster not refreshed
File "service_roster.py", line 138, in refresh_celery_roster
grouped = await asyncio.wait_for(...)
TimeoutError
The inspect calls were working. The budget was wrong.
`_inspect_celery_sync` makes TWO broadcasts — `active_queues()` and
`active()` — and a broadcast with no `destination` cannot know how many
replies to expect, so each waits out its full timeout rather than returning
on the last reply. The sync call costs ~2 x INSPECT_TIMEOUT_SECONDS.
The wrapper allowed `INSPECT_TIMEOUT_SECONDS * 2`. That reads like a safety
factor and is precisely the worst case with nothing left over — and this runs
on a web process that was serving ninety thumbnails a second at the time, so
the thread handing off through `asyncio.to_thread` need not even be scheduled
inside the budget. A budget equal to the work fails under any load at all.
Now derived: `INSPECT_TIMEOUT_SECONDS * INSPECT_ROUND_TRIPS + slack`, with
the round-trip count named beside the calls it counts. Both tests assert the
RELATION rather than the numbers, and one reads the source to check the count
still matches the calls actually made — a third inspect call added later is
exactly how this comes back silently.
Consequence while it was broken: the roster stopped advancing and the System
tab's rows went stale, with a traceback per attempt. Never an outage —
`refresh_celery_roster` catches and returns, `/api/system/health` kept
answering 200 throughout, which the same log shows.
## Observed, not fixed here
`worker_control.inspect_lanes_sync` makes FOUR of these broadcasts
(active_queues, stats, active, reserved) at 2.0s each — roughly 8s — and
`lane_view` awaits it with no deadline at all. That is the Settings ->
Activity -> Worker lanes card, so that card likely takes ~8s to load, and the
composite healthcheck carries the same cost against its 15s timeout. Reported
to the operator rather than changed: they are mid-deploy, and the fix is to
cut round trips rather than raise a number.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LVjrnpQjRgHdvq95rASoiR
55 lines
2.3 KiB
Python
55 lines
2.3 KiB
Python
"""The roster's inspect budget must exceed the inspect work.
|
|
|
|
Both tests here assert a RELATION between constants rather than their values.
|
|
The failure they exist for is not a wrong number — it is the budget and the
|
|
work drifting apart, which is invisible in each one read on its own.
|
|
"""
|
|
|
|
from __future__ import annotations
|
|
|
|
from backend.app.services import service_roster as sr
|
|
|
|
|
|
def test_the_wrapper_budget_exceeds_the_work_it_waits_for():
|
|
"""The bug the operator's first consolidated deploy surfaced (2026-09-23).
|
|
|
|
`_inspect_celery_sync` makes INSPECT_ROUND_TRIPS broadcasts, and a
|
|
broadcast with no `destination` cannot know how many replies to expect, so
|
|
each waits out its full timeout rather than returning on the last reply.
|
|
The sync call therefore costs round_trips x INSPECT_TIMEOUT_SECONDS.
|
|
|
|
The wrapper allowed `INSPECT_TIMEOUT_SECONDS * 2`, which reads like a
|
|
safety factor and is exactly that worst case with nothing left over. Live
|
|
result: a TimeoutError traceback on every refresh while the two inspect
|
|
calls were working perfectly, and a roster that stopped advancing.
|
|
|
|
Asserted as a RELATION, not as a number. A third inspect call added to the
|
|
sync function is the way this silently comes back, and the only thing that
|
|
keeps the two honest is deriving one from the other.
|
|
"""
|
|
budget = (
|
|
sr.INSPECT_TIMEOUT_SECONDS * sr.INSPECT_ROUND_TRIPS
|
|
+ sr.INSPECT_SLACK_SECONDS
|
|
)
|
|
work = sr.INSPECT_TIMEOUT_SECONDS * sr.INSPECT_ROUND_TRIPS
|
|
assert budget > work, (
|
|
f"the wrapper allows {budget}s for {work}s of broadcasts — a budget "
|
|
f"equal to the work fails under any load at all"
|
|
)
|
|
assert sr.INSPECT_SLACK_SECONDS > 0
|
|
|
|
|
|
def test_the_round_trip_count_matches_the_calls_actually_made():
|
|
"""INSPECT_ROUND_TRIPS is only true if someone keeps it true, so read the
|
|
source rather than trusting the constant: the budget above is derived from
|
|
it, and a call added without updating it puts the wrapper back under the
|
|
work."""
|
|
import inspect as _inspect
|
|
|
|
src = _inspect.getsource(sr._inspect_celery_sync)
|
|
calls = src.count("insp.")
|
|
assert calls == sr.INSPECT_ROUND_TRIPS, (
|
|
f"_inspect_celery_sync makes {calls} inspect calls but "
|
|
f"INSPECT_ROUND_TRIPS says {sr.INSPECT_ROUND_TRIPS}"
|
|
)
|