[NATS] The cluster is inconsistent after a k3s restart

[babykart]

The cluster bootstrap is done without problem.

--datastore-endpoint "nats://kine:xxxxxxxxxxxx@localhost:4222/?noEmbed&bucket=kine"

For example, I deploy ArgoCD and everything works perfectly.
After a restart of the k3s service, the cluster is inconsistent: missing CRD, configMap ... I deploy the application again: the objects (CRD, configMaps ...) seem to be present and yet the deployments cannot access to them.
The only way to return to a consistent state is to reset and bootstrap the cluster again.
I tested manually creating the kv and letting k3s do it but the only difference is the discard parameter (old vs new) which does not impact the behavior after restarting k3s.
No error in NATS.
Obviously I'm using the latest stable version of NATS (2.10.25) with jetstram:

nats --context=sys server info

Server information for nikita (ND2VWGKBNHQHNOOEJ3E56D2DYJUJPT2HAM6JGCSINT6Q6POMZM5SCJ4H)

Process Details:

                     Version: 2.10.25
                  Git Commit: 006039e
                  Go Version: go1.23.5
                  Start Time: 2025-01-27 11:10:42
            Config Load Time: 2025-01-27 11:10:42
                      Uptime: 1h51m7s

Connection Details:

               Auth Required: true
                TLS Required: false
                        Host: 0.0.0.0:4222

JetStream:

                      Domain:
           Storage Directory: /var/lib/nats/jetstream
                  Max Memory: 1.0 GiB
                    Max File: 2.0 GiB
             Active Accounts: 1
               Memory In Use: 0 B
                 File In Use: 8.9 MiB
                API Requests: 490
                  API Errors: 1
  Always sync writes to disk: false
        Write sync Frequency: 2m0s

Limits:

                    Max Conn: 65,536
                    Max Subs: 0
                 Max Payload: 1.0 MiB
                 TLS Timeout: 2.00s
              Write Deadline: 10.00s

Statistics:

                   CPU Cores: 4 29.00%
                      Memory: 110 MiB
                 Connections: 2
               Subscriptions: 353
                    Messages: 150,316 in 3,411,786 out
                       Bytes: 37 MiB in 3.2 GiB out
              Slow Consumers: 0

nats kv info kine

Information for Key-Value Store Bucket kine created 2025-01-27T11:24:11+01:00

Configuration:

          Bucket Name: kine
         History Kept: 10
        Values Stored: 2,853
           Compressed: false
   Backing Store Kind: JetStream
          Description: Holds kine key/values
          Bucket Size: 8.9 MiB
  Maximum Bucket Size: unlimited
   Maximum Value Size: unlimited
          Maximum Age: unlimited
     JetStream Stream: KV_kine
              Storage: File

Cluster Information:

                 Name:
               Leader: nikita

nats str info KV_kine

Information for Stream KV_kine created 2025-01-27 11:24:11

           Description: Holds kine key/values
              Subjects: $KV.kine.>
              Replicas: 1
               Storage: File

Options:

             Retention: Limits
       Acknowledgments: true
        Discard Policy: Old
      Duplicate Window: 2m0s
            Direct Get: true
     Allows Msg Delete: false
          Allows Purge: true
        Allows Rollups: true

Limits:

      Maximum Messages: unlimited
   Maximum Per Subject: 10
         Maximum Bytes: unlimited
           Maximum Age: unlimited
  Maximum Message Size: unlimited
     Maximum Consumers: unlimited

State:

              Messages: 2,853
                 Bytes: 8.9 MiB
        First Sequence: 1 @ 2025-01-27 11:24:11
         Last Sequence: 31,939 @ 2025-01-27 12:53:33
      Deleted Messages: 29,086
      Active Consumers: 96
    Number of Subjects: 1,207

Reproductible with k3s-v1.3{0,1} and k0s-v1.31.
Let me know if you need more information.

[brandond]

Cc @bruth

[babykart]

When the cluster is inconsistent, I see this type of message in the k{3,0}s logs:

time="2025-02-15 20:46:43" level=info msg="W0215 20:46:43.469093   27113 reflector.go:561] k8s.io/client-go/metadata/metadatainformer/informer.go:138: failed to list *v1.PartialObjectMetadata: the server could not find the requested resource" component=kube-controller-manager stream=stderr
time="2025-02-15 20:46:43" level=info msg="E0215 20:46:43.469152   27113 reflector.go:158] \"Unhandled Error\" err=\"k8s.io/client-go/metadata/metadatainformer/informer.go:138: Failed to watch *v1.PartialObjectMetadata: failed to list *v1.PartialObjectMetadata: the server could not find the requested resource\" logger=\"UnhandledError\"" component=kube-controller-manager stream=stderr
time="2025-02-15 20:46:43" level=info msg="W0215 20:46:43.772395   27113 reflector.go:561] k8s.io/client-go/metadata/metadatainformer/informer.go:138: failed to list *v1.PartialObjectMetadata: the server could not find the requested resource" component=kube-controller-manager stream=stderr
time="2025-02-15 20:46:43" level=info msg="E0215 20:46:43.772452   27113 reflector.go:158] \"Unhandled Error\" err=\"k8s.io/client-go/metadata/metadatainformer/informer.go:138: Failed to watch *v1.PartialObjectMetadata: failed to list *v1.PartialObjectMetadata: the server could not find the requested resource\" logger=\"UnhandledError\"" component=kube-controller-manager stream=stderr

Maybe this will help.

[brandond]

No, that's not related.

[bruth]

We have a PR coming this week that addresses a number of issues based on the k8s conformance tests. This may still be the happy path, but it will rule out a certain class of issue. If the issue you are observing still remains then we can work together to get a reproduction to debug further.

[simonwu-os]

I encountered a similar issue. Initially, I suspected it was related to the replicas=3 configuration for the NATS key-value (KV) store. However, even after rebuilding the cluster and setting replicas=1, the problem persisted. The issue consistently occurs after running systemctl restart k3s, causing inconsistencies in the output of kubectl get pods -n kube-system each time. This leads to various pod failures, including terminations, restarts, pending states, and more.

[simonwu-os]

After the data-store node was shut down, several pods originally running on it were automatically rescheduled to the dify-app node. When the data-store node is rebooted, the dify-app node correctly reflects the current state, but the data-store node still displays entries for terminated pods that have already been deleted. Even after restarting k3s on the data-store node, these deleted pods continue to appear as lingering entries.
In data-store master node:

[apps@data-store ~]$ kubectl get pods -n kube-system
NAME                                      READY   STATUS        RESTARTS      AGE
cilium-4htp4                              1/1     Running       0             11h
cilium-6vj4t                              1/1     Running       0             11h
cilium-envoy-vl9zj                        1/1     Running       1 (11h ago)   11h
cilium-envoy-vncvw                        1/1     Running       0             11h
cilium-envoy-z9vzr                        1/1     Running       0             11h
cilium-gdrvg                              1/1     Running       0             11h
cilium-node-init-9wctv                    1/1     Running       0             12h
cilium-node-init-cg2cv                    1/1     Running       2 (11h ago)   12h
cilium-node-init-kmgld                    1/1     Running       0             12h
cilium-operator-6994644564-8lm87          1/1     Running       0             11h
cilium-operator-6994644564-r9v98          1/1     Running       0             11h
coredns-7c88fbcb7d-6vxx2                  1/1     Running       0             11h
coredns-7c88fbcb7d-lp5mw                  0/1     Terminating   1             12h
hubble-relay-7bf4fc498b-7j4cj             1/1     Running       0             11h
hubble-relay-7bf4fc498b-mflkr             0/1     Terminating   1             12h
hubble-ui-69d69b64cf-cggc5                2/2     Running       0             11h
hubble-ui-69d69b64cf-sbxnh                0/2     Terminating   2             12h
local-path-provisioner-68b8dfc6d6-vlgmw   1/1     Running       0             11h
local-path-provisioner-68b8dfc6d6-xsh9f   0/1     Terminating   1             12h
metrics-server-7cbbccf87b-54h4z           0/1     Terminating   1             12h
metrics-server-7cbbccf87b-mz7gs           1/1     Running       0             11h

In another node:

[apps@dify-app ~]$ kubectl get pods -n kube-system
NAME                                      READY   STATUS    RESTARTS      AGE
cilium-4htp4                              1/1     Running   0             12h
cilium-6vj4t                              1/1     Running   0             12h
cilium-envoy-vl9zj                        1/1     Running   1 (11h ago)   12h
cilium-envoy-vncvw                        1/1     Running   0             12h
cilium-envoy-z9vzr                        1/1     Running   0             12h
cilium-gdrvg                              1/1     Running   0             12h
cilium-node-init-9wctv                    1/1     Running   0             12h
cilium-node-init-cg2cv                    1/1     Running   2 (11h ago)   12h
cilium-node-init-kmgld                    1/1     Running   0             12h
cilium-operator-6994644564-8lm87          1/1     Running   0             12h
cilium-operator-6994644564-r9v98          1/1     Running   0             12h
coredns-7c88fbcb7d-6vxx2                  1/1     Running   0             11h
hubble-relay-7bf4fc498b-7j4cj             1/1     Running   0             11h
hubble-ui-69d69b64cf-cggc5                2/2     Running   0             11h
local-path-provisioner-68b8dfc6d6-vlgmw   1/1     Running   0             11h
metrics-server-7cbbccf87b-mz7gs           1/1     Running   0             11h

I found a solution: clear the k3s pod data and containerd storage on the data-store node, then restart k3s.

in data-store node:

sudo systemctl stop k3s
sudo rm -rf /var/lib/kubelet/pods/*
sudo rm -rf /var/lib/rancher/k3s/agent/containerd/*
sudo systemctl start k3s

The result:

[apps@data-store ~]$ kubectl get pod -n kube-system
NAME                                      READY   STATUS    RESTARTS      AGE
cilium-4htp4                              1/1     Running   0             12h
cilium-6vj4t                              1/1     Running   0             12h
cilium-envoy-vl9zj                        1/1     Running   1 (12h ago)   12h
cilium-envoy-vncvw                        1/1     Running   0             12h
cilium-envoy-z9vzr                        1/1     Running   0             12h
cilium-gdrvg                              1/1     Running   0             12h
cilium-node-init-9wctv                    1/1     Running   0             12h
cilium-node-init-cg2cv                    1/1     Running   2 (12h ago)   12h
cilium-node-init-kmgld                    1/1     Running   0             12h
cilium-operator-6994644564-8lm87          1/1     Running   0             12h
cilium-operator-6994644564-r9v98          1/1     Running   0             12h
coredns-7c88fbcb7d-6vxx2                  1/1     Running   0             12h
hubble-relay-7bf4fc498b-7j4cj             1/1     Running   0             12h
hubble-ui-69d69b64cf-cggc5                2/2     Running   0             12h
local-path-provisioner-68b8dfc6d6-vlgmw   1/1     Running   0             12h
metrics-server-7cbbccf87b-mz7gs           1/1     Running   0             12h

[brandond]

NATS doesn't work right. I probably wouldn't bother collecting too much more info, the Synadia folks are aware of the issue and will hopefully share fixes with us at some point.

[babykart]

@brandond @bruth Any news about this patch and any chance to see this patch integrated to kine ?