search

rancher / rke2

https://docs.rke2.io/
Apache License 2.0
1.5k stars 261 forks source link

RKE2 Control Plane node rotation fails after installing kyverno #4781

Closed riuvshyn closed 11 months ago

riuvshyn commented 11 months ago

Environmental Info: RKE2 Version: v1.26.7+rke2r1

Cluster Configuration: 3 CP / 3 Workers

Describe the bug: Control Plane node rotation fails after installed kyverno New node comes up and some k8s components are actually getting provisioned except kube-proxy. rke2-server is crashlooping and kube-proxy is never gets provisioned. In rke2-server logs not much going on related to kube-proxy:

Sep 21 12:41:55 ip-172-29-195-214 rke2[21652]: time="2023-09-21T12:41:55Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"

For some reason kube-proxy.yaml manifests is not getting created in /var/lib/rancher/rke2/agent/pod-manifests/

and there are only:

$ ls /var/lib/rancher/rke2/agent/pod-manifests/
etcd.yaml                     kube-apiserver.yaml           kube-controller-manager.yaml  kube-scheduler.yaml

Manual creation of /var/lib/rancher/rke2/agent/pod-manifests/kube-proxy.yaml allows to bootstrapping CP node to continue and then it works fine.

This bug can't be reproduced with kyverno admission controller scaled down.

Steps To Reproduce:

Expected behavior: CP node is rotated and on new CP node all k8s core components are deployed and functioning as expected

Actual behavior: CP node is rotated and on new CP node kube-proxy is missing which prevents CP node to transition to healthy state.

Additional context / logs: All kyverno policies are in Audit mode so shouldn't be actually blocking anything and I believe it will reproduce even without any policies created it looks like the issue is kyverno mutation/validation webhooks which are supposed to intercept all traffic to API server. Looks like rke2-server is attempting to perform some k8s API calls but it is getting failed as kyverno is not accessible without kube-proxy.

brandond commented 11 months ago

Have you opened an issue on the kyverno side? I will note that just putting it into audit mode will not help you if the webhooks are set to fail closed; if the webhook is set to intercept management of secrets or other resources that are critical to the startup of rke2, failing closed when the backend is unavailable can easily break things to the point where the cluster will not start until you remove the webhook configuration. This is a known issue with webhooks in general, especially when the webhook endpoint is hosted within the cluster it is supposed to protect.

riuvshyn commented 11 months ago

Thanks for looking in to this one! I did not open ticket on kyverno side as I believe that it is not kyverno specific problem, as you mentioned it fails due to the validating webhook not being able to connect to the controller due to missing kube-proxy and it is indeed has failurePolicy: Fail. I understand the problem with webhooks but thought that kube-proxy.yaml can be actually created even if k8s API is not reachable, if it is not the case I guess I will need to thing about some workarounds.

riuvshyn commented 11 months ago

Also, what other resources are critical for start up rke2 other than secrets?

brandond commented 11 months ago

kube-proxy should be able to run, as it is a static pod deployed on each node - it does not need to go through scheduling or any of the usual stuff that would block a pod being created via the apiserver.

It is possible that the webhook might be blocking the overall startup of RKE2 though, including the bit that drops the kube-proxy static pod manifest. You should see errors in the rke2 journald logs about this though. Have you checked that yet?

riuvshyn commented 11 months ago

kube-proxy is able to run for sure, but manifest for it isn't getting created in /var/lib/rancher/rke2/agent/pod-manifests/ for some reason... If I create manifest manually it gets picked up and works then. the only kube-proxy related logs in rke2-server I see is:

Sep 21 12:41:55 ip-172-29-195-214 rke2[21652]: time="2023-09-21T12:41:55Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"

Kyverno also have resource filtering, I will try to configure it maybe I can configure filter to skip resources on cattle-* namespaces

brandond commented 11 months ago

There should be other messages in there that indicate why the readyz check isn't passing, such as waiting for the apiserver or roles or so on.

You can also do kubectl get --raw /readyz?verbose on the server to see what apiserver health checks are failing, if any.

will try to configure it maybe I can configure filter to skip resources on cattle-* namespaces

rke2 doesn't use the cattle namespaces, those are only used by rancher. RKE2 stuff is all in kube-system.

riuvshyn commented 11 months ago

Looks like all apiserver endpoints are ok

[+]ping ok
[+]log ok
[+]etcd ok
[+]etcd-readiness ok
[+]informer-sync ok
[+]poststarthook/start-kube-apiserver-admission-initializer ok
[+]poststarthook/generic-apiserver-start-informers ok
[+]poststarthook/priority-and-fairness-config-consumer ok
[+]poststarthook/priority-and-fairness-filter ok
[+]poststarthook/storage-object-count-tracker-hook ok
[+]poststarthook/start-apiextensions-informers ok
[+]poststarthook/start-apiextensions-controllers ok
[+]poststarthook/crd-informer-synced ok
[+]poststarthook/bootstrap-controller ok
[+]poststarthook/rbac/bootstrap-roles ok
[+]poststarthook/scheduling/bootstrap-system-priority-classes ok
[+]poststarthook/priority-and-fairness-config-producer ok
[+]poststarthook/start-cluster-authentication-info-controller ok
[+]poststarthook/start-kube-apiserver-identity-lease-controller ok
[+]poststarthook/start-kube-apiserver-identity-lease-garbage-collector ok
[+]poststarthook/start-legacy-token-tracking-controller ok
[+]poststarthook/aggregator-reload-proxy-client-cert ok
[+]poststarthook/start-kube-aggregator-informers ok
[+]poststarthook/apiservice-registration-controller ok
[+]poststarthook/apiservice-status-available-controller ok
[+]poststarthook/kube-apiserver-autoregistration ok
[+]autoregister-completion ok
[+]poststarthook/apiservice-openapi-controller ok
[+]poststarthook/apiservice-openapiv3-controller ok
[+]shutdown ok
readyz check passed
riuvshyn commented 11 months ago

here is also kyverno validatingWH rules:

  rules:
  - apiGroups:
    - ""
    apiVersions:
    - v1
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - persistentvolumeclaims
    - pods
    - pods/ephemeralcontainers
    - replicationcontrollers
    scope: '*'
  - apiGroups:
    - apps
    apiVersions:
    - v1
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - daemonsets
    - deployments
    - replicasets
    - statefulsets
    scope: '*'
  - apiGroups:
    - autoscaling
    apiVersions:
    - v1
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - horizontalpodautoscalers
    scope: '*'
  - apiGroups:
    - autoscaling
    apiVersions:
    - v2
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - horizontalpodautoscalers
    scope: '*'
  - apiGroups:
    - batch
    apiVersions:
    - v1
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - cronjobs
    - jobs
    scope: '*'
  - apiGroups:
    - flowcontrol.apiserver.k8s.io
    apiVersions:
    - v1beta2
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - flowschemas
    - prioritylevelconfigurations
    scope: '*'
  - apiGroups:
    - flowcontrol.apiserver.k8s.io
    apiVersions:
    - v1beta3
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - flowschemas
    - prioritylevelconfigurations
    scope: '*'
  - apiGroups:
    - monitoring.coreos.com
    apiVersions:
    - v1
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - prometheusrules
    scope: '*'
  - apiGroups:
    - networking.k8s.io
    apiVersions:
    - v1
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - ingresses
    scope: '*'
  - apiGroups:
    - policy
    apiVersions:
    - v1
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - poddisruptionbudgets
    scope: '*'
  - apiGroups:
    - rbac.authorization.k8s.io
    apiVersions:
    - v1
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - clusterrolebindings
    - rolebindings
    scope: '*'
  - apiGroups:
    - scheduling.k8s.io
    apiVersions:
    - v1
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - priorityclasses
    scope: '*'
  - apiGroups:
    - storage.k8s.io
    apiVersions:
    - v1
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - csistoragecapacities
    scope: '*'
  - apiGroups:
    - storage.k8s.io
    apiVersions:
    - v1beta1
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - csistoragecapacities
    scope: '*'

It doesn't track secrets/configMaps etc...

riuvshyn commented 11 months ago

also

rke2-server logs ``` Sep 21 17:55:51 ip-172-29-195-106 systemd[1]: Starting Rancher Kubernetes Engine v2 (server)... Sep 21 17:55:51 ip-172-29-195-106 sh[1350]: + /usr/bin/systemctl is-enabled --quiet nm-cloud-setup.service Sep 21 17:55:51 ip-172-29-195-106 sh[1351]: Failed to get unit file state for nm-cloud-setup.service: No such file or directory Sep 21 17:55:51 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:51Z" level=info msg="Applying Pod Security Admission Configuration" Sep 21 17:55:51 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:51Z" level=info msg="Starting rke2 v1.26.7+rke2r1 (374bdaf23d963e7d16bcaa820e95f792b1d3c661)" Sep 21 17:55:51 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:51Z" level=warning msg="Cluster CA certificate is not trusted by the host CA bundle, but the token does not include a CA hash. Use the full tok> Sep 21 17:55:51 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:51Z" level=info msg="Managed etcd cluster not yet initialized" Sep 21 17:55:51 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:51Z" level=warning msg="Cluster CA certificate is not trusted by the host CA bundle, but the token does not include a CA hash. Use the full tok> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Reconciling bootstrap data between datastore and disk" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=debug msg="/var/lib/rancher/rke2/server/cred directory is empty" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=debug msg="One or more certificate directories do not exist; writing data to disk from datastore" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=system:admin,O=system:masters signed by CN=rke2-client-ca@1695226275: notBefore=2023-09-20 16:11:15 +0000 U> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=system:rke2-supervisor,O=system:masters signed by CN=rke2-client-ca@1695226275: notBefore=2023-09-20 16:11:> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=system:kube-controller-manager signed by CN=rke2-client-ca@1695226275: notBefore=2023-09-20 16:11:15 +0000 > Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=system:kube-scheduler signed by CN=rke2-client-ca@1695226275: notBefore=2023-09-20 16:11:15 +0000 UTC notAf> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=system:apiserver,O=system:masters signed by CN=rke2-client-ca@1695226275: notBefore=2023-09-20 16:11:15 +00> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=system:kube-proxy signed by CN=rke2-client-ca@1695226275: notBefore=2023-09-20 16:11:15 +0000 UTC notAfter=> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=system:rke2-controller signed by CN=rke2-client-ca@1695226275: notBefore=2023-09-20 16:11:15 +0000 UTC notA> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=rke2-cloud-controller-manager signed by CN=rke2-client-ca@1695226275: notBefore=2023-09-20 16:11:15 +0000 U> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=kube-apiserver signed by CN=rke2-server-ca@1695226275: notBefore=2023-09-20 16:11:15 +0000 UTC notAfter=202> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=system:auth-proxy signed by CN=rke2-request-header-ca@1695226275: notBefore=2023-09-20 16:11:15 +0000 UTC n> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=etcd-server signed by CN=etcd-server-ca@1695226275: notBefore=2023-09-20 16:11:15 +0000 UTC notAfter=2024-0> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=etcd-client signed by CN=etcd-server-ca@1695226275: notBefore=2023-09-20 16:11:15 +0000 UTC notAfter=2024-0> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=etcd-peer signed by CN=etcd-peer-ca@1695226275: notBefore=2023-09-20 16:11:15 +0000 UTC notAfter=2024-09-20> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: W0921 17:55:52.126950 1367 logging.go:59] [core] [Channel #1 SubChannel #2] grpc: addrConn.createTransport failed to connect to { Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "Addr": "127.0.0.1:2379", Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "ServerName": "127.0.0.1", Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "Attributes": null, Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "BalancerAttributes": null, Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "Type": 0, Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "Metadata": null Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: }. Err: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg=start Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="schedule, now=2023-09-21T17:55:52Z, entry=1, next=2023-09-21T20:00:00Z" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=rke2,O=rke2 signed by CN=rke2-server-ca@1695226275: notBefore=2023-09-20 16:11:15 +0000 UTC notAfter=2024-0> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=warning msg="dynamiclistener [::]:9345: no cached certificate available for preload - deferring certificate load until storage initi> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: W0921 17:55:52.129190 1367 logging.go:59] [core] [Channel #3 SubChannel #4] grpc: addrConn.createTransport failed to connect to { Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "Addr": "127.0.0.1:2379", Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "ServerName": "127.0.0.1", Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "Attributes": null, Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "BalancerAttributes": null, Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "Type": 0, Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "Metadata": null Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: }. Err: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Active TLS secret / (ver=) (count 10): map[listener.cattle.io/cn-100.64.0.1:100.64.0.1 listener.cattle.io/cn-127.0.0.1:127> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Running kube-apiserver --admission-control-config-file=/etc/rancher/rke2/config/rancher-psact.yaml --advertise-address=172> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Running kube-scheduler --authentication-kubeconfig=/var/lib/rancher/rke2/server/cred/scheduler.kubeconfig --authorization-> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Running kube-controller-manager --allocate-node-cidrs=true --attach-detach-reconcile-sync-period=1m0s --authentication-kub> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Applying network policies..." Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Restricting automount..." Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Server node token is available at /var/lib/rancher/rke2/server/token" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="To join server node to cluster: rke2 server -s https://172.29.195.106:9345 -t ${SERVER_NODE_TOKEN}" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: W0921 17:55:52.360451 1367 logging.go:59] [core] [Channel #5 SubChannel #6] grpc: addrConn.createTransport failed to connect to { Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "Addr": "/run/k3s/containerd/containerd.sock", Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "ServerName": "/run/k3s/containerd/containerd.sock", Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "Attributes": null, Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "BalancerAttributes": null, Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "Type": 0, Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: "Metadata": null Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: }. Err: connection error: desc = "transport: Error while dialing dial unix /run/k3s/containerd/containerd.sock: connect: no such file or directory" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Agent node token is available at /var/lib/rancher/rke2/server/agent-token" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Waiting for cri connection: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing> Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="To join agent node to cluster: rke2 agent -s https://172.29.195.106:9345 -t ${AGENT_NODE_TOKEN}" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Wrote kubeconfig /etc/rancher/rke2/rke2.yaml" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Run: rke2 kubectl" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Cluster-Http-Server 2023/09/21 17:55:52 http: TLS handshake error from 127.0.0.1:40192: remote error: tls: bad certificate" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Cluster-Http-Server 2023/09/21 17:55:52 http: TLS handshake error from 127.0.0.1:40236: remote error: tls: bad certificate" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="Password verified locally for node ip-172-29-195-106.eu-central-1.compute.internal" Sep 21 17:55:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:52Z" level=info msg="certificate CN=ip-172-29-195-106.eu-central-1.compute.internal signed by CN=rke2-server-ca@1695226275: notBefore=2023-09-2> Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: W0921 17:55:53.128054 1367 logging.go:59] [core] [Channel #1 SubChannel #2] grpc: addrConn.createTransport failed to connect to { Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: "Addr": "127.0.0.1:2379", Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: "ServerName": "127.0.0.1", Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: "Attributes": null, Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: "BalancerAttributes": null, Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: "Type": 0, Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: "Metadata": null Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: }. Err: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused" Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: W0921 17:55:53.130256 1367 logging.go:59] [core] [Channel #3 SubChannel #4] grpc: addrConn.createTransport failed to connect to { Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: "Addr": "127.0.0.1:2379", Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: "ServerName": "127.0.0.1", Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: "Attributes": null, Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: "BalancerAttributes": null, Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: "Type": 0, Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: "Metadata": null Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: }. Err: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused" Sep 21 17:55:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:53Z" level=info msg="certificate CN=system:node:ip-172-29-195-106.eu-central-1.compute.internal,O=system:nodes signed by CN=rke2-client-ca@1695> Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Module overlay was already loaded" Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Module br_netfilter was already loaded" Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=debug msg="getConntrackMax: using scaled conntrack-max-per-core" Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_max' to 1048576" Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_established' to 86400" Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Checking local image archives in /var/lib/rancher/rke2/agent/images for index.docker.io/rancher/rke2-runtime:v1.26.7-rke2r> Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=warning msg="Failed to load runtime image index.docker.io/rancher/rke2-runtime:v1.26.7-rke2r1 from tarball: no local image available> Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Checking local image archives in /var/lib/rancher/rke2/agent/images for docker-hub.tw.ee/rancher/rke2-runtime:v1.26.7-rke2> Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=warning msg="Failed to load runtime image docker-hub.tw.ee/rancher/rke2-runtime:v1.26.7-rke2r1 from tarball: no local image availabl> Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Using private registry config file at /etc/rancher/rke2/registries.yaml" Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=debug msg="Kubelet image credential provider bin directory check failed: stat /var/lib/rancher/credentialprovider/bin: no such file > Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Pulling runtime image docker-hub.tw.ee/rancher/rke2-runtime:v1.26.7-rke2r1" Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Creating directory /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/bin" Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Extracting file bin/containerd to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/bin/containerd" Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: W0921 17:55:54.502790 1367 logging.go:59] [core] [Channel #1 SubChannel #2] grpc: addrConn.createTransport failed to connect to { Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: "Addr": "127.0.0.1:2379", Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: "ServerName": "127.0.0.1", Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: "Attributes": null, Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: "BalancerAttributes": null, Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: "Type": 0, Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: "Metadata": null Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: }. Err: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused" Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Extracting file bin/containerd-shim to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/bin/containerd-shim" Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Extracting file bin/containerd-shim-runc-v1 to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/bin/containerd-shim-> Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:54Z" level=info msg="Extracting file bin/containerd-shim-runc-v2 to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/bin/containerd-shim-> Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: W0921 17:55:54.986791 1367 logging.go:59] [core] [Channel #3 SubChannel #4] grpc: addrConn.createTransport failed to connect to { Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: "Addr": "127.0.0.1:2379", Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: "ServerName": "127.0.0.1", Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: "Attributes": null, Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: "BalancerAttributes": null, Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: "Type": 0, Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: "Metadata": null Sep 21 17:55:54 ip-172-29-195-106 rke2[1367]: }. Err: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused" Sep 21 17:55:55 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:55Z" level=info msg="Extracting file bin/crictl to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/bin/crictl" Sep 21 17:55:55 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:55Z" level=info msg="Extracting file bin/ctr to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/bin/ctr" Sep 21 17:55:55 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:55Z" level=info msg="Extracting file bin/kubectl to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/bin/kubectl" Sep 21 17:55:56 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:56Z" level=info msg="Extracting file bin/kubelet to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/bin/kubelet" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: W0921 17:55:57.010163 1367 logging.go:59] [core] [Channel #1 SubChannel #2] grpc: addrConn.createTransport failed to connect to { Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "Addr": "127.0.0.1:2379", Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "ServerName": "127.0.0.1", Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "Attributes": null, Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "BalancerAttributes": null, Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "Type": 0, Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "Metadata": null Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: }. Err: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file bin/runc to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/bin/runc" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Creating directory /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/harvester-cloud-provider.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/harv> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/harvester-csi-driver.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/harveste> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rancher-vsphere-cpi.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/rancher-v> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rancher-vsphere-csi.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/rancher-v> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rke2-calico-crd.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/rke2-calico-c> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rke2-calico.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/rke2-calico.yaml" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rke2-canal.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/rke2-canal.yaml" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rke2-cilium.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/rke2-cilium.yaml" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rke2-coredns.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/rke2-coredns.yam> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rke2-ingress-nginx.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/rke2-ingre> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rke2-metrics-server.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/rke2-metr> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rke2-multus.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/rke2-multus.yaml" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rke2-snapshot-controller-crd.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rke2-snapshot-controller.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/charts/rke2> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Extracting file charts/rke2-snapshot-validation-webhook.yaml to /var/lib/rancher/rke2/data/v1.26.7-rke2r1-9873cf6e613f/cha> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rancher/addons.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rancher-vsphere-cpi.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rancher-vsphere-csi.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-calico-crd.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-calico.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-canal.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-snapshot-controller.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/harvester-csi-driver.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="No cluster configuration value changes necessary for manifest /var/lib/rancher/rke2/server/manifests/rancher/managed-chart> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-multus.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/harvester-cloud-provider.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-ingress-nginx.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="No cluster configuration value changes necessary for manifest /var/lib/rancher/rke2/server/manifests/rancher/cluster-agent> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="No cluster configuration value changes necessary for manifest /var/lib/rancher/rke2/server/manifests/rancher/rke2-etcd-sna> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-cilium.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-coredns.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-metrics-server.yaml to set cluster configuration values" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-snapshot-controller-crd.yaml to set cluster configuration val> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-snapshot-validation-webhook.yaml to set cluster configuration> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Using private registry config file at /etc/rancher/rke2/registries.yaml" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=debug msg="Searching for nvidia container runtime at /usr/local/nvidia/toolkit/nvidia-container-runtime" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=debug msg="nvidia container runtime not found at /usr/local/nvidia/toolkit/nvidia-container-runtime" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=debug msg="Searching for nvidia container runtime at /usr/bin/nvidia-container-runtime" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=debug msg="nvidia container runtime not found at /usr/bin/nvidia-container-runtime" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=debug msg="Searching for nvidia-experimental container runtime at /usr/local/nvidia/toolkit/nvidia-container-runtime-experimental" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=debug msg="nvidia-experimental container runtime not found at /usr/local/nvidia/toolkit/nvidia-container-runtime-experimental" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=debug msg="Searching for nvidia-experimental container runtime at /usr/bin/nvidia-container-runtime-experimental" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=debug msg="nvidia-experimental container runtime not found at /usr/bin/nvidia-container-runtime-experimental" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Logging containerd to /var/lib/rancher/rke2/agent/containerd/containerd.log" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:57Z" level=info msg="Running containerd -c /var/lib/rancher/rke2/agent/etc/containerd/config.toml -a /run/k3s/containerd/containerd.sock --stat> Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: W0921 17:55:57.467715 1367 logging.go:59] [core] [Channel #7 SubChannel #8] grpc: addrConn.createTransport failed to connect to { Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "Addr": "/run/k3s/containerd/containerd.sock", Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "ServerName": "/run/k3s/containerd/containerd.sock", Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "Attributes": null, Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "BalancerAttributes": null, Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "Type": 0, Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "Metadata": null Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: }. Err: connection error: desc = "transport: Error while dialing dial unix /run/k3s/containerd/containerd.sock: connect: no such file or directory" Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: W0921 17:55:57.780212 1367 logging.go:59] [core] [Channel #3 SubChannel #4] grpc: addrConn.createTransport failed to connect to { Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "Addr": "127.0.0.1:2379", Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "ServerName": "127.0.0.1", Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "Attributes": null, Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "BalancerAttributes": null, Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "Type": 0, Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: "Metadata": null Sep 21 17:55:57 ip-172-29-195-106 rke2[1367]: }. Err: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused" Sep 21 17:55:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:58Z" level=info msg="containerd is now running" Sep 21 17:55:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:58Z" level=info msg="Pulling images from /var/lib/rancher/rke2/agent/images/kube-apiserver-image.txt" Sep 21 17:55:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:55:58Z" level=info msg="Pulling image docker-hub.tw.ee/rancher/hardened-kubernetes:v1.26.7-rke2r1-build20230719..." Sep 21 17:56:00 ip-172-29-195-106 rke2[1367]: W0921 17:56:00.639328 1367 logging.go:59] [core] [Channel #1 SubChannel #2] grpc: addrConn.createTransport failed to connect to { Sep 21 17:56:00 ip-172-29-195-106 rke2[1367]: "Addr": "127.0.0.1:2379", Sep 21 17:56:00 ip-172-29-195-106 rke2[1367]: "ServerName": "127.0.0.1", Sep 21 17:56:00 ip-172-29-195-106 rke2[1367]: "Attributes": null, Sep 21 17:56:00 ip-172-29-195-106 rke2[1367]: "BalancerAttributes": null, Sep 21 17:56:00 ip-172-29-195-106 rke2[1367]: "Type": 0, Sep 21 17:56:00 ip-172-29-195-106 rke2[1367]: "Metadata": null Sep 21 17:56:00 ip-172-29-195-106 rke2[1367]: }. Err: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused" Sep 21 17:56:01 ip-172-29-195-106 rke2[1367]: W0921 17:56:01.875813 1367 logging.go:59] [core] [Channel #3 SubChannel #4] grpc: addrConn.createTransport failed to connect to { Sep 21 17:56:01 ip-172-29-195-106 rke2[1367]: "Addr": "127.0.0.1:2379", Sep 21 17:56:01 ip-172-29-195-106 rke2[1367]: "ServerName": "127.0.0.1", Sep 21 17:56:01 ip-172-29-195-106 rke2[1367]: "Attributes": null, Sep 21 17:56:01 ip-172-29-195-106 rke2[1367]: "BalancerAttributes": null, Sep 21 17:56:01 ip-172-29-195-106 rke2[1367]: "Type": 0, Sep 21 17:56:01 ip-172-29-195-106 rke2[1367]: "Metadata": null Sep 21 17:56:01 ip-172-29-195-106 rke2[1367]: }. Err: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:2379: connect: connection refused" Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=info msg="Imported images from /var/lib/rancher/rke2/agent/images/kube-apiserver-image.txt in 8.288434758s" Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=info msg="Pulling images from /var/lib/rancher/rke2/agent/images/kube-controller-manager-image.txt" Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=info msg="Imported images from /var/lib/rancher/rke2/agent/images/kube-controller-manager-image.txt in 398.282µs" Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=info msg="Pulling images from /var/lib/rancher/rke2/agent/images/kube-scheduler-image.txt" Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=info msg="Imported images from /var/lib/rancher/rke2/agent/images/kube-scheduler-image.txt in 348.079µs" Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=info msg="Connecting to proxy" url="wss://127.0.0.1:9345/v1-rke2/connect" Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=debug msg="Kubelet image credential provider bin directory check failed: stat /var/lib/rancher/credentialprovider/bin: no such file > Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=info msg="Running kubelet --address=0.0.0.0 --alsologtostderr=false --anonymous-auth=false --authentication-token-webhook=true --aut> Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=info msg="Cluster-Http-Server 2023/09/21 17:56:06 http: TLS handshake error from 127.0.0.1:58860: remote error: tls: bad certificate" Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-rke2/connect from 127.0.0.1:58846" Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=info msg="Handling backend connection request [ip-172-29-195-106.eu-central-1.compute.internal]" Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=info msg="Adding member ip-172-29-195-106.eu-central-1.compute.internal-0dcd3fd8=https://172.29.195.106:2380 to etcd cluster [ip-172> Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: {"level":"warn","ts":"2023-09-21T17:56:06.795Z","logger":"etcd-client","caller":"v3@v3.5.7-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","tar> Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=info msg="Waiting for other members to finish joining etcd cluster: etcdserver: unhealthy cluster" Sep 21 17:56:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:06Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:56:07 ip-172-29-195-106 rke2[1367]: {"level":"warn","ts":"2023-09-21T17:56:07.127Z","logger":"etcd-client","caller":"v3@v3.5.7-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","tar> Sep 21 17:56:07 ip-172-29-195-106 rke2[1367]: {"level":"info","ts":"2023-09-21T17:56:07.127Z","logger":"etcd-client","caller":"v3@v3.5.7-k3s1/client.go:210","msg":"Auto sync endpoints failed.","error":"context de> Sep 21 17:56:07 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:07Z" level=info msg="Adding member ip-172-29-195-106.eu-central-1.compute.internal-0dcd3fd8=https://172.29.195.106:2380 to etcd cluster [ip-172> Sep 21 17:56:07 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:07Z" level=info msg="Starting etcd to join cluster with members [ip-172-29-197-103.eu-central-1.compute.internal-16de3b98=https://172.29.197.10> Sep 21 17:56:11 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:11Z" level=info msg="Cluster-Http-Server 2023/09/21 17:56:11 http: TLS handshake error from 127.0.0.1:58892: remote error: tls: bad certificate" Sep 21 17:56:11 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:11Z" level=debug msg="Wrote ping" Sep 21 17:56:11 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:11Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:56:12 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:12Z" level=info msg="Container for etcd not found (no matching container found), retrying" Sep 21 17:56:16 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:16Z" level=info msg="Cluster-Http-Server 2023/09/21 17:56:16 http: TLS handshake error from 127.0.0.1:54450: remote error: tls: bad certificate" Sep 21 17:56:16 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:16Z" level=debug msg="Wrote ping" Sep 21 17:56:16 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:16Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:56:21 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:21Z" level=info msg="Cluster-Http-Server 2023/09/21 17:56:21 http: TLS handshake error from 127.0.0.1:54472: remote error: tls: bad certificate" Sep 21 17:56:21 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:21Z" level=debug msg="Wrote ping" Sep 21 17:56:21 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:21Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:56:22 ip-172-29-195-106 rke2[1367]: {"level":"warn","ts":"2023-09-21T17:56:22.127Z","logger":"etcd-client","caller":"v3@v3.5.7-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","tar> Sep 21 17:56:22 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:22Z" level=info msg="Failed to test data store connection: context deadline exceeded" Sep 21 17:56:22 ip-172-29-195-106 rke2[1367]: {"level":"warn","ts":"2023-09-21T17:56:22.128Z","logger":"etcd-client","caller":"v3@v3.5.7-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","tar> Sep 21 17:56:22 ip-172-29-195-106 rke2[1367]: {"level":"info","ts":"2023-09-21T17:56:22.128Z","logger":"etcd-client","caller":"v3@v3.5.7-k3s1/client.go:210","msg":"Auto sync endpoints failed.","error":"context de> Sep 21 17:56:22 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:22Z" level=info msg="Waiting for etcd server to become available" Sep 21 17:56:26 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:26Z" level=info msg="Cluster-Http-Server 2023/09/21 17:56:26 http: TLS handshake error from 127.0.0.1:51484: remote error: tls: bad certificate" Sep 21 17:56:26 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:26Z" level=debug msg="Wrote ping" Sep 21 17:56:26 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:26Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:56:31 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:31Z" level=info msg="Cluster-Http-Server 2023/09/21 17:56:31 http: TLS handshake error from 127.0.0.1:51512: remote error: tls: bad certificate" Sep 21 17:56:31 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:31Z" level=debug msg="Wrote ping" Sep 21 17:56:31 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:31Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:56:32 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:32Z" level=info msg="Container for etcd is running" Sep 21 17:56:33 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:33Z" level=info msg="Defragmenting etcd database" Sep 21 17:56:34 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:34Z" level=info msg="etcd data store connection OK" Sep 21 17:56:34 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:34Z" level=info msg="Saving cluster bootstrap data to datastore" Sep 21 17:56:34 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:34Z" level=info msg="Waiting for API server to become available" Sep 21 17:56:35 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:35Z" level=warning msg="Bootstrap key already exists" Sep 21 17:56:35 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:35Z" level=info msg="Reconciling etcd snapshot data in rke2-etcd-snapshots ConfigMap" Sep 21 17:56:36 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:36Z" level=debug msg="Wrote ping" Sep 21 17:56:36 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:36Z" level=info msg="Cluster-Http-Server 2023/09/21 17:56:36 http: TLS handshake error from 127.0.0.1:56736: remote error: tls: bad certificate" Sep 21 17:56:36 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:36Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:56:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:38Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:56798" Sep 21 17:56:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:38Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:38Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:56754" Sep 21 17:56:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:38Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:38Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:56758" Sep 21 17:56:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:38Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:38Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:56788" Sep 21 17:56:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:38Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:38Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:56772" Sep 21 17:56:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:38Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:39 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:39Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:56804" Sep 21 17:56:39 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:39Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:39 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:39Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:56812" Sep 21 17:56:39 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:39Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:39 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:39Z" level=debug msg="Tunnel authorizer failed to get Kubelet Port: nodes \"ip-172-29-195-106.eu-central-1.compute.internal\" not found" Sep 21 17:56:39 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:39Z" level=info msg="Kube API server is now running" Sep 21 17:56:39 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:39Z" level=info msg="Applying Cluster Role Bindings" Sep 21 17:56:39 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:39Z" level=info msg="Watching for delete of ip-172-29-195-106.eu-central-1.compute.internal Node object" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Applying network policies complete" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Restricting automount for default serviceAccounts complete" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-rke2/connect from 172.29.197.103:33952" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Handling backend connection request [ip-172-29-197-103.eu-central-1.compute.internal]" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-rke2/connect from 172.29.196.223:51414" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Handling backend connection request [ip-172-29-196-223.eu-central-1.compute.internal]" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-rke2/connect from 172.29.196.207:39236" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Handling backend connection request [ip-172-29-196-207.eu-central-1.compute.internal]" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-rke2/connect from 172.29.197.31:56820" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Handling backend connection request [ip-172-29-197-31.eu-central-1.compute.internal]" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-rke2/connect from 172.29.197.191:50320" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Handling backend connection request [ip-172-29-197-191.eu-central-1.compute.internal]" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-rke2/connect from 172.29.195.225:52550" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Handling backend connection request [ip-172-29-195-225.eu-central-1.compute.internal]" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-rke2/connect from 172.29.195.108:52120" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Handling backend connection request [ip-172-29-195-108.eu-central-1.compute.internal]" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-rke2/connect from 172.29.195.31:34954" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Handling backend connection request [ip-172-29-195-31.eu-central-1.compute.internal]" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-rke2/connect from 172.29.196.125:47614" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Handling backend connection request [ip-172-29-196-125.eu-central-1.compute.internal]" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-rke2/connect from 172.29.196.133:53040" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Handling backend connection request [ip-172-29-196-133.eu-central-1.compute.internal]" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Applying CRD helmcharts.helm.cattle.io" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Stopped tunnel to 127.0.0.1:9345" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Connecting to proxy" url="wss://172.29.195.106:9345/v1-rke2/connect" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:9345/v1-rke2/connect" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Connecting to proxy" url="wss://172.29.197.103:9345/v1-rke2/connect" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Connecting to proxy" url="wss://172.29.196.223:9345/v1-rke2/connect" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-rke2/connect from 172.29.195.106:46852" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Handling backend connection request [ip-172-29-195-106.eu-central-1.compute.internal]" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="Tunnel authorizer failed to get Kubelet Port: nodes \"ip-172-29-195-106.eu-central-1.compute.internal\" not found" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="DesiredSet - Patch apiextensions.k8s.io/v1, Kind=CustomResourceDefinition /helmcharts.helm.cattle.io for helmcharts.helm> Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=debug msg="DesiredSet - Updated apiextensions.k8s.io/v1, Kind=CustomResourceDefinition /helmcharts.helm.cattle.io for helmcharts.he> Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Failed to set annotations and labels on node ip-172-29-195-106.eu-central-1.compute.internal: Operation cannot be fulfille> Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Applying CRD helmchartconfigs.helm.cattle.io" Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Failed to set annotations and labels on node ip-172-29-195-106.eu-central-1.compute.internal: Operation cannot be fulfille> Sep 21 17:56:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:40Z" level=info msg="Failed to set annotations and labels on node ip-172-29-195-106.eu-central-1.compute.internal: Operation cannot be fulfille> Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=info msg="Failed to set annotations and labels on node ip-172-29-195-106.eu-central-1.compute.internal: Operation cannot be fulfille> Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=info msg="Annotations and labels have been set successfully on node: ip-172-29-195-106.eu-central-1.compute.internal" Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.137.76:9443 from 127.0.0.1:56820" Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=debug msg="Tunnel server egress proxy dialing 100.64.137.76:9443 directly" Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=debug msg="DesiredSet - Patch apiextensions.k8s.io/v1, Kind=CustomResourceDefinition /helmchartconfigs.helm.cattle.io for helmchart> Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=debug msg="DesiredSet - Updated apiextensions.k8s.io/v1, Kind=CustomResourceDefinition /helmchartconfigs.helm.cattle.io for helmcha> Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=info msg="Applying CRD addons.k3s.cattle.io" Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=debug msg="DesiredSet - Patch apiextensions.k8s.io/v1, Kind=CustomResourceDefinition /addons.k3s.cattle.io for addons.k3s.cattle.io> Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=debug msg="DesiredSet - Updated apiextensions.k8s.io/v1, Kind=CustomResourceDefinition /addons.k3s.cattle.io for addons.k3s.cattle.> Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=info msg="Creating rke2-supervisor event broadcaster" Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=info msg="Cluster-Http-Server 2023/09/21 17:56:41 http: TLS handshake error from 127.0.0.1:56828: remote error: tls: bad certificate" Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:41Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:56:42 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:42Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:43 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:43Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50722" Sep 21 17:56:43 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:43Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:43 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:43Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50718" Sep 21 17:56:43 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:43Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:43 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:43Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50692" Sep 21 17:56:43 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:43Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:43 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:43Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50690" Sep 21 17:56:43 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:43Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:43 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:43Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50706" Sep 21 17:56:43 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:43Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:43 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:43Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:44 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:44Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:45 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:45Z" level=debug msg="Wrote ping" Sep 21 17:56:45 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:45Z" level=debug msg="Wrote ping" Sep 21 17:56:45 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:45Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:45 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:45Z" level=debug msg="Wrote ping" Sep 21 17:56:46 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:46Z" level=info msg="Cluster-Http-Server 2023/09/21 17:56:46 http: TLS handshake error from 127.0.0.1:50736: remote error: tls: bad certificate" Sep 21 17:56:46 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:46Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:46 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:46Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:56:47 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:47Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:48 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:48Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50778" Sep 21 17:56:48 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:48Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:48 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:48Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50788" Sep 21 17:56:48 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:48Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:48 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:48Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50758" Sep 21 17:56:48 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:48Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:48 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:48Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50772" Sep 21 17:56:48 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:48Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:48 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:48Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50774" Sep 21 17:56:48 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:48Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:48 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:48Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:49 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:49Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:50 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:50Z" level=debug msg="Wrote ping" Sep 21 17:56:50 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:50Z" level=debug msg="Wrote ping" Sep 21 17:56:50 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:50Z" level=debug msg="Wrote ping" Sep 21 17:56:50 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:50Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:51 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:51Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.137.74:9443 from 127.0.0.1:50792" Sep 21 17:56:51 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:51Z" level=debug msg="Tunnel server egress proxy dialing 100.64.137.74:9443 directly" Sep 21 17:56:51 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:51Z" level=info msg="Cluster-Http-Server 2023/09/21 17:56:51 http: TLS handshake error from 127.0.0.1:50800: remote error: tls: bad certificate" Sep 21 17:56:51 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:51Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:51 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:51Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:56:52 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:52Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40090" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40118" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40132" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40092" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40104" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.137.74:9443 from 127.0.0.1:40134" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server egress proxy dialing 100.64.137.74:9443 directly" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.137.74:9443 from 127.0.0.1:40142" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Tunnel server egress proxy dialing 100.64.137.74:9443 directly" Sep 21 17:56:53 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:53Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:54 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:54Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:55 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:55Z" level=debug msg="Wrote ping" Sep 21 17:56:55 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:55Z" level=debug msg="Wrote ping" Sep 21 17:56:55 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:55Z" level=debug msg="Wrote ping" Sep 21 17:56:55 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:55Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:55 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:55Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.137.76:9443 from 127.0.0.1:40150" Sep 21 17:56:55 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:55Z" level=debug msg="Tunnel server egress proxy dialing 100.64.137.76:9443 directly" Sep 21 17:56:56 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:56Z" level=info msg="Cluster-Http-Server 2023/09/21 17:56:56 http: TLS handshake error from 127.0.0.1:40154: remote error: tls: bad certificate" Sep 21 17:56:56 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:56Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:56 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:56Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:56:57 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:57Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:58Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40212" Sep 21 17:56:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:58Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:58Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40172" Sep 21 17:56:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:58Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:58Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40200" Sep 21 17:56:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:58Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:58Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40178" Sep 21 17:56:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:58Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:58Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40192" Sep 21 17:56:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:58Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:56:58 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:58Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:56:59 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:56:59Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:00 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:00Z" level=debug msg="Wrote ping" Sep 21 17:57:00 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:00Z" level=debug msg="Wrote ping" Sep 21 17:57:00 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:00Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:00 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:00Z" level=debug msg="Wrote ping" Sep 21 17:57:01 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:01Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.128.28:9443 from 127.0.0.1:40218" Sep 21 17:57:01 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:01Z" level=debug msg="Tunnel server egress proxy dialing 100.64.128.28:9443 directly" Sep 21 17:57:01 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:01Z" level=info msg="Cluster-Http-Server 2023/09/21 17:57:01 http: TLS handshake error from 127.0.0.1:40222: remote error: tls: bad certificate" Sep 21 17:57:01 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:01Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:01 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:01Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:57:02 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:02Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:03 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:03Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52854" Sep 21 17:57:03 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:03Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:03 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:03Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52840" Sep 21 17:57:03 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:03Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:03 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:03Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52852" Sep 21 17:57:03 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:03Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:03 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:03Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52846" Sep 21 17:57:03 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:03Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:03 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:03Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52838" Sep 21 17:57:03 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:03Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:03 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:03Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:04 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:04Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.137.76:9443 from 127.0.0.1:52866" Sep 21 17:57:04 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:04Z" level=debug msg="Tunnel server egress proxy dialing 100.64.137.76:9443 directly" Sep 21 17:57:04 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:04Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.137.74:9443 from 127.0.0.1:52876" Sep 21 17:57:04 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:04Z" level=debug msg="Tunnel server egress proxy dialing 100.64.137.74:9443 directly" Sep 21 17:57:04 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:04Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.137.74:9443 from 127.0.0.1:52886" Sep 21 17:57:04 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:04Z" level=debug msg="Tunnel server egress proxy dialing 100.64.137.74:9443 directly" Sep 21 17:57:04 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:04Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:05 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:05Z" level=debug msg="Wrote ping" Sep 21 17:57:05 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:05Z" level=debug msg="Wrote ping" Sep 21 17:57:05 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:05Z" level=debug msg="Wrote ping" Sep 21 17:57:05 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:05Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:06Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.128.28:9443 from 127.0.0.1:52894" Sep 21 17:57:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:06Z" level=debug msg="Tunnel server egress proxy dialing 100.64.128.28:9443 directly" Sep 21 17:57:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:06Z" level=info msg="Cluster-Http-Server 2023/09/21 17:57:06 http: TLS handshake error from 127.0.0.1:52898: remote error: tls: bad certificate" Sep 21 17:57:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:06Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:06 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:06Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:57:07 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:07Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:08 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:08Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52922" Sep 21 17:57:08 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:08Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:08 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:08Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52938" Sep 21 17:57:08 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:08Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:08 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:08Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52950" Sep 21 17:57:08 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:08Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:08 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:08Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52918" Sep 21 17:57:08 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:08Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:08 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:08Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52944" Sep 21 17:57:08 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:08Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:08 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:08Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:09 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:09Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:10 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:10Z" level=debug msg="Wrote ping" Sep 21 17:57:11 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:10Z" level=debug msg="Wrote ping" Sep 21 17:57:11 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:10Z" level=debug msg="Wrote ping" Sep 21 17:57:11 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:11Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:11 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:11Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.137.76:9443 from 127.0.0.1:52952" Sep 21 17:57:11 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:11Z" level=debug msg="Tunnel server egress proxy dialing 100.64.137.76:9443 directly" Sep 21 17:57:11 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:11Z" level=info msg="Cluster-Http-Server 2023/09/21 17:57:11 http: TLS handshake error from 127.0.0.1:52964: remote error: tls: bad certificate" Sep 21 17:57:11 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:11Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:11 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:11Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:57:12 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:12Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:13 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:13Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40056" Sep 21 17:57:13 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:13Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:13 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:13Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40036" Sep 21 17:57:13 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:13Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:13 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:13Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40020" Sep 21 17:57:13 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:13Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:13 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:13Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40048" Sep 21 17:57:13 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:13Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:13 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:13Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40032" Sep 21 17:57:13 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:13Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:13 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:13Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:14 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:14Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:15 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:15Z" level=debug msg="Wrote ping" Sep 21 17:57:15 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:15Z" level=debug msg="Wrote ping" Sep 21 17:57:15 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:15Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:15 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:15Z" level=debug msg="Wrote ping" Sep 21 17:57:16 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:16Z" level=info msg="Cluster-Http-Server 2023/09/21 17:57:16 http: TLS handshake error from 127.0.0.1:40064: remote error: tls: bad certificate" Sep 21 17:57:16 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:16Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:16 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:16Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:57:17 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:17Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:18 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:18Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40094" Sep 21 17:57:18 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:18Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:18 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:18Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40080" Sep 21 17:57:18 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:18Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:18 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:18Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40106" Sep 21 17:57:18 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:18Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:18 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:18Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40096" Sep 21 17:57:18 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:18Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:18 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:18Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:40120" Sep 21 17:57:18 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:18Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:18 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:18Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:19 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:19Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:20 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:20Z" level=debug msg="Wrote ping" Sep 21 17:57:20 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:20Z" level=debug msg="Wrote ping" Sep 21 17:57:20 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:20Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:20 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:20Z" level=debug msg="Wrote ping" Sep 21 17:57:21 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:21Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.137.74:9443 from 127.0.0.1:40124" Sep 21 17:57:21 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:21Z" level=debug msg="Tunnel server egress proxy dialing 100.64.137.74:9443 directly" Sep 21 17:57:21 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:21Z" level=info msg="Cluster-Http-Server 2023/09/21 17:57:21 http: TLS handshake error from 127.0.0.1:40126: remote error: tls: bad certificate" Sep 21 17:57:21 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:21Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:21 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:21Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:57:22 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:22Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:23 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:23Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52102" Sep 21 17:57:23 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:23Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:23 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:23Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52104" Sep 21 17:57:23 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:23Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:23 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:23Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52128" Sep 21 17:57:23 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:23Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:23 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:23Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52106" Sep 21 17:57:23 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:23Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:23 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:23Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52086" Sep 21 17:57:23 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:23Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:23 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:23Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:24 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:24Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:25 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:25Z" level=debug msg="Wrote ping" Sep 21 17:57:25 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:25Z" level=debug msg="Wrote ping" Sep 21 17:57:25 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:25Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:25 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:25Z" level=debug msg="Wrote ping" Sep 21 17:57:26 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:26Z" level=info msg="Cluster-Http-Server 2023/09/21 17:57:26 http: TLS handshake error from 127.0.0.1:52144: remote error: tls: bad certificate" Sep 21 17:57:26 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:26Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:26 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:26Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:57:27 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:27Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:28 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:28Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52180" Sep 21 17:57:28 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:28Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:28 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:28Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52178" Sep 21 17:57:28 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:28Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:28 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:28Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52174" Sep 21 17:57:28 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:28Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:28 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:28Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52210" Sep 21 17:57:28 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:28Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:28 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:28Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:52194" Sep 21 17:57:28 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:28Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:28 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:28Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:29 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:29Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:30 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:30Z" level=debug msg="Wrote ping" Sep 21 17:57:30 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:30Z" level=debug msg="Wrote ping" Sep 21 17:57:30 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:30Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:30 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:30Z" level=debug msg="Wrote ping" Sep 21 17:57:31 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:31Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.137.76:9443 from 127.0.0.1:52214" Sep 21 17:57:31 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:31Z" level=debug msg="Tunnel server egress proxy dialing 100.64.137.76:9443 directly" Sep 21 17:57:31 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:31Z" level=info msg="Cluster-Http-Server 2023/09/21 17:57:31 http: TLS handshake error from 127.0.0.1:52226: remote error: tls: bad certificate" Sep 21 17:57:31 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:31Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:31 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:31Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:57:32 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:32Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:33 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:33Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50338" Sep 21 17:57:33 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:33Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:33 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:33Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50346" Sep 21 17:57:33 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:33Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:33 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:33Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50370" Sep 21 17:57:33 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:33Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:33 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:33Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50356" Sep 21 17:57:33 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:33Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:33 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:33Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50368" Sep 21 17:57:33 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:33Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:33 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:33Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:34 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:34Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:35 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:35Z" level=debug msg="Wrote ping" Sep 21 17:57:35 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:35Z" level=debug msg="Wrote ping" Sep 21 17:57:35 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:35Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:35 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:35Z" level=debug msg="Wrote ping" Sep 21 17:57:36 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:36Z" level=info msg="Cluster-Http-Server 2023/09/21 17:57:36 http: TLS handshake error from 127.0.0.1:50382: remote error: tls: bad certificate" Sep 21 17:57:36 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:36Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:36 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:36Z" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Ser> Sep 21 17:57:37 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:37Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:38Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50408" Sep 21 17:57:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:38Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:38Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50422" Sep 21 17:57:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:38Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:38Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50426" Sep 21 17:57:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:38Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:38Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50442" Sep 21 17:57:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:38Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:38Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50428" Sep 21 17:57:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:38Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:38 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:38Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:39 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:39Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:40Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50456" Sep 21 17:57:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:40Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:40Z" level=debug msg="Tunnel server handing HTTP/1.1 CONNECT request for //100.64.145.166:4443 from 127.0.0.1:50454" Sep 21 17:57:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:40Z" level=debug msg="Tunnel server egress proxy dialing 100.64.145.166:4443 directly" Sep 21 17:57:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:40Z" level=debug msg="Wrote ping" Sep 21 17:57:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:40Z" level=debug msg="Wrote ping" Sep 21 17:57:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:40Z" level=debug msg="Waiting for Ready condition to be updated for Kubelet Port assignment" Sep 21 17:57:40 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:40Z" level=debug msg="Wrote ping" Sep 21 17:57:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:41Z" level=fatal msg="clusterrole: EnsureRBACPolicy failed: unable to initialize roles: timed out waiting for the condition" Sep 21 17:57:41 ip-172-29-195-106 systemd[1]: rke2-server.service: Main process exited, code=exited, status=1/FAILURE Sep 21 17:57:41 ip-172-29-195-106 systemd[1]: rke2-server.service: Failed with result 'exit-code'. Sep 21 17:57:41 ip-172-29-195-106 systemd[1]: Failed to start Rancher Kubernetes Engine v2 (server). ```

rke2-server actually fails with:


Sep 21 17:57:41 ip-172-29-195-106 rke2[1367]: time="2023-09-21T17:57:41Z" level=fatal msg="clusterrole: EnsureRBACPolicy failed: unable to initialize roles: timed out waiting for the condition"

and RBAC is actually tracked by the WH rules:

  - apiGroups:
    - rbac.authorization.k8s.io
    apiVersions:
    - v1
    operations:
    - CREATE
    - UPDATE
    - DELETE
    - CONNECT
    resources:
    - clusterrolebindings
    - rolebindings
    scope: '*'

I guess that's why it gets faileds and just can't get to the point where kube-proxy manifest is created

I will try to filter configure kyverno to skip cattle-* and rke2-* cluster roles/rolebindings

brandond commented 11 months ago

Ah yeah, that'd be it. We ensure the state of some core RBAC for the embedded controllers; if kyverno is blocking those it would definitely create problems.

riuvshyn commented 11 months ago

yeah, this is not rke2 problem then, looks like I can workaround this only in 1.27+ with AdmissionWebhookMatchConditions as I would need to skip clusterrolebindings rke2-server is trying to provision.

but if rke2-server did create kube-proxy manifests before it was trying to provison RBAC it would eventually work, but I am not sure if that's make sense from RKE2 perspective.

brandond commented 11 months ago

it doesn't drop the kube-proxy manifest until after the rest of the core stuff is up, as it needs to query some stuff from the core in order to determine whether or not to enable kube-proxy, since kube-proxy is considered a client component. It's definitely a bit complicated.

gapopp commented 9 months ago

@riuvshyn could you please share, how do you able to workaround this issue? Thank you

riuvshyn commented 8 months ago

hey @gapopp It really depends on which kyverno policies you have... so first of all check your kyverno admission failures.

In my case I had to configure following policies:

  restrict-binding-clusteradmin
  restrict-binding-system-groups

with failurePolicy set to Ignore to stop blocking rke2 bootstrapping. And once I will be at 1.27 I was planning to tune kyverno WH with AdmissionWebhookMatchConditions to exclude rke2 related stuff.

tmmorin commented 5 months ago

for the record, we're seeing a variant of this issue in https://github.com/rancher/rke2/issues/5693

I would tend to think that changing the failurePolicy of webhooks to Ignore is not a satisfying solution to this problem, because (a) changing this field may or may not be easy (for Rancher webhooks, it definitely does not seem trivial), and because (b) having a failurePolicy: Fail is a legitimate value that can be chosen to enforce things for security reason and that loosening how strictly such things are enforced is not a decision that can always be made.

brandond commented 5 months ago

xref: https://github.com/rancher/rke2/issues/5693#issuecomment-2048202926