fix(worker): log the reconnect after a stable connection drops at INFO - #6771
Open
bharadwaj-pendyala wants to merge 1 commit into
Open
fix(worker): log the reconnect after a stable connection drops at INFO#6771bharadwaj-pendyala wants to merge 1 commit into
bharadwaj-pendyala wants to merge 1 commit into
Conversation
Worker._connection_task resets retry_count to 0 right after a successful ws_connect, so the first retry following any control-plane websocket drop computes a 0s delay and logs at WARNING. Long-running deployments see a steady trickle of these self-healing warnings, which trips warning-level alerting with nothing actionable behind it. Demote that log to INFO, but only when the connection had been up for STABLE_CONNECTION_INTERVAL and the failure was the connection itself going away. A worker that never connected, one dropping faster than that interval, a retry that had to back off, and any fault that is not a lost connection all keep warning.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Closes #6108.
Problem
Worker._connection_taskresetsretry_countto0atworker.py:1118, immediately after a successfulws_connect. Every failure after that computesretry_delay = min(0 * 2, 10), so the first retry following any control-plane websocket drop logs:and then reconnects successfully. The reporter sees these a few times a day across worker replicas, every one self-healing. They trip warning-level alerting with nothing behind them, so operators learn to filter the whole message, which then hides the backoff events that do matter.
Solution
Log that retry at INFO instead, under two conditions:
STABLE_CONNECTION_INTERVAL(30s) before it dropped, andAPIStatusErrorfrom the unexpected-close path in_run_ws,aiohttp.ClientError, orOSError.Everything else stays at WARNING: a worker that never connected, one dropping faster than the interval, any retry that had to back off, and any fault that is not a lost connection.
Both conditions are load-bearing. Demoting on
retry_delay == 0alone silences real outages, which I verified against this base commit before settling on the current shape:mainretry_delay == 0demotionNeither hot loop backs off or reaches
max_retry, becauseretry_countis reset by the accepted upgrade, so demoting them would have made a permanently broken worker silent.Scope
One behaviour change, in one function. I deliberately left the
retry_countreset at line 1118 alone: moving it is what would actually stop those two hot loops, but it changes backoff andmax_retrysemantics well beyond this issue, so it belongs in its own change with a maintainer's call on the semantics.STABLE_CONNECTION_INTERVALis a policy choice and I would rather you pick it than me. Any duration threshold moves the blind spot instead of removing it: a proxy that kills the connection every 31s still logs INFO forever. If you prefer a rate limit on the demotion, escalating when the quiet reconnect fires more than N times in a window, I will switch it. Raised the same question on the issue.Validation
Base commit
060f107, all commands run locally.uv run pytest tests/test_worker_connection.py --unit→ 7 passed. Six are new, one per row of the table above plus the backoff and non-transport-fault cases. Each was confirmed red before the fix and green after.uv run pytest tests/ --unit→ 1498 passed, 5 skipped. Baseline on a clean tree is 1492 passed, so the 6 new tests are the only difference.uv run pytest tests/test_worker_connection.py --unit --concurrent→ 7 passed. The module is markedno_concurrentbecause thevirtual_timeclock is process-global, matchingtest_connection_pool.pyand the other virtual-time modules.uv run ruff checkanduv run ruff format --checkon both changed files → clean.uv run python scripts/check_types.py→ 2 errors, both pre-existing missingcv2andlogurustubs inlivekit-plugins-bithuman. Identical on a clean tree; nothing in the changed files.The 3670 and 3450 figures come from driving
_connection_taskwith a stubbedws_connectfor 2 seconds and counting the retry records.Note
I opened this without waiting for a reply on the issue, since the failing behaviour is unambiguous and the change is small. The threshold question above is the one assumption I made on your behalf, and I am happy to rework it.
This change was written with AI assistance. Every claim above comes from a command I ran on the base commit.