Skip to content

fix: escalate watcher-task failures from the orchestrator loop - #1313

Merged
nolar merged 2 commits into
nolar:mainfrom
mvanhorn:fix/1145-orchestrator-watcher-failure-escalation
Oct 4, 2026
Merged

nolar merged 2 commits into
nolar:mainfrom
mvanhorn:fix/1145-orchestrator-watcher-failure-escalation

Conversation

@mvanhorn

Copy link
Copy Markdown
Contributor

Summary

When a kopf operator runs with namespace-restricted RBAC, the cluster-scoped resource-observer / namespace-observer core tasks are skipped and, for custom resources, the event-poster safety net does not apply either. In that configuration a watcher task in the orchestrator's Ensemble can die and nothing escalates the failure - the operator keeps running while no resources are watched.

This makes ochestrator() in kopf/_core/reactor/orchestration.py observe the ensemble tasks' exit status. Each loop iteration now waits on the insights-revision condition AND the current ensemble tasks with asyncio.wait(..., return_when=FIRST_COMPLETED); for any completed ensemble task, its exception is retrieved and re-raised so the failure propagates through the operator's root task and the process exits with crash-and-restart semantics instead of running dead.

Why this matters

The reporter traced the hang to the orchestrator loop only awaiting insights.revised.wait() and never observing the ensemble tasks. Maintainer @nolar confirmed the analysis, noted it reproduces roughly 50/50 even with non-HTTP errors (not just LoginError), and flagged that the reporter's inline sketch leaked abandoned wait tasks. This change addresses that concern directly: the insights-wait is wrapped in a single task that is explicitly cancelled and awaited whenever left pending, and ensemble tasks are re-collected each iteration via ensemble.get_tasks(...) rather than re-wrapped, so no orphaned tasks accumulate across iterations.

Testing

Added coverage for the orchestrator loop: a watcher task raising a non-HTTP exception now propagates out of ochestrator() (previously the loop swallowed it and continued), and the happy path - insights revised with all ensemble tasks healthy - still loops without leaking the insights-wait task.

Fixes #1145

…ator does not run silently dead

Fixes nolar#1145

Signed-off-by: Matt Van Horn <455140+mvanhorn@users.noreply.github.com>
@mvanhorn
mvanhorn force-pushed the fix/1145-orchestrator-watcher-failure-escalation branch from a65085f to f35d1e6 Compare July 10, 2026 18:42
@nolar

nolar commented Oct 2, 2026 •

Copy link
Copy Markdown
Owner

Notes for self: using a shorter but hackier repro from #1145 (comment) — adding this line to watcher():

            if resource.plural == 'kopfexamples':
                if raw_event['object']['spec']['field'] == 'boo':
                    raise Exception("boo!")

Then create an object and patch from the command line:

kubectl apply -f examples/obj.yaml
kubectl patch kex kopf-example-1 --type merge -p '{"spec":{"field": "boo"}}'

Without the PR, the operator shows an error and gets stuck.

With this PR applied, the error escalates and stops the whole operator via the graceful shutdown. Which is perhaps a better way of signalling the unexpected errors than retrying them. The log (a little bit redacted for less noise):

[2026-10-02 15:24:27,844] kopf._core.reactor.o [ERROR   ] Watcher for kopfexamples.v1.kopf.dev@default has failed: boo!
Traceback (most recent call last):
  File "/Users/nolar/src/kopf/kopf/_cogs/aiokits/aiotasks.py", line 96, in guard
  File "/Users/nolar/src/kopf/kopf/_core/reactor/queueing.py", line 202, in watcher
    raise Exception("boo!")
Exception: boo!

[2026-10-02 15:24:27,861] kopf._core.reactor.r [ERROR   ] Multidimensional multitasker has failed: boo!
Traceback (most recent call last):
  File "/Users/nolar/src/kopf/kopf/_cogs/aiokits/aiotasks.py", line 96, in guard
  File "/Users/nolar/src/kopf/kopf/_core/reactor/orchestration.py", line 148, in orchestrator
  File "/Users/nolar/src/kopf/kopf/_cogs/aiokits/aiotasks.py", line 226, in reraise
  File "/Users/nolar/src/kopf/kopf/_cogs/aiokits/aiotasks.py", line 96, in guard
  File "/Users/nolar/src/kopf/kopf/_core/reactor/queueing.py", line 202, in watcher
    raise Exception("boo!")
Exception: boo!

………
……… (here come a lot of graceful shutdown messages)
………

[2026-10-02 15:24:32,869] kopf._cogs.clients.w [DEBUG   ] Stopping the watch-stream for kopfexamples.v1.kopf.dev in 'default'.
Traceback (most recent call last):
………
  File "/Users/nolar/src/kopf/kopf/_core/reactor/queueing.py", line 202, in watcher
    raise Exception("boo!")
Exception: boo!

Process finished with exit code 1

@nolar
nolar force-pushed the fix/1145-orchestrator-watcher-failure-escalation branch 3 times, most recently from ccc49af to c859e06 Compare October 2, 2026 18:16
@nolar

nolar commented Oct 2, 2026

Copy link
Copy Markdown
Owner

Hm. I will probably put this PR on a little longer pause — until I figure out what is wrong with tests. Otherwise, the solution looks good and solves the issue with the repro.

test_threadsafe_indeed_works fails specifically in the "Python 3.12 full-auth" CI job. It passes in all other setups, including Python 3.12 without the full-auth and in all other full-auth with different versions of Pythons. It fails on the sync primitive taking 0.3–0.4 seconds despite the test has special marks only at 0.2 and 0.5 seconds. And it is 100% reproducible in CI — no way to re-run to pass.

That failing test has absolutely nothing to do with this PR — neither with its main code, nor with its new tests — but disabling the tests here fixes the issue. So far, this makes no sense — I need some time to experiment with it. Probably, as usual, some leftovers (asyncio tasks?) from these new tests leak into the following tests and pop up some time later at the next real-clock test (my only hypothesis now). These cases are difficult to debug.

@nolar
nolar force-pushed the fix/1145-orchestrator-watcher-failure-escalation branch from c859e06 to f35d1e6 Compare October 4, 2026 15:03
Due to new three tests, another completely unrelated test (`test_threadsafe_indeed_works()`) started to fail unusually: only in Python 3.12 full-auth; works fine in other 3.12 modes and other full-auth versions — but 100% reproducible in CI and in CI only (not locally).

Experiments have shown that the issue happens only when all three tests are active (1+2+3), while the test run passes with only one or two tests (1+2, 2+3, 1+3). Time measurements indicated that the extra time (≈0.13s) was spent on operations so routine that they were not even suspected: exiting a function or adding an item to a list, not in the actual thread starting or something resource-intense. Besides, simple time measurements themselves caused the tests to pass sometimes.

The only suspicion was that something was happening under the hood at these moments, and the garbage collection was the number one candidate (in the absence of any parallel/concurrent activities). Probably, the amount of garbage accumulated from all tests was anyway huge, and adding three more tests pushed it beyond the threshold, which accidentally caused the garbage collection in these particular real-clock tests (previously, probably happened in other tests that did not notice anything). Just a sequence of accidents.

Either way, enforcing the garbage collection before the test and disabling the garbage collection during the real-clock tests fixed the issue. Pure luck.

Signed-off-by: Sergey Vasilyev <nolar@nolar.info>
@nolar
nolar force-pushed the fix/1145-orchestrator-watcher-failure-escalation branch from 879ea8d to c1e1462 Compare October 4, 2026 17:05
@nolar

nolar commented Oct 4, 2026

Copy link
Copy Markdown
Owner

As experimented in #1331, this seems to be the garbage collection being accidentally triggered in the real-clock tests under the time-measuring section, and these three tests probably added enough garbage to trigger the collection or to shift it from some earlier/later moment in the test run precisely into this section. Pure luck.

Fixed by disabling the garbage collection during the real-clock tests (unrelated to this PR), commit c1e1462

@nolar
nolar merged commit dc10b8a into nolar:main Oct 4, 2026
@mvanhorn

mvanhorn commented Oct 5, 2026

Copy link
Copy Markdown
Contributor Author

Thanks @nolar for working through the repro and merging the watcher-task escalation, and for chasing down that flaky test on the side.

@nolar

nolar commented Oct 5, 2026

Copy link
Copy Markdown
Owner

@mvanhorn You are welcome! And thanks for the PR!

I plan to release it as soon as Python 3.15 is out — it was delayed by a week, 2026-10-09 is the new date, as I heard. Otherwise, there are no new features planned between the current state of the main branch and the release — so you can already try it as a preview.

@nolar

nolar commented Oct 14, 2026

Copy link
Copy Markdown
Owner

@mvanhorn Thank you for the contribution. Released as 1.45.0

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.

Custom resource watchers die but operator does not in environments with restricted Kubernetes API access

2 participants