Deferred node password secret validation failed and complete.

[xhejtman]

It seem that for a few latest versions of rke2 in 1.30 branch, I can see this after server rke2-server restart:

Warning  NodePasswordValidationFailed    45s (x3 over 46s)  rke2-supervisor  Deferred node password secret validation failed: secrets "kub-r1.node-password.rke2" already exists
Normal   NodePasswordValidationComplete  40s                rke2-supervisor  Deferred node password secret validation complete

or sometimes in variant:

Warning  NodePasswordValidationFailed    21s                rke2-supervisor  Deferred node password secret validation failed: Internal error occurred: resource quota evaluation timed out
Warning  NodePasswordValidationFailed    19s                rke2-supervisor  Deferred node password secret validation failed: secrets "kub-h1.node-password.rke2" already exists
Normal   NodePasswordValidationComplete  16s                rke2-supervisor  Deferred node password secret validation complete

is it expected?

[brandond]

The failure messages are not expected. I don't know where the "resource quota" messages are coming from, nor why it would be trying to recreate the secret if it already exists.

[xhejtman]

Should I create an issue then?

[brandond]

If you can figure out what's causing it, sure. Its not something I've ever seen before. Do you have anything else deployed to the cluster that might be causing this?

[sirajkrm]

hey @xhejtman @brandond
I'm seeing the same messages after an incident that led all CP nodes to a sudden reboot.

I1029 16:34:51.044838    1734 event.go:307] "Event occurred" object="node-az-3" fieldPath="" kind="Node" apiVersion="" type="Warning" reason="NodePasswordValidationFailed" message="Deferred node password secret validation failed: secrets \"node-az-3.node-password.rke2\" already exists"
I1029 16:34:55.939401    1734 event.go:307] "Event occurred" object="node-az-3" fieldPath="" kind="Node" apiVersion="" type="Warning" reason="NodePasswordValidationFailed" message="Deferred node password secret validation failed: secrets \"node-az-3.node-password.rke2\" already exists"
I1029 16:34:58.546811    1734 trace.go:236] Trace[2104555766]: "Reflector ListAndWatch" name:k8s.io/[email protected]/tools/cache/reflector.go:231 (29-Oct-2024 16:34:42.999) (total time: 15547ms):
Trace[2104555766]: ---"Objects listed" error:<nil> 15504ms (16:34:58.504)
Trace[2104555766]: [15.547132193s] [15.547132193s] END
I1029 16:35:00.965414    1734 event.go:307] "Event occurred" object="node-az-3" fieldPath="" kind="Node" apiVersion="" type="Normal" reason="NodePasswordValidationComplete" message="Deferred node password secret validation complete"

seeing this in using the dmesg command

2024-11-20T14:22:11.881049+00:00 node-az-3  rke2[3922]: time="2024-11-20T14:22:11Z" level=warning msg="Unable to remove node password: secrets \"dev-worker-az-2.node-password.rke2\" not found"
2024-11-20T14:22:11.899934+00:00 node-az-3  rke2[3922]: time="2024-11-20T14:22:11Z" level=warning msg="Unable to remove node password: secrets \"dev-worker-az-2.node-password.rke2\" not found"

not sure why it's trying to remove the node here
The cluster is built using RKE2 v1.27

I'm considering disabling the rke2-server service, deleting the existing secret with node-password.rke2, then starting rke2-server
I might go into a restore as it somehow giving the thought of the cluster losing the quorum

any input is appreciated.

please paste the GH issue if there's one created, thanks!

[brandond]

These are just warning messages and will not prevent anything from working properly.

The bigger problem is that something caused the Node resources to get deleted and recreated. It seems like the secrets are also gone for some reason; that warning message is from the node OnDelete handler that attempts to delete the node password Secret when the Node is deleted.

I would probably go figure out what caused the "incident" and what deleted the nodes. That is the real problem here, not the warnings about the node password secrets.

[xhejtman]

I tried to debug this issue a bit.

I added some prints here: https://github.com/k3s-io/k3s/blob/b83f80372a740277c95ee431c740f78ccc17136e/pkg/nodepassword/nodepassword.go#L54

If I change the line: secret, err := secretClient.Cache().Get(metav1.NamespaceSystem, name) to secret, err := secretClient.Get(metav1.NamespaceSystem, name, metav1.GetOptions{}) then it works as expected. Otherwise, the cache returns no secret althought the secret does exist.

[brandond]

Its possible that the secret informer hasn't synced yet at this point if the system is somewhat overloaded during startup. I can't reproduce this locally or in a lab environment, so I suspect it's related to system resources. How many nodes are in this cluster, and what cpu/memory resources are available on the server in question?

[xhejtman]

41 nodes, 64/128 CPU cores per node and 512GB RAM. Few nodes have 96/192 CPU cores and 1.5TB RAM.

These control plane nodes have 64/128 CPU cores and 512GB RAM. On startup, many service containers are starting (like fluentbit logging and so on), the control plane has about 33 pods/node.

[brandond]

interesting. may just be related to the number of secrets then.

• Spurious Deferred node password secret validation failed: secrets "NODENAME" already exists when restarting servers k3s-io/k3s#11354

[xhejtman]

ok, number of secrets is about 8000.

[brandond]

that's.... a lot