May 29 00:56:12 truenas systemd[1]: k3s.service: Scheduled restart job, restart counter is at 5. ░░ Subject: Automatic restarting of a unit has been scheduled ░░ Defined-By: systemd ░░ Support: https://www.debian.org/support ░░ ░░ Automatic restarting of the unit k3s.service has been scheduled, as the result for ░░ the configured Restart= setting for the unit. May 29 00:56:12 truenas systemd[1]: Stopped Lightweight Kubernetes. ░░ Subject: A stop job for unit k3s.service has finished ░░ Defined-By: systemd ░░ Support: https://www.debian.org/support ░░ ░░ A stop job for unit k3s.service has finished. ░░ ░░ The job identifier is 15086 and the job result is done. May 29 00:56:12 truenas systemd[1]: Starting Lightweight Kubernetes... ░░ Subject: A start job for unit k3s.service has begun execution ░░ Defined-By: systemd ░░ Support: https://www.debian.org/support ░░ ░░ A start job for unit k3s.service has begun execution. ░░ ░░ The job identifier is 15086. May 29 00:56:13 truenas k3s[99312]: time="2022-05-29T00:56:13+08:00" level=info msg="Starting k3s v1.23.5+k3s-937d546a-dirty (937d546a)" May 29 00:56:13 truenas k3s[99312]: time="2022-05-29T00:56:13+08:00" level=info msg="Configuring sqlite3 database connection pooling: maxIdleConns=2, maxOpenConns=0, connMaxLifetime=0s" May 29 00:56:13 truenas k3s[99312]: time="2022-05-29T00:56:13+08:00" level=info msg="Configuring database table schema and indexes, this may take a moment..." May 29 00:56:13 truenas k3s[99312]: time="2022-05-29T00:56:13+08:00" level=info msg="Database tables and indexes are up to date" May 29 00:56:14 truenas k3s[99312]: time="2022-05-29T00:56:14+08:00" level=info msg="Kine available at unix://kine.sock" May 29 00:56:14 truenas k3s[99312]: time="2022-05-29T00:56:14+08:00" level=info msg="Reconciling bootstrap data between datastore and disk" May 29 00:56:14 truenas k3s[99312]: time="2022-05-29T00:56:14+08:00" level=info msg="Migrating bootstrap data to new format" May 29 00:56:14 truenas k3s[99312]: time="2022-05-29T00:56:14+08:00" level=info msg="certificate CN=k3s,O=k3s signed by CN=k3s-server-ca@1642612322: notBefore=2022-01-19 17:12:02 +0000 UTC notAfter=2023-05-28 16:56:14 +0000 UTC" May 29 00:56:14 truenas k3s[99312]: time="2022-05-29T00:56:14+08:00" level=info msg="Running kube-apiserver --advertise-address=0.0.0.0 --advertise-port=6443 --allow-privileged=true --anonymous-auth=false --api-audiences=https://kubernetes.default.svc.cluster.local,k3s --audit-log-maxage=30 --audit-log-maxbackup=10 --audit-log-maxsize=100 --audit-log-path=/var/log/k3s_server_audit.log --authorization-mode=Node,RBAC --bind-address=127.0.0.1 --cert-dir=/mnt/Storage/ix-applications/k3s/server/tls/temporary-certs --client-ca-file=/mnt/Storage/ix-applications/k3s/server/tls/client-ca.crt --enable-admission-plugins=NodeRestriction,NamespaceLifecycle,ServiceAccount --etcd-servers=unix://kine.sock --feature-gates=JobTrackingWithFinalizers=true --insecure-port=0 --kubelet-certificate-authority=/mnt/Storage/ix-applications/k3s/server/tls/server-ca.crt --kubelet-client-certificate=/mnt/Storage/ix-applications/k3s/server/tls/client-kube-apiserver.crt --kubelet-client-key=/mnt/Storage/ix-applications/k3s/server/tls/client-kube-apiserver.key --profiling=false --proxy-client-cert-file=/mnt/Storage/ix-applications/k3s/server/tls/client-auth-proxy.crt --proxy-client-key-file=/mnt/Storage/ix-applications/k3s/server/tls/client-auth-proxy.key --requestheader-allowed-names=system:auth-proxy --requestheader-client-ca-file=/mnt/Storage/ix-applications/k3s/server/tls/request-header-ca.crt --requestheader-extra-headers-prefix=X-Remote-Extra- --requestheader-group-headers=X-Remote-Group --requestheader-username-headers=X-Remote-User --secure-port=6444 --service-account-issuer=https://kubernetes.default.svc.cluster.local --service-account-key-file=/mnt/Storage/ix-applications/k3s/server/tls/service.key --service-account-lookup=true --service-account-signing-key-file=/mnt/Storage/ix-applications/k3s/server/tls/service.key --service-cluster-ip-range=172.17.0.0/16 --service-node-port-range=9000-65535 --storage-backend=etcd3 --tls-cert-file=/mnt/Storage/ix-applications/k3s/server/tls/serving-kube-apiserver.crt --tls-private-key-file=/mnt/Storage/ix-applications/k3s/server/tls/serving-kube-apiserver.key" May 29 00:56:14 truenas k3s[99312]: Flag --insecure-port has been deprecated, This flag has no effect now and will be removed in v1.24. May 29 00:56:14 truenas k3s[99312]: I0529 00:56:14.834069 99312 server.go:593] external host was not specified, using 192.168.50.8 May 29 00:56:14 truenas k3s[99312]: I0529 00:56:14.834642 99312 server.go:186] Version: v1.23.5+k3s-937d546a-dirty May 29 00:56:14 truenas k3s[99312]: time="2022-05-29T00:56:14+08:00" level=info msg="Running kube-scheduler --authentication-kubeconfig=/mnt/Storage/ix-applications/k3s/server/cred/scheduler.kubeconfig --authorization-kubeconfig=/mnt/Storage/ix-applications/k3s/server/cred/scheduler.kubeconfig --bind-address=127.0.0.1 --kubeconfig=/mnt/Storage/ix-applications/k3s/server/cred/scheduler.kubeconfig --leader-elect=false --profiling=false --secure-port=10259" May 29 00:56:14 truenas k3s[99312]: time="2022-05-29T00:56:14+08:00" level=info msg="Running kube-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/mnt/Storage/ix-applications/k3s/server/cred/controller.kubeconfig --authorization-kubeconfig=/mnt/Storage/ix-applications/k3s/server/cred/controller.kubeconfig --bind-address=127.0.0.1 --cluster-cidr=172.16.0.0/16 --cluster-signing-kube-apiserver-client-cert-file=/mnt/Storage/ix-applications/k3s/server/tls/client-ca.crt --cluster-signing-kube-apiserver-client-key-file=/mnt/Storage/ix-applications/k3s/server/tls/client-ca.key --cluster-signing-kubelet-client-cert-file=/mnt/Storage/ix-applications/k3s/server/tls/client-ca.crt --cluster-signing-kubelet-client-key-file=/mnt/Storage/ix-applications/k3s/server/tls/client-ca.key --cluster-signing-kubelet-serving-cert-file=/mnt/Storage/ix-applications/k3s/server/tls/server-ca.crt --cluster-signing-kubelet-serving-key-file=/mnt/Storage/ix-applications/k3s/server/tls/server-ca.key --cluster-signing-legacy-unknown-cert-file=/mnt/Storage/ix-applications/k3s/server/tls/server-ca.crt --cluster-signing-legacy-unknown-key-file=/mnt/Storage/ix-applications/k3s/server/tls/server-ca.key --feature-gates=JobTrackingWithFinalizers=true --kubeconfig=/mnt/Storage/ix-applications/k3s/server/cred/controller.kubeconfig --leader-elect=false --node-cidr-mask-size=16 --profiling=false --root-ca-file=/mnt/Storage/ix-applications/k3s/server/tls/server-ca.crt --secure-port=10257 --service-account-private-key-file=/mnt/Storage/ix-applications/k3s/server/tls/service.key --terminated-pod-gc-threshold=5 --use-service-account-credentials=true" May 29 00:56:14 truenas k3s[99312]: I0529 00:56:14.844958 99312 shared_informer.go:240] Waiting for caches to sync for node_authorizer May 29 00:56:14 truenas k3s[99312]: time="2022-05-29T00:56:14+08:00" level=info msg="Waiting for API server to become available" May 29 00:56:14 truenas k3s[99312]: I0529 00:56:14.845976 99312 plugins.go:158] Loaded 12 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,RuntimeClass,DefaultIngressClass,MutatingAdmissionWebhook. May 29 00:56:14 truenas k3s[99312]: I0529 00:56:14.862986 99312 plugins.go:161] Loaded 11 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota. May 29 00:56:14 truenas k3s[99312]: time="2022-05-29T00:56:14+08:00" level=info msg="Node token is available at /mnt/Storage/ix-applications/k3s/server/token" May 29 00:56:14 truenas k3s[99312]: time="2022-05-29T00:56:14+08:00" level=info msg="To join node to cluster: k3s agent -s https://192.168.50.8:6443 -t ${NODE_TOKEN}" May 29 00:56:14 truenas k3s[99312]: I0529 00:56:14.882051 99312 plugins.go:158] Loaded 12 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,RuntimeClass,DefaultIngressClass,MutatingAdmissionWebhook. May 29 00:56:14 truenas k3s[99312]: I0529 00:56:14.882112 99312 plugins.go:161] Loaded 11 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota. May 29 00:56:14 truenas k3s[99312]: time="2022-05-29T00:56:14+08:00" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml" May 29 00:56:14 truenas k3s[99312]: time="2022-05-29T00:56:14+08:00" level=info msg="Run: k3s kubectl" May 29 00:56:14 truenas k3s[99312]: {"level":"warn","ts":"2022-05-29T00:56:14.962+0800","logger":"etcd-client","caller":"v3@v3.5.1-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc001121340/kine.sock","attempt":0,"error":"rpc error: code = Unknown desc = no such table: dbstat"} May 29 00:56:15 truenas k3s[99312]: time="2022-05-29T00:56:15+08:00" level=info msg="certificate CN=ix-truenas signed by CN=k3s-server-ca@1642612322: notBefore=2022-01-19 17:12:02 +0000 UTC notAfter=2023-05-28 16:56:15 +0000 UTC" May 29 00:56:15 truenas k3s[99312]: time="2022-05-29T00:56:15+08:00" level=info msg="certificate CN=system:node:ix-truenas,O=system:nodes signed by CN=k3s-client-ca@1642612322: notBefore=2022-01-19 17:12:02 +0000 UTC notAfter=2023-05-28 16:56:15 +0000 UTC" May 29 00:56:15 truenas k3s[99312]: W0529 00:56:15.116118 99312 genericapiserver.go:538] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources. May 29 00:56:15 truenas k3s[99312]: I0529 00:56:15.117884 99312 instance.go:274] Using reconciler: lease May 29 00:56:15 truenas k3s[99312]: time="2022-05-29T00:56:15+08:00" level=info msg="Module overlay was already loaded" May 29 00:56:15 truenas k3s[99312]: time="2022-05-29T00:56:15+08:00" level=info msg="Module nf_conntrack was already loaded" May 29 00:56:15 truenas k3s[99312]: time="2022-05-29T00:56:15+08:00" level=info msg="Module br_netfilter was already loaded" May 29 00:56:15 truenas k3s[99312]: time="2022-05-29T00:56:15+08:00" level=info msg="Module iptable_nat was already loaded" May 29 00:56:15 truenas k3s[99312]: time="2022-05-29T00:56:15+08:00" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect" May 29 00:56:15 truenas k3s[99312]: time="2022-05-29T00:56:15+08:00" level=error msg="Failed to connect to proxy" error="websocket: bad handshake" May 29 00:56:15 truenas k3s[99312]: time="2022-05-29T00:56:15+08:00" level=error msg="Remotedialer proxy error" error="websocket: bad handshake" May 29 00:56:15 truenas k3s[99312]: I0529 00:56:15.873108 99312 trace.go:205] Trace[992045089]: "List etcd3" key:/minions,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.280) (total time: 592ms): May 29 00:56:15 truenas k3s[99312]: Trace[992045089]: [592.961211ms] [592.961211ms] END May 29 00:56:15 truenas k3s[99312]: I0529 00:56:15.921335 99312 trace.go:205] Trace[784707628]: "List etcd3" key:/namespaces,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.250) (total time: 670ms): May 29 00:56:15 truenas k3s[99312]: Trace[784707628]: [670.682119ms] [670.682119ms] END May 29 00:56:15 truenas k3s[99312]: I0529 00:56:15.982441 99312 trace.go:205] Trace[691267638]: "List etcd3" key:/apiextensions.k8s.io/customresourcedefinitions,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:14.901) (total time: 1080ms): May 29 00:56:15 truenas k3s[99312]: Trace[691267638]: [1.080618407s] [1.080618407s] END May 29 00:56:16 truenas k3s[99312]: I0529 00:56:16.021652 99312 trace.go:205] Trace[287905863]: "List etcd3" key:/persistentvolumes,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.209) (total time: 811ms): May 29 00:56:16 truenas k3s[99312]: Trace[287905863]: [811.775662ms] [811.775662ms] END May 29 00:56:16 truenas k3s[99312]: I0529 00:56:16.026319 99312 trace.go:205] Trace[2050067685]: "List etcd3" key:/services/endpoints,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.263) (total time: 762ms): May 29 00:56:16 truenas k3s[99312]: Trace[2050067685]: [762.711424ms] [762.711424ms] END May 29 00:56:16 truenas k3s[99312]: I0529 00:56:16.068423 99312 trace.go:205] Trace[1831807845]: "List etcd3" key:/configmaps,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.249) (total time: 819ms): May 29 00:56:16 truenas k3s[99312]: Trace[1831807845]: [819.291983ms] [819.291983ms] END May 29 00:56:16 truenas k3s[99312]: I0529 00:56:16.509810 99312 trace.go:205] Trace[1106522658]: "List etcd3" key:/serviceaccounts,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.370) (total time: 1139ms): May 29 00:56:16 truenas k3s[99312]: Trace[1106522658]: [1.139429521s] [1.139429521s] END May 29 00:56:16 truenas k3s[99312]: I0529 00:56:16.557448 99312 trace.go:205] Trace[172066393]: "List etcd3" key:/persistentvolumeclaims,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.237) (total time: 1319ms): May 29 00:56:16 truenas k3s[99312]: Trace[172066393]: [1.319931947s] [1.319931947s] END May 29 00:56:16 truenas k3s[99312]: I0529 00:56:16.564952 99312 trace.go:205] Trace[177428914]: "List etcd3" key:/resourcequotas,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.186) (total time: 1378ms): May 29 00:56:16 truenas k3s[99312]: Trace[177428914]: [1.378650417s] [1.378650417s] END May 29 00:56:16 truenas k3s[99312]: I0529 00:56:16.570489 99312 trace.go:205] Trace[932920940]: "List etcd3" key:/services/specs,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.613) (total time: 957ms): May 29 00:56:16 truenas k3s[99312]: Trace[932920940]: [957.276058ms] [957.276058ms] END May 29 00:56:16 truenas k3s[99312]: I0529 00:56:16.577662 99312 trace.go:205] Trace[791470012]: "List etcd3" key:/podtemplates,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.132) (total time: 1444ms): May 29 00:56:16 truenas k3s[99312]: Trace[791470012]: [1.44469s] [1.44469s] END May 29 00:56:16 truenas k3s[99312]: I0529 00:56:16.597601 99312 trace.go:205] Trace[1392061918]: "List etcd3" key:/pods,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.301) (total time: 1295ms): May 29 00:56:16 truenas k3s[99312]: Trace[1392061918]: [1.295606971s] [1.295606971s] END May 29 00:56:16 truenas k3s[99312]: I0529 00:56:16.632557 99312 trace.go:205] Trace[167075681]: "List etcd3" key:/limitranges,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.162) (total time: 1470ms): May 29 00:56:16 truenas k3s[99312]: Trace[167075681]: [1.470432463s] [1.470432463s] END May 29 00:56:17 truenas k3s[99312]: I0529 00:56:17.365500 99312 trace.go:205] Trace[1446238619]: "List etcd3" key:/cronjobs,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:16.817) (total time: 547ms): May 29 00:56:17 truenas k3s[99312]: Trace[1446238619]: [547.629682ms] [547.629682ms] END May 29 00:56:17 truenas k3s[99312]: I0529 00:56:17.393597 99312 trace.go:205] Trace[349759794]: "List etcd3" key:/controllers,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.512) (total time: 1880ms): May 29 00:56:17 truenas k3s[99312]: Trace[349759794]: [1.88095248s] [1.88095248s] END May 29 00:56:17 truenas k3s[99312]: I0529 00:56:17.421292 99312 trace.go:205] Trace[806995288]: "List etcd3" key:/leases,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:16.870) (total time: 550ms): May 29 00:56:17 truenas k3s[99312]: Trace[806995288]: [550.510225ms] [550.510225ms] END May 29 00:56:17 truenas k3s[99312]: I0529 00:56:17.433034 99312 trace.go:205] Trace[711125527]: "List etcd3" key:/cronjobs,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:16.833) (total time: 599ms): May 29 00:56:17 truenas k3s[99312]: Trace[711125527]: [599.377442ms] [599.377442ms] END May 29 00:56:17 truenas k3s[99312]: I0529 00:56:17.450283 99312 trace.go:205] Trace[198536196]: "List etcd3" key:/jobs,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:16.811) (total time: 638ms): May 29 00:56:17 truenas k3s[99312]: Trace[198536196]: [638.930447ms] [638.930447ms] END May 29 00:56:18 truenas k3s[99312]: I0529 00:56:18.494151 99312 trace.go:205] Trace[295410401]: "List etcd3" key:/certificatesigningrequests,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:16.863) (total time: 1630ms): May 29 00:56:18 truenas k3s[99312]: Trace[295410401]: [1.63082599s] [1.63082599s] END May 29 00:56:18 truenas k3s[99312]: I0529 00:56:18.927279 99312 trace.go:205] Trace[1123414202]: "List etcd3" key:/priorityclasses,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.482) (total time: 1445ms): May 29 00:56:18 truenas k3s[99312]: Trace[1123414202]: [1.445050995s] [1.445050995s] END May 29 00:56:18 truenas k3s[99312]: I0529 00:56:18.934662 99312 trace.go:205] Trace[1939643646]: "List etcd3" key:/storageclasses,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.505) (total time: 1428ms): May 29 00:56:18 truenas k3s[99312]: Trace[1939643646]: [1.428739468s] [1.428739468s] END May 29 00:56:18 truenas k3s[99312]: I0529 00:56:18.935348 99312 trace.go:205] Trace[808130171]: "List etcd3" key:/rolebindings,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.453) (total time: 1481ms): May 29 00:56:18 truenas k3s[99312]: Trace[808130171]: [1.481327674s] [1.481327674s] END May 29 00:56:18 truenas k3s[99312]: I0529 00:56:18.935521 99312 trace.go:205] Trace[711385153]: "List etcd3" key:/horizontalpodautoscalers,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:16.792) (total time: 2142ms): May 29 00:56:18 truenas k3s[99312]: Trace[711385153]: [2.142575176s] [2.142575176s] END May 29 00:56:18 truenas k3s[99312]: I0529 00:56:18.939189 99312 trace.go:205] Trace[1767966305]: "List etcd3" key:/ingress,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.345) (total time: 1593ms): May 29 00:56:18 truenas k3s[99312]: Trace[1767966305]: [1.593898177s] [1.593898177s] END May 29 00:56:18 truenas k3s[99312]: I0529 00:56:18.957654 99312 trace.go:205] Trace[1959385415]: "List etcd3" key:/endpointslices,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.016) (total time: 1941ms): May 29 00:56:18 truenas k3s[99312]: Trace[1959385415]: [1.941156564s] [1.941156564s] END May 29 00:56:18 truenas k3s[99312]: I0529 00:56:18.971108 99312 trace.go:205] Trace[551625127]: "List etcd3" key:/horizontalpodautoscalers,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:16.797) (total time: 2173ms): May 29 00:56:18 truenas k3s[99312]: Trace[551625127]: [2.173958402s] [2.173958402s] END May 29 00:56:18 truenas k3s[99312]: I0529 00:56:18.982994 99312 trace.go:205] Trace[36618373]: "List etcd3" key:/horizontalpodautoscalers,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:16.803) (total time: 2178ms): May 29 00:56:18 truenas k3s[99312]: Trace[36618373]: [2.178983556s] [2.178983556s] END May 29 00:56:18 truenas k3s[99312]: I0529 00:56:18.992832 99312 trace.go:205] Trace[264641952]: "List etcd3" key:/csinodes,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.621) (total time: 1371ms): May 29 00:56:18 truenas k3s[99312]: Trace[264641952]: [1.371080598s] [1.371080598s] END May 29 00:56:18 truenas k3s[99312]: I0529 00:56:18.993080 99312 trace.go:205] Trace[1192872781]: "List etcd3" key:/horizontalpodautoscalers,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:16.780) (total time: 2212ms): May 29 00:56:18 truenas k3s[99312]: Trace[1192872781]: [2.212738617s] [2.212738617s] END May 29 00:56:19 truenas k3s[99312]: I0529 00:56:19.086536 99312 trace.go:205] Trace[1995190525]: "List etcd3" key:/endpointslices,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:16.881) (total time: 2204ms): May 29 00:56:19 truenas k3s[99312]: Trace[1995190525]: [2.204941549s] [2.204941549s] END May 29 00:56:19 truenas k3s[99312]: I0529 00:56:19.772617 99312 trace.go:205] Trace[931255498]: "List etcd3" key:/prioritylevelconfigurations,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.644) (total time: 2128ms): May 29 00:56:19 truenas k3s[99312]: Trace[931255498]: [2.128439918s] [2.128439918s] END May 29 00:56:19 truenas k3s[99312]: I0529 00:56:19.819544 99312 trace.go:205] Trace[329171629]: "List etcd3" key:/roles,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.453) (total time: 2366ms): May 29 00:56:19 truenas k3s[99312]: Trace[329171629]: [2.366378562s] [2.366378562s] END May 29 00:56:19 truenas k3s[99312]: I0529 00:56:19.837325 99312 trace.go:205] Trace[617083904]: "List etcd3" key:/csidrivers,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.621) (total time: 2215ms): May 29 00:56:19 truenas k3s[99312]: Trace[617083904]: [2.215325576s] [2.215325576s] END May 29 00:56:19 truenas k3s[99312]: I0529 00:56:19.838127 99312 trace.go:205] Trace[529365520]: "List etcd3" key:/prioritylevelconfigurations,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.717) (total time: 2120ms): May 29 00:56:19 truenas k3s[99312]: Trace[529365520]: [2.12018899s] [2.12018899s] END May 29 00:56:19 truenas k3s[99312]: I0529 00:56:19.854004 99312 trace.go:205] Trace[875340242]: "List etcd3" key:/flowschemas,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.642) (total time: 2211ms): May 29 00:56:19 truenas k3s[99312]: Trace[875340242]: [2.211751967s] [2.211751967s] END May 29 00:56:19 truenas k3s[99312]: I0529 00:56:19.903858 99312 trace.go:205] Trace[1189217711]: "List etcd3" key:/clusterrolebindings,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.473) (total time: 2430ms): May 29 00:56:19 truenas k3s[99312]: Trace[1189217711]: [2.430204229s] [2.430204229s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.031893 99312 trace.go:205] Trace[947156814]: "List etcd3" key:/statefulsets,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.784) (total time: 2247ms): May 29 00:56:20 truenas k3s[99312]: Trace[947156814]: [2.247414125s] [2.247414125s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.056579 99312 trace.go:205] Trace[223859472]: "List etcd3" key:/clusterroles,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.460) (total time: 2595ms): May 29 00:56:20 truenas k3s[99312]: Trace[223859472]: [2.595567728s] [2.595567728s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.062049 99312 trace.go:205] Trace[1940227650]: "List etcd3" key:/flowschemas,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.688) (total time: 2373ms): May 29 00:56:20 truenas k3s[99312]: Trace[1940227650]: [2.37304332s] [2.37304332s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.063956 99312 trace.go:205] Trace[864710659]: "List etcd3" key:/deployments,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.734) (total time: 2329ms): May 29 00:56:20 truenas k3s[99312]: Trace[864710659]: [2.329403331s] [2.329403331s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.065929 99312 trace.go:205] Trace[600401205]: "List etcd3" key:/controllerrevisions,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.808) (total time: 2257ms): May 29 00:56:20 truenas k3s[99312]: Trace[600401205]: [2.257355002s] [2.257355002s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.111623 99312 trace.go:205] Trace[349035884]: "List etcd3" key:/replicasets,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.806) (total time: 2304ms): May 29 00:56:20 truenas k3s[99312]: Trace[349035884]: [2.304853633s] [2.304853633s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.186253 99312 trace.go:205] Trace[217732496]: "List etcd3" key:/runtimeclasses,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.414) (total time: 2771ms): May 29 00:56:20 truenas k3s[99312]: Trace[217732496]: [2.771860102s] [2.771860102s] END May 29 00:56:20 truenas k3s[99312]: time="2022-05-29T00:56:20+08:00" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect" May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.199918 99312 trace.go:205] Trace[2109449684]: "List etcd3" key:/daemonsets,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.790) (total time: 2408ms): May 29 00:56:20 truenas k3s[99312]: Trace[2109449684]: [2.408941355s] [2.408941355s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.208659 99312 trace.go:205] Trace[131273893]: "List etcd3" key:/runtimeclasses,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.406) (total time: 2802ms): May 29 00:56:20 truenas k3s[99312]: Trace[131273893]: [2.802148658s] [2.802148658s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.229684 99312 trace.go:205] Trace[282210393]: "List etcd3" key:/ingressclasses,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.377) (total time: 2852ms): May 29 00:56:20 truenas k3s[99312]: Trace[282210393]: [2.852295809s] [2.852295809s] END May 29 00:56:20 truenas k3s[99312]: time="2022-05-29T00:56:20+08:00" level=error msg="Failed to connect to proxy" error="websocket: bad handshake" May 29 00:56:20 truenas k3s[99312]: time="2022-05-29T00:56:20+08:00" level=error msg="Remotedialer proxy error" error="websocket: bad handshake" May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.260440 99312 trace.go:205] Trace[1496654686]: "List etcd3" key:/poddisruptionbudgets,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.418) (total time: 2842ms): May 29 00:56:20 truenas k3s[99312]: Trace[1496654686]: [2.842245258s] [2.842245258s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.394592 99312 trace.go:205] Trace[301325627]: "List etcd3" key:/volumeattachments,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.548) (total time: 2845ms): May 29 00:56:20 truenas k3s[99312]: Trace[301325627]: [2.845816996s] [2.845816996s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.406851 99312 trace.go:205] Trace[347867592]: "List etcd3" key:/networkpolicies,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.171) (total time: 3235ms): May 29 00:56:20 truenas k3s[99312]: Trace[347867592]: [3.235667907s] [3.235667907s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.737225 99312 trace.go:205] Trace[1134839890]: "List etcd3" key:/poddisruptionbudgets,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.450) (total time: 3286ms): May 29 00:56:20 truenas k3s[99312]: Trace[1134839890]: [3.286226435s] [3.286226435s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.740011 99312 trace.go:205] Trace[1167841456]: "List etcd3" key:/podsecuritypolicy,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.433) (total time: 3306ms): May 29 00:56:20 truenas k3s[99312]: Trace[1167841456]: [3.30621827s] [3.30621827s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.740578 99312 trace.go:205] Trace[491885248]: "List etcd3" key:/mutatingwebhookconfigurations,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.820) (total time: 2919ms): May 29 00:56:20 truenas k3s[99312]: Trace[491885248]: [2.919870226s] [2.919870226s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.761495 99312 trace.go:205] Trace[534792498]: "List etcd3" key:/validatingwebhookconfigurations,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.819) (total time: 2942ms): May 29 00:56:20 truenas k3s[99312]: Trace[534792498]: [2.942157139s] [2.942157139s] END May 29 00:56:20 truenas k3s[99312]: I0529 00:56:20.764275 99312 trace.go:205] Trace[831859955]: "List etcd3" key:/csistoragecapacities,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:17.494) (total time: 3270ms): May 29 00:56:20 truenas k3s[99312]: Trace[831859955]: [3.270206888s] [3.270206888s] END May 29 00:56:20 truenas k3s[99312]: W0529 00:56:20.964520 99312 genericapiserver.go:538] Skipping API authentication.k8s.io/v1beta1 because it has no resources. May 29 00:56:20 truenas k3s[99312]: W0529 00:56:20.984096 99312 genericapiserver.go:538] Skipping API authorization.k8s.io/v1beta1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.241647 99312 genericapiserver.go:538] Skipping API certificates.k8s.io/v1beta1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.299350 99312 genericapiserver.go:538] Skipping API coordination.k8s.io/v1beta1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.403179 99312 genericapiserver.go:538] Skipping API networking.k8s.io/v1beta1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.456460 99312 genericapiserver.go:538] Skipping API node.k8s.io/v1alpha1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.531478 99312 genericapiserver.go:538] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.531537 99312 genericapiserver.go:538] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.590711 99312 genericapiserver.go:538] Skipping API scheduling.k8s.io/v1beta1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.590776 99312 genericapiserver.go:538] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.617822 99312 genericapiserver.go:538] Skipping API storage.k8s.io/v1alpha1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.627022 99312 genericapiserver.go:538] Skipping API flowcontrol.apiserver.k8s.io/v1alpha1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.635842 99312 genericapiserver.go:538] Skipping API apps/v1beta2 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.635898 99312 genericapiserver.go:538] Skipping API apps/v1beta1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.639747 99312 genericapiserver.go:538] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources. May 29 00:56:21 truenas k3s[99312]: I0529 00:56:21.647137 99312 plugins.go:158] Loaded 12 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,RuntimeClass,DefaultIngressClass,MutatingAdmissionWebhook. May 29 00:56:21 truenas k3s[99312]: I0529 00:56:21.647184 99312 plugins.go:161] Loaded 11 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota. May 29 00:56:21 truenas k3s[99312]: W0529 00:56:21.775173 99312 genericapiserver.go:538] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources. May 29 00:56:22 truenas k3s[99312]: I0529 00:56:22.240113 99312 trace.go:205] Trace[709436931]: "List etcd3" key:/apiregistration.k8s.io/apiservices,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:21.649) (total time: 590ms): May 29 00:56:22 truenas k3s[99312]: Trace[709436931]: [590.106474ms] [590.106474ms] END May 29 00:56:22 truenas k3s[99312]: I0529 00:56:22.832664 99312 trace.go:205] Trace[1580489076]: "List etcd3" key:/secrets,resourceVersion:,resourceVersionMatch:,limit:10000,continue: (29-May-2022 00:56:15.194) (total time: 7638ms): May 29 00:56:22 truenas k3s[99312]: Trace[1580489076]: [7.638336159s] [7.638336159s] END May 29 00:56:25 truenas k3s[99312]: time="2022-05-29T00:56:25+08:00" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect" May 29 00:56:25 truenas k3s[99312]: time="2022-05-29T00:56:25+08:00" level=info msg="Handling backend connection request [ix-truenas]" May 29 00:56:25 truenas k3s[99312]: time="2022-05-29T00:56:25+08:00" level=info msg="Running kubelet --address=0.0.0.0 --anonymous-auth=false --authentication-token-webhook=true --authorization-mode=Webhook --cgroup-driver=cgroupfs --client-ca-file=/mnt/Storage/ix-applications/k3s/agent/client-ca.crt --cluster-dns=172.17.0.10 --cluster-domain=cluster.local --eviction-hard=imagefs.available<5%,nodefs.available<5% --eviction-minimum-reclaim=imagefs.available=10%,nodefs.available=10% --fail-swap-on=false --healthz-bind-address=127.0.0.1 --hostname-override=ix-truenas --kubeconfig=/mnt/Storage/ix-applications/k3s/agent/kubelet.kubeconfig --network-plugin=cni --node-ip=0.0.0.0 --node-labels= --pod-infra-container-image=rancher/mirrored-pause:3.6 --pod-manifest-path=/mnt/Storage/ix-applications/k3s/agent/pod-manifests --protect-kernel-defaults=true --read-only-port=0 --resolv-conf=/etc/resolv.conf --tls-cert-file=/mnt/Storage/ix-applications/k3s/agent/serving-kubelet.crt --tls-private-key-file=/mnt/Storage/ix-applications/k3s/agent/serving-kubelet.key" May 29 00:56:25 truenas k3s[99312]: Flag --network-plugin has been deprecated, will be removed along with dockershim. May 29 00:56:25 truenas k3s[99312]: time="2022-05-29T00:56:25+08:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:6443/v1-k3s/readyz: 500 Internal Server Error" May 29 00:56:25 truenas systemd[1]: Started Kubernetes systemd probe. ░░ Subject: A start job for unit run-r2132d3219a7a4bda83542c08c3b2d7fa.scope has finished successfully ░░ Defined-By: systemd ░░ Support: https://www.debian.org/support ░░ ░░ A start job for unit run-r2132d3219a7a4bda83542c08c3b2d7fa.scope has finished successfully. ░░ ░░ The job identifier is 15148. May 29 00:56:25 truenas systemd[1]: run-r2132d3219a7a4bda83542c08c3b2d7fa.scope: Succeeded. ░░ Subject: Unit succeeded ░░ Defined-By: systemd ░░ Support: https://www.debian.org/support ░░ ░░ The unit run-r2132d3219a7a4bda83542c08c3b2d7fa.scope has successfully entered the 'dead' state. May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.315522 99312 server.go:442] "Kubelet version" kubeletVersion="v1.23.5+k3s-937d546a-dirty" May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.352893 99312 dynamic_cafile_content.go:156] "Starting controller" name="client-ca-bundle::/mnt/Storage/ix-applications/k3s/agent/client-ca.crt" May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.785068 99312 server.go:693] "--cgroups-per-qos enabled, but --cgroup-root was not specified. defaulting to /" May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.785430 99312 container_manager_linux.go:281] "Container manager verified user specified cgroup-root exists" cgroupRoot=[] May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.785540 99312 container_manager_linux.go:286] "Creating Container Manager object based on Node Config" nodeConfig={RuntimeCgroupsName: SystemCgroupsName: KubeletCgroupsName: ContainerRuntime:docker CgroupsPerQOS:true CgroupRoot:/ CgroupDriver:cgroupfs KubeletRootDir:/var/lib/kubelet ProtectKernelDefaults:true NodeAllocatableConfig:{KubeReservedCgroupName: SystemReservedCgroupName: ReservedSystemCPUs: EnforceNodeAllocatable:map[pods:{}] KubeReserved:map[] SystemReserved:map[] HardEvictionThresholds:[{Signal:imagefs.available Operator:LessThan Value:{Quantity: Percentage:0.05} GracePeriod:0s MinReclaim:} {Signal:nodefs.available Operator:LessThan Value:{Quantity: Percentage:0.05} GracePeriod:0s MinReclaim:}]} QOSReserved:map[] ExperimentalCPUManagerPolicy:none ExperimentalCPUManagerPolicyOptions:map[] ExperimentalTopologyManagerScope:container ExperimentalCPUManagerReconcilePeriod:10s ExperimentalMemoryManagerPolicy:None ExperimentalMemoryManagerReservedMemory:[] ExperimentalPodPidsLimit:-1 EnforceCPULimits:true CPUCFSQuotaPeriod:100ms ExperimentalTopologyManagerPolicy:none} May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.785577 99312 topology_manager.go:133] "Creating topology manager with policy per scope" topologyPolicyName="none" topologyScopeName="container" May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.785596 99312 container_manager_linux.go:321] "Creating device plugin manager" devicePluginEnabled=true May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.785655 99312 state_mem.go:36] "Initialized new in-memory state store" May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.785760 99312 kubelet.go:313] "Using dockershim is deprecated, please consider using a full-fledged CRI implementation" May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.785798 99312 client.go:80] "Connecting to docker on the dockerEndpoint" endpoint="unix:///var/run/docker.sock" May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.785820 99312 client.go:99] "Start docker client with request timeout" timeout="2m0s" May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.833699 99312 docker_service.go:571] "Hairpin mode is set but kubenet is not enabled, falling back to HairpinVeth" hairpinMode=promiscuous-bridge May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.833777 99312 docker_service.go:243] "Hairpin mode is set" hairpinMode=hairpin-veth May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.833939 99312 cni.go:240] "Unable to update cni config" err="no networks found in /etc/cni/net.d" May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.866363 99312 cni.go:240] "Unable to update cni config" err="no networks found in /etc/cni/net.d" May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.866473 99312 docker_service.go:258] "Docker cri networking managed by the network plugin" networkPluginName="cni" May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.866526 99312 cni.go:240] "Unable to update cni config" err="no networks found in /etc/cni/net.d" May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.937786 99312 docker_service.go:264] "Docker Info" dockerInfo=&{ID:LDP3:QWYG:3W4Y:7QGS:G2HL:FQ7C:3POL:3A77:LPSU:SLAL:4IDY:AZYA Containers:147 ContainersRunning:0 ContainersPaused:0 ContainersStopped:147 Images:44 Driver:zfs DriverStatus:[[Zpool Storage] [Zpool Health ONLINE] [Parent Dataset Storage/ix-applications/docker] [Space Used By Parent 12061650624] [Space Available 4357043827392] [Parent Quota no] [Compression lz4]] SystemStatus:[] Plugins:{Volume:[local] Network:[bridge host ipvlan macvlan null overlay] Authorization:[] Log:[awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog]} MemoryLimit:true SwapLimit:true KernelMemory:true KernelMemoryTCP:true CPUCfsPeriod:true CPUCfsQuota:true CPUShares:true CPUSet:true PidsLimit:true IPv4Forwarding:true BridgeNfIptables:true BridgeNfIP6tables:true Debug:false NFd:23 OomKillDisable:true NGoroutines:40 SystemTime:2022-05-29T00:56:25.869029779+08:00 LoggingDriver:json-file CgroupDriver:cgroupfs CgroupVersion:1 NEventsListener:0 KernelVersion:5.10.109+truenas OperatingSystem:Debian GNU/Linux 11 (bullseye) OSVersion:11 OSType:linux Architecture:x86_64 IndexServerAddress:https://index.docker.io/v1/ RegistryConfig:0xc0060bf880 NCPU:4 MemTotal:16218898432 GenericResources:[] DockerRootDir:/mnt/Storage/ix-applications/docker HTTPProxy: HTTPSProxy: NoProxy: Name:truenas Labels:[] ExperimentalBuild:false ServerVersion:dev ClusterStore: ClusterAdvertise: Runtimes:map[io.containerd.runc.v2:{Path:runc Args:[] Shim:} io.containerd.runtime.v1.linux:{Path:runc Args:[] Shim:} runc:{Path:runc Args:[] Shim:}] DefaultRuntime:runc Swarm:{NodeID: NodeAddr: LocalNodeState:inactive ControlAvailable:false Error: RemoteManagers:[] Nodes:0 Managers:0 Cluster: Warnings:[]} LiveRestoreEnabled:false Isolation: InitBinary:docker-init ContainerdCommit:{ID:7b11cfaabd73bb80907dd23182b9347b4245eb5d Expected:7b11cfaabd73bb80907dd23182b9347b4245eb5d} RuncCommit:{ID:v1.0.2-0-g52b36a2 Expected:v1.0.2-0-g52b36a2} InitCommit:{ID:de40ad0 Expected:de40ad0} SecurityOptions:[name=apparmor] ProductLicense: DefaultAddressPools:[] Warnings:[]} May 29 00:56:25 truenas k3s[99312]: I0529 00:56:25.937848 99312 docker_service.go:279] "Setting cgroupDriver" cgroupDriver="cgroupfs" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.019862 99312 kubelet.go:416] "Attempting to sync node with API server" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.020187 99312 kubelet.go:278] "Adding static pod path" path="/mnt/Storage/ix-applications/k3s/agent/pod-manifests" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.020388 99312 kubelet.go:289] "Adding apiserver pod source" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.020565 99312 apiserver.go:42] "Waiting for node sync before watching apiserver pods" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.033776 99312 apiserver.go:52] "Watching apiserver" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.092901 99312 kuberuntime_manager.go:249] "Container runtime initialized" containerRuntime="docker" version="dev" apiVersion="1.41.0" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.106347 99312 server.go:1231] "Started kubelet" May 29 00:56:26 truenas k3s[99312]: E0529 00:56:26.112885 99312 kubelet.go:1351] "Image garbage collection failed once. Stats initialization may not have completed yet" err="failed to get imageFs info: unable to find data in memory cache" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.122877 99312 server.go:150] "Starting to listen" address="0.0.0.0" port=10250 May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.161079 99312 server.go:410] "Adding debug handlers to kubelet server" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.180148 99312 fs_resource_analyzer.go:67] "Starting FS ResourceAnalyzer" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.212036 99312 volume_manager.go:291] "Starting Kubelet Volume Manager" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.222069 99312 desired_state_of_world_populator.go:147] "Desired state populator starts to run" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.363079 99312 kuberuntime_manager.go:1105] "Updating runtime config through cri with podcidr" CIDR="172.16.0.0/16" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.385447 99312 docker_service.go:364] "Docker cri received runtime config" runtimeConfig="&RuntimeConfig{NetworkConfig:&NetworkConfig{PodCidr:172.16.0.0/16,},}" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.429364 99312 kubelet_network.go:76] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="172.16.0.0/16" May 29 00:56:26 truenas k3s[99312]: E0529 00:56:26.429493 99312 kubelet.go:2347] "Container runtime network not ready" networkReady="NetworkReady=false reason:NetworkPluginNotReady message:docker: network plugin is not ready: cni config uninitialized" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.509521 99312 kubelet_node_status.go:70] "Attempting to register node" node="ix-truenas" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.627185 99312 kubelet_network_linux.go:57] "Initialized protocol iptables rules." protocol=IPv4 May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.652095 99312 trace.go:205] Trace[1057190855]: "Get" url:/apis/storage.k8s.io/v1/csinodes/ix-truenas,user-agent:Go-http-client/2.0,audit-id:3b4f13fc-62b9-4669-ad9b-d3d4f9c45a80,client:127.0.0.1,accept:application/vnd.kubernetes.protobuf,application/json,protocol:HTTP/2.0 (29-May-2022 00:56:26.126) (total time: 525ms): May 29 00:56:26 truenas k3s[99312]: Trace[1057190855]: ---"About to write a response" 525ms (00:56:26.651) May 29 00:56:26 truenas k3s[99312]: Trace[1057190855]: [525.542427ms] [525.542427ms] END May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.965692 99312 kubelet_network_linux.go:57] "Initialized protocol iptables rules." protocol=IPv6 May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.965751 99312 status_manager.go:159] "Starting to sync pod status with apiserver" May 29 00:56:26 truenas k3s[99312]: I0529 00:56:26.965779 99312 kubelet.go:1977] "Starting kubelet main sync loop" May 29 00:56:26 truenas k3s[99312]: E0529 00:56:26.965924 99312 kubelet.go:2001] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]" May 29 00:56:27 truenas k3s[99312]: E0529 00:56:27.066347 99312 kubelet.go:2001] "Skipping pod synchronization" err="container runtime status check may not have completed yet" May 29 00:56:27 truenas k3s[99312]: I0529 00:56:27.073248 99312 docker_sandbox.go:402] "Failed to read pod IP from plugin/docker" err="networkPlugin cni failed on the status hook for pod \"svclb-emulatorjs-front-v2z7v_ix-emulatorjs\": CNI failed to retrieve network namespace path: cannot find network namespace for the terminated container \"aab88d5b8138ada04bd654d4c5ceb961110c98a2d82bd5194a7cb5a2d2709723\"" May 29 00:56:27 truenas k3s[99312]: I0529 00:56:27.126478 99312 docker_sandbox.go:402] "Failed to read pod IP from plugin/docker" err="networkPlugin cni failed on the status hook for pod \"home-assistant-postgresql-0_ix-home-assistant\": CNI failed to retrieve network namespace path: cannot find network namespace for the terminated container \"20479c9f6b66525d51badd80f97a6bc309909653e13e70e6bf540b7c69c06404\"" May 29 00:56:27 truenas k3s[99312]: I0529 00:56:27.183795 99312 docker_sandbox.go:402] "Failed to read pod IP from plugin/docker" err="networkPlugin cni failed on the status hook for pod \"openebs-zfs-controller-0_kube-system\": CNI failed to retrieve network namespace path: cannot find network namespace for the terminated container \"ea401cad22345cae62240443c4f6c043c6081713b463638e924791f270ad8adc\"" May 29 00:56:27 truenas k3s[99312]: I0529 00:56:27.227479 99312 trace.go:205] Trace[729068837]: "Get" url:/apis/storage.k8s.io/v1/csinodes/ix-truenas,user-agent:Go-http-client/2.0,audit-id:8a52c427-7638-4548-b8c0-388c6b9070a6,client:127.0.0.1,accept:application/vnd.kubernetes.protobuf,application/json,protocol:HTTP/2.0 (29-May-2022 00:56:26.686) (total time: 540ms): May 29 00:56:27 truenas k3s[99312]: Trace[729068837]: ---"About to write a response" 540ms (00:56:27.227) May 29 00:56:27 truenas k3s[99312]: Trace[729068837]: [540.969364ms] [540.969364ms] END May 29 00:56:27 truenas k3s[99312]: E0529 00:56:27.248144 99312 kubelet.go:1431] "Failed to start ContainerManager" err="failed to build map of initial containers from runtime: no PodsandBox found with Id '03fedcbce181d2f238239ecd81549fc16190c6d522b72dcfe0696e686daea366'" May 29 00:56:27 truenas systemd[1]: k3s.service: Main process exited, code=exited, status=1/FAILURE ░░ Subject: Unit process exited ░░ Defined-By: systemd ░░ Support: https://www.debian.org/support ░░ ░░ An ExecStart= process belonging to unit k3s.service has exited. ░░ ░░ The process' exit code is 'exited' and its exit status is 1. May 29 00:56:27 truenas systemd[1]: k3s.service: Failed with result 'exit-code'. ░░ Subject: Unit failed ░░ Defined-By: systemd ░░ Support: https://www.debian.org/support ░░ ░░ The unit k3s.service has entered the 'failed' state with result 'exit-code'. May 29 00:56:27 truenas systemd[1]: Failed to start Lightweight Kubernetes. ░░ Subject: A start job for unit k3s.service has failed ░░ Defined-By: systemd ░░ Support: https://www.debian.org/support ░░ ░░ A start job for unit k3s.service has finished with a failure. ░░ ░░ The job identifier is 15086 and the job result is failed.