🐛 ClusterResourceSet controller: fix reconciliation triggered by resource changes #4491

sbueringer · 2021-04-16T22:01:55Z

What this PR does / why we need it:
The ClusterResourceSet controller did not react to changes on
ConfigMaps and Secrets (except when OwnerReferences were already set).

The problem was that we use OnlyMetadata on the watches and we tried to
get the kind of ConfigMap/Secret from the TypeMeta of an PartialObjectMetadata.
The TypeMeta of a PartialObjectMetadata is empty so apiutil.GVKForObject(o,
r.Client.Scheme()) always returned an error and the reconciliation was
not triggered.

Which issue(s) this PR fixes (optional, in fixes #<issue number>(, fixes #<issue_number>, ...) format, will close the issue(s) when PR gets merged):
Fixes #4486

Additional context:

https://kubernetes.slack.com/archives/C8TSNPY4T/p1618606088075900
branch to reproduce the issue easily: [WIP] debug: TestAPI flaky test #4490
- explanations on how to do that are in the Slack thread

sbueringer · 2021-04-16T22:04:47Z

exp/addons/controllers/clusterresourceset_controller_test.go

 		Expect(testEnv.Create(ctx, newConfigmap)).To(Succeed())
 		defer func() {
 			Expect(testEnv.Delete(ctx, newConfigmap)).To(Succeed())
 		}()

-		cmKey := client.ObjectKey{


I'm not sure what the purpose of this Eventually Get was. It should just return instantly because the Create above is synchronous. Maybe it was a try to ensure that the ConfigMap exists in the local cache to fix some test flakiness?

Maybe it was a try to ensure that the ConfigMap exists in the local cache to fix some test flakiness?

This sounds about right 😅 All the controller runtime stuff uses cached clients normally so if testEnv is also caching, this would be it waiting until the informer has received the create event and updated the cache. Looking at the next Eventually, this basically allows us to know that the timeout is used solely for that reconcile.

Have you tried running this many times to see if you can get it to fail without this extra block?

Not yet, I'll try. Although the 10s timeout is easily enough. So it's highly likely that there won't be any difference.

I ran it locally in a loop a few hundred times successfully. But I think we don't need the Get. The Eventually below tries for 20 seconds and locally it takes < 1s. But I don't really care, if the consensus is that we should keep it, I'll just add it again.

Let's add it back, having a Get to make sure the cache syncs is the most idiomatic way to deal with caches and controllers lagging behind a bit

sbueringer · 2021-04-16T22:06:59Z

exp/addons/controllers/clusterresourceset_controller_test.go

+		// if the ConfigMap creation triggers a reconciliation. Otherwise a previous change
+		// of another resource triggers the reconciliation and we cannot verify if we react
+		// correctly to the ConfigMap creation
+		time.Sleep(5 * time.Second)


This has been added to ensure the test would consistently fail without the fix in the ClusterRersourceSet controller. If possible I would like to avoid adding a sleep. Are there any ways to detect the previous reconciliations are done? (I think the last one doesn't change anything anywhere, so I cannot really wait for something specific reconciliation)

Short of wrapping the reconciler to count reconciles (which I would recommend avoiding), I don't think there's really anything that can be done. You also need to account for other controllers and tests in the test suite that may also be creating events, so to get the queue to truly be empty will be very very difficult AFAIK.

If we wanted to be more certain that, we could potentially create a new test with a separate manager watching a different test namespace (I'm not sure this is actually possible here, this is more general advice), that would then be more isolated. In these scenarios it's easier to verify reaction to specific events occurring.

Out of interest, without this, were you seeing the test flaking at all?

not ideal but could think about something like adding an optional event recorder to the resourceToClusterResourceSet signature that we only pass through in tests that would record the exact resource and operation triggering the reconciliation

What about relying on Observed generation instead?

@JoelSpeed
The problem is that without the timeout the test was not reliably able to detect the broken code. So this means when I drop the timeout the test has a certain probability that it doesn't test the reconcile of the create ConfigMap but one of the previous one either Cluster or ClusterResourceSet creation. So this only makes the test "greener" but just because we're testing the wrong thing. So the test was flaky because it couldn't reliably detect the broken code, with the timeout it can. Usually tests are flaky because the bug in the code occur only under certain conditions, in this case the test code was only testing correctly under certain conditions (i.e. when all previous reconciles where already finished). In case the test code was working correctly the test did always fail.

@enxebre Would it be possible with this solution to detect which exact reconcile of which event lead to the condition we're checking in l.313? If it was already done by a previous reconcile and the "right" reconcile does a no-op, the test is already testing the wrong thing.

@fabriziopandini Do you mean instead of the sleep I should wait until the resources has a specific ObservedGeneration and only after that create the ConfigMap? I'm not entirely sure which reconcilation is currently the problem. I suspect there might be one which is actually a no-op (which then shouldn't change the ObservedGeneration?). I'm not sure if I can wait for that one when it usually does nothing :/.

I think the problem is that I don't have to only detect when the existing resources are steady. I also have to detect if there are some upcoming reconciliations, which are usually no-ops but could reconcile if they are triggered after the ConfigMap creation.

@fabriziopandini I added

fmt.Printf("reconcile: %v %v\n", req.NamespacedName, clusterResourceSet.ObjectMeta.Generation)

After:

cluster-api/exp/addons/controllers/clusterresourceset_controller.go

Lines 106 to 117 in 2ff65de

clusterResourceSet := &addonsv1.ClusterResourceSet{}

if err := r.Client.Get(ctx, req.NamespacedName, clusterResourceSet); err != nil {

if apierrors.IsNotFound(err) {

// Object not found, return. Created objects are automatically garbage collected.

// For additional cleanup logic use finalizers.

return ctrl.Result{}, nil

}

// Error reading the object - requeue the request.

return ctrl.Result{}, err

}

// Initialize the patch helper.

The output was:

reconcile: default/clusterresourceset-c5u43l 1 reconcile: default/clusterresourceset-c5u43l 1 reconcile: default/clusterresourceset-c5u43l 1 ... < create configmap > ... after each reconcile: default/clusterresourceset-c5u43l 2

So it looks like there are multiple reconciliations with the same observed generation. So I can't really wait until the last one by checking the generation

P.S. previous version of this comment showed a slightly different log, but that was because I tested it incorrectly and didn't realized that the cleanup lead to generation 2.

@sbueringer
Catching up after lagging a little bit on this...

I think we should avoid to add a sleep here, because ensuring that watches with partial metadata works as expected is not really something a behavioural test for ClusterResourceSet should be concerned of.

If we want to have test coverage ensuring that watches with partial metadata works well, I think we should have a dedicated test, might be under util/predicates so we can separate this issue from the CRS specific tests.
This will allow us to use a dedicated, super simple, test reconciler that e.g. increases an annotation value at every reconcile, so we can actually check when a reconcile happens.

Does this makes sense? This can be eventually addressed also in a separated PR...

sbueringer · 2021-04-16T22:11:24Z

/assign @vincepri

fabriziopandini

@sbueringer thanks for the huge work in investigating this issue.
Before green lighting the fix I would like to understand with @vincepri if there is chance/It should be better to fix this tricky error up in the stack (controller runtime or client-go)

sbueringer · 2021-04-19T15:21:59Z

@sbueringer thanks for the huge work in investigating this issue.
Before green lighting the fix I would like to understand with @vincepri if there is chance/It should be better to fix this tricky error up in the stack (controller runtime or client-go)

Yeah of course, no problem. My take is that we cannot fix it upstream, because the builder.OnlyMetadata watch behaves as intended. It was a misunderstanding that the PartialObjectMetadata contains the TypeMeta of our ConfigMap, as it has to contain the TypeMeta of the PartialObjectMetadata.

But of course there might be entirely different ways to fix this.

vincepri · 2021-04-19T17:07:18Z

/hold

I might have a solution for this in Controller Runtime, which is due to review kubernetes-sigs/controller-runtime#1484

sbueringer · 2021-04-19T17:43:46Z

/hold

I might have a solution for this in Controller Runtime, which is due to review kubernetes-sigs/controller-runtime#1484

Sounds reasonable, essentially looks like the same fix just one layer below. Didn't thought of that.

If that one is merged, I would drop the changes to the controller and only fix the test.

k8s-ci-robot · 2021-05-05T21:40:45Z

[APPROVALNOTIFIER] This PR is NOT APPROVED

This pull-request has been approved by:
To complete the pull request process, please ask for approval from vincepri after the PR has been reviewed.

The full list of commands accepted by this bot can be found here.

Needs approval from an approver in each of these files:

OWNERS

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

sbueringer · 2021-05-05T21:44:45Z

I rebased the PR and dropped the changes to the controller as the upgrade to the new controller-runtime version should fix the issue.

I think it still makes sense to improve the test so it actually tests correct (i.e. it tests the reconciliation triggered by the ConfigMap creation).

I'm not sure what we should do about: #4491 (comment)

I still don't have a better solution than adding the sleep.

sbueringer · 2021-05-11T19:51:55Z

@vincepri @fabriziopandini any ideas how/ if we should continue here?

changes The ClusterResourceSet controller did not react to changes on ConfigMaps and Secrets (except when OwnerReferences were already set). The problem was that we use OnlyMetadata on the watches and we tried to get the kind of ConfigMap/Secret from the TypeMeta of an PartialObjectMetadata. The TypeMeta of a PartialObjectMetadata is empty so apiutil.GVKForObject(o, r.Client.Scheme()) always returned an error and the reconciliation was not triggered.

sbueringer · 2021-05-14T18:01:15Z

(Had to rebase because of the test refactoring, but essentially same situation as before)

k8s-ci-robot · 2021-05-29T04:48:42Z

@sbueringer: PR needs rebase.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

vincepri · 2021-06-03T19:37:19Z

Should we close this?

sedefsavas · 2021-06-04T04:59:08Z

Created a new PR that solves this issue: #4723

vincepri · 2021-06-04T14:48:01Z

/close

k8s-ci-robot · 2021-06-04T14:48:06Z

@vincepri: Closed this PR.

In response to this:

/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

sbueringer · 2021-06-09T17:58:08Z

New PR looks good to me, thx for taking care of this.

k8s-ci-robot added the cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. label Apr 16, 2021

k8s-ci-robot requested review from JoelSpeed and vincepri April 16, 2021 22:02

k8s-ci-robot added the size/M Denotes a PR that changes 30-99 lines, ignoring generated files. label Apr 16, 2021

sbueringer force-pushed the pr-fix-clusterresourceset-controller branch from 43e2eb0 to 2ff65de Compare April 16, 2021 22:03

sbueringer commented Apr 16, 2021

View reviewed changes

sbueringer mentioned this pull request Apr 16, 2021

✨ Use docker API instead of exec'ing docker cmds #4413

Merged

k8s-ci-robot assigned vincepri Apr 16, 2021

sbueringer changed the title ~~🐛 ClusterResourceSet controller: fix reconciliation based on resource changes~~ 🐛 ClusterResourceSet controller: fix reconciliation triggered by resource changes Apr 16, 2021

fabriziopandini reviewed Apr 19, 2021

View reviewed changes

k8s-ci-robot added the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Apr 19, 2021

sbueringer force-pushed the pr-fix-clusterresourceset-controller branch from 2ff65de to 445a8f5 Compare May 5, 2021 21:40

k8s-ci-robot added size/S Denotes a PR that changes 10-29 lines, ignoring generated files. and removed size/M Denotes a PR that changes 30-99 lines, ignoring generated files. labels May 5, 2021

k8s-ci-robot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label May 14, 2021

sbueringer force-pushed the pr-fix-clusterresourceset-controller branch from 445a8f5 to 6dbf521 Compare May 14, 2021 18:00

k8s-ci-robot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label May 14, 2021

sbueringer mentioned this pull request May 14, 2021

Periodic tests are failing: exp/addons/controllers.TestAPIs #4486

Closed

k8s-ci-robot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label May 29, 2021

k8s-ci-robot closed this Jun 4, 2021

sbueringer deleted the pr-fix-clusterresourceset-controller branch June 9, 2021 17:59

	clusterResourceSet := &addonsv1.ClusterResourceSet{}
	if err := r.Client.Get(ctx, req.NamespacedName, clusterResourceSet); err != nil {
	if apierrors.IsNotFound(err) {
	// Object not found, return. Created objects are automatically garbage collected.
	// For additional cleanup logic use finalizers.
	return ctrl.Result{}, nil
	}
	// Error reading the object - requeue the request.
	return ctrl.Result{}, err
	}

	// Initialize the patch helper.

🐛 ClusterResourceSet controller: fix reconciliation triggered by resource changes #4491

🐛 ClusterResourceSet controller: fix reconciliation triggered by resource changes #4491

Uh oh!

Conversation

sbueringer commented Apr 16, 2021

Uh oh!

sbueringer Apr 16, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

JoelSpeed Apr 19, 2021

Choose a reason for hiding this comment

Uh oh!

sbueringer Apr 19, 2021

Choose a reason for hiding this comment

Uh oh!

sbueringer Apr 19, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

vincepri May 24, 2021

Choose a reason for hiding this comment

Uh oh!

sbueringer Apr 16, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

JoelSpeed Apr 19, 2021

Choose a reason for hiding this comment

Uh oh!

enxebre Apr 19, 2021

Choose a reason for hiding this comment

Uh oh!

fabriziopandini Apr 19, 2021

Choose a reason for hiding this comment

Uh oh!

sbueringer Apr 19, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

sbueringer Apr 19, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

fabriziopandini May 18, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

sbueringer commented Apr 16, 2021

Uh oh!

fabriziopandini left a comment

Choose a reason for hiding this comment

Uh oh!

sbueringer commented Apr 19, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

vincepri commented Apr 19, 2021

Uh oh!

sbueringer commented Apr 19, 2021

Uh oh!

k8s-ci-robot commented May 5, 2021

Uh oh!

sbueringer commented May 5, 2021

Uh oh!

sbueringer commented May 11, 2021

Uh oh!

sbueringer commented May 14, 2021

Uh oh!

k8s-ci-robot commented May 29, 2021

Uh oh!

vincepri commented Jun 3, 2021

Uh oh!

sedefsavas commented Jun 4, 2021

Uh oh!

vincepri commented Jun 4, 2021

Uh oh!

k8s-ci-robot commented Jun 4, 2021

Uh oh!

sbueringer commented Jun 9, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

sbueringer Apr 16, 2021 •

edited

Loading

sbueringer Apr 19, 2021 •

edited

Loading

sbueringer Apr 16, 2021 •

edited

Loading

sbueringer Apr 19, 2021 •

edited

Loading

sbueringer Apr 19, 2021 •

edited

Loading

fabriziopandini May 18, 2021 •

edited

Loading

sbueringer commented Apr 19, 2021 •

edited

Loading

sbueringer commented Jun 9, 2021 •

edited

Loading