+--------------------------------------------------------------------------------+
+                      Kubernetes Configuration @1676842806                      +
+--------------------------------------------------------------------------------+
{
  "id": 1,
  "pool": "LUNE01-SSD",
  "cluster_cidr": "172.16.0.0/16",
  "service_cidr": "172.17.0.0/16",
  "cluster_dns_ip": "172.17.0.10",
  "route_v4_interface": null,
  "route_v4_gateway": "",
  "route_v6_interface": null,
  "route_v6_gateway": null,
  "node_ip": "0.0.0.0",
  "configure_gpus": true,
  "servicelb": true,
  "validate_host_path": true,
  "dataset": "LUNE01-SSD/ix-applications"
}
debug finished in 0 seconds for Kubernetes Configuration


+--------------------------------------------------------------------------------+
+                     K3s Logs (last 1000 lines) @1676842806                     +
+--------------------------------------------------------------------------------+
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.479297 3310503 server.go:410] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="Stopped tunnel to 127.0.0.1:6443"
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="Connecting to proxy" url="wss://192.168.5.4:6443/v1-k3s/connect"
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:6443/v1-k3s/connect"
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF"
Feb 19 22:39:18 srv-nas k3s[3310503]: W0219 22:39:18.480833 3310503 manager.go:159] Cannot detect current cgroup on cgroup v2
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.480851 3310503 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/agent/client-ca.crt"
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="Tunnel authorizer set Kubelet Port 10250"
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="Handling backend connection request [ix-truenas]"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.505066 3310503 server.go:655] "--cgroups-per-qos enabled, but --cgroup-root was not specified.  defaulting to /"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.505225 3310503 container_manager_linux.go:262] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.505277 3310503 container_manager_linux.go:267] "Creating Container Manager object based on Node Config" nodeConfig={RuntimeCgroupsName: SystemCgroupsName: KubeletCgroupsName: KubeletOOMScoreAdj:-999 ContainerRuntime: 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:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>} {Signal:nodefs.available Operator:LessThan Value:{Quantity:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>}]} QOSReserved:map[] ExperimentalCPUManagerPolicy:none ExperimentalCPUManagerPolicyOptions:map[] ExperimentalTopologyManagerScope:container ExperimentalCPUManagerReconcilePeriod:10s ExperimentalMemoryManagerPolicy:None ExperimentalMemoryManagerReservedMemory:[] ExperimentalPodPidsLimit:-1 EnforceCPULimits:true CPUCFSQuotaPeriod:100ms ExperimentalTopologyManagerPolicy:none}
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.505292 3310503 topology_manager.go:134] "Creating topology manager with policy per scope" topologyPolicyName="none" topologyScopeName="container"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.505302 3310503 container_manager_linux.go:302] "Creating device plugin manager" devicePluginEnabled=true
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.505326 3310503 state_mem.go:36] "Initialized new in-memory state store"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.506588 3310503 kubelet.go:381] "Attempting to sync node with API server"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.506602 3310503 kubelet.go:270] "Adding static pod path" path="/mnt/LUNE01-SSD/ix-applications/k3s/agent/pod-manifests"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.506625 3310503 kubelet.go:281] "Adding apiserver pod source"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.506639 3310503 apiserver.go:42] "Waiting for node sync before watching apiserver pods"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.521382 3310503 kuberuntime_manager.go:240] "Container runtime initialized" containerRuntime="docker" version="dev" apiVersion="1.41.0"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.522065 3310503 server.go:1170] "Started kubelet"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.524210 3310503 server.go:155] "Starting to listen" address="0.0.0.0" port=10250
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.525329 3310503 server.go:438] "Adding debug handlers to kubelet server"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.525363 3310503 fs_resource_analyzer.go:67] "Starting FS ResourceAnalyzer"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.525666 3310503 volume_manager.go:293] "Starting Kubelet Volume Manager"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.525951 3310503 desired_state_of_world_populator.go:149] "Desired state populator starts to run"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.530415 3310503 controller.go:616] quota admission added evaluator for: leases.coordination.k8s.io
Feb 19 22:39:18 srv-nas k3s[3310503]: E0219 22:39:18.532472 3310503 cri_stats_provider.go:452] "Failed to get the info of the filesystem with mountpoint" err="unable to find data in memory cache" mountpoint="/mnt/LUNE01-SSD/ix-applications/docker"
Feb 19 22:39:18 srv-nas k3s[3310503]: E0219 22:39:18.532497 3310503 kubelet.go:1317] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.544181 3310503 kubelet_network_linux.go:63] "Initialized iptables rules." protocol=IPv4
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.552019 3310503 kubelet_network_linux.go:63] "Initialized iptables rules." protocol=IPv6
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.552034 3310503 status_manager.go:161] "Starting to sync pod status with apiserver"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.552045 3310503 kubelet.go:2010] "Starting kubelet main sync loop"
Feb 19 22:39:18 srv-nas k3s[3310503]: E0219 22:39:18.552110 3310503 kubelet.go:2034] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.559195 3310503 cpu_manager.go:213] "Starting CPU manager" policy="none"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.559205 3310503 cpu_manager.go:214] "Reconciling" reconcilePeriod="10s"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.559219 3310503 state_mem.go:36] "Initialized new in-memory state store"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.559332 3310503 state_mem.go:88] "Updated default CPUSet" cpuSet=""
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.559342 3310503 state_mem.go:96] "Updated CPUSet assignments" assignments=map[]
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.559347 3310503 policy_none.go:49] "None policy: Start"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.559831 3310503 memory_manager.go:168] "Starting memorymanager" policy="None"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.559847 3310503 state_mem.go:35] "Initializing new in-memory state store"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.559961 3310503 state_mem.go:75] "Updated machine memory state"
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="Waiting for cloud-controller-manager privileges to become available"
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="Kube API server is now running"
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="ETCD server is now running"
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="k3s is up and running"
Feb 19 22:39:18 srv-nas systemd[1]: Started Lightweight Kubernetes.
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="Applying CRD addons.k3s.cattle.io"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.626993 3310503 kuberuntime_manager.go:1050] "Updating runtime config through cri with podcidr" CIDR="172.16.0.0/16"
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="Docker cri received runtime config &RuntimeConfig{NetworkConfig:&NetworkConfig{PodCidr:172.16.0.0/16,},}"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.627230 3310503 kubelet_network.go:60] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="172.16.0.0/16"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.632093 3310503 kubelet_node_status.go:70] "Attempting to register node" node="ix-truenas"
Feb 19 22:39:18 srv-nas k3s[3310503]: time="2023-02-19T22:39:18+01:00" level=info msg="Applying CRD helmcharts.helm.cattle.io"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.638360 3310503 kubelet_node_status.go:108] "Node was previously registered" node="ix-truenas"
Feb 19 22:39:18 srv-nas k3s[3310503]: I0219 22:39:18.638450 3310503 kubelet_node_status.go:73] "Successfully registered node" node="ix-truenas"
Feb 19 22:39:18 srv-nas k3s[3310503]: E0219 22:39:18.641742 3310503 kubelet.go:1397] "Failed to start ContainerManager" err="failed to initialize top level QOS containers: root container [kubepods] doesn't exist"
Feb 19 22:39:18 srv-nas systemd[1]: k3s.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 22:39:18 srv-nas systemd[1]: k3s.service: Failed with result 'exit-code'.
Feb 19 22:39:18 srv-nas systemd[1]: k3s.service: Consumed 3.647s CPU time.
Feb 19 22:39:23 srv-nas systemd[1]: k3s.service: Scheduled restart job, restart counter is at 40.
Feb 19 22:39:23 srv-nas systemd[1]: Stopped Lightweight Kubernetes.
Feb 19 22:39:23 srv-nas systemd[1]: k3s.service: Consumed 3.647s CPU time.
Feb 19 22:39:23 srv-nas systemd[1]: Starting Lightweight Kubernetes...
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Starting k3s v1.25.3+k3s-9afcd6b9-dirty (9afcd6b9)"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Configuring sqlite3 database connection pooling: maxIdleConns=2, maxOpenConns=0, connMaxLifetime=0s"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Configuring database table schema and indexes, this may take a moment..."
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Database tables and indexes are up to date"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Kine available at unix://kine.sock"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Reconciling bootstrap data between datastore and disk"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Tunnel server egress proxy mode: agent"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Tunnel server egress proxy waiting for runtime core to become available"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Running kube-apiserver --advertise-address=192.168.5.4 --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/LUNE01-SSD/ix-applications/k3s/server/tls/temporary-certs --client-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --egress-selector-config-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/etc/egress-selector-config.yaml --enable-admission-plugins=NodeRestriction,NamespaceLifecycle,ServiceAccount --enable-aggregator-routing=true --etcd-servers=unix://kine.sock --feature-gates=MixedProtocolLBService=true --kubelet-certificate-authority=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --kubelet-client-certificate=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-kube-apiserver.crt --kubelet-client-key=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-kube-apiserver.key --kubelet-preferred-address-types=InternalIP,ExternalIP,Hostname --profiling=false --proxy-client-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.crt --proxy-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.key --requestheader-allowed-names=system:auth-proxy --requestheader-client-ca-file=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/service.key --service-account-lookup=true --service-account-signing-key-file=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.crt --tls-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.key"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Running kube-scheduler --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --bind-address=127.0.0.1 --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --leader-elect=false --profiling=false --secure-port=10259"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Waiting for API server to become available"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Running kube-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/controller.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --cluster-signing-kube-apiserver-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.key --cluster-signing-kubelet-client-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --cluster-signing-kubelet-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.key --cluster-signing-kubelet-serving-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --cluster-signing-kubelet-serving-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.key --cluster-signing-legacy-unknown-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --cluster-signing-legacy-unknown-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.key --feature-gates=JobTrackingWithFinalizers=true --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/controller.kubeconfig --leader-elect=false --node-cidr-mask-size=16 --profiling=false --root-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --secure-port=10257 --service-account-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/service.key --service-cluster-ip-range=172.17.0.0/16 --terminated-pod-gc-threshold=5 --use-service-account-credentials=true"
Feb 19 22:39:24 srv-nas k3s[3312113]: I0219 22:39:24.222852 3312113 server.go:581] external host was not specified, using 192.168.5.4
Feb 19 22:39:24 srv-nas k3s[3312113]: I0219 22:39:24.223076 3312113 server.go:171] Version: v1.25.3+k3s-9afcd6b9-dirty
Feb 19 22:39:24 srv-nas k3s[3312113]: I0219 22:39:24.223090 3312113 server.go:173] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Running cloud-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --bind-address=127.0.0.1 --cloud-config=/mnt/LUNE01-SSD/ix-applications/k3s/server/etc/cloud-config.yaml --cloud-provider=k3s --cluster-cidr=172.16.0.0/16 --configure-cloud-routes=false --controllers=*,-route,-cloud-node,-cloud-node-lifecycle --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --leader-elect=false --leader-elect-resource-name=k3s-cloud-controller-manager --node-status-update-frequency=1m0s --profiling=false"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Server node token is available at /mnt/LUNE01-SSD/ix-applications/k3s/server/token"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="To join server node to cluster: k3s server -s https://192.168.5.4:6443 -t ${SERVER_NODE_TOKEN}"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Agent node token is available at /mnt/LUNE01-SSD/ix-applications/k3s/server/agent-token"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="To join agent node to cluster: k3s agent -s https://192.168.5.4:6443 -t ${AGENT_NODE_TOKEN}"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Run: k3s kubectl"
Feb 19 22:39:24 srv-nas k3s[3312113]: I0219 22:39:24.241322 3312113 shared_informer.go:255] Waiting for caches to sync for node_authorizer
Feb 19 22:39:24 srv-nas k3s[3312113]: I0219 22:39:24.242504 3312113 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.
Feb 19 22:39:24 srv-nas k3s[3312113]: I0219 22:39:24.242528 3312113 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.
Feb 19 22:39:24 srv-nas k3s[3312113]: I0219 22:39:24.243771 3312113 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.
Feb 19 22:39:24 srv-nas k3s[3312113]: I0219 22:39:24.243784 3312113 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.
Feb 19 22:39:24 srv-nas k3s[3312113]: {"level":"warn","ts":"2023-02-19T22:39:24.246+0100","logger":"etcd-client","caller":"v3@v3.5.3-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc001e9e000/kine.sock","attempt":0,"error":"rpc error: code = Unknown desc = no such table: dbstat"}
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="certificate CN=ix-truenas signed by CN=k3s-server-ca@1676395070: notBefore=2023-02-14 17:17:50 +0000 UTC notAfter=2024-02-19 21:39:24 +0000 UTC"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="certificate CN=system:node:ix-truenas,O=system:nodes signed by CN=k3s-client-ca@1676395070: notBefore=2023-02-14 17:17:50 +0000 UTC notAfter=2024-02-19 21:39:24 +0000 UTC"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Module overlay was already loaded"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Module nf_conntrack was already loaded"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Module br_netfilter was already loaded"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Module iptable_nat was already loaded"
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.265066 3312113 genericapiserver.go:656] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: I0219 22:39:24.265860 3312113 instance.go:261] Using reconciler: lease
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Running cri-dockerd --container-runtime-endpoint=unix:///run/k3s/cri-dockerd/cri-dockerd.sock --cri-dockerd-root-directory=/mnt/LUNE01-SSD/ix-applications/k3s/agent/cri-dockerd --network-plugin=cni --pod-infra-container-image=rancher/mirrored-pause:3.6"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Connecting to docker on the Endpoint unix:///var/run/docker.sock"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Start docker client with request timeout 0s"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Running kubelet --address=0.0.0.0 --allowed-unsafe-sysctls=net.ipv4.ip_forward,net.ipv6.conf.all.forwarding --anonymous-auth=false --authentication-token-webhook=true --authorization-mode=Webhook --cgroup-driver=cgroupfs --client-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/client-ca.crt --cluster-dns=172.17.0.10 --cluster-domain=cluster.local --container-runtime-endpoint=unix:///run/k3s/cri-dockerd/cri-dockerd.sock --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/LUNE01-SSD/ix-applications/k3s/agent/kubelet.kubeconfig --max-pods=250 --node-ip=0.0.0.0 --node-labels= --pod-infra-container-image=rancher/mirrored-pause:3.6 --pod-manifest-path=/mnt/LUNE01-SSD/ix-applications/k3s/agent/pod-manifests --protect-kernel-defaults=true --read-only-port=0 --resolv-conf=/etc/resolv.conf --serialize-image-pulls=false --tls-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/serving-kubelet.crt --tls-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/serving-kubelet.key"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Handling backend connection request [ix-truenas]"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Hairpin mode is set to none"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01: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"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Loaded network plugin cni"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Docker cri networking managed by network plugin cni"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Docker Info: &{ID:BKP5:UDTS:L4SB:F4DH:ZHKD:G4IO:CPIK:V3L2:LUIN:WSG6:7ANG:TRQ2 Containers:0 ContainersRunning:0 ContainersPaused:0 ContainersStopped:0 Images:4 Driver:overlay2 DriverStatus:[[Backing Filesystem zfs] [Supports d_type true] [Native Overlay Diff true] [userxattr false]] 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:false KernelMemoryTCP:false CPUCfsPeriod:true CPUCfsQuota:true CPUShares:true CPUSet:true PidsLimit:true IPv4Forwarding:true BridgeNfIptables:true BridgeNfIP6tables:true Debug:false NFd:23 OomKillDisable:false NGoroutines:40 SystemTime:2023-02-19T22:39:24.30520564+01:00 LoggingDriver:json-file CgroupDriver:cgroupfs CgroupVersion:2 NEventsListener:0 KernelVersion:5.15.79+truenas OperatingSystem:Debian GNU/Linux 11 (bullseye) OSVersion:11 OSType:linux Architecture:x86_64 IndexServerAddress:https://index.docker.io/v1/ RegistryConfig:0xc00077f6c0 NCPU:8 MemTotal:33604182016 GenericResources:[] DockerRootDir:/mnt/LUNE01-SSD/ix-applications/docker HTTPProxy: HTTPSProxy: NoProxy: Name:srv-nas Labels:[] ExperimentalBuild:false ServerVersion:dev ClusterStore: ClusterAdvertise: Runtimes:map[io.containerd.runc.v2:{Path:runc Args:[] Shim:<nil>} io.containerd.runtime.v1.linux:{Path:runc Args:[] Shim:<nil>} runc:{Path:runc Args:[] Shim:<nil>}] DefaultRuntime:runc Swarm:{NodeID: NodeAddr: LocalNodeState:inactive ControlAvailable:false Error: RemoteManagers:[] Nodes:0 Managers:0 Cluster:<nil> Warnings:[]} LiveRestoreEnabled:false Isolation: InitBinary:docker-init ContainerdCommit:{ID:9cd3357b7fd7218e4aec3eae239db1f68a5a6ec6 Expected:9cd3357b7fd7218e4aec3eae239db1f68a5a6ec6} RuncCommit:{ID:v1.1.4-0-g5fd4c4d Expected:v1.1.4-0-g5fd4c4d} InitCommit:{ID:de40ad0 Expected:de40ad0} SecurityOptions:[name=apparmor name=cgroupns] ProductLicense: DefaultAddressPools:[] Warnings:[]}"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Setting cgroupDriver cgroupfs"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Docker cri received runtime config &RuntimeConfig{NetworkConfig:&NetworkConfig{PodCidr:,},}"
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Starting the GRPC backend for the Docker CRI interface."
Feb 19 22:39:24 srv-nas k3s[3312113]: time="2023-02-19T22:39:24+01:00" level=info msg="Start cri-dockerd grpc backend"
Feb 19 22:39:24 srv-nas k3s[3312113]: I0219 22:39:24.334392 3312113 instance.go:574] API group "internal.apiserver.k8s.io" is not enabled, skipping.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.422078 3312113 genericapiserver.go:656] Skipping API authentication.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.423141 3312113 genericapiserver.go:656] Skipping API authorization.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.426349 3312113 genericapiserver.go:656] Skipping API autoscaling/v2beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.429006 3312113 genericapiserver.go:656] Skipping API batch/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.430183 3312113 genericapiserver.go:656] Skipping API certificates.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.431224 3312113 genericapiserver.go:656] Skipping API coordination.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.431248 3312113 genericapiserver.go:656] Skipping API discovery.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.434095 3312113 genericapiserver.go:656] Skipping API networking.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.434105 3312113 genericapiserver.go:656] Skipping API networking.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.435008 3312113 genericapiserver.go:656] Skipping API node.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.435015 3312113 genericapiserver.go:656] Skipping API node.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.435049 3312113 genericapiserver.go:656] Skipping API policy/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.437846 3312113 genericapiserver.go:656] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.437857 3312113 genericapiserver.go:656] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.438984 3312113 genericapiserver.go:656] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.438992 3312113 genericapiserver.go:656] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.441887 3312113 genericapiserver.go:656] Skipping API storage.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.444548 3312113 genericapiserver.go:656] Skipping API flowcontrol.apiserver.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.447224 3312113 genericapiserver.go:656] Skipping API apps/v1beta2 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.447234 3312113 genericapiserver.go:656] Skipping API apps/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.448633 3312113 genericapiserver.go:656] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.449698 3312113 genericapiserver.go:656] Skipping API events.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:24 srv-nas k3s[3312113]: I0219 22:39:24.450302 3312113 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.
Feb 19 22:39:24 srv-nas k3s[3312113]: I0219 22:39:24.450313 3312113 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.
Feb 19 22:39:24 srv-nas k3s[3312113]: W0219 22:39:24.461375 3312113 genericapiserver.go:656] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.335285 3312113 dynamic_cafile_content.go:157] "Starting controller" name="request-header::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/request-header-ca.crt"
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.335294 3312113 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt"
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.335471 3312113 dynamic_serving_content.go:132] "Starting controller" name="serving-cert::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.crt::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.key"
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.335543 3312113 secure_serving.go:210] Serving securely on 127.0.0.1:6444
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.335575 3312113 tlsconfig.go:240] "Starting DynamicServingCertificateController"
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.335631 3312113 apiservice_controller.go:97] Starting APIServiceRegistrationController
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.335641 3312113 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.335672 3312113 dynamic_serving_content.go:132] "Starting controller" name="aggregator-proxy-cert::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.crt::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.key"
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.335919 3312113 controller.go:80] Starting OpenAPI V3 AggregationController
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.336009 3312113 autoregister_controller.go:141] Starting autoregister controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.336017 3312113 cache.go:32] Waiting for caches to sync for autoregister controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.336019 3312113 cluster_authentication_trust_controller.go:440] Starting cluster_authentication_trust_controller controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.336033 3312113 shared_informer.go:255] Waiting for caches to sync for cluster_authentication_trust_controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.336052 3312113 crdregistration_controller.go:111] Starting crd-autoregister controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.336057 3312113 shared_informer.go:255] Waiting for caches to sync for crd-autoregister
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.336061 3312113 controller.go:83] Starting OpenAPI AggregationController
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.336165 3312113 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt"
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.336170 3312113 available_controller.go:491] Starting AvailableConditionController
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.336183 3312113 cache.go:32] Waiting for caches to sync for AvailableConditionController controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.336211 3312113 apf_controller.go:300] Starting API Priority and Fairness config controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.337931 3312113 dynamic_cafile_content.go:157] "Starting controller" name="request-header::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/request-header-ca.crt"
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.353739 3312113 customresource_discovery_controller.go:209] Starting DiscoveryController
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.354098 3312113 controller.go:85] Starting OpenAPI controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.354125 3312113 controller.go:85] Starting OpenAPI V3 controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.354141 3312113 naming_controller.go:291] Starting NamingConditionController
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.354151 3312113 establishing_controller.go:76] Starting EstablishingController
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.354163 3312113 nonstructuralschema_controller.go:192] Starting NonStructuralSchemaConditionController
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.354171 3312113 apiapproval_controller.go:186] Starting KubernetesAPIApprovalPolicyConformantConditionController
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.354181 3312113 crd_finalizer.go:266] Starting CRDFinalizer
Feb 19 22:39:25 srv-nas k3s[3312113]: E0219 22:39:25.371069 3312113 controller.go:163] Error removing old endpoints from kubernetes service: no master IPs were listed in storage, refusing to erase all endpoints for the kubernetes service
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.435720 3312113 cache.go:39] Caches are synced for APIServiceRegistrationController controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.436915 3312113 apf_controller.go:305] Running API Priority and Fairness config worker
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.436942 3312113 cache.go:39] Caches are synced for AvailableConditionController controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.436954 3312113 shared_informer.go:262] Caches are synced for crd-autoregister
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.436967 3312113 cache.go:39] Caches are synced for autoregister controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.437154 3312113 shared_informer.go:262] Caches are synced for cluster_authentication_trust_controller
Feb 19 22:39:25 srv-nas k3s[3312113]: I0219 22:39:25.441693 3312113 shared_informer.go:262] Caches are synced for node_authorizer
Feb 19 22:39:26 srv-nas k3s[3312113]: I0219 22:39:26.169970 3312113 controller.go:132] OpenAPI AggregationController: action for item k8s_internal_local_delegation_chain_0000000000: Nothing (removed from the queue).
Feb 19 22:39:26 srv-nas k3s[3312113]: I0219 22:39:26.338728 3312113 storage_scheduling.go:111] all system priority classes are created successfully or already exist.
Feb 19 22:39:27 srv-nas k3s[3312113]: Flag --pod-infra-container-image has been deprecated, will be removed in 1.27. Image garbage collector will get sandbox image information from CRI.
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.291614 3312113 server.go:199] "--pod-infra-container-image will not be pruned by the image garbage collector in kubelet and should also be set in the remote runtime"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.292908 3312113 server.go:408] "Kubelet version" kubeletVersion="v1.25.3+k3s-9afcd6b9-dirty"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.292918 3312113 server.go:410] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Feb 19 22:39:27 srv-nas k3s[3312113]: W0219 22:39:27.293803 3312113 manager.go:159] Cannot detect current cgroup on cgroup v2
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.293831 3312113 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/agent/client-ca.crt"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Annotations and labels have already set on node: ix-truenas"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Stopped tunnel to 127.0.0.1:6443"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Connecting to proxy" url="wss://192.168.5.4:6443/v1-k3s/connect"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:6443/v1-k3s/connect"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Tunnel authorizer set Kubelet Port 10250"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Handling backend connection request [ix-truenas]"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.315578 3312113 server.go:655] "--cgroups-per-qos enabled, but --cgroup-root was not specified.  defaulting to /"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.315700 3312113 container_manager_linux.go:262] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.315741 3312113 container_manager_linux.go:267] "Creating Container Manager object based on Node Config" nodeConfig={RuntimeCgroupsName: SystemCgroupsName: KubeletCgroupsName: KubeletOOMScoreAdj:-999 ContainerRuntime: 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:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>} {Signal:nodefs.available Operator:LessThan Value:{Quantity:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>}]} QOSReserved:map[] ExperimentalCPUManagerPolicy:none ExperimentalCPUManagerPolicyOptions:map[] ExperimentalTopologyManagerScope:container ExperimentalCPUManagerReconcilePeriod:10s ExperimentalMemoryManagerPolicy:None ExperimentalMemoryManagerReservedMemory:[] ExperimentalPodPidsLimit:-1 EnforceCPULimits:true CPUCFSQuotaPeriod:100ms ExperimentalTopologyManagerPolicy:none}
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.315758 3312113 topology_manager.go:134] "Creating topology manager with policy per scope" topologyPolicyName="none" topologyScopeName="container"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.315765 3312113 container_manager_linux.go:302] "Creating device plugin manager" devicePluginEnabled=true
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.315785 3312113 state_mem.go:36] "Initialized new in-memory state store"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.317031 3312113 kubelet.go:381] "Attempting to sync node with API server"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.317051 3312113 kubelet.go:270] "Adding static pod path" path="/mnt/LUNE01-SSD/ix-applications/k3s/agent/pod-manifests"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.317089 3312113 kubelet.go:281] "Adding apiserver pod source"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.317114 3312113 apiserver.go:42] "Waiting for node sync before watching apiserver pods"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.323527 3312113 kuberuntime_manager.go:240] "Container runtime initialized" containerRuntime="docker" version="dev" apiVersion="1.41.0"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.323918 3312113 server.go:1170] "Started kubelet"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.323952 3312113 server.go:155] "Starting to listen" address="0.0.0.0" port=10250
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.324642 3312113 server.go:438] "Adding debug handlers to kubelet server"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.324893 3312113 fs_resource_analyzer.go:67] "Starting FS ResourceAnalyzer"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.325481 3312113 volume_manager.go:293] "Starting Kubelet Volume Manager"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.325545 3312113 desired_state_of_world_populator.go:149] "Desired state populator starts to run"
Feb 19 22:39:27 srv-nas k3s[3312113]: E0219 22:39:27.330444 3312113 cri_stats_provider.go:452] "Failed to get the info of the filesystem with mountpoint" err="unable to find data in memory cache" mountpoint="/mnt/LUNE01-SSD/ix-applications/docker"
Feb 19 22:39:27 srv-nas k3s[3312113]: E0219 22:39:27.330472 3312113 kubelet.go:1317] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.331723 3312113 controller.go:616] quota admission added evaluator for: leases.coordination.k8s.io
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.343154 3312113 kubelet_network_linux.go:63] "Initialized iptables rules." protocol=IPv4
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.351094 3312113 kubelet_network_linux.go:63] "Initialized iptables rules." protocol=IPv6
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.351112 3312113 status_manager.go:161] "Starting to sync pod status with apiserver"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.351126 3312113 kubelet.go:2010] "Starting kubelet main sync loop"
Feb 19 22:39:27 srv-nas k3s[3312113]: E0219 22:39:27.351202 3312113 kubelet.go:2034] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.357034 3312113 cpu_manager.go:213] "Starting CPU manager" policy="none"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.357044 3312113 cpu_manager.go:214] "Reconciling" reconcilePeriod="10s"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.357054 3312113 state_mem.go:36] "Initialized new in-memory state store"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.357198 3312113 state_mem.go:88] "Updated default CPUSet" cpuSet=""
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.357214 3312113 state_mem.go:96] "Updated CPUSet assignments" assignments=map[]
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.357219 3312113 policy_none.go:49] "None policy: Start"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.357640 3312113 memory_manager.go:168] "Starting memorymanager" policy="None"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.357657 3312113 state_mem.go:35] "Initializing new in-memory state store"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.357768 3312113 state_mem.go:75] "Updated machine memory state"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Waiting for cloud-controller-manager privileges to become available"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Kube API server is now running"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="ETCD server is now running"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="k3s is up and running"
Feb 19 22:39:27 srv-nas systemd[1]: Started Lightweight Kubernetes.
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Applying CRD addons.k3s.cattle.io"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Applying CRD helmcharts.helm.cattle.io"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Applying CRD helmchartconfigs.helm.cattle.io"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.425635 3312113 kuberuntime_manager.go:1050] "Updating runtime config through cri with podcidr" CIDR="172.16.0.0/16"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Docker cri received runtime config &RuntimeConfig{NetworkConfig:&NetworkConfig{PodCidr:172.16.0.0/16,},}"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.425950 3312113 kubelet_network.go:60] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="172.16.0.0/16"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.432964 3312113 kubelet_node_status.go:70] "Attempting to register node" node="ix-truenas"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.438605 3312113 kubelet_node_status.go:108] "Node was previously registered" node="ix-truenas"
Feb 19 22:39:27 srv-nas k3s[3312113]: I0219 22:39:27.438705 3312113 kubelet_node_status.go:73] "Successfully registered node" node="ix-truenas"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Writing static file: /mnt/LUNE01-SSD/ix-applications/k3s/server/static/charts/traefik-10.19.300.tgz"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Writing static file: /mnt/LUNE01-SSD/ix-applications/k3s/server/static/charts/traefik-crd-10.19.300.tgz"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Writing manifest: /mnt/LUNE01-SSD/ix-applications/k3s/server/manifests/rolebindings.yaml"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Writing manifest: /mnt/LUNE01-SSD/ix-applications/k3s/server/manifests/ccm.yaml"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Writing manifest: /mnt/LUNE01-SSD/ix-applications/k3s/server/manifests/zfs-operator.yaml"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Writing manifest: /mnt/LUNE01-SSD/ix-applications/k3s/server/manifests/coredns.yaml"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Writing manifest: /mnt/LUNE01-SSD/ix-applications/k3s/server/manifests/kuberouter.yaml"
Feb 19 22:39:27 srv-nas k3s[3312113]: time="2023-02-19T22:39:27+01:00" level=info msg="Writing manifest: /mnt/LUNE01-SSD/ix-applications/k3s/server/manifests/multus-daemonset.yaml"
Feb 19 22:39:27 srv-nas k3s[3312113]: E0219 22:39:27.451256 3312113 kubelet.go:2034] "Skipping pod synchronization" err="container runtime status check may not have completed yet"
Feb 19 22:39:27 srv-nas k3s[3312113]: E0219 22:39:27.452696 3312113 kubelet.go:1397] "Failed to start ContainerManager" err="failed to initialize top level QOS containers: root container [kubepods] doesn't exist"
Feb 19 22:39:27 srv-nas systemd[1]: k3s.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 22:39:27 srv-nas systemd[1]: k3s.service: Failed with result 'exit-code'.
Feb 19 22:39:27 srv-nas systemd[1]: k3s.service: Consumed 3.842s CPU time.
Feb 19 22:39:32 srv-nas systemd[1]: k3s.service: Scheduled restart job, restart counter is at 41.
Feb 19 22:39:32 srv-nas systemd[1]: Stopped Lightweight Kubernetes.
Feb 19 22:39:32 srv-nas systemd[1]: k3s.service: Consumed 3.842s CPU time.
Feb 19 22:39:32 srv-nas systemd[1]: Starting Lightweight Kubernetes...
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Starting k3s v1.25.3+k3s-9afcd6b9-dirty (9afcd6b9)"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Configuring sqlite3 database connection pooling: maxIdleConns=2, maxOpenConns=0, connMaxLifetime=0s"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Configuring database table schema and indexes, this may take a moment..."
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Database tables and indexes are up to date"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Kine available at unix://kine.sock"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Reconciling bootstrap data between datastore and disk"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Tunnel server egress proxy mode: agent"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Tunnel server egress proxy waiting for runtime core to become available"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Running kube-apiserver --advertise-address=192.168.5.4 --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/LUNE01-SSD/ix-applications/k3s/server/tls/temporary-certs --client-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --egress-selector-config-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/etc/egress-selector-config.yaml --enable-admission-plugins=NodeRestriction,NamespaceLifecycle,ServiceAccount --enable-aggregator-routing=true --etcd-servers=unix://kine.sock --feature-gates=MixedProtocolLBService=true --kubelet-certificate-authority=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --kubelet-client-certificate=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-kube-apiserver.crt --kubelet-client-key=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-kube-apiserver.key --kubelet-preferred-address-types=InternalIP,ExternalIP,Hostname --profiling=false --proxy-client-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.crt --proxy-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.key --requestheader-allowed-names=system:auth-proxy --requestheader-client-ca-file=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/service.key --service-account-lookup=true --service-account-signing-key-file=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.crt --tls-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.key"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Running kube-scheduler --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --bind-address=127.0.0.1 --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --leader-elect=false --profiling=false --secure-port=10259"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Waiting for API server to become available"
Feb 19 22:39:32 srv-nas k3s[3313662]: I0219 22:39:32.994496 3313662 server.go:581] external host was not specified, using 192.168.5.4
Feb 19 22:39:32 srv-nas k3s[3313662]: I0219 22:39:32.994749 3313662 server.go:171] Version: v1.25.3+k3s-9afcd6b9-dirty
Feb 19 22:39:32 srv-nas k3s[3313662]: I0219 22:39:32.994769 3313662 server.go:173] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Running kube-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/controller.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --cluster-signing-kube-apiserver-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.key --cluster-signing-kubelet-client-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --cluster-signing-kubelet-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.key --cluster-signing-kubelet-serving-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --cluster-signing-kubelet-serving-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.key --cluster-signing-legacy-unknown-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --cluster-signing-legacy-unknown-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.key --feature-gates=JobTrackingWithFinalizers=true --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/controller.kubeconfig --leader-elect=false --node-cidr-mask-size=16 --profiling=false --root-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --secure-port=10257 --service-account-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/service.key --service-cluster-ip-range=172.17.0.0/16 --terminated-pod-gc-threshold=5 --use-service-account-credentials=true"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Running cloud-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --bind-address=127.0.0.1 --cloud-config=/mnt/LUNE01-SSD/ix-applications/k3s/server/etc/cloud-config.yaml --cloud-provider=k3s --cluster-cidr=172.16.0.0/16 --configure-cloud-routes=false --controllers=*,-route,-cloud-node,-cloud-node-lifecycle --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --leader-elect=false --leader-elect-resource-name=k3s-cloud-controller-manager --node-status-update-frequency=1m0s --profiling=false"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Server node token is available at /mnt/LUNE01-SSD/ix-applications/k3s/server/token"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="To join server node to cluster: k3s server -s https://192.168.5.4:6443 -t ${SERVER_NODE_TOKEN}"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Agent node token is available at /mnt/LUNE01-SSD/ix-applications/k3s/server/agent-token"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="To join agent node to cluster: k3s agent -s https://192.168.5.4:6443 -t ${AGENT_NODE_TOKEN}"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml"
Feb 19 22:39:32 srv-nas k3s[3313662]: time="2023-02-19T22:39:32+01:00" level=info msg="Run: k3s kubectl"
Feb 19 22:39:33 srv-nas k3s[3313662]: I0219 22:39:33.017285 3313662 shared_informer.go:255] Waiting for caches to sync for node_authorizer
Feb 19 22:39:33 srv-nas k3s[3313662]: I0219 22:39:33.017476 3313662 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.
Feb 19 22:39:33 srv-nas k3s[3313662]: I0219 22:39:33.017503 3313662 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.
Feb 19 22:39:33 srv-nas k3s[3313662]: I0219 22:39:33.019240 3313662 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.
Feb 19 22:39:33 srv-nas k3s[3313662]: I0219 22:39:33.019252 3313662 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.
Feb 19 22:39:33 srv-nas k3s[3313662]: {"level":"warn","ts":"2023-02-19T22:39:33.021+0100","logger":"etcd-client","caller":"v3@v3.5.3-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc000832700/kine.sock","attempt":0,"error":"rpc error: code = Unknown desc = no such table: dbstat"}
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="certificate CN=ix-truenas signed by CN=k3s-server-ca@1676395070: notBefore=2023-02-14 17:17:50 +0000 UTC notAfter=2024-02-19 21:39:33 +0000 UTC"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="certificate CN=system:node:ix-truenas,O=system:nodes signed by CN=k3s-client-ca@1676395070: notBefore=2023-02-14 17:17:50 +0000 UTC notAfter=2024-02-19 21:39:33 +0000 UTC"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Module overlay was already loaded"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Module nf_conntrack was already loaded"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Module br_netfilter was already loaded"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Module iptable_nat was already loaded"
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.040983 3313662 genericapiserver.go:656] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: I0219 22:39:33.041552 3313662 instance.go:261] Using reconciler: lease
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Running cri-dockerd --container-runtime-endpoint=unix:///run/k3s/cri-dockerd/cri-dockerd.sock --cri-dockerd-root-directory=/mnt/LUNE01-SSD/ix-applications/k3s/agent/cri-dockerd --network-plugin=cni --pod-infra-container-image=rancher/mirrored-pause:3.6"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Running kubelet --address=0.0.0.0 --allowed-unsafe-sysctls=net.ipv4.ip_forward,net.ipv6.conf.all.forwarding --anonymous-auth=false --authentication-token-webhook=true --authorization-mode=Webhook --cgroup-driver=cgroupfs --client-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/client-ca.crt --cluster-dns=172.17.0.10 --cluster-domain=cluster.local --container-runtime-endpoint=unix:///run/k3s/cri-dockerd/cri-dockerd.sock --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/LUNE01-SSD/ix-applications/k3s/agent/kubelet.kubeconfig --max-pods=250 --node-ip=0.0.0.0 --node-labels= --pod-infra-container-image=rancher/mirrored-pause:3.6 --pod-manifest-path=/mnt/LUNE01-SSD/ix-applications/k3s/agent/pod-manifests --protect-kernel-defaults=true --read-only-port=0 --resolv-conf=/etc/resolv.conf --serialize-image-pulls=false --tls-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/serving-kubelet.crt --tls-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/serving-kubelet.key"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Connecting to docker on the Endpoint unix:///var/run/docker.sock"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Start docker client with request timeout 0s"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Handling backend connection request [ix-truenas]"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01: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"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Hairpin mode is set to none"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Loaded network plugin cni"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Docker cri networking managed by network plugin cni"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Docker Info: &{ID:BKP5:UDTS:L4SB:F4DH:ZHKD:G4IO:CPIK:V3L2:LUIN:WSG6:7ANG:TRQ2 Containers:0 ContainersRunning:0 ContainersPaused:0 ContainersStopped:0 Images:4 Driver:overlay2 DriverStatus:[[Backing Filesystem zfs] [Supports d_type true] [Native Overlay Diff true] [userxattr false]] 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:false KernelMemoryTCP:false CPUCfsPeriod:true CPUCfsQuota:true CPUShares:true CPUSet:true PidsLimit:true IPv4Forwarding:true BridgeNfIptables:true BridgeNfIP6tables:true Debug:false NFd:23 OomKillDisable:false NGoroutines:40 SystemTime:2023-02-19T22:39:33.078621254+01:00 LoggingDriver:json-file CgroupDriver:cgroupfs CgroupVersion:2 NEventsListener:0 KernelVersion:5.15.79+truenas OperatingSystem:Debian GNU/Linux 11 (bullseye) OSVersion:11 OSType:linux Architecture:x86_64 IndexServerAddress:https://index.docker.io/v1/ RegistryConfig:0xc0002cc000 NCPU:8 MemTotal:33604182016 GenericResources:[] DockerRootDir:/mnt/LUNE01-SSD/ix-applications/docker HTTPProxy: HTTPSProxy: NoProxy: Name:srv-nas Labels:[] ExperimentalBuild:false ServerVersion:dev ClusterStore: ClusterAdvertise: Runtimes:map[io.containerd.runc.v2:{Path:runc Args:[] Shim:<nil>} io.containerd.runtime.v1.linux:{Path:runc Args:[] Shim:<nil>} runc:{Path:runc Args:[] Shim:<nil>}] DefaultRuntime:runc Swarm:{NodeID: NodeAddr: LocalNodeState:inactive ControlAvailable:false Error: RemoteManagers:[] Nodes:0 Managers:0 Cluster:<nil> Warnings:[]} LiveRestoreEnabled:false Isolation: InitBinary:docker-init ContainerdCommit:{ID:9cd3357b7fd7218e4aec3eae239db1f68a5a6ec6 Expected:9cd3357b7fd7218e4aec3eae239db1f68a5a6ec6} RuncCommit:{ID:v1.1.4-0-g5fd4c4d Expected:v1.1.4-0-g5fd4c4d} InitCommit:{ID:de40ad0 Expected:de40ad0} SecurityOptions:[name=apparmor name=cgroupns] ProductLicense: DefaultAddressPools:[] Warnings:[]}"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Setting cgroupDriver cgroupfs"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Docker cri received runtime config &RuntimeConfig{NetworkConfig:&NetworkConfig{PodCidr:,},}"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Starting the GRPC backend for the Docker CRI interface."
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Start cri-dockerd grpc backend"
Feb 19 22:39:33 srv-nas k3s[3313662]: time="2023-02-19T22:39:33+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:33 srv-nas k3s[3313662]: I0219 22:39:33.107483 3313662 instance.go:574] API group "internal.apiserver.k8s.io" is not enabled, skipping.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.208324 3313662 genericapiserver.go:656] Skipping API authentication.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.210247 3313662 genericapiserver.go:656] Skipping API authorization.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.213747 3313662 genericapiserver.go:656] Skipping API autoscaling/v2beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.216655 3313662 genericapiserver.go:656] Skipping API batch/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.217930 3313662 genericapiserver.go:656] Skipping API certificates.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.218984 3313662 genericapiserver.go:656] Skipping API coordination.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.219018 3313662 genericapiserver.go:656] Skipping API discovery.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.221758 3313662 genericapiserver.go:656] Skipping API networking.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.221769 3313662 genericapiserver.go:656] Skipping API networking.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.222933 3313662 genericapiserver.go:656] Skipping API node.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.222945 3313662 genericapiserver.go:656] Skipping API node.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.222997 3313662 genericapiserver.go:656] Skipping API policy/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.227272 3313662 genericapiserver.go:656] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.227294 3313662 genericapiserver.go:656] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.228890 3313662 genericapiserver.go:656] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.228904 3313662 genericapiserver.go:656] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.232108 3313662 genericapiserver.go:656] Skipping API storage.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.234858 3313662 genericapiserver.go:656] Skipping API flowcontrol.apiserver.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.237589 3313662 genericapiserver.go:656] Skipping API apps/v1beta2 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.237600 3313662 genericapiserver.go:656] Skipping API apps/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.238834 3313662 genericapiserver.go:656] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.239875 3313662 genericapiserver.go:656] Skipping API events.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:33 srv-nas k3s[3313662]: I0219 22:39:33.240492 3313662 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.
Feb 19 22:39:33 srv-nas k3s[3313662]: I0219 22:39:33.240503 3313662 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.
Feb 19 22:39:33 srv-nas k3s[3313662]: W0219 22:39:33.249926 3313662 genericapiserver.go:656] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.227434 3313662 dynamic_cafile_content.go:157] "Starting controller" name="request-header::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/request-header-ca.crt"
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.227451 3313662 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt"
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.227642 3313662 dynamic_serving_content.go:132] "Starting controller" name="serving-cert::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.crt::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.key"
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.227730 3313662 secure_serving.go:210] Serving securely on 127.0.0.1:6444
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.227786 3313662 tlsconfig.go:240] "Starting DynamicServingCertificateController"
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.227912 3313662 available_controller.go:491] Starting AvailableConditionController
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.227921 3313662 cache.go:32] Waiting for caches to sync for AvailableConditionController controller
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.227935 3313662 apf_controller.go:300] Starting API Priority and Fairness config controller
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.227948 3313662 controller.go:80] Starting OpenAPI V3 AggregationController
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.227956 3313662 dynamic_serving_content.go:132] "Starting controller" name="aggregator-proxy-cert::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.crt::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.key"
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.228218 3313662 controller.go:83] Starting OpenAPI AggregationController
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.228249 3313662 autoregister_controller.go:141] Starting autoregister controller
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.228256 3313662 cache.go:32] Waiting for caches to sync for autoregister controller
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.228273 3313662 crdregistration_controller.go:111] Starting crd-autoregister controller
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.228278 3313662 shared_informer.go:255] Waiting for caches to sync for crd-autoregister
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.228316 3313662 apiservice_controller.go:97] Starting APIServiceRegistrationController
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.228323 3313662 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.228409 3313662 cluster_authentication_trust_controller.go:440] Starting cluster_authentication_trust_controller controller
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.228417 3313662 shared_informer.go:255] Waiting for caches to sync for cluster_authentication_trust_controller
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.228505 3313662 customresource_discovery_controller.go:209] Starting DiscoveryController
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.228650 3313662 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt"
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.241365 3313662 dynamic_cafile_content.go:157] "Starting controller" name="request-header::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/request-header-ca.crt"
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.243748 3313662 controller.go:85] Starting OpenAPI V3 controller
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.243811 3313662 naming_controller.go:291] Starting NamingConditionController
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.243832 3313662 establishing_controller.go:76] Starting EstablishingController
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.243852 3313662 nonstructuralschema_controller.go:192] Starting NonStructuralSchemaConditionController
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.243867 3313662 apiapproval_controller.go:186] Starting KubernetesAPIApprovalPolicyConformantConditionController
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.243881 3313662 crd_finalizer.go:266] Starting CRDFinalizer
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.244307 3313662 controller.go:85] Starting OpenAPI controller
Feb 19 22:39:34 srv-nas k3s[3313662]: E0219 22:39:34.260129 3313662 controller.go:163] Error removing old endpoints from kubernetes service: no master IPs were listed in storage, refusing to erase all endpoints for the kubernetes service
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.318017 3313662 shared_informer.go:262] Caches are synced for node_authorizer
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.328200 3313662 apf_controller.go:305] Running API Priority and Fairness config worker
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.328243 3313662 cache.go:39] Caches are synced for AvailableConditionController controller
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.328315 3313662 shared_informer.go:262] Caches are synced for crd-autoregister
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.328343 3313662 cache.go:39] Caches are synced for autoregister controller
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.328393 3313662 cache.go:39] Caches are synced for APIServiceRegistrationController controller
Feb 19 22:39:34 srv-nas k3s[3313662]: I0219 22:39:34.328465 3313662 shared_informer.go:262] Caches are synced for cluster_authentication_trust_controller
Feb 19 22:39:35 srv-nas k3s[3313662]: I0219 22:39:35.026003 3313662 controller.go:132] OpenAPI AggregationController: action for item k8s_internal_local_delegation_chain_0000000000: Nothing (removed from the queue).
Feb 19 22:39:35 srv-nas k3s[3313662]: I0219 22:39:35.233206 3313662 storage_scheduling.go:111] all system priority classes are created successfully or already exist.
Feb 19 22:39:36 srv-nas k3s[3313662]: Flag --pod-infra-container-image has been deprecated, will be removed in 1.27. Image garbage collector will get sandbox image information from CRI.
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.057087 3313662 server.go:199] "--pod-infra-container-image will not be pruned by the image garbage collector in kubelet and should also be set in the remote runtime"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.058118 3313662 server.go:408] "Kubelet version" kubeletVersion="v1.25.3+k3s-9afcd6b9-dirty"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.058134 3313662 server.go:410] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Feb 19 22:39:36 srv-nas k3s[3313662]: W0219 22:39:36.059416 3313662 manager.go:159] Cannot detect current cgroup on cgroup v2
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.059444 3313662 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/agent/client-ca.crt"
Feb 19 22:39:36 srv-nas k3s[3313662]: time="2023-02-19T22:39:36+01:00" level=info msg="Stopped tunnel to 127.0.0.1:6443"
Feb 19 22:39:36 srv-nas k3s[3313662]: time="2023-02-19T22:39:36+01:00" level=info msg="Connecting to proxy" url="wss://192.168.5.4:6443/v1-k3s/connect"
Feb 19 22:39:36 srv-nas k3s[3313662]: time="2023-02-19T22:39:36+01:00" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:6443/v1-k3s/connect"
Feb 19 22:39:36 srv-nas k3s[3313662]: time="2023-02-19T22:39:36+01:00" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF"
Feb 19 22:39:36 srv-nas k3s[3313662]: time="2023-02-19T22:39:36+01:00" level=info msg="Annotations and labels have already set on node: ix-truenas"
Feb 19 22:39:36 srv-nas k3s[3313662]: time="2023-02-19T22:39:36+01:00" level=info msg="Tunnel authorizer set Kubelet Port 10250"
Feb 19 22:39:36 srv-nas k3s[3313662]: time="2023-02-19T22:39:36+01:00" level=info msg="Handling backend connection request [ix-truenas]"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.091047 3313662 server.go:655] "--cgroups-per-qos enabled, but --cgroup-root was not specified.  defaulting to /"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.091261 3313662 container_manager_linux.go:262] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.091338 3313662 container_manager_linux.go:267] "Creating Container Manager object based on Node Config" nodeConfig={RuntimeCgroupsName: SystemCgroupsName: KubeletCgroupsName: KubeletOOMScoreAdj:-999 ContainerRuntime: 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:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>} {Signal:nodefs.available Operator:LessThan Value:{Quantity:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>}]} QOSReserved:map[] ExperimentalCPUManagerPolicy:none ExperimentalCPUManagerPolicyOptions:map[] ExperimentalTopologyManagerScope:container ExperimentalCPUManagerReconcilePeriod:10s ExperimentalMemoryManagerPolicy:None ExperimentalMemoryManagerReservedMemory:[] ExperimentalPodPidsLimit:-1 EnforceCPULimits:true CPUCFSQuotaPeriod:100ms ExperimentalTopologyManagerPolicy:none}
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.091365 3313662 topology_manager.go:134] "Creating topology manager with policy per scope" topologyPolicyName="none" topologyScopeName="container"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.091379 3313662 container_manager_linux.go:302] "Creating device plugin manager" devicePluginEnabled=true
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.091412 3313662 state_mem.go:36] "Initialized new in-memory state store"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.092698 3313662 kubelet.go:381] "Attempting to sync node with API server"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.092712 3313662 kubelet.go:270] "Adding static pod path" path="/mnt/LUNE01-SSD/ix-applications/k3s/agent/pod-manifests"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.092733 3313662 kubelet.go:281] "Adding apiserver pod source"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.092749 3313662 apiserver.go:42] "Waiting for node sync before watching apiserver pods"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.099443 3313662 kuberuntime_manager.go:240] "Container runtime initialized" containerRuntime="docker" version="dev" apiVersion="1.41.0"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.099893 3313662 server.go:1170] "Started kubelet"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.099935 3313662 server.go:155] "Starting to listen" address="0.0.0.0" port=10250
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.101017 3313662 fs_resource_analyzer.go:67] "Starting FS ResourceAnalyzer"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.101143 3313662 server.go:438] "Adding debug handlers to kubelet server"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.102896 3313662 volume_manager.go:293] "Starting Kubelet Volume Manager"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.102977 3313662 desired_state_of_world_populator.go:149] "Desired state populator starts to run"
Feb 19 22:39:36 srv-nas k3s[3313662]: E0219 22:39:36.107547 3313662 cri_stats_provider.go:452] "Failed to get the info of the filesystem with mountpoint" err="unable to find data in memory cache" mountpoint="/mnt/LUNE01-SSD/ix-applications/docker"
Feb 19 22:39:36 srv-nas k3s[3313662]: E0219 22:39:36.107568 3313662 kubelet.go:1317] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.107648 3313662 controller.go:616] quota admission added evaluator for: leases.coordination.k8s.io
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.118518 3313662 kubelet_network_linux.go:63] "Initialized iptables rules." protocol=IPv4
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.126575 3313662 kubelet_network_linux.go:63] "Initialized iptables rules." protocol=IPv6
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.126591 3313662 status_manager.go:161] "Starting to sync pod status with apiserver"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.126609 3313662 kubelet.go:2010] "Starting kubelet main sync loop"
Feb 19 22:39:36 srv-nas k3s[3313662]: E0219 22:39:36.126686 3313662 kubelet.go:2034] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.135921 3313662 cpu_manager.go:213] "Starting CPU manager" policy="none"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.135931 3313662 cpu_manager.go:214] "Reconciling" reconcilePeriod="10s"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.135944 3313662 state_mem.go:36] "Initialized new in-memory state store"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.136065 3313662 state_mem.go:88] "Updated default CPUSet" cpuSet=""
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.136077 3313662 state_mem.go:96] "Updated CPUSet assignments" assignments=map[]
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.136082 3313662 policy_none.go:49] "None policy: Start"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.136507 3313662 memory_manager.go:168] "Starting memorymanager" policy="None"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.136523 3313662 state_mem.go:35] "Initializing new in-memory state store"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.136633 3313662 state_mem.go:75] "Updated machine memory state"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.203669 3313662 kuberuntime_manager.go:1050] "Updating runtime config through cri with podcidr" CIDR="172.16.0.0/16"
Feb 19 22:39:36 srv-nas k3s[3313662]: time="2023-02-19T22:39:36+01:00" level=info msg="Docker cri received runtime config &RuntimeConfig{NetworkConfig:&NetworkConfig{PodCidr:172.16.0.0/16,},}"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.204003 3313662 kubelet_network.go:60] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="172.16.0.0/16"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.208268 3313662 kubelet_node_status.go:70] "Attempting to register node" node="ix-truenas"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.213899 3313662 kubelet_node_status.go:108] "Node was previously registered" node="ix-truenas"
Feb 19 22:39:36 srv-nas k3s[3313662]: I0219 22:39:36.213997 3313662 kubelet_node_status.go:73] "Successfully registered node" node="ix-truenas"
Feb 19 22:39:36 srv-nas k3s[3313662]: E0219 22:39:36.227521 3313662 kubelet.go:2034] "Skipping pod synchronization" err="container runtime status check may not have completed yet"
Feb 19 22:39:36 srv-nas k3s[3313662]: E0219 22:39:36.248661 3313662 kubelet.go:1397] "Failed to start ContainerManager" err="failed to initialize top level QOS containers: root container [kubepods] doesn't exist"
Feb 19 22:39:36 srv-nas systemd[1]: k3s.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 22:39:36 srv-nas systemd[1]: k3s.service: Failed with result 'exit-code'.
Feb 19 22:39:36 srv-nas systemd[1]: Failed to start Lightweight Kubernetes.
Feb 19 22:39:36 srv-nas systemd[1]: k3s.service: Consumed 3.508s CPU time.
Feb 19 22:39:41 srv-nas systemd[1]: k3s.service: Scheduled restart job, restart counter is at 42.
Feb 19 22:39:41 srv-nas systemd[1]: Stopped Lightweight Kubernetes.
Feb 19 22:39:41 srv-nas systemd[1]: k3s.service: Consumed 3.508s CPU time.
Feb 19 22:39:41 srv-nas systemd[1]: Starting Lightweight Kubernetes...
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Starting k3s v1.25.3+k3s-9afcd6b9-dirty (9afcd6b9)"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Configuring sqlite3 database connection pooling: maxIdleConns=2, maxOpenConns=0, connMaxLifetime=0s"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Configuring database table schema and indexes, this may take a moment..."
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Database tables and indexes are up to date"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Kine available at unix://kine.sock"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Reconciling bootstrap data between datastore and disk"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Tunnel server egress proxy mode: agent"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Tunnel server egress proxy waiting for runtime core to become available"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Running kube-apiserver --advertise-address=192.168.5.4 --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/LUNE01-SSD/ix-applications/k3s/server/tls/temporary-certs --client-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --egress-selector-config-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/etc/egress-selector-config.yaml --enable-admission-plugins=NodeRestriction,NamespaceLifecycle,ServiceAccount --enable-aggregator-routing=true --etcd-servers=unix://kine.sock --feature-gates=MixedProtocolLBService=true --kubelet-certificate-authority=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --kubelet-client-certificate=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-kube-apiserver.crt --kubelet-client-key=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-kube-apiserver.key --kubelet-preferred-address-types=InternalIP,ExternalIP,Hostname --profiling=false --proxy-client-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.crt --proxy-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.key --requestheader-allowed-names=system:auth-proxy --requestheader-client-ca-file=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/service.key --service-account-lookup=true --service-account-signing-key-file=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.crt --tls-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.key"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Running kube-scheduler --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --bind-address=127.0.0.1 --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --leader-elect=false --profiling=false --secure-port=10259"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Waiting for API server to become available"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Running kube-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/controller.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --cluster-signing-kube-apiserver-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.key --cluster-signing-kubelet-client-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --cluster-signing-kubelet-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.key --cluster-signing-kubelet-serving-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --cluster-signing-kubelet-serving-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.key --cluster-signing-legacy-unknown-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --cluster-signing-legacy-unknown-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.key --feature-gates=JobTrackingWithFinalizers=true --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/controller.kubeconfig --leader-elect=false --node-cidr-mask-size=16 --profiling=false --root-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --secure-port=10257 --service-account-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/service.key --service-cluster-ip-range=172.17.0.0/16 --terminated-pod-gc-threshold=5 --use-service-account-credentials=true"
Feb 19 22:39:41 srv-nas k3s[3315057]: I0219 22:39:41.735850 3315057 server.go:581] external host was not specified, using 192.168.5.4
Feb 19 22:39:41 srv-nas k3s[3315057]: I0219 22:39:41.736084 3315057 server.go:171] Version: v1.25.3+k3s-9afcd6b9-dirty
Feb 19 22:39:41 srv-nas k3s[3315057]: I0219 22:39:41.736103 3315057 server.go:173] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Running cloud-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --bind-address=127.0.0.1 --cloud-config=/mnt/LUNE01-SSD/ix-applications/k3s/server/etc/cloud-config.yaml --cloud-provider=k3s --cluster-cidr=172.16.0.0/16 --configure-cloud-routes=false --controllers=*,-route,-cloud-node,-cloud-node-lifecycle --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --leader-elect=false --leader-elect-resource-name=k3s-cloud-controller-manager --node-status-update-frequency=1m0s --profiling=false"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Server node token is available at /mnt/LUNE01-SSD/ix-applications/k3s/server/token"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="To join server node to cluster: k3s server -s https://192.168.5.4:6443 -t ${SERVER_NODE_TOKEN}"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Agent node token is available at /mnt/LUNE01-SSD/ix-applications/k3s/server/agent-token"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="To join agent node to cluster: k3s agent -s https://192.168.5.4:6443 -t ${AGENT_NODE_TOKEN}"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Run: k3s kubectl"
Feb 19 22:39:41 srv-nas k3s[3315057]: I0219 22:39:41.754055 3315057 shared_informer.go:255] Waiting for caches to sync for node_authorizer
Feb 19 22:39:41 srv-nas k3s[3315057]: I0219 22:39:41.754946 3315057 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.
Feb 19 22:39:41 srv-nas k3s[3315057]: I0219 22:39:41.754957 3315057 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.
Feb 19 22:39:41 srv-nas k3s[3315057]: I0219 22:39:41.755789 3315057 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.
Feb 19 22:39:41 srv-nas k3s[3315057]: I0219 22:39:41.755800 3315057 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.
Feb 19 22:39:41 srv-nas k3s[3315057]: {"level":"warn","ts":"2023-02-19T22:39:41.758+0100","logger":"etcd-client","caller":"v3@v3.5.3-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc0005456c0/kine.sock","attempt":0,"error":"rpc error: code = Unknown desc = no such table: dbstat"}
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="certificate CN=ix-truenas signed by CN=k3s-server-ca@1676395070: notBefore=2023-02-14 17:17:50 +0000 UTC notAfter=2024-02-19 21:39:41 +0000 UTC"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="certificate CN=system:node:ix-truenas,O=system:nodes signed by CN=k3s-client-ca@1676395070: notBefore=2023-02-14 17:17:50 +0000 UTC notAfter=2024-02-19 21:39:41 +0000 UTC"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Module overlay was already loaded"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Module nf_conntrack was already loaded"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Module br_netfilter was already loaded"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Module iptable_nat was already loaded"
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.777394 3315057 genericapiserver.go:656] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: I0219 22:39:41.778258 3315057 instance.go:261] Using reconciler: lease
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Running cri-dockerd --container-runtime-endpoint=unix:///run/k3s/cri-dockerd/cri-dockerd.sock --cri-dockerd-root-directory=/mnt/LUNE01-SSD/ix-applications/k3s/agent/cri-dockerd --network-plugin=cni --pod-infra-container-image=rancher/mirrored-pause:3.6"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Connecting to docker on the Endpoint unix:///var/run/docker.sock"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Start docker client with request timeout 0s"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Running kubelet --address=0.0.0.0 --allowed-unsafe-sysctls=net.ipv4.ip_forward,net.ipv6.conf.all.forwarding --anonymous-auth=false --authentication-token-webhook=true --authorization-mode=Webhook --cgroup-driver=cgroupfs --client-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/client-ca.crt --cluster-dns=172.17.0.10 --cluster-domain=cluster.local --container-runtime-endpoint=unix:///run/k3s/cri-dockerd/cri-dockerd.sock --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/LUNE01-SSD/ix-applications/k3s/agent/kubelet.kubeconfig --max-pods=250 --node-ip=0.0.0.0 --node-labels= --pod-infra-container-image=rancher/mirrored-pause:3.6 --pod-manifest-path=/mnt/LUNE01-SSD/ix-applications/k3s/agent/pod-manifests --protect-kernel-defaults=true --read-only-port=0 --resolv-conf=/etc/resolv.conf --serialize-image-pulls=false --tls-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/serving-kubelet.crt --tls-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/serving-kubelet.key"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Handling backend connection request [ix-truenas]"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01: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"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Hairpin mode is set to none"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Loaded network plugin cni"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Docker cri networking managed by network plugin cni"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Docker Info: &{ID:BKP5:UDTS:L4SB:F4DH:ZHKD:G4IO:CPIK:V3L2:LUIN:WSG6:7ANG:TRQ2 Containers:0 ContainersRunning:0 ContainersPaused:0 ContainersStopped:0 Images:4 Driver:overlay2 DriverStatus:[[Backing Filesystem zfs] [Supports d_type true] [Native Overlay Diff true] [userxattr false]] 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:false KernelMemoryTCP:false CPUCfsPeriod:true CPUCfsQuota:true CPUShares:true CPUSet:true PidsLimit:true IPv4Forwarding:true BridgeNfIptables:true BridgeNfIP6tables:true Debug:false NFd:23 OomKillDisable:false NGoroutines:40 SystemTime:2023-02-19T22:39:41.836797711+01:00 LoggingDriver:json-file CgroupDriver:cgroupfs CgroupVersion:2 NEventsListener:0 KernelVersion:5.15.79+truenas OperatingSystem:Debian GNU/Linux 11 (bullseye) OSVersion:11 OSType:linux Architecture:x86_64 IndexServerAddress:https://index.docker.io/v1/ RegistryConfig:0xc000517810 NCPU:8 MemTotal:33604182016 GenericResources:[] DockerRootDir:/mnt/LUNE01-SSD/ix-applications/docker HTTPProxy: HTTPSProxy: NoProxy: Name:srv-nas Labels:[] ExperimentalBuild:false ServerVersion:dev ClusterStore: ClusterAdvertise: Runtimes:map[io.containerd.runc.v2:{Path:runc Args:[] Shim:<nil>} io.containerd.runtime.v1.linux:{Path:runc Args:[] Shim:<nil>} runc:{Path:runc Args:[] Shim:<nil>}] DefaultRuntime:runc Swarm:{NodeID: NodeAddr: LocalNodeState:inactive ControlAvailable:false Error: RemoteManagers:[] Nodes:0 Managers:0 Cluster:<nil> Warnings:[]} LiveRestoreEnabled:false Isolation: InitBinary:docker-init ContainerdCommit:{ID:9cd3357b7fd7218e4aec3eae239db1f68a5a6ec6 Expected:9cd3357b7fd7218e4aec3eae239db1f68a5a6ec6} RuncCommit:{ID:v1.1.4-0-g5fd4c4d Expected:v1.1.4-0-g5fd4c4d} InitCommit:{ID:de40ad0 Expected:de40ad0} SecurityOptions:[name=apparmor name=cgroupns] ProductLicense: DefaultAddressPools:[] Warnings:[]}"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Setting cgroupDriver cgroupfs"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Docker cri received runtime config &RuntimeConfig{NetworkConfig:&NetworkConfig{PodCidr:,},}"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Starting the GRPC backend for the Docker CRI interface."
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Start cri-dockerd grpc backend"
Feb 19 22:39:41 srv-nas k3s[3315057]: time="2023-02-19T22:39:41+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:41 srv-nas k3s[3315057]: I0219 22:39:41.845860 3315057 instance.go:574] API group "internal.apiserver.k8s.io" is not enabled, skipping.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.940299 3315057 genericapiserver.go:656] Skipping API authentication.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.941783 3315057 genericapiserver.go:656] Skipping API authorization.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.946103 3315057 genericapiserver.go:656] Skipping API autoscaling/v2beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.949541 3315057 genericapiserver.go:656] Skipping API batch/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.950737 3315057 genericapiserver.go:656] Skipping API certificates.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.951805 3315057 genericapiserver.go:656] Skipping API coordination.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.951830 3315057 genericapiserver.go:656] Skipping API discovery.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.954538 3315057 genericapiserver.go:656] Skipping API networking.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.954547 3315057 genericapiserver.go:656] Skipping API networking.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.955555 3315057 genericapiserver.go:656] Skipping API node.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.955562 3315057 genericapiserver.go:656] Skipping API node.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.955586 3315057 genericapiserver.go:656] Skipping API policy/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.958358 3315057 genericapiserver.go:656] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.958367 3315057 genericapiserver.go:656] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.959339 3315057 genericapiserver.go:656] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.959346 3315057 genericapiserver.go:656] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.962379 3315057 genericapiserver.go:656] Skipping API storage.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.965215 3315057 genericapiserver.go:656] Skipping API flowcontrol.apiserver.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.968724 3315057 genericapiserver.go:656] Skipping API apps/v1beta2 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.968740 3315057 genericapiserver.go:656] Skipping API apps/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.969951 3315057 genericapiserver.go:656] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.970959 3315057 genericapiserver.go:656] Skipping API events.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:41 srv-nas k3s[3315057]: I0219 22:39:41.971794 3315057 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.
Feb 19 22:39:41 srv-nas k3s[3315057]: I0219 22:39:41.971805 3315057 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.
Feb 19 22:39:41 srv-nas k3s[3315057]: W0219 22:39:41.982510 3315057 genericapiserver.go:656] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.913864 3315057 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt"
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.913865 3315057 dynamic_cafile_content.go:157] "Starting controller" name="request-header::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/request-header-ca.crt"
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914066 3315057 dynamic_serving_content.go:132] "Starting controller" name="serving-cert::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.crt::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.key"
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914100 3315057 secure_serving.go:210] Serving securely on 127.0.0.1:6444
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914133 3315057 tlsconfig.go:240] "Starting DynamicServingCertificateController"
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914209 3315057 apf_controller.go:300] Starting API Priority and Fairness config controller
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914222 3315057 apiservice_controller.go:97] Starting APIServiceRegistrationController
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914234 3315057 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914258 3315057 controller.go:83] Starting OpenAPI AggregationController
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914279 3315057 controller.go:80] Starting OpenAPI V3 AggregationController
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914420 3315057 cluster_authentication_trust_controller.go:440] Starting cluster_authentication_trust_controller controller
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914431 3315057 shared_informer.go:255] Waiting for caches to sync for cluster_authentication_trust_controller
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914671 3315057 customresource_discovery_controller.go:209] Starting DiscoveryController
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914707 3315057 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt"
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914808 3315057 autoregister_controller.go:141] Starting autoregister controller
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914818 3315057 cache.go:32] Waiting for caches to sync for autoregister controller
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914952 3315057 crdregistration_controller.go:111] Starting crd-autoregister controller
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.914960 3315057 shared_informer.go:255] Waiting for caches to sync for crd-autoregister
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.916249 3315057 dynamic_serving_content.go:132] "Starting controller" name="aggregator-proxy-cert::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.crt::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.key"
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.916591 3315057 available_controller.go:491] Starting AvailableConditionController
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.916597 3315057 cache.go:32] Waiting for caches to sync for AvailableConditionController controller
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.928891 3315057 dynamic_cafile_content.go:157] "Starting controller" name="request-header::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/request-header-ca.crt"
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.930970 3315057 controller.go:85] Starting OpenAPI controller
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.931123 3315057 controller.go:85] Starting OpenAPI V3 controller
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.931219 3315057 naming_controller.go:291] Starting NamingConditionController
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.931300 3315057 establishing_controller.go:76] Starting EstablishingController
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.931382 3315057 nonstructuralschema_controller.go:192] Starting NonStructuralSchemaConditionController
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.931459 3315057 apiapproval_controller.go:186] Starting KubernetesAPIApprovalPolicyConformantConditionController
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.931537 3315057 crd_finalizer.go:266] Starting CRDFinalizer
Feb 19 22:39:42 srv-nas k3s[3315057]: E0219 22:39:42.943071 3315057 controller.go:163] Error removing old endpoints from kubernetes service: no master IPs were listed in storage, refusing to erase all endpoints for the kubernetes service
Feb 19 22:39:42 srv-nas k3s[3315057]: I0219 22:39:42.955408 3315057 shared_informer.go:262] Caches are synced for node_authorizer
Feb 19 22:39:43 srv-nas k3s[3315057]: I0219 22:39:43.014387 3315057 cache.go:39] Caches are synced for APIServiceRegistrationController controller
Feb 19 22:39:43 srv-nas k3s[3315057]: I0219 22:39:43.014395 3315057 apf_controller.go:305] Running API Priority and Fairness config worker
Feb 19 22:39:43 srv-nas k3s[3315057]: I0219 22:39:43.014536 3315057 shared_informer.go:262] Caches are synced for cluster_authentication_trust_controller
Feb 19 22:39:43 srv-nas k3s[3315057]: I0219 22:39:43.014893 3315057 cache.go:39] Caches are synced for autoregister controller
Feb 19 22:39:43 srv-nas k3s[3315057]: I0219 22:39:43.014992 3315057 shared_informer.go:262] Caches are synced for crd-autoregister
Feb 19 22:39:43 srv-nas k3s[3315057]: I0219 22:39:43.016693 3315057 cache.go:39] Caches are synced for AvailableConditionController controller
Feb 19 22:39:43 srv-nas k3s[3315057]: I0219 22:39:43.747395 3315057 controller.go:132] OpenAPI AggregationController: action for item k8s_internal_local_delegation_chain_0000000000: Nothing (removed from the queue).
Feb 19 22:39:43 srv-nas k3s[3315057]: I0219 22:39:43.918442 3315057 storage_scheduling.go:111] all system priority classes are created successfully or already exist.
Feb 19 22:39:44 srv-nas k3s[3315057]: Flag --pod-infra-container-image has been deprecated, will be removed in 1.27. Image garbage collector will get sandbox image information from CRI.
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.818184 3315057 server.go:199] "--pod-infra-container-image will not be pruned by the image garbage collector in kubelet and should also be set in the remote runtime"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.819050 3315057 server.go:408] "Kubelet version" kubeletVersion="v1.25.3+k3s-9afcd6b9-dirty"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.819062 3315057 server.go:410] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="Stopped tunnel to 127.0.0.1:6443"
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="Connecting to proxy" url="wss://192.168.5.4:6443/v1-k3s/connect"
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:6443/v1-k3s/connect"
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.820110 3315057 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/agent/client-ca.crt"
Feb 19 22:39:44 srv-nas k3s[3315057]: W0219 22:39:44.820119 3315057 manager.go:159] Cannot detect current cgroup on cgroup v2
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="Annotations and labels have already set on node: ix-truenas"
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="Tunnel authorizer set Kubelet Port 10250"
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="Handling backend connection request [ix-truenas]"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.847912 3315057 server.go:655] "--cgroups-per-qos enabled, but --cgroup-root was not specified.  defaulting to /"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.848050 3315057 container_manager_linux.go:262] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.848091 3315057 container_manager_linux.go:267] "Creating Container Manager object based on Node Config" nodeConfig={RuntimeCgroupsName: SystemCgroupsName: KubeletCgroupsName: KubeletOOMScoreAdj:-999 ContainerRuntime: 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:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>} {Signal:nodefs.available Operator:LessThan Value:{Quantity:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>}]} QOSReserved:map[] ExperimentalCPUManagerPolicy:none ExperimentalCPUManagerPolicyOptions:map[] ExperimentalTopologyManagerScope:container ExperimentalCPUManagerReconcilePeriod:10s ExperimentalMemoryManagerPolicy:None ExperimentalMemoryManagerReservedMemory:[] ExperimentalPodPidsLimit:-1 EnforceCPULimits:true CPUCFSQuotaPeriod:100ms ExperimentalTopologyManagerPolicy:none}
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.848110 3315057 topology_manager.go:134] "Creating topology manager with policy per scope" topologyPolicyName="none" topologyScopeName="container"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.848117 3315057 container_manager_linux.go:302] "Creating device plugin manager" devicePluginEnabled=true
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.848136 3315057 state_mem.go:36] "Initialized new in-memory state store"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.849139 3315057 kubelet.go:381] "Attempting to sync node with API server"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.849152 3315057 kubelet.go:270] "Adding static pod path" path="/mnt/LUNE01-SSD/ix-applications/k3s/agent/pod-manifests"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.849175 3315057 kubelet.go:281] "Adding apiserver pod source"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.849194 3315057 apiserver.go:42] "Waiting for node sync before watching apiserver pods"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.854060 3315057 kuberuntime_manager.go:240] "Container runtime initialized" containerRuntime="docker" version="dev" apiVersion="1.41.0"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.854483 3315057 server.go:1170] "Started kubelet"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.854525 3315057 server.go:155] "Starting to listen" address="0.0.0.0" port=10250
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.855110 3315057 server.go:438] "Adding debug handlers to kubelet server"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.855504 3315057 fs_resource_analyzer.go:67] "Starting FS ResourceAnalyzer"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.856162 3315057 volume_manager.go:293] "Starting Kubelet Volume Manager"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.856206 3315057 desired_state_of_world_populator.go:149] "Desired state populator starts to run"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.859973 3315057 controller.go:616] quota admission added evaluator for: leases.coordination.k8s.io
Feb 19 22:39:44 srv-nas k3s[3315057]: E0219 22:39:44.862102 3315057 cri_stats_provider.go:452] "Failed to get the info of the filesystem with mountpoint" err="unable to find data in memory cache" mountpoint="/mnt/LUNE01-SSD/ix-applications/docker"
Feb 19 22:39:44 srv-nas k3s[3315057]: E0219 22:39:44.862124 3315057 kubelet.go:1317] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.871642 3315057 kubelet_network_linux.go:63] "Initialized iptables rules." protocol=IPv4
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.879383 3315057 kubelet_network_linux.go:63] "Initialized iptables rules." protocol=IPv6
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.879396 3315057 status_manager.go:161] "Starting to sync pod status with apiserver"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.879407 3315057 kubelet.go:2010] "Starting kubelet main sync loop"
Feb 19 22:39:44 srv-nas k3s[3315057]: E0219 22:39:44.879471 3315057 kubelet.go:2034] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.885610 3315057 cpu_manager.go:213] "Starting CPU manager" policy="none"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.885619 3315057 cpu_manager.go:214] "Reconciling" reconcilePeriod="10s"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.885631 3315057 state_mem.go:36] "Initialized new in-memory state store"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.885749 3315057 state_mem.go:88] "Updated default CPUSet" cpuSet=""
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.885758 3315057 state_mem.go:96] "Updated CPUSet assignments" assignments=map[]
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.885762 3315057 policy_none.go:49] "None policy: Start"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.886202 3315057 memory_manager.go:168] "Starting memorymanager" policy="None"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.886214 3315057 state_mem.go:35] "Initializing new in-memory state store"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.886319 3315057 state_mem.go:75] "Updated machine memory state"
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="Waiting for cloud-controller-manager privileges to become available"
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="Kube API server is now running"
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="ETCD server is now running"
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="k3s is up and running"
Feb 19 22:39:44 srv-nas systemd[1]: Started Lightweight Kubernetes.
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.956173 3315057 kuberuntime_manager.go:1050] "Updating runtime config through cri with podcidr" CIDR="172.16.0.0/16"
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="Docker cri received runtime config &RuntimeConfig{NetworkConfig:&NetworkConfig{PodCidr:172.16.0.0/16,},}"
Feb 19 22:39:44 srv-nas k3s[3315057]: I0219 22:39:44.956518 3315057 kubelet_network.go:60] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="172.16.0.0/16"
Feb 19 22:39:44 srv-nas k3s[3315057]: time="2023-02-19T22:39:44+01:00" level=info msg="Applying CRD addons.k3s.cattle.io"
Feb 19 22:39:44 srv-nas k3s[3315057]: E0219 22:39:44.964760 3315057 kubelet.go:1397] "Failed to start ContainerManager" err="failed to initialize top level QOS containers: root container [kubepods] doesn't exist"
Feb 19 22:39:45 srv-nas systemd[1]: k3s.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 22:39:45 srv-nas systemd[1]: k3s.service: Failed with result 'exit-code'.
Feb 19 22:39:45 srv-nas systemd[1]: k3s.service: Consumed 3.612s CPU time.
Feb 19 22:39:50 srv-nas systemd[1]: k3s.service: Scheduled restart job, restart counter is at 43.
Feb 19 22:39:50 srv-nas systemd[1]: Stopped Lightweight Kubernetes.
Feb 19 22:39:50 srv-nas systemd[1]: k3s.service: Consumed 3.612s CPU time.
Feb 19 22:39:50 srv-nas systemd[1]: Starting Lightweight Kubernetes...
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Starting k3s v1.25.3+k3s-9afcd6b9-dirty (9afcd6b9)"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Configuring sqlite3 database connection pooling: maxIdleConns=2, maxOpenConns=0, connMaxLifetime=0s"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Configuring database table schema and indexes, this may take a moment..."
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Database tables and indexes are up to date"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Kine available at unix://kine.sock"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Reconciling bootstrap data between datastore and disk"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Tunnel server egress proxy mode: agent"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Tunnel server egress proxy waiting for runtime core to become available"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Running kube-apiserver --advertise-address=192.168.5.4 --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/LUNE01-SSD/ix-applications/k3s/server/tls/temporary-certs --client-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --egress-selector-config-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/etc/egress-selector-config.yaml --enable-admission-plugins=NodeRestriction,NamespaceLifecycle,ServiceAccount --enable-aggregator-routing=true --etcd-servers=unix://kine.sock --feature-gates=MixedProtocolLBService=true --kubelet-certificate-authority=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --kubelet-client-certificate=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-kube-apiserver.crt --kubelet-client-key=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-kube-apiserver.key --kubelet-preferred-address-types=InternalIP,ExternalIP,Hostname --profiling=false --proxy-client-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.crt --proxy-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.key --requestheader-allowed-names=system:auth-proxy --requestheader-client-ca-file=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/service.key --service-account-lookup=true --service-account-signing-key-file=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.crt --tls-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.key"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Running kube-scheduler --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --bind-address=127.0.0.1 --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --leader-elect=false --profiling=false --secure-port=10259"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Waiting for API server to become available"
Feb 19 22:39:50 srv-nas k3s[3316634]: I0219 22:39:50.388927 3316634 server.go:581] external host was not specified, using 192.168.5.4
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Running kube-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/controller.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --cluster-signing-kube-apiserver-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.key --cluster-signing-kubelet-client-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --cluster-signing-kubelet-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.key --cluster-signing-kubelet-serving-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --cluster-signing-kubelet-serving-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.key --cluster-signing-legacy-unknown-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --cluster-signing-legacy-unknown-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.key --feature-gates=JobTrackingWithFinalizers=true --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/controller.kubeconfig --leader-elect=false --node-cidr-mask-size=16 --profiling=false --root-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --secure-port=10257 --service-account-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/service.key --service-cluster-ip-range=172.17.0.0/16 --terminated-pod-gc-threshold=5 --use-service-account-credentials=true"
Feb 19 22:39:50 srv-nas k3s[3316634]: I0219 22:39:50.389157 3316634 server.go:171] Version: v1.25.3+k3s-9afcd6b9-dirty
Feb 19 22:39:50 srv-nas k3s[3316634]: I0219 22:39:50.389172 3316634 server.go:173] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Running cloud-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --bind-address=127.0.0.1 --cloud-config=/mnt/LUNE01-SSD/ix-applications/k3s/server/etc/cloud-config.yaml --cloud-provider=k3s --cluster-cidr=172.16.0.0/16 --configure-cloud-routes=false --controllers=*,-route,-cloud-node,-cloud-node-lifecycle --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --leader-elect=false --leader-elect-resource-name=k3s-cloud-controller-manager --node-status-update-frequency=1m0s --profiling=false"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Server node token is available at /mnt/LUNE01-SSD/ix-applications/k3s/server/token"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="To join server node to cluster: k3s server -s https://192.168.5.4:6443 -t ${SERVER_NODE_TOKEN}"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Agent node token is available at /mnt/LUNE01-SSD/ix-applications/k3s/server/agent-token"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="To join agent node to cluster: k3s agent -s https://192.168.5.4:6443 -t ${AGENT_NODE_TOKEN}"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Run: k3s kubectl"
Feb 19 22:39:50 srv-nas k3s[3316634]: I0219 22:39:50.406616 3316634 shared_informer.go:255] Waiting for caches to sync for node_authorizer
Feb 19 22:39:50 srv-nas k3s[3316634]: I0219 22:39:50.407772 3316634 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.
Feb 19 22:39:50 srv-nas k3s[3316634]: I0219 22:39:50.407785 3316634 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.
Feb 19 22:39:50 srv-nas k3s[3316634]: I0219 22:39:50.409491 3316634 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.
Feb 19 22:39:50 srv-nas k3s[3316634]: I0219 22:39:50.409508 3316634 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.
Feb 19 22:39:50 srv-nas k3s[3316634]: {"level":"warn","ts":"2023-02-19T22:39:50.412+0100","logger":"etcd-client","caller":"v3@v3.5.3-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc001f9c000/kine.sock","attempt":0,"error":"rpc error: code = Unknown desc = no such table: dbstat"}
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="certificate CN=ix-truenas signed by CN=k3s-server-ca@1676395070: notBefore=2023-02-14 17:17:50 +0000 UTC notAfter=2024-02-19 21:39:50 +0000 UTC"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="certificate CN=system:node:ix-truenas,O=system:nodes signed by CN=k3s-client-ca@1676395070: notBefore=2023-02-14 17:17:50 +0000 UTC notAfter=2024-02-19 21:39:50 +0000 UTC"
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.434870 3316634 genericapiserver.go:656] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: I0219 22:39:50.435681 3316634 instance.go:261] Using reconciler: lease
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Module overlay was already loaded"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Module nf_conntrack was already loaded"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Module br_netfilter was already loaded"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Module iptable_nat was already loaded"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Running cri-dockerd --container-runtime-endpoint=unix:///run/k3s/cri-dockerd/cri-dockerd.sock --cri-dockerd-root-directory=/mnt/LUNE01-SSD/ix-applications/k3s/agent/cri-dockerd --network-plugin=cni --pod-infra-container-image=rancher/mirrored-pause:3.6"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Running kubelet --address=0.0.0.0 --allowed-unsafe-sysctls=net.ipv4.ip_forward,net.ipv6.conf.all.forwarding --anonymous-auth=false --authentication-token-webhook=true --authorization-mode=Webhook --cgroup-driver=cgroupfs --client-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/client-ca.crt --cluster-dns=172.17.0.10 --cluster-domain=cluster.local --container-runtime-endpoint=unix:///run/k3s/cri-dockerd/cri-dockerd.sock --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/LUNE01-SSD/ix-applications/k3s/agent/kubelet.kubeconfig --max-pods=250 --node-ip=0.0.0.0 --node-labels= --pod-infra-container-image=rancher/mirrored-pause:3.6 --pod-manifest-path=/mnt/LUNE01-SSD/ix-applications/k3s/agent/pod-manifests --protect-kernel-defaults=true --read-only-port=0 --resolv-conf=/etc/resolv.conf --serialize-image-pulls=false --tls-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/serving-kubelet.crt --tls-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/serving-kubelet.key"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Connecting to docker on the Endpoint unix:///var/run/docker.sock"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Start docker client with request timeout 0s"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Handling backend connection request [ix-truenas]"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01: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"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Hairpin mode is set to none"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Loaded network plugin cni"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Docker cri networking managed by network plugin cni"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Docker Info: &{ID:BKP5:UDTS:L4SB:F4DH:ZHKD:G4IO:CPIK:V3L2:LUIN:WSG6:7ANG:TRQ2 Containers:0 ContainersRunning:0 ContainersPaused:0 ContainersStopped:0 Images:4 Driver:overlay2 DriverStatus:[[Backing Filesystem zfs] [Supports d_type true] [Native Overlay Diff true] [userxattr false]] 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:false KernelMemoryTCP:false CPUCfsPeriod:true CPUCfsQuota:true CPUShares:true CPUSet:true PidsLimit:true IPv4Forwarding:true BridgeNfIptables:true BridgeNfIP6tables:true Debug:false NFd:23 OomKillDisable:false NGoroutines:40 SystemTime:2023-02-19T22:39:50.470460218+01:00 LoggingDriver:json-file CgroupDriver:cgroupfs CgroupVersion:2 NEventsListener:0 KernelVersion:5.15.79+truenas OperatingSystem:Debian GNU/Linux 11 (bullseye) OSVersion:11 OSType:linux Architecture:x86_64 IndexServerAddress:https://index.docker.io/v1/ RegistryConfig:0xc0004b8000 NCPU:8 MemTotal:33604182016 GenericResources:[] DockerRootDir:/mnt/LUNE01-SSD/ix-applications/docker HTTPProxy: HTTPSProxy: NoProxy: Name:srv-nas Labels:[] ExperimentalBuild:false ServerVersion:dev ClusterStore: ClusterAdvertise: Runtimes:map[io.containerd.runc.v2:{Path:runc Args:[] Shim:<nil>} io.containerd.runtime.v1.linux:{Path:runc Args:[] Shim:<nil>} runc:{Path:runc Args:[] Shim:<nil>}] DefaultRuntime:runc Swarm:{NodeID: NodeAddr: LocalNodeState:inactive ControlAvailable:false Error: RemoteManagers:[] Nodes:0 Managers:0 Cluster:<nil> Warnings:[]} LiveRestoreEnabled:false Isolation: InitBinary:docker-init ContainerdCommit:{ID:9cd3357b7fd7218e4aec3eae239db1f68a5a6ec6 Expected:9cd3357b7fd7218e4aec3eae239db1f68a5a6ec6} RuncCommit:{ID:v1.1.4-0-g5fd4c4d Expected:v1.1.4-0-g5fd4c4d} InitCommit:{ID:de40ad0 Expected:de40ad0} SecurityOptions:[name=apparmor name=cgroupns] ProductLicense: DefaultAddressPools:[] Warnings:[]}"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Setting cgroupDriver cgroupfs"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Docker cri received runtime config &RuntimeConfig{NetworkConfig:&NetworkConfig{PodCidr:,},}"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Starting the GRPC backend for the Docker CRI interface."
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Start cri-dockerd grpc backend"
Feb 19 22:39:50 srv-nas k3s[3316634]: time="2023-02-19T22:39:50+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:50 srv-nas k3s[3316634]: I0219 22:39:50.501324 3316634 instance.go:574] API group "internal.apiserver.k8s.io" is not enabled, skipping.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.591133 3316634 genericapiserver.go:656] Skipping API authentication.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.593811 3316634 genericapiserver.go:656] Skipping API authorization.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.597804 3316634 genericapiserver.go:656] Skipping API autoscaling/v2beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.600640 3316634 genericapiserver.go:656] Skipping API batch/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.601886 3316634 genericapiserver.go:656] Skipping API certificates.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.602998 3316634 genericapiserver.go:656] Skipping API coordination.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.603025 3316634 genericapiserver.go:656] Skipping API discovery.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.605762 3316634 genericapiserver.go:656] Skipping API networking.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.605772 3316634 genericapiserver.go:656] Skipping API networking.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.606743 3316634 genericapiserver.go:656] Skipping API node.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.606751 3316634 genericapiserver.go:656] Skipping API node.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.606776 3316634 genericapiserver.go:656] Skipping API policy/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.609565 3316634 genericapiserver.go:656] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.609575 3316634 genericapiserver.go:656] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.610638 3316634 genericapiserver.go:656] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.610647 3316634 genericapiserver.go:656] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.613588 3316634 genericapiserver.go:656] Skipping API storage.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.616297 3316634 genericapiserver.go:656] Skipping API flowcontrol.apiserver.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.619013 3316634 genericapiserver.go:656] Skipping API apps/v1beta2 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.619022 3316634 genericapiserver.go:656] Skipping API apps/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.620219 3316634 genericapiserver.go:656] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.621231 3316634 genericapiserver.go:656] Skipping API events.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:50 srv-nas k3s[3316634]: I0219 22:39:50.621823 3316634 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.
Feb 19 22:39:50 srv-nas k3s[3316634]: I0219 22:39:50.621835 3316634 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.
Feb 19 22:39:50 srv-nas k3s[3316634]: W0219 22:39:50.630594 3316634 genericapiserver.go:656] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.544869 3316634 dynamic_cafile_content.go:157] "Starting controller" name="request-header::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/request-header-ca.crt"
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.544977 3316634 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt"
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.544982 3316634 dynamic_serving_content.go:132] "Starting controller" name="serving-cert::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.crt::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.key"
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545089 3316634 secure_serving.go:210] Serving securely on 127.0.0.1:6444
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545121 3316634 controller.go:83] Starting OpenAPI AggregationController
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545145 3316634 apiservice_controller.go:97] Starting APIServiceRegistrationController
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545155 3316634 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545188 3316634 dynamic_serving_content.go:132] "Starting controller" name="aggregator-proxy-cert::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.crt::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.key"
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545202 3316634 apf_controller.go:300] Starting API Priority and Fairness config controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545523 3316634 tlsconfig.go:240] "Starting DynamicServingCertificateController"
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545538 3316634 available_controller.go:491] Starting AvailableConditionController
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545547 3316634 cache.go:32] Waiting for caches to sync for AvailableConditionController controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545569 3316634 autoregister_controller.go:141] Starting autoregister controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545573 3316634 cache.go:32] Waiting for caches to sync for autoregister controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545774 3316634 cluster_authentication_trust_controller.go:440] Starting cluster_authentication_trust_controller controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.545788 3316634 shared_informer.go:255] Waiting for caches to sync for cluster_authentication_trust_controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.546081 3316634 controller.go:80] Starting OpenAPI V3 AggregationController
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.546226 3316634 customresource_discovery_controller.go:209] Starting DiscoveryController
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.546277 3316634 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt"
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.548123 3316634 crdregistration_controller.go:111] Starting crd-autoregister controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.548134 3316634 shared_informer.go:255] Waiting for caches to sync for crd-autoregister
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.558609 3316634 dynamic_cafile_content.go:157] "Starting controller" name="request-header::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/request-header-ca.crt"
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.560038 3316634 controller.go:85] Starting OpenAPI controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.560078 3316634 controller.go:85] Starting OpenAPI V3 controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.560102 3316634 naming_controller.go:291] Starting NamingConditionController
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.560114 3316634 establishing_controller.go:76] Starting EstablishingController
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.560129 3316634 nonstructuralschema_controller.go:192] Starting NonStructuralSchemaConditionController
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.560147 3316634 apiapproval_controller.go:186] Starting KubernetesAPIApprovalPolicyConformantConditionController
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.560158 3316634 crd_finalizer.go:266] Starting CRDFinalizer
Feb 19 22:39:51 srv-nas k3s[3316634]: E0219 22:39:51.572975 3316634 controller.go:163] Error removing old endpoints from kubernetes service: no master IPs were listed in storage, refusing to erase all endpoints for the kubernetes service
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.606670 3316634 shared_informer.go:262] Caches are synced for node_authorizer
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.646034 3316634 shared_informer.go:262] Caches are synced for cluster_authentication_trust_controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.646060 3316634 apf_controller.go:305] Running API Priority and Fairness config worker
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.646088 3316634 cache.go:39] Caches are synced for autoregister controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.646101 3316634 cache.go:39] Caches are synced for APIServiceRegistrationController controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.646092 3316634 cache.go:39] Caches are synced for AvailableConditionController controller
Feb 19 22:39:51 srv-nas k3s[3316634]: I0219 22:39:51.648158 3316634 shared_informer.go:262] Caches are synced for crd-autoregister
Feb 19 22:39:52 srv-nas k3s[3316634]: I0219 22:39:52.351310 3316634 controller.go:132] OpenAPI AggregationController: action for item k8s_internal_local_delegation_chain_0000000000: Nothing (removed from the queue).
Feb 19 22:39:52 srv-nas k3s[3316634]: I0219 22:39:52.547995 3316634 storage_scheduling.go:111] all system priority classes are created successfully or already exist.
Feb 19 22:39:53 srv-nas k3s[3316634]: Flag --pod-infra-container-image has been deprecated, will be removed in 1.27. Image garbage collector will get sandbox image information from CRI.
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.459235 3316634 server.go:199] "--pod-infra-container-image will not be pruned by the image garbage collector in kubelet and should also be set in the remote runtime"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.460101 3316634 server.go:408] "Kubelet version" kubeletVersion="v1.25.3+k3s-9afcd6b9-dirty"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.460116 3316634 server.go:410] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="Annotations and labels have already set on node: ix-truenas"
Feb 19 22:39:53 srv-nas k3s[3316634]: W0219 22:39:53.460969 3316634 manager.go:159] Cannot detect current cgroup on cgroup v2
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.461067 3316634 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/agent/client-ca.crt"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="Stopped tunnel to 127.0.0.1:6443"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="Connecting to proxy" url="wss://192.168.5.4:6443/v1-k3s/connect"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:6443/v1-k3s/connect"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="Tunnel authorizer set Kubelet Port 10250"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="Handling backend connection request [ix-truenas]"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.487939 3316634 server.go:655] "--cgroups-per-qos enabled, but --cgroup-root was not specified.  defaulting to /"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.488078 3316634 container_manager_linux.go:262] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.488119 3316634 container_manager_linux.go:267] "Creating Container Manager object based on Node Config" nodeConfig={RuntimeCgroupsName: SystemCgroupsName: KubeletCgroupsName: KubeletOOMScoreAdj:-999 ContainerRuntime: 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:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>} {Signal:nodefs.available Operator:LessThan Value:{Quantity:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>}]} QOSReserved:map[] ExperimentalCPUManagerPolicy:none ExperimentalCPUManagerPolicyOptions:map[] ExperimentalTopologyManagerScope:container ExperimentalCPUManagerReconcilePeriod:10s ExperimentalMemoryManagerPolicy:None ExperimentalMemoryManagerReservedMemory:[] ExperimentalPodPidsLimit:-1 EnforceCPULimits:true CPUCFSQuotaPeriod:100ms ExperimentalTopologyManagerPolicy:none}
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.488136 3316634 topology_manager.go:134] "Creating topology manager with policy per scope" topologyPolicyName="none" topologyScopeName="container"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.488143 3316634 container_manager_linux.go:302] "Creating device plugin manager" devicePluginEnabled=true
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.488163 3316634 state_mem.go:36] "Initialized new in-memory state store"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.489202 3316634 kubelet.go:381] "Attempting to sync node with API server"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.489214 3316634 kubelet.go:270] "Adding static pod path" path="/mnt/LUNE01-SSD/ix-applications/k3s/agent/pod-manifests"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.489234 3316634 kubelet.go:281] "Adding apiserver pod source"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.489247 3316634 apiserver.go:42] "Waiting for node sync before watching apiserver pods"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.494255 3316634 kuberuntime_manager.go:240] "Container runtime initialized" containerRuntime="docker" version="dev" apiVersion="1.41.0"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.494630 3316634 server.go:1170] "Started kubelet"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.495051 3316634 server.go:155] "Starting to listen" address="0.0.0.0" port=10250
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.495521 3316634 fs_resource_analyzer.go:67] "Starting FS ResourceAnalyzer"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.495856 3316634 server.go:438] "Adding debug handlers to kubelet server"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.495897 3316634 volume_manager.go:293] "Starting Kubelet Volume Manager"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.496758 3316634 desired_state_of_world_populator.go:149] "Desired state populator starts to run"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.500909 3316634 controller.go:616] quota admission added evaluator for: leases.coordination.k8s.io
Feb 19 22:39:53 srv-nas k3s[3316634]: E0219 22:39:53.503844 3316634 cri_stats_provider.go:452] "Failed to get the info of the filesystem with mountpoint" err="unable to find data in memory cache" mountpoint="/mnt/LUNE01-SSD/ix-applications/docker"
Feb 19 22:39:53 srv-nas k3s[3316634]: E0219 22:39:53.503863 3316634 kubelet.go:1317] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.512097 3316634 kubelet_network_linux.go:63] "Initialized iptables rules." protocol=IPv4
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.519678 3316634 kubelet_network_linux.go:63] "Initialized iptables rules." protocol=IPv6
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.519690 3316634 status_manager.go:161] "Starting to sync pod status with apiserver"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.519704 3316634 kubelet.go:2010] "Starting kubelet main sync loop"
Feb 19 22:39:53 srv-nas k3s[3316634]: E0219 22:39:53.519778 3316634 kubelet.go:2034] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.526863 3316634 cpu_manager.go:213] "Starting CPU manager" policy="none"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.526877 3316634 cpu_manager.go:214] "Reconciling" reconcilePeriod="10s"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.526896 3316634 state_mem.go:36] "Initialized new in-memory state store"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.527040 3316634 state_mem.go:88] "Updated default CPUSet" cpuSet=""
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.527051 3316634 state_mem.go:96] "Updated CPUSet assignments" assignments=map[]
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.527057 3316634 policy_none.go:49] "None policy: Start"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.527600 3316634 memory_manager.go:168] "Starting memorymanager" policy="None"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.527618 3316634 state_mem.go:35] "Initializing new in-memory state store"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.527748 3316634 state_mem.go:75] "Updated machine memory state"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="Waiting for cloud-controller-manager privileges to become available"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="Kube API server is now running"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="ETCD server is now running"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="k3s is up and running"
Feb 19 22:39:53 srv-nas systemd[1]: Started Lightweight Kubernetes.
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="Applying CRD addons.k3s.cattle.io"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.597256 3316634 kuberuntime_manager.go:1050] "Updating runtime config through cri with podcidr" CIDR="172.16.0.0/16"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="Docker cri received runtime config &RuntimeConfig{NetworkConfig:&NetworkConfig{PodCidr:172.16.0.0/16,},}"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.597573 3316634 kubelet_network.go:60] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="172.16.0.0/16"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.603192 3316634 kubelet_node_status.go:70] "Attempting to register node" node="ix-truenas"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="Applying CRD helmcharts.helm.cattle.io"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.609224 3316634 kubelet_node_status.go:108] "Node was previously registered" node="ix-truenas"
Feb 19 22:39:53 srv-nas k3s[3316634]: I0219 22:39:53.609329 3316634 kubelet_node_status.go:73] "Successfully registered node" node="ix-truenas"
Feb 19 22:39:53 srv-nas k3s[3316634]: time="2023-02-19T22:39:53+01:00" level=info msg="Applying CRD helmchartconfigs.helm.cattle.io"
Feb 19 22:39:53 srv-nas k3s[3316634]: E0219 22:39:53.619835 3316634 kubelet.go:2034] "Skipping pod synchronization" err="container runtime status check may not have completed yet"
Feb 19 22:39:53 srv-nas k3s[3316634]: E0219 22:39:53.624649 3316634 kubelet.go:1397] "Failed to start ContainerManager" err="failed to initialize top level QOS containers: root container [kubepods] doesn't exist"
Feb 19 22:39:53 srv-nas systemd[1]: k3s.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 22:39:53 srv-nas systemd[1]: k3s.service: Failed with result 'exit-code'.
Feb 19 22:39:53 srv-nas systemd[1]: k3s.service: Consumed 3.721s CPU time.
Feb 19 22:39:58 srv-nas systemd[1]: k3s.service: Scheduled restart job, restart counter is at 44.
Feb 19 22:39:58 srv-nas systemd[1]: Stopped Lightweight Kubernetes.
Feb 19 22:39:58 srv-nas systemd[1]: k3s.service: Consumed 3.721s CPU time.
Feb 19 22:39:58 srv-nas systemd[1]: Starting Lightweight Kubernetes...
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Starting k3s v1.25.3+k3s-9afcd6b9-dirty (9afcd6b9)"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Configuring sqlite3 database connection pooling: maxIdleConns=2, maxOpenConns=0, connMaxLifetime=0s"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Configuring database table schema and indexes, this may take a moment..."
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Database tables and indexes are up to date"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Kine available at unix://kine.sock"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Reconciling bootstrap data between datastore and disk"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Tunnel server egress proxy mode: agent"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Tunnel server egress proxy waiting for runtime core to become available"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Running kube-apiserver --advertise-address=192.168.5.4 --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/LUNE01-SSD/ix-applications/k3s/server/tls/temporary-certs --client-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --egress-selector-config-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/etc/egress-selector-config.yaml --enable-admission-plugins=NodeRestriction,NamespaceLifecycle,ServiceAccount --enable-aggregator-routing=true --etcd-servers=unix://kine.sock --feature-gates=MixedProtocolLBService=true --kubelet-certificate-authority=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --kubelet-client-certificate=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-kube-apiserver.crt --kubelet-client-key=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-kube-apiserver.key --kubelet-preferred-address-types=InternalIP,ExternalIP,Hostname --profiling=false --proxy-client-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.crt --proxy-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.key --requestheader-allowed-names=system:auth-proxy --requestheader-client-ca-file=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/service.key --service-account-lookup=true --service-account-signing-key-file=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.crt --tls-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.key"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Running kube-scheduler --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --bind-address=127.0.0.1 --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/scheduler.kubeconfig --leader-elect=false --profiling=false --secure-port=10259"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Waiting for API server to become available"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Running kube-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/controller.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/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/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --cluster-signing-kube-apiserver-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.key --cluster-signing-kubelet-client-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt --cluster-signing-kubelet-client-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.key --cluster-signing-kubelet-serving-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --cluster-signing-kubelet-serving-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.key --cluster-signing-legacy-unknown-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --cluster-signing-legacy-unknown-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.key --feature-gates=JobTrackingWithFinalizers=true --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/controller.kubeconfig --leader-elect=false --node-cidr-mask-size=16 --profiling=false --root-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/server-ca.crt --secure-port=10257 --service-account-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/service.key --service-cluster-ip-range=172.17.0.0/16 --terminated-pod-gc-threshold=5 --use-service-account-credentials=true"
Feb 19 22:39:59 srv-nas k3s[3318450]: I0219 22:39:59.227913 3318450 server.go:581] external host was not specified, using 192.168.5.4
Feb 19 22:39:59 srv-nas k3s[3318450]: I0219 22:39:59.228157 3318450 server.go:171] Version: v1.25.3+k3s-9afcd6b9-dirty
Feb 19 22:39:59 srv-nas k3s[3318450]: I0219 22:39:59.228173 3318450 server.go:173] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Running cloud-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --authorization-kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --bind-address=127.0.0.1 --cloud-config=/mnt/LUNE01-SSD/ix-applications/k3s/server/etc/cloud-config.yaml --cloud-provider=k3s --cluster-cidr=172.16.0.0/16 --configure-cloud-routes=false --controllers=*,-route,-cloud-node,-cloud-node-lifecycle --kubeconfig=/mnt/LUNE01-SSD/ix-applications/k3s/server/cred/cloud-controller.kubeconfig --leader-elect=false --leader-elect-resource-name=k3s-cloud-controller-manager --node-status-update-frequency=1m0s --profiling=false"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Server node token is available at /mnt/LUNE01-SSD/ix-applications/k3s/server/token"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="To join server node to cluster: k3s server -s https://192.168.5.4:6443 -t ${SERVER_NODE_TOKEN}"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Agent node token is available at /mnt/LUNE01-SSD/ix-applications/k3s/server/agent-token"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="To join agent node to cluster: k3s agent -s https://192.168.5.4:6443 -t ${AGENT_NODE_TOKEN}"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Run: k3s kubectl"
Feb 19 22:39:59 srv-nas k3s[3318450]: I0219 22:39:59.244339 3318450 shared_informer.go:255] Waiting for caches to sync for node_authorizer
Feb 19 22:39:59 srv-nas k3s[3318450]: I0219 22:39:59.245502 3318450 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.
Feb 19 22:39:59 srv-nas k3s[3318450]: I0219 22:39:59.245584 3318450 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.
Feb 19 22:39:59 srv-nas k3s[3318450]: I0219 22:39:59.246923 3318450 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.
Feb 19 22:39:59 srv-nas k3s[3318450]: I0219 22:39:59.247006 3318450 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.
Feb 19 22:39:59 srv-nas k3s[3318450]: {"level":"warn","ts":"2023-02-19T22:39:59.252+0100","logger":"etcd-client","caller":"v3@v3.5.3-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc0005e3dc0/kine.sock","attempt":0,"error":"rpc error: code = Unknown desc = no such table: dbstat"}
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="certificate CN=ix-truenas signed by CN=k3s-server-ca@1676395070: notBefore=2023-02-14 17:17:50 +0000 UTC notAfter=2024-02-19 21:39:59 +0000 UTC"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="certificate CN=system:node:ix-truenas,O=system:nodes signed by CN=k3s-client-ca@1676395070: notBefore=2023-02-14 17:17:50 +0000 UTC notAfter=2024-02-19 21:39:59 +0000 UTC"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Module overlay was already loaded"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Module nf_conntrack was already loaded"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Module br_netfilter was already loaded"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Module iptable_nat was already loaded"
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.268757 3318450 genericapiserver.go:656] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: I0219 22:39:59.269463 3318450 instance.go:261] Using reconciler: lease
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Running cri-dockerd --container-runtime-endpoint=unix:///run/k3s/cri-dockerd/cri-dockerd.sock --cri-dockerd-root-directory=/mnt/LUNE01-SSD/ix-applications/k3s/agent/cri-dockerd --network-plugin=cni --pod-infra-container-image=rancher/mirrored-pause:3.6"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Connecting to docker on the Endpoint unix:///var/run/docker.sock"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Start docker client with request timeout 0s"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Running kubelet --address=0.0.0.0 --allowed-unsafe-sysctls=net.ipv4.ip_forward,net.ipv6.conf.all.forwarding --anonymous-auth=false --authentication-token-webhook=true --authorization-mode=Webhook --cgroup-driver=cgroupfs --client-ca-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/client-ca.crt --cluster-dns=172.17.0.10 --cluster-domain=cluster.local --container-runtime-endpoint=unix:///run/k3s/cri-dockerd/cri-dockerd.sock --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/LUNE01-SSD/ix-applications/k3s/agent/kubelet.kubeconfig --max-pods=250 --node-ip=0.0.0.0 --node-labels= --pod-infra-container-image=rancher/mirrored-pause:3.6 --pod-manifest-path=/mnt/LUNE01-SSD/ix-applications/k3s/agent/pod-manifests --protect-kernel-defaults=true --read-only-port=0 --resolv-conf=/etc/resolv.conf --serialize-image-pulls=false --tls-cert-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/serving-kubelet.crt --tls-private-key-file=/mnt/LUNE01-SSD/ix-applications/k3s/agent/serving-kubelet.key"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Connecting to proxy" url="wss://127.0.0.1:6443/v1-k3s/connect"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Handling backend connection request [ix-truenas]"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01: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"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Hairpin mode is set to none"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Loaded network plugin cni"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Docker cri networking managed by network plugin cni"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Docker Info: &{ID:BKP5:UDTS:L4SB:F4DH:ZHKD:G4IO:CPIK:V3L2:LUIN:WSG6:7ANG:TRQ2 Containers:0 ContainersRunning:0 ContainersPaused:0 ContainersStopped:0 Images:4 Driver:overlay2 DriverStatus:[[Backing Filesystem zfs] [Supports d_type true] [Native Overlay Diff true] [userxattr false]] 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:false KernelMemoryTCP:false CPUCfsPeriod:true CPUCfsQuota:true CPUShares:true CPUSet:true PidsLimit:true IPv4Forwarding:true BridgeNfIptables:true BridgeNfIP6tables:true Debug:false NFd:23 OomKillDisable:false NGoroutines:40 SystemTime:2023-02-19T22:39:59.307088878+01:00 LoggingDriver:json-file CgroupDriver:cgroupfs CgroupVersion:2 NEventsListener:0 KernelVersion:5.15.79+truenas OperatingSystem:Debian GNU/Linux 11 (bullseye) OSVersion:11 OSType:linux Architecture:x86_64 IndexServerAddress:https://index.docker.io/v1/ RegistryConfig:0xc00094f490 NCPU:8 MemTotal:33604182016 GenericResources:[] DockerRootDir:/mnt/LUNE01-SSD/ix-applications/docker HTTPProxy: HTTPSProxy: NoProxy: Name:srv-nas Labels:[] ExperimentalBuild:false ServerVersion:dev ClusterStore: ClusterAdvertise: Runtimes:map[io.containerd.runc.v2:{Path:runc Args:[] Shim:<nil>} io.containerd.runtime.v1.linux:{Path:runc Args:[] Shim:<nil>} runc:{Path:runc Args:[] Shim:<nil>}] DefaultRuntime:runc Swarm:{NodeID: NodeAddr: LocalNodeState:inactive ControlAvailable:false Error: RemoteManagers:[] Nodes:0 Managers:0 Cluster:<nil> Warnings:[]} LiveRestoreEnabled:false Isolation: InitBinary:docker-init ContainerdCommit:{ID:9cd3357b7fd7218e4aec3eae239db1f68a5a6ec6 Expected:9cd3357b7fd7218e4aec3eae239db1f68a5a6ec6} RuncCommit:{ID:v1.1.4-0-g5fd4c4d Expected:v1.1.4-0-g5fd4c4d} InitCommit:{ID:de40ad0 Expected:de40ad0} SecurityOptions:[name=apparmor name=cgroupns] ProductLicense: DefaultAddressPools:[] Warnings:[]}"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Setting cgroupDriver cgroupfs"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Docker cri received runtime config &RuntimeConfig{NetworkConfig:&NetworkConfig{PodCidr:,},}"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Starting the GRPC backend for the Docker CRI interface."
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Start cri-dockerd grpc backend"
Feb 19 22:39:59 srv-nas k3s[3318450]: time="2023-02-19T22:39:59+01:00" level=info msg="Using CNI configuration file /etc/cni/net.d/00-multus.conf"
Feb 19 22:39:59 srv-nas k3s[3318450]: I0219 22:39:59.346490 3318450 instance.go:574] API group "internal.apiserver.k8s.io" is not enabled, skipping.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.430979 3318450 genericapiserver.go:656] Skipping API authentication.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.432210 3318450 genericapiserver.go:656] Skipping API authorization.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.435630 3318450 genericapiserver.go:656] Skipping API autoscaling/v2beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.438301 3318450 genericapiserver.go:656] Skipping API batch/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.439655 3318450 genericapiserver.go:656] Skipping API certificates.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.440857 3318450 genericapiserver.go:656] Skipping API coordination.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.440882 3318450 genericapiserver.go:656] Skipping API discovery.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.443591 3318450 genericapiserver.go:656] Skipping API networking.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.443600 3318450 genericapiserver.go:656] Skipping API networking.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.444729 3318450 genericapiserver.go:656] Skipping API node.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.444736 3318450 genericapiserver.go:656] Skipping API node.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.444763 3318450 genericapiserver.go:656] Skipping API policy/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.447476 3318450 genericapiserver.go:656] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.447485 3318450 genericapiserver.go:656] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.448515 3318450 genericapiserver.go:656] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.448524 3318450 genericapiserver.go:656] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.451927 3318450 genericapiserver.go:656] Skipping API storage.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.460308 3318450 genericapiserver.go:656] Skipping API flowcontrol.apiserver.k8s.io/v1alpha1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.463787 3318450 genericapiserver.go:656] Skipping API apps/v1beta2 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.463804 3318450 genericapiserver.go:656] Skipping API apps/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.465224 3318450 genericapiserver.go:656] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.466360 3318450 genericapiserver.go:656] Skipping API events.k8s.io/v1beta1 because it has no resources.
Feb 19 22:39:59 srv-nas k3s[3318450]: I0219 22:39:59.466981 3318450 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.
Feb 19 22:39:59 srv-nas k3s[3318450]: I0219 22:39:59.466991 3318450 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.
Feb 19 22:39:59 srv-nas k3s[3318450]: W0219 22:39:59.476293 3318450 genericapiserver.go:656] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394222 3318450 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt"
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394222 3318450 dynamic_cafile_content.go:157] "Starting controller" name="request-header::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/request-header-ca.crt"
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394400 3318450 dynamic_serving_content.go:132] "Starting controller" name="serving-cert::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.crt::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/serving-kube-apiserver.key"
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394483 3318450 secure_serving.go:210] Serving securely on 127.0.0.1:6444
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394523 3318450 tlsconfig.go:240] "Starting DynamicServingCertificateController"
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394578 3318450 autoregister_controller.go:141] Starting autoregister controller
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394585 3318450 cache.go:32] Waiting for caches to sync for autoregister controller
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394605 3318450 available_controller.go:491] Starting AvailableConditionController
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394611 3318450 cache.go:32] Waiting for caches to sync for AvailableConditionController controller
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394625 3318450 controller.go:80] Starting OpenAPI V3 AggregationController
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394655 3318450 customresource_discovery_controller.go:209] Starting DiscoveryController
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394660 3318450 apf_controller.go:300] Starting API Priority and Fairness config controller
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394740 3318450 dynamic_serving_content.go:132] "Starting controller" name="aggregator-proxy-cert::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.crt::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-auth-proxy.key"
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394808 3318450 cluster_authentication_trust_controller.go:440] Starting cluster_authentication_trust_controller controller
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394816 3318450 shared_informer.go:255] Waiting for caches to sync for cluster_authentication_trust_controller
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394864 3318450 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/client-ca.crt"
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394890 3318450 crdregistration_controller.go:111] Starting crd-autoregister controller
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394898 3318450 shared_informer.go:255] Waiting for caches to sync for crd-autoregister
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.394918 3318450 controller.go:83] Starting OpenAPI AggregationController
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.395117 3318450 controller.go:85] Starting OpenAPI controller
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.395138 3318450 controller.go:85] Starting OpenAPI V3 controller
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.395156 3318450 naming_controller.go:291] Starting NamingConditionController
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.395168 3318450 establishing_controller.go:76] Starting EstablishingController
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.395180 3318450 nonstructuralschema_controller.go:192] Starting NonStructuralSchemaConditionController
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.395191 3318450 apiapproval_controller.go:186] Starting KubernetesAPIApprovalPolicyConformantConditionController
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.395202 3318450 crd_finalizer.go:266] Starting CRDFinalizer
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.405216 3318450 dynamic_cafile_content.go:157] "Starting controller" name="request-header::/mnt/LUNE01-SSD/ix-applications/k3s/server/tls/request-header-ca.crt"
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.405334 3318450 apiservice_controller.go:97] Starting APIServiceRegistrationController
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.405342 3318450 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller
Feb 19 22:40:00 srv-nas k3s[3318450]: E0219 22:40:00.420247 3318450 controller.go:163] Error removing old endpoints from kubernetes service: no master IPs were listed in storage, refusing to erase all endpoints for the kubernetes service
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.445041 3318450 shared_informer.go:262] Caches are synced for node_authorizer
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.494804 3318450 cache.go:39] Caches are synced for autoregister controller
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.494837 3318450 cache.go:39] Caches are synced for AvailableConditionController controller
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.494802 3318450 apf_controller.go:305] Running API Priority and Fairness config worker
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.494869 3318450 shared_informer.go:262] Caches are synced for cluster_authentication_trust_controller
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.495012 3318450 shared_informer.go:262] Caches are synced for crd-autoregister
Feb 19 22:40:00 srv-nas k3s[3318450]: I0219 22:40:00.516700 3318450 cache.go:39] Caches are synced for APIServiceRegistrationController controller
Feb 19 22:40:01 srv-nas k3s[3318450]: I0219 22:40:01.370704 3318450 controller.go:132] OpenAPI AggregationController: action for item k8s_internal_local_delegation_chain_0000000000: Nothing (removed from the queue).
Feb 19 22:40:01 srv-nas k3s[3318450]: I0219 22:40:01.397422 3318450 storage_scheduling.go:111] all system priority classes are created successfully or already exist.
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="Stopped tunnel to 127.0.0.1:6443"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="Connecting to proxy" url="wss://192.168.5.4:6443/v1-k3s/connect"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="Proxy done" err="context canceled" url="wss://127.0.0.1:6443/v1-k3s/connect"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="Handling backend connection request [ix-truenas]"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="Tunnel authorizer set Kubelet Port 10250"
Feb 19 22:40:02 srv-nas k3s[3318450]: Flag --pod-infra-container-image has been deprecated, will be removed in 1.27. Image garbage collector will get sandbox image information from CRI.
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.292549 3318450 server.go:199] "--pod-infra-container-image will not be pruned by the image garbage collector in kubelet and should also be set in the remote runtime"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.293395 3318450 server.go:408] "Kubelet version" kubeletVersion="v1.25.3+k3s-9afcd6b9-dirty"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.293408 3318450 server.go:410] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.294443 3318450 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/mnt/LUNE01-SSD/ix-applications/k3s/agent/client-ca.crt"
Feb 19 22:40:02 srv-nas k3s[3318450]: W0219 22:40:02.294461 3318450 manager.go:159] Cannot detect current cgroup on cgroup v2
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="Annotations and labels have already set on node: ix-truenas"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.317337 3318450 server.go:655] "--cgroups-per-qos enabled, but --cgroup-root was not specified.  defaulting to /"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.317548 3318450 container_manager_linux.go:262] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.317624 3318450 container_manager_linux.go:267] "Creating Container Manager object based on Node Config" nodeConfig={RuntimeCgroupsName: SystemCgroupsName: KubeletCgroupsName: KubeletOOMScoreAdj:-999 ContainerRuntime: 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:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>} {Signal:nodefs.available Operator:LessThan Value:{Quantity:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>}]} QOSReserved:map[] ExperimentalCPUManagerPolicy:none ExperimentalCPUManagerPolicyOptions:map[] ExperimentalTopologyManagerScope:container ExperimentalCPUManagerReconcilePeriod:10s ExperimentalMemoryManagerPolicy:None ExperimentalMemoryManagerReservedMemory:[] ExperimentalPodPidsLimit:-1 EnforceCPULimits:true CPUCFSQuotaPeriod:100ms ExperimentalTopologyManagerPolicy:none}
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.317657 3318450 topology_manager.go:134] "Creating topology manager with policy per scope" topologyPolicyName="none" topologyScopeName="container"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.317672 3318450 container_manager_linux.go:302] "Creating device plugin manager" devicePluginEnabled=true
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.317708 3318450 state_mem.go:36] "Initialized new in-memory state store"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.318821 3318450 kubelet.go:381] "Attempting to sync node with API server"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.318832 3318450 kubelet.go:270] "Adding static pod path" path="/mnt/LUNE01-SSD/ix-applications/k3s/agent/pod-manifests"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.318852 3318450 kubelet.go:281] "Adding apiserver pod source"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.318865 3318450 apiserver.go:42] "Waiting for node sync before watching apiserver pods"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.323882 3318450 kuberuntime_manager.go:240] "Container runtime initialized" containerRuntime="docker" version="dev" apiVersion="1.41.0"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.324296 3318450 server.go:1170] "Started kubelet"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.324379 3318450 server.go:155] "Starting to listen" address="0.0.0.0" port=10250
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.325053 3318450 server.go:438] "Adding debug handlers to kubelet server"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.325447 3318450 fs_resource_analyzer.go:67] "Starting FS ResourceAnalyzer"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.325743 3318450 volume_manager.go:293] "Starting Kubelet Volume Manager"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.325825 3318450 desired_state_of_world_populator.go:149] "Desired state populator starts to run"
Feb 19 22:40:02 srv-nas k3s[3318450]: E0219 22:40:02.330745 3318450 cri_stats_provider.go:452] "Failed to get the info of the filesystem with mountpoint" err="unable to find data in memory cache" mountpoint="/mnt/LUNE01-SSD/ix-applications/docker"
Feb 19 22:40:02 srv-nas k3s[3318450]: E0219 22:40:02.330768 3318450 kubelet.go:1317] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.331063 3318450 controller.go:616] quota admission added evaluator for: leases.coordination.k8s.io
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.340953 3318450 kubelet_network_linux.go:63] "Initialized iptables rules." protocol=IPv4
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.348697 3318450 kubelet_network_linux.go:63] "Initialized iptables rules." protocol=IPv6
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.348716 3318450 status_manager.go:161] "Starting to sync pod status with apiserver"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.348730 3318450 kubelet.go:2010] "Starting kubelet main sync loop"
Feb 19 22:40:02 srv-nas k3s[3318450]: E0219 22:40:02.348799 3318450 kubelet.go:2034] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.358491 3318450 cpu_manager.go:213] "Starting CPU manager" policy="none"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.358504 3318450 cpu_manager.go:214] "Reconciling" reconcilePeriod="10s"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.358523 3318450 state_mem.go:36] "Initialized new in-memory state store"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.358679 3318450 state_mem.go:88] "Updated default CPUSet" cpuSet=""
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.358690 3318450 state_mem.go:96] "Updated CPUSet assignments" assignments=map[]
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.358696 3318450 policy_none.go:49] "None policy: Start"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.359155 3318450 memory_manager.go:168] "Starting memorymanager" policy="None"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.359174 3318450 state_mem.go:35] "Initializing new in-memory state store"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.359307 3318450 state_mem.go:75] "Updated machine memory state"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="Waiting for cloud-controller-manager privileges to become available"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="Kube API server is now running"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="ETCD server is now running"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="k3s is up and running"
Feb 19 22:40:02 srv-nas systemd[1]: Started Lightweight Kubernetes.
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.426081 3318450 kuberuntime_manager.go:1050] "Updating runtime config through cri with podcidr" CIDR="172.16.0.0/16"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="Docker cri received runtime config &RuntimeConfig{NetworkConfig:&NetworkConfig{PodCidr:172.16.0.0/16,},}"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.426407 3318450 kubelet_network.go:60] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="172.16.0.0/16"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.431492 3318450 kubelet_node_status.go:70] "Attempting to register node" node="ix-truenas"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="Applying CRD addons.k3s.cattle.io"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.438937 3318450 kubelet_node_status.go:108] "Node was previously registered" node="ix-truenas"
Feb 19 22:40:02 srv-nas k3s[3318450]: I0219 22:40:02.439034 3318450 kubelet_node_status.go:73] "Successfully registered node" node="ix-truenas"
Feb 19 22:40:02 srv-nas k3s[3318450]: E0219 22:40:02.448839 3318450 kubelet.go:2034] "Skipping pod synchronization" err="container runtime status check may not have completed yet"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="Applying CRD helmcharts.helm.cattle.io"
Feb 19 22:40:02 srv-nas k3s[3318450]: time="2023-02-19T22:40:02+01:00" level=info msg="Applying CRD helmchartconfigs.helm.cattle.io"
Feb 19 22:40:02 srv-nas k3s[3318450]: E0219 22:40:02.464684 3318450 kubelet.go:1397] "Failed to start ContainerManager" err="failed to initialize top level QOS containers: root container [kubepods] doesn't exist"
Feb 19 22:40:02 srv-nas systemd[1]: k3s.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 22:40:02 srv-nas systemd[1]: k3s.service: Failed with result 'exit-code'.
Feb 19 22:40:02 srv-nas systemd[1]: k3s.service: Consumed 3.534s CPU time.
debug finished in 0 seconds for K3s Logs (last 1000 lines)


