Describe the bug
There's a race between ManifestWorkAgentClient.Patch and the agent watcher store's HandleReceivedResource. When a delete event arrives while a status patch is in flight, the patch's final watcherStore.Update can write back a pre-delete copy of the work, erasing the DeletionTimestamp that HandleReceivedResource just set. The work controller's next requeue then finds a work with finalizers and no deletion timestamp, so it recreates the ManifestWork and AppliedManifestWork on the spoke, and from there it reapplies every 4 to 6 minutes indefinitely. We observed a zombie work being reapplied for 16+ hours until a spec resync happened to correct the store.
This looks like the root cause of the behaviour reported in open-cluster-management-io/ocm#1404.
The race window
Patch in pkg/cloudevents/clients/work/agent/client/manifestwork.go does roughly:
Get (~line 188) reads the work at local RV N
Publish (~line 230) status event, network round trip
Get (~line 240) second read
versionCompare (~line 250) patched RV vs store RV
watcherStore.Update (~line 253) full object replacement in the cache
HandleReceivedResource is subscribed directly on the store (options/generic.go), so it doesn't share the client mutex that Patch holds. The double versionCompare actually catches most interleavings, because the agent work store bumps a local per-name resource version on every write. If the delete write lands before the second Get, the compare sees RV N+1 against patched RV N and returns a conflict, which is fine. The losing window is between the second Get and the Update:
Patch does its second Get, reads RV N, no deletion timestamp
versionCompare passes, N == N, only newRV < lastRV is rejected
HandleReceivedResource writes the deleting work at RV N+1
Patch calls watcherStore.Update(newWork), the cache does a full object replacement, and the deletion timestamp is gone at RV N+2
The comment above the second Get already acknowledges the lack of read-modify-write guarantees in the store, this is a concrete reproduction of it biting.
The downstream effect is what makes it nasty. The finalize controller has usually already cleaned the spoke resources by this point using its own DeepCopy, so the spoke looks clean at first. But the finalizer removal never happens, ManifestWorkFinalizeController re-syncs, sees no deletion timestamp, and returns early. The work is now stuck as finalizer present plus no deletion timestamp, which passes the gate in the manifestwork controller sync, and applyAppliedManifestWork recreates everything on the next requeue.
Observed timeline
From a Maestro (openshift-online/maestro) agent using the gRPC driver, single work, one incident:
08:12:03.864 create_request received, spoke work applied
08:12:04 four status update_requests published in quick succession
08:12:06.886 delete_request received, deletiontimestamp=08:12:06.726528Z
08:12:07.090 spoke ManifestWork deleted ("is terminating"), so the store held the deletion timestamp at this point
08:12:14.662 status update_request published whose metadata has no deletionTimestamp, the store copy has lost it
08:17:33 requeue fires, spoke ManifestWork recreated with a new UID, plus a new AppliedManifestWork
- every 4 to 6 minutes after that, requeue and reapply, for roughly 16.5 hours
00:44:38 next day, a spec resync_response carrying the deletiontimestamp extension corrects the store and the work finally deletes
Happy to attach the full agent log.
To Reproduce
Delete a work within a few seconds of creating it, while status updates are still being published. The window itself is tiny but there are typically several status patches in flight right after create, we hit it 4 times in a week of e2e CI runs.
Expected behaviour
Once the delete event is processed, the store never again holds the work without a deletion timestamp, and the work converges to deleted.
A second, related bug
AgentInformerWatcherStore.Delete removes the versioner entry, so a deleted-then-recreated work restarts at RV 1. An in-flight stale Patch holding, say, RV 5 passes the newRV < lastRV check against RV 1 and can clobber a fresh work. Same root cause, the version check tolerates equality and versioner resets.
Proposed fix
We'd like to send a PR along these lines:
- Add a mutex to the generic
AgentInformerWatcherStore[T] guarding Add/Update/Delete and the whole HandleReceivedResource body.
- Add an optional capability interface, something like
UpdateWithVersion(resource, expectedResourceVersion), implemented by the work agent store as a single critical section: get, compare resource version for equality, bump the versioner, write the store. Equality instead of < closes both bugs above.
Patch type-asserts for the capability and uses it for the final write, keeping the current Get/compare/Update as the fallback for other store implementations, so ClientWatcherStore doesn't change.
The CloudEvents publish stays outside the lock, so the lock is only ever held for an in-memory map operation, no contention on the network path. On conflict the caller already retries and re-derives the patch from the fresh store state, so nothing is lost.
Environment ie: OCM version, Kubernetes version and provider:
open-cluster-management.io/sdk-go v1.2.1-0.20260323031834-e885ccee3f1b, and I've confirmed the relevant code is unchanged on current main
- Maestro server and agent over the gRPC driver, ARO HCP e2e environment
Describe the bug
There's a race between
ManifestWorkAgentClient.Patchand the agent watcher store'sHandleReceivedResource. When a delete event arrives while a status patch is in flight, the patch's finalwatcherStore.Updatecan write back a pre-delete copy of the work, erasing theDeletionTimestampthatHandleReceivedResourcejust set. The work controller's next requeue then finds a work with finalizers and no deletion timestamp, so it recreates the ManifestWork and AppliedManifestWork on the spoke, and from there it reapplies every 4 to 6 minutes indefinitely. We observed a zombie work being reapplied for 16+ hours until a spec resync happened to correct the store.This looks like the root cause of the behaviour reported in open-cluster-management-io/ocm#1404.
The race window
Patchinpkg/cloudevents/clients/work/agent/client/manifestwork.godoes roughly:HandleReceivedResourceis subscribed directly on the store (options/generic.go), so it doesn't share the client mutex thatPatchholds. The doubleversionCompareactually catches most interleavings, because the agent work store bumps a local per-name resource version on every write. If the delete write lands before the secondGet, the compare sees RV N+1 against patched RV N and returns a conflict, which is fine. The losing window is between the secondGetand theUpdate:Patchdoes its secondGet, reads RV N, no deletion timestampversionComparepasses, N == N, onlynewRV < lastRVis rejectedHandleReceivedResourcewrites the deleting work at RV N+1PatchcallswatcherStore.Update(newWork), the cache does a full object replacement, and the deletion timestamp is gone at RV N+2The comment above the second
Getalready acknowledges the lack of read-modify-write guarantees in the store, this is a concrete reproduction of it biting.The downstream effect is what makes it nasty. The finalize controller has usually already cleaned the spoke resources by this point using its own DeepCopy, so the spoke looks clean at first. But the finalizer removal never happens,
ManifestWorkFinalizeControllerre-syncs, sees no deletion timestamp, and returns early. The work is now stuck as finalizer present plus no deletion timestamp, which passes the gate in the manifestwork controller sync, andapplyAppliedManifestWorkrecreates everything on the next requeue.Observed timeline
From a Maestro (openshift-online/maestro) agent using the gRPC driver, single work, one incident:
08:12:03.864create_requestreceived, spoke work applied08:12:04four statusupdate_requests published in quick succession08:12:06.886delete_requestreceived,deletiontimestamp=08:12:06.726528Z08:12:07.090spoke ManifestWork deleted ("is terminating"), so the store held the deletion timestamp at this point08:12:14.662statusupdate_requestpublished whose metadata has nodeletionTimestamp, the store copy has lost it08:17:33requeue fires, spoke ManifestWork recreated with a new UID, plus a new AppliedManifestWork00:44:38next day, a specresync_responsecarrying thedeletiontimestampextension corrects the store and the work finally deletesHappy to attach the full agent log.
To Reproduce
Delete a work within a few seconds of creating it, while status updates are still being published. The window itself is tiny but there are typically several status patches in flight right after create, we hit it 4 times in a week of e2e CI runs.
Expected behaviour
Once the delete event is processed, the store never again holds the work without a deletion timestamp, and the work converges to deleted.
A second, related bug
AgentInformerWatcherStore.Deleteremoves the versioner entry, so a deleted-then-recreated work restarts at RV 1. An in-flight stalePatchholding, say, RV 5 passes thenewRV < lastRVcheck against RV 1 and can clobber a fresh work. Same root cause, the version check tolerates equality and versioner resets.Proposed fix
We'd like to send a PR along these lines:
AgentInformerWatcherStore[T]guardingAdd/Update/Deleteand the wholeHandleReceivedResourcebody.UpdateWithVersion(resource, expectedResourceVersion), implemented by the work agent store as a single critical section: get, compare resource version for equality, bump the versioner, write the store. Equality instead of<closes both bugs above.Patchtype-asserts for the capability and uses it for the final write, keeping the current Get/compare/Update as the fallback for other store implementations, soClientWatcherStoredoesn't change.The CloudEvents publish stays outside the lock, so the lock is only ever held for an in-memory map operation, no contention on the network path. On conflict the caller already retries and re-derives the patch from the fresh store state, so nothing is lost.
Environment ie: OCM version, Kubernetes version and provider:
open-cluster-management.io/sdk-gov1.2.1-0.20260323031834-e885ccee3f1b, and I've confirmed the relevant code is unchanged on currentmain