Operator's controller logs are repeated when they shouldn't be. Possible duplicate function calls.

Question

Operator's controller logs are repeated when they shouldn't be. Possible duplicate function calls.

Closed this issue 3 years ago · 7 comments

The operator's logs are repeated twice when launching NFD -- meaning, some commands are actually called twice -- but sometimes the repetitions occur even three, four, or more times. This issue could have existed before my PR #183, or it could have been introduced with my PR #183. Either way, the repetition problem does need to be fixed because it likely will have an impact on NFD functionality in the future.

Sample:

2021-08-05T15:05:48.251Z	INFO	controllers.NodeFeatureDiscovery	Fetch the NodeFeatureDiscovery instance
2021-08-05T15:05:48.251Z	INFO	controllers.NodeFeatureDiscovery	Ready to apply components
2021-08-05T15:05:48.251Z	INFO	controller_nodefeaturediscovery	Looking for	{"ServiceAccount": "nfd-master", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.251Z	INFO	controller_nodefeaturediscovery	Found, skipping update	{"ServiceAccount": "nfd-master", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.251Z	INFO	controller_nodefeaturediscovery	Looking for	{"ClusterRole": "nfd-master", "Namespace": ""}
2021-08-05T15:05:48.251Z	INFO	controller_nodefeaturediscovery	Found, updating	{"ClusterRole": "nfd-master", "Namespace": ""}
2021-08-05T15:05:48.343Z	INFO	controller_nodefeaturediscovery	Looking for	{"ClusterRoleBinding": "nfd-master", "Namespace": ""}
2021-08-05T15:05:48.343Z	INFO	controller_nodefeaturediscovery	Found, updating	{"ClusterRoleBinding": "nfd-master", "Namespace": ""}
2021-08-05T15:05:48.434Z	INFO	controller_nodefeaturediscovery	Looking for	{"DaemonSet": "nfd-master", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.434Z	INFO	controller_nodefeaturediscovery	Found, updating	{"DaemonSet": "nfd-master", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.458Z	INFO	controller_nodefeaturediscovery	Looking for	{"Service": "nfd-master", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.458Z	INFO	controller_nodefeaturediscovery	Found, updating	{"Service": "nfd-master", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.470Z	INFO	controller_nodefeaturediscovery	Looking for	{"ServiceAccount": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.470Z	INFO	controller_nodefeaturediscovery	Found, skipping update	{"ServiceAccount": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.470Z	INFO	controller_nodefeaturediscovery	Looking for	{"Role": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.470Z	INFO	controller_nodefeaturediscovery	Found, updating	{"Role": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.479Z	INFO	controller_nodefeaturediscovery	Looking for	{"RoleBinding": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.479Z	INFO	controller_nodefeaturediscovery	Found, updating	{"RoleBinding": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.486Z	INFO	controller_nodefeaturediscovery	Looking for	{"ConfigMap": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.486Z	INFO	controller_nodefeaturediscovery	Found, updating	{"ConfigMap": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.493Z	INFO	controller_nodefeaturediscovery	Looking for	{"DaemonSet": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.493Z	INFO	controller_nodefeaturediscovery	Found, updating	{"DaemonSet": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.506Z	INFO	controller_nodefeaturediscovery	Looking for	{"SecurityContextConstraints": "nfd-worker", "Namespace": "default"}
2021-08-05T15:05:48.506Z	INFO	controller_nodefeaturediscovery	Found, updating	{"SecurityContextConstraints": "nfd-worker", "Namespace": "default"}
2021-08-05T15:05:48.516Z	INFO	controllers.NodeFeatureDiscovery	Fetch the NodeFeatureDiscovery instance
2021-08-05T15:05:48.516Z	INFO	controllers.NodeFeatureDiscovery	Ready to apply components
2021-08-05T15:05:48.516Z	INFO	controller_nodefeaturediscovery	Looking for	{"ServiceAccount": "nfd-master", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.516Z	INFO	controller_nodefeaturediscovery	Found, skipping update	{"ServiceAccount": "nfd-master", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.516Z	INFO	controller_nodefeaturediscovery	Looking for	{"ClusterRole": "nfd-master", "Namespace": ""}
2021-08-05T15:05:48.516Z	INFO	controller_nodefeaturediscovery	Found, updating	{"ClusterRole": "nfd-master", "Namespace": ""}
2021-08-05T15:05:48.587Z	INFO	controller_nodefeaturediscovery	Looking for	{"ClusterRoleBinding": "nfd-master", "Namespace": ""}
2021-08-05T15:05:48.587Z	INFO	controller_nodefeaturediscovery	Found, updating	{"ClusterRoleBinding": "nfd-master", "Namespace": ""}
2021-08-05T15:05:48.659Z	INFO	controller_nodefeaturediscovery	Looking for	{"DaemonSet": "nfd-master", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.659Z	INFO	controller_nodefeaturediscovery	Found, updating	{"DaemonSet": "nfd-master", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.666Z	INFO	controller_nodefeaturediscovery	Looking for	{"Service": "nfd-master", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.666Z	INFO	controller_nodefeaturediscovery	Found, updating	{"Service": "nfd-master", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.679Z	INFO	controller_nodefeaturediscovery	Looking for	{"ServiceAccount": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.679Z	INFO	controller_nodefeaturediscovery	Found, skipping update	{"ServiceAccount": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.679Z	INFO	controller_nodefeaturediscovery	Looking for	{"Role": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.679Z	INFO	controller_nodefeaturediscovery	Found, updating	{"Role": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.687Z	INFO	controller_nodefeaturediscovery	Looking for	{"RoleBinding": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.687Z	INFO	controller_nodefeaturediscovery	Found, updating	{"RoleBinding": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.693Z	INFO	controller_nodefeaturediscovery	Looking for	{"ConfigMap": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.693Z	INFO	controller_nodefeaturediscovery	Found, updating	{"ConfigMap": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.700Z	INFO	controller_nodefeaturediscovery	Looking for	{"DaemonSet": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.700Z	INFO	controller_nodefeaturediscovery	Found, updating	{"DaemonSet": "nfd-worker", "Namespace": "openshift-nfd"}
2021-08-05T15:05:48.710Z	INFO	controller_nodefeaturediscovery	Looking for	{"SecurityContextConstraints": "nfd-worker", "Namespace": "default"}
2021-08-05T15:05:48.710Z	INFO	controller_nodefeaturediscovery	Found, updating	{"SecurityContextConstraints": "nfd-worker", "Namespace": "default"}

Answer 1 · 2021-08-05T16:32:38.000Z

/assign @courtneypacheco

Answer 2 · 2021-08-06T14:53:52.000Z

There is an additional error that occurs many hours after the initial error message occurs, and this error message may or may not be related:

E0806 06:29:33.557593       1 reflector.go:138] sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:225: Failed to watch *v1.ServiceAccount: the server has received too many requests and has asked us to try again later (get serviceaccounts)
E0806 06:29:33.602845       1 reflector.go:138] sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:225: Failed to watch *v1.NodeFeatureDiscovery: the server has received too many requests and has asked us to try again later (get nodefeaturediscoveries.nfd.openshift.io)
E0806 06:29:33.602845       1 reflector.go:138] sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:225: Failed to watch *v1.RoleBinding: the server has received too many requests and has asked us to try again later (get rolebindings.rbac.authorization.k8s.io)
E0806 06:29:34.911612       1 reflector.go:138] sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:225: Failed to watch *v1.ServiceAccount: the server has received too many requests and has asked us to try again later (get serviceaccounts)
E0806 06:29:34.911683       1 reflector.go:138] sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:225: Failed to watch *v1.RoleBinding: the server has received too many requests and has asked us to try again later (get rolebindings.rbac.authorization.k8s.io)
E0806 06:29:37.340204       1 reflector.go:138] sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:225: Failed to watch *v1.ServiceAccount: the server has received too many requests and has asked us to try again later (get serviceaccounts)
E0806 06:29:37.489996       1 reflector.go:138] sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:225: Failed to watch *v1.RoleBinding: the server has received too many requests and has asked us to try again later (get rolebindings.rbac.authorization.k8s.io)
E0806 06:29:40.803230       1 reflector.go:138] sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:225: Failed to watch *v1.RoleBinding: the server has received too many requests and has asked us to try again later (get rolebindings.rbac.authorization.k8s.io)
E0806 06:29:41.090993       1 reflector.go:138] sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:225: Failed to watch *v1.ServiceAccount: the server has received too many requests and has asked us to try again later (get serviceaccounts)
E0806 12:25:08.318737       1 reflector.go:138] sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:225: Failed to watch *v1.NodeFeatureDiscovery: the server has received too many requests and has asked us to try again later (get nodefeaturediscoveries.nfd.openshift.io)

Answer 3 · 2021-08-06T15:41:52.000Z

Potential fix with PR #193

Answer 4 · 2021-11-04T21:29:22.000Z

Issues go stale after 90d of inactivity.

Mark the issue as fresh by commenting /remove-lifecycle stale.
Stale issues rot after an additional 30d of inactivity and eventually close.
Exclude this issue from closing by commenting /lifecycle frozen.

If this issue is safe to close now please do so with /close.

/lifecycle stale

Answer 5 · 2021-12-04T22:01:25.000Z

Stale issues rot after 30d of inactivity.

Mark the issue as fresh by commenting /remove-lifecycle rotten.
Rotten issues close after an additional 30d of inactivity.
Exclude this issue from closing by commenting /lifecycle frozen.

If this issue is safe to close now please do so with /close.

/lifecycle rotten
/remove-lifecycle stale

Answer 6 · 2022-01-03T22:21:36.000Z

Rotten issues close after 30d of inactivity.

Reopen the issue by commenting /reopen.
Mark the issue as fresh by commenting /remove-lifecycle rotten.
Exclude this issue from closing again by commenting /lifecycle frozen.

/close

Answer 7 · 2022-01-03T22:22:06.000Z

@openshift-bot: Closing this issue.

In response to this:

Rotten issues close after 30d of inactivity.

Reopen the issue by commenting /reopen.
Mark the issue as fresh by commenting /remove-lifecycle rotten.
Exclude this issue from closing again by commenting /lifecycle frozen.

/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.