[BUG] hub-agent making noop /status updates on every reconciliation

[ahmetb]

Describe the bug

I'm observing that every time hub-agent restarts, it makes a ton of updates to clusterrresourceplacement/status for no reason. Given the default worker count is configured to be 1, this starves the new items on the work queue on large clusters with lots of work to do for 10-20 minutes.

Similarly the resync period on the hub-agent is configured to be 5 minutes by default (way too aggressive IMO) and it exacerbates the frequency of the problem:

fleet/cmd/hubagent/options/options.go

Lines 66 to 67 in 6b81bdb

	// ResyncPeriod is the base frequency the informers are resynced. Defaults is 5 minutes.
	ResyncPeriod metav1.Duration

Environment

Please provide the following:

• Hub cluster details: hub-agent v0.8.5
• Member cluster details: member-agent v0.8.5

To Reproduce

Steps to reproduce the behavior:

• Restart controller (trigger a rolling update)

• Tail logs from the leader

• Observe it prints log statements to re-reconcile everything

  1030 17:55:03.104691       1 framework/framework.go:1310] "No change in scheduling decisions and condition, and the observed CRP generation remains the same" clusterSchedulingPolicySnapshot="lep-...
  1030 17:55:03.522789       1 framework/framework.go:1310] "No change in scheduling decisions and condition, and the observed CRP generation remains the same" clusterSchedulingPolicySnapshot="depo...
  1030 17:55:03.930300       1 framework/framework.go:1310] "No change in scheduling decisions and condition, and the observed CRP generation remains the same" clusterSchedulingPolicySnapshot="tran...
  1030 17:55:04.400769       1 framework/framework.go:1310] "No change in scheduling decisions and condition, and the observed CRP generation remains the same" clusterSchedulingPolicySnapshot="job-...
  1030 17:55:04.812419       1 framework/framework.go:1310] "No change in scheduling decisions and condition, and the observed CRP generation remains the same" clusterSchedulingPolicySnapshot="deci...
  1030 17:55:05.282259       1 framework/framework.go:1310] "No change in scheduling decisions and condition, and the observed CRP generation remains the same" clusterSchedulingPolicySnapshot="auto...
  1030 17:55:05.690881       1 framework/framework.go:1310] "No change in scheduling decisions and condition, and the observed CRP generation remains the same" clusterSchedulingPolicySnapshot="samp...
  1030 17:55:06.145613       1 framework/framework.go:1310] "No change in scheduling decisions and condition, and the observed CRP generation remains the same" clusterSchedulingPolicySnapshot="anti...
  

• Look at API Server audit logs, observe that it's making updates to clusterrresourceplacement/status for every clusterSchedulingPolicySnapshot object despite there should be no changes to the object (timestamps are matching):

  

• I'm not seeing any updated timestamps etc in clusterresourceplacement/status to warrant this /status update:

  status:
    conditions:
    - lastTransitionTime: "2024-09-19T00:06:37Z" # this is not today
      message: found all the clusters needed as specified by the scheduling policy
      observedGeneration: 1
      reason: SchedulingPolicyFulfilled
      status: "True"
      type: Scheduled
    observedCRPGeneration: 1
    targetClusters:
    - clusterName: redacted
      reason: picked by scheduling policy
      selected: true
  

In this part of the code we can clearly see the status update call is made unconditionally:

fleet/pkg/controllers/clusterresourceplacement/controller.go

Lines 193 to 201 in cb9a7a0

	isClusterScheduled, err := r.setPlacementStatus(ctx, crp, selectedResourceIDs, latestSchedulingPolicySnapshot, latestResourceSnapshot)
	if err != nil {
	return ctrl.Result{}, err
	}
	if err := r.Client.Status().Update(ctx, crp); err != nil {
	klog.ErrorS(err, "Failed to update the status", "clusterResourcePlacement", crpKObj)
	return ctrl.Result{}, err
	}

Expected behavior

The controller should do apiequality.Semantic.DeepEqual(old.status,new.status), and skip updating the status on the API when there's no reason to make this API call.

This would ensure the full resyncs and controller startup can happen very fast, and reduce the load on the API Server.

Screenshots

Attached above

Additional context

N/A

[ryanzhang-oss]

Thank you very much, we will triage this bug.

[ahmetb]

@ryanzhang-oss This is probably like a 5-line fix and it's still ravaging our apiservers. Please let me know if you're interested in a patch and I can send it.

[ryanzhang-oss]

@ahmetb, Thank you for the issue. We looked into this issue and we are not entirely sure if the status compare is safe enough to skip the update as the status is from the cache. What if the status in the etcd is different? How can we recover from that (especially if the resync period is longer)? However, we could definitely make the resync period a configurable parameter (and with a default of more like 1 hour than 5 mins).
With that said, we would love to take a look at your fix.

[ahmetb]

We looked into this issue and we are not entirely sure if the status compare is safe enough to skip the update as the status is from the cache

By this logic any controller in Kubernetes would be constantly updating all object statuses all the time when the controller boots or resyncs. Unfortunately that's not correct. :)

Controllers work on a stale view of the world, that's by design, and it includes the status.

Once the controller's cache notices an update, you'll get another reconciliation request enqueued, and if the reconciler notices a drift (that's why you should do an equals check), you'll make a status update. This is how controller-runtime or the controller machinery broadly works.

So what I proposed is safe. Please refer to other controllers in the community, like the cluster-api.

Edit: Sent #1079 as a proof of concept.

[ryanzhang-oss]

I have replied on the PR. I think we need to think a bit more on the solution. I wonder if you have examples on some well known controller does the status compare logic in memory? The idea of comparing to cache before writing through does not seem to be a sound practice in general unless there are some other mechanism to guarantee cache consistency.

In our case, the CRP status is the most important part of the system for users to know what happened so we cannot risk it being stuck in a stale state. i.e. the real value in etcd is A while it is B in cache and we compute the status as B so we skip the update. User will see A for a long time until we retry as we don't watch the status of the CRP (as a general rule to cut down the extra unnecessary reconcile when we update the status)

[ahmetb]

I recommend referring to core controllers https://github.com/kubernetes/kubernetes/blob/master/pkg/controller/replicaset/replica_set_utils.go#L40 or cluster-api repo. If this indeed were the case we'd be seeing non-stop status updates from everything in Kubernetes ecosystem. :)

Anything you read is already stale basically and once you observe the desired status reflected in the cached view you have, what would you be hoping to fix by making an update?

Do you expect someone else to update the status? It'd make sense to hit the apiserver if you made a permanent decision, like a placement, that you don't wanna lose.

Otherwise I'm not certain what we get by status update every time. It'll only make the controller less scalable and apiserver more burdened.

I wrote a whole article about why offline reconciliation is critical https://ahmet.im/blog/controller-pitfalls/#fast-and-offline-reconciliation if you're interested.