search

k3s-io / k3s

Lightweight Kubernetes
https://k3s.io
Apache License 2.0
28.08k stars 2.35k forks source link

Enhance compressed image tarball logging #2220

Closed rancher-max closed 3 years ago

rancher-max commented 4 years ago

Is your feature request related to a problem? Please describe. Related to: https://github.com/rancher/k3s/issues/2145#issuecomment-689656848

Describe the solution you'd like

Describe alternatives you've considered N/A

Additional context These are additional user-enhancements to supply operators with more information on what is happening during k3s startup, and save time and system power when a potential restart happens.

fapatel1 commented 3 years ago

@rancher-max would you be able to re-validate to see if this still needs to be changed

rancher-max commented 3 years ago

I quickly checked a tarball airgap setup I have using v1.21.3 and still do not see any logs at INFO level mentioning the encountered files in the images dir. For the second part of this issue, I'm not entirely sure, although we still do not have a k3s-local data dir configured so it seems this is still occurring as well.

brandond commented 3 years ago

@rancher-max it tells you what it's importing and from where, do you not have these lines?

time="2021-07-29T12:34:03.470068895-07:00" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/k3s-airgap-images-amd64.tar.zst"
time="2021-07-29T12:34:09.536074627-07:00" level=info msg="Imported docker.io/rancher/pause:3.1"
time="2021-07-29T12:34:09.536095116-07:00" level=info msg="Imported docker.io/rancher/coredns-coredns:1.8.3"
time="2021-07-29T12:34:09.536106757-07:00" level=info msg="Imported docker.io/rancher/klipper-helm:v0.6.1-build20210616"
time="2021-07-29T12:34:09.536115824-07:00" level=info msg="Imported docker.io/rancher/klipper-lb:v0.2.0"
time="2021-07-29T12:34:09.536133958-07:00" level=info msg="Imported docker.io/rancher/library-busybox:1.32.1"
time="2021-07-29T12:34:09.536142825-07:00" level=info msg="Imported docker.io/rancher/library-traefik:2.4.8"
time="2021-07-29T12:34:09.536154257-07:00" level=info msg="Imported docker.io/rancher/local-path-provisioner:v0.0.19"
time="2021-07-29T12:34:09.536162452-07:00" level=info msg="Imported docker.io/rancher/metrics-server:v0.3.6"
rancher-max commented 3 years ago

Hmmmm, I do, but they are buried. See snippet of my logs below that contains all of that if you search for "Import".

That said, I've noticed those logs you posted before, and my logs being less dirty before. This could be due to my setup being uninstalled and reinstalled a few times with different versions. Given that, I'm actually personally okay with closing this issue out.

# k3s server 2>&1 &
[1] 27170
root@ip-172-31-5-153:~# INFO[0000] Acquiring lock file /var/lib/rancher/k3s/data/.lock 
INFO[0000] Preparing data dir /var/lib/rancher/k3s/data/9df574741d2573cbbe6616e8624488b36b3340d077bc50da7cb167f1b08a64d1 
INFO[2021-07-29T18:34:54.438866947Z] Starting k3s v1.21.3+k3s1 (1d1f220f)         
INFO[2021-07-29T18:34:54.447291800Z] Configuring sqlite3 database connection pooling: maxIdleConns=2, maxOpenConns=0, connMaxLifetime=0s 
INFO[2021-07-29T18:34:54.447365451Z] Configuring database table schema and indexes, this may take a moment... 
INFO[2021-07-29T18:34:54.450726615Z] Database tables and indexes are up to date   
INFO[2021-07-29T18:34:54.453256075Z] Kine listening on unix://kine.sock           
INFO[2021-07-29T18:34:54.467891810Z] certificate CN=system:admin,O=system:masters signed by CN=k3s-client-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.468766822Z] certificate CN=system:kube-controller-manager signed by CN=k3s-client-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.469580073Z] certificate CN=system:kube-scheduler signed by CN=k3s-client-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.470439832Z] certificate CN=kube-apiserver signed by CN=k3s-client-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.471347029Z] certificate CN=system:kube-proxy signed by CN=k3s-client-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.472162711Z] certificate CN=system:k3s-controller signed by CN=k3s-client-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.473005007Z] certificate CN=k3s-cloud-controller-manager signed by CN=k3s-client-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.474400387Z] certificate CN=kube-apiserver signed by CN=k3s-server-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.475582564Z] certificate CN=system:auth-proxy signed by CN=k3s-request-header-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.476774103Z] certificate CN=etcd-server signed by CN=etcd-server-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.477547469Z] certificate CN=etcd-client signed by CN=etcd-server-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.478640593Z] certificate CN=etcd-peer signed by CN=etcd-peer-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.840487960Z] certificate CN=k3s,O=k3s signed by CN=k3s-server-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:54 +0000 UTC 
INFO[2021-07-29T18:34:54.841188045Z] Active TLS secret  (ver=) (count 8): map[listener.cattle.io/cn-10.43.0.1:10.43.0.1 listener.cattle.io/cn-127.0.0.1:127.0.0.1 listener.cattle.io/cn-172.31.5.153:172.31.5.153 listener.cattle.io/cn-kubernetes:kubernetes listener.cattle.io/cn-kubernetes.default:kubernetes.default listener.cattle.io/cn-kubernetes.default.svc:kubernetes.default.svc listener.cattle.io/cn-kubernetes.default.svc.cluster.local:kubernetes.default.svc.cluster.local listener.cattle.io/cn-localhost:localhost listener.cattle.io/fingerprint:SHA1=B05F40177D8FFF8DF3C6B69267C8D94ADFCD845E] 
INFO[2021-07-29T18:34:54.850288200Z] Running kube-apiserver --advertise-port=6443 --allow-privileged=true --anonymous-auth=false --api-audiences=https://kubernetes.default.svc.cluster.local,k3s --authorization-mode=Node,RBAC --bind-address=127.0.0.1 --cert-dir=/var/lib/rancher/k3s/server/tls/temporary-certs --client-ca-file=/var/lib/rancher/k3s/server/tls/client-ca.crt --enable-admission-plugins=NodeRestriction --etcd-servers=unix://kine.sock --insecure-port=0 --kubelet-certificate-authority=/var/lib/rancher/k3s/server/tls/server-ca.crt --kubelet-client-certificate=/var/lib/rancher/k3s/server/tls/client-kube-apiserver.crt --kubelet-client-key=/var/lib/rancher/k3s/server/tls/client-kube-apiserver.key --profiling=false --proxy-client-cert-file=/var/lib/rancher/k3s/server/tls/client-auth-proxy.crt --proxy-client-key-file=/var/lib/rancher/k3s/server/tls/client-auth-proxy.key --requestheader-allowed-names=system:auth-proxy --requestheader-client-ca-file=/var/lib/rancher/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=/var/lib/rancher/k3s/server/tls/service.key --service-account-signing-key-file=/var/lib/rancher/k3s/server/tls/service.key --service-cluster-ip-range=10.43.0.0/16 --service-node-port-range=30000-32767 --storage-backend=etcd3 --tls-cert-file=/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.crt --tls-private-key-file=/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.key 
Flag --insecure-port has been deprecated, This flag has no effect now and will be removed in v1.24.
I0729 18:34:54.851816   27170 server.go:656] external host was not specified, using 172.31.5.153
I0729 18:34:54.852134   27170 server.go:195] Version: v1.21.3+k3s1
INFO[2021-07-29T18:34:55.116685099Z] Cluster-Http-Server 2021/07/29 18:34:55 http: TLS handshake error from 172.31.10.82:45326: remote error: tls: bad certificate 
I0729 18:34:55.555751   27170 shared_informer.go:240] Waiting for caches to sync for node_authorizer
I0729 18:34:55.559447   27170 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.
I0729 18:34:55.559634   27170 plugins.go:161] Loaded 10 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota.
I0729 18:34:55.564192   27170 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.
I0729 18:34:55.564397   27170 plugins.go:161] Loaded 10 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota.
I0729 18:34:55.595855   27170 instance.go:283] Using reconciler: lease
I0729 18:34:55.700355   27170 rest.go:130] the default service ipfamily for this cluster is: IPv4
W0729 18:34:56.309678   27170 genericapiserver.go:425] Skipping API node.k8s.io/v1alpha1 because it has no resources.
W0729 18:34:56.322369   27170 genericapiserver.go:425] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.
W0729 18:34:56.327207   27170 genericapiserver.go:425] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources.
W0729 18:34:56.334964   27170 genericapiserver.go:425] Skipping API storage.k8s.io/v1alpha1 because it has no resources.
W0729 18:34:56.338302   27170 genericapiserver.go:425] Skipping API flowcontrol.apiserver.k8s.io/v1alpha1 because it has no resources.
W0729 18:34:56.344353   27170 genericapiserver.go:425] Skipping API apps/v1beta2 because it has no resources.
W0729 18:34:56.344417   27170 genericapiserver.go:425] Skipping API apps/v1beta1 because it has no resources.
I0729 18:34:56.357504   27170 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.
I0729 18:34:56.357556   27170 plugins.go:161] Loaded 10 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota.
INFO[2021-07-29T18:34:56.374465186Z] Running kube-scheduler --address=127.0.0.1 --bind-address=127.0.0.1 --kubeconfig=/var/lib/rancher/k3s/server/cred/scheduler.kubeconfig --leader-elect=false --port=10251 --profiling=false --secure-port=0 
INFO[2021-07-29T18:34:56.375199056Z] Running kube-controller-manager --address=127.0.0.1 --allocate-node-cidrs=true --bind-address=127.0.0.1 --cluster-cidr=10.42.0.0/16 --cluster-signing-kube-apiserver-client-cert-file=/var/lib/rancher/k3s/server/tls/client-ca.crt --cluster-signing-kube-apiserver-client-key-file=/var/lib/rancher/k3s/server/tls/client-ca.key --cluster-signing-kubelet-client-cert-file=/var/lib/rancher/k3s/server/tls/client-ca.crt --cluster-signing-kubelet-client-key-file=/var/lib/rancher/k3s/server/tls/client-ca.key --cluster-signing-kubelet-serving-cert-file=/var/lib/rancher/k3s/server/tls/server-ca.crt --cluster-signing-kubelet-serving-key-file=/var/lib/rancher/k3s/server/tls/server-ca.key --cluster-signing-legacy-unknown-cert-file=/var/lib/rancher/k3s/server/tls/client-ca.crt --cluster-signing-legacy-unknown-key-file=/var/lib/rancher/k3s/server/tls/client-ca.key --configure-cloud-routes=false --controllers=*,-service,-route,-cloud-node-lifecycle --kubeconfig=/var/lib/rancher/k3s/server/cred/controller.kubeconfig --leader-elect=false --port=10252 --profiling=false --root-ca-file=/var/lib/rancher/k3s/server/tls/server-ca.crt --secure-port=0 --service-account-private-key-file=/var/lib/rancher/k3s/server/tls/service.key --use-service-account-credentials=true 
INFO[2021-07-29T18:34:56.375867156Z] Running cloud-controller-manager --allocate-node-cidrs=true --bind-address=127.0.0.1 --cloud-provider=k3s --cluster-cidr=10.42.0.0/16 --configure-cloud-routes=false --kubeconfig=/var/lib/rancher/k3s/server/cred/cloud-controller.kubeconfig --leader-elect=false --node-status-update-frequency=1m0s --port=0 --profiling=false 
INFO[2021-07-29T18:34:56.376870927Z] Node token is available at /var/lib/rancher/k3s/server/token 
INFO[2021-07-29T18:34:56.376935986Z] To join node to cluster: k3s agent -s https://172.31.5.153:6443 -t ${NODE_TOKEN} 
INFO[2021-07-29T18:34:56.378972892Z] Wrote kubeconfig /etc/rancher/k3s/k3s.yaml   
INFO[2021-07-29T18:34:56.379014318Z] Run: k3s kubectl                             
INFO[2021-07-29T18:34:56.379445433Z] Waiting for API server to become available   
INFO[2021-07-29T18:34:56.426267966Z] Cluster-Http-Server 2021/07/29 18:34:56 http: TLS handshake error from 127.0.0.1:56428: remote error: tls: bad certificate 
INFO[2021-07-29T18:34:56.431493920Z] Cluster-Http-Server 2021/07/29 18:34:56 http: TLS handshake error from 127.0.0.1:56436: remote error: tls: bad certificate 
INFO[2021-07-29T18:34:56.445753499Z] certificate CN=ip-172-31-5-153 signed by CN=k3s-server-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:56 +0000 UTC 
INFO[2021-07-29T18:34:56.449622629Z] certificate CN=system:node:ip-172-31-5-153,O=system:nodes signed by CN=k3s-client-ca@1627583694: notBefore=2021-07-29 18:34:54 +0000 UTC notAfter=2022-07-29 18:34:56 +0000 UTC 
INFO[2021-07-29T18:34:56.834037602Z] Module overlay was already loaded            
INFO[2021-07-29T18:34:56.834071987Z] Module nf_conntrack was already loaded       
INFO[2021-07-29T18:34:56.834084519Z] Module br_netfilter was already loaded       
INFO[2021-07-29T18:34:56.834095640Z] Module iptable_nat was already loaded        
INFO[2021-07-29T18:34:56.835961920Z] Logging containerd to /var/lib/rancher/k3s/agent/containerd/containerd.log 
INFO[2021-07-29T18:34:56.836175082Z] Running containerd -c /var/lib/rancher/k3s/agent/etc/containerd/config.toml -a /run/k3s/containerd/containerd.sock --state /run/k3s/containerd --root /var/lib/rancher/k3s/agent/containerd 
INFO[2021-07-29T18:34:57.185102451Z] Cluster-Http-Server 2021/07/29 18:34:57 http: TLS handshake error from 172.31.10.82:45328: remote error: tls: bad certificate 
INFO[2021-07-29T18:34:57.213595995Z] Cluster-Http-Server 2021/07/29 18:34:57 http: TLS handshake error from 172.31.10.82:45332: remote error: tls: bad certificate 
INFO[2021-07-29T18:34:57.600706452Z] Cluster-Http-Server 2021/07/29 18:34:57 http: TLS handshake error from 172.31.10.82:56938: remote error: tls: bad certificate 
INFO[2021-07-29T18:34:57.855885749Z] Containerd is now running                    
INFO[2021-07-29T18:34:57.862263645Z] Importing images from /var/lib/rancher/k3s/agent/images/k3s-airgap-images-amd64.tar 
INFO[2021-07-29T18:34:58.321075347Z] Cluster-Http-Server 2021/07/29 18:34:58 http: TLS handshake error from 172.31.10.82:45338: remote error: tls: bad certificate 
I0729 18:35:00.928829   27170 secure_serving.go:197] Serving securely on 127.0.0.1:6444
I0729 18:35:00.929099   27170 dynamic_cafile_content.go:167] Starting request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt
I0729 18:35:00.929255   27170 dynamic_serving_content.go:130] Starting serving-cert::/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.crt::/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.key
I0729 18:35:00.929392   27170 tlsconfig.go:240] Starting DynamicServingCertificateController
I0729 18:35:00.930636   27170 controller.go:83] Starting OpenAPI AggregationController
I0729 18:35:00.941520   27170 apf_controller.go:294] Starting API Priority and Fairness config controller
I0729 18:35:00.941697   27170 available_controller.go:475] Starting AvailableConditionController
I0729 18:35:00.941819   27170 cache.go:32] Waiting for caches to sync for AvailableConditionController controller
I0729 18:35:00.941968   27170 autoregister_controller.go:141] Starting autoregister controller
I0729 18:35:00.942052   27170 cache.go:32] Waiting for caches to sync for autoregister controller
I0729 18:35:00.942393   27170 dynamic_serving_content.go:130] Starting aggregator-proxy-cert::/var/lib/rancher/k3s/server/tls/client-auth-proxy.crt::/var/lib/rancher/k3s/server/tls/client-auth-proxy.key
I0729 18:35:00.943432   27170 apiservice_controller.go:97] Starting APIServiceRegistrationController
I0729 18:35:00.943509   27170 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller
I0729 18:35:00.943852   27170 customresource_discovery_controller.go:209] Starting DiscoveryController
I0729 18:35:00.943965   27170 dynamic_cafile_content.go:167] Starting client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt
I0729 18:35:00.971752   27170 crdregistration_controller.go:111] Starting crd-autoregister controller
I0729 18:35:00.971909   27170 shared_informer.go:240] Waiting for caches to sync for crd-autoregister
I0729 18:35:00.972381   27170 dynamic_cafile_content.go:167] Starting client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt
I0729 18:35:00.972512   27170 dynamic_cafile_content.go:167] Starting request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt
I0729 18:35:00.972639   27170 cluster_authentication_trust_controller.go:440] Starting cluster_authentication_trust_controller controller
I0729 18:35:00.972725   27170 shared_informer.go:240] Waiting for caches to sync for cluster_authentication_trust_controller
I0729 18:35:00.973108   27170 controller.go:86] Starting OpenAPI controller
I0729 18:35:00.973271   27170 naming_controller.go:291] Starting NamingConditionController
I0729 18:35:00.973411   27170 establishing_controller.go:76] Starting EstablishingController
I0729 18:35:00.973546   27170 nonstructuralschema_controller.go:192] Starting NonStructuralSchemaConditionController
I0729 18:35:00.973682   27170 apiapproval_controller.go:186] Starting KubernetesAPIApprovalPolicyConformantConditionController
I0729 18:35:00.973817   27170 crd_finalizer.go:266] Starting CRDFinalizer
I0729 18:35:01.047742   27170 apf_controller.go:299] Running API Priority and Fairness config worker
I0729 18:35:01.047921   27170 cache.go:39] Caches are synced for AvailableConditionController controller
I0729 18:35:01.048023   27170 cache.go:39] Caches are synced for autoregister controller
I0729 18:35:01.048448   27170 cache.go:39] Caches are synced for APIServiceRegistrationController controller
I0729 18:35:01.061309   27170 shared_informer.go:247] Caches are synced for node_authorizer 
I0729 18:35:01.072159   27170 shared_informer.go:247] Caches are synced for crd-autoregister 
I0729 18:35:01.085889   27170 shared_informer.go:247] Caches are synced for cluster_authentication_trust_controller 
I0729 18:35:01.098495   27170 controller.go:611] quota admission added evaluator for: namespaces
E0729 18:35:01.185138   27170 controller.go:151] Unable to perform initial Kubernetes service initialization: Service "kubernetes" is invalid: spec.clusterIPs: Invalid value: []string{"10.43.0.1"}: failed to allocated ip:10.43.0.1 with error:cannot allocate resources of type serviceipallocations at this time
E0729 18:35:01.199214   27170 controller.go:156] Unable to remove old endpoints from kubernetes service: StorageError: key not found, Code: 1, Key: /registry/masterleases/172.31.5.153, ResourceVersion: 0, AdditionalErrorMsg: 
INFO[2021-07-29T18:35:01.806323043Z] Cluster-Http-Server 2021/07/29 18:35:01 http: TLS handshake error from 172.31.10.82:1024: remote error: tls: bad certificate 
INFO[2021-07-29T18:35:01.927599965Z] Cluster-Http-Server 2021/07/29 18:35:01 http: TLS handshake error from 172.31.10.82:56952: remote error: tls: bad certificate 
I0729 18:35:01.928911   27170 controller.go:132] OpenAPI AggregationController: action for item : Nothing (removed from the queue).
I0729 18:35:01.928944   27170 controller.go:132] OpenAPI AggregationController: action for item k8s_internal_local_delegation_chain_0000000000: Nothing (removed from the queue).
I0729 18:35:01.941425   27170 storage_scheduling.go:132] created PriorityClass system-node-critical with value 2000001000
I0729 18:35:01.952066   27170 storage_scheduling.go:132] created PriorityClass system-cluster-critical with value 2000000000
I0729 18:35:01.952218   27170 storage_scheduling.go:148] all system priority classes are created successfully or already exist.
INFO[2021-07-29T18:35:02.195057773Z] Cluster-Http-Server 2021/07/29 18:35:02 http: TLS handshake error from 172.31.10.82:45350: remote error: tls: bad certificate 
INFO[2021-07-29T18:35:02.220837040Z] Cluster-Http-Server 2021/07/29 18:35:02 http: TLS handshake error from 172.31.10.82:45354: remote error: tls: bad certificate 
INFO[2021-07-29T18:35:02.543979402Z] Cluster-Http-Server 2021/07/29 18:35:02 http: TLS handshake error from 172.31.10.82:45358: remote error: tls: bad certificate 
I0729 18:35:02.567112   27170 controller.go:611] quota admission added evaluator for: roles.rbac.authorization.k8s.io
I0729 18:35:02.617209   27170 controller.go:611] quota admission added evaluator for: rolebindings.rbac.authorization.k8s.io
W0729 18:35:02.703816   27170 lease.go:233] Resetting endpoints for master service "kubernetes" to [172.31.5.153]
I0729 18:35:02.704887   27170 controller.go:611] quota admission added evaluator for: endpoints
I0729 18:35:02.709202   27170 controller.go:611] quota admission added evaluator for: endpointslices.discovery.k8s.io
INFO[2021-07-29T18:35:03.065953078Z] Kube API server is now running               
INFO[2021-07-29T18:35:03.066043051Z] k3s is up and running                        
INFO[2021-07-29T18:35:03.067142176Z] Waiting for cloud-controller-manager privileges to become available 
Flag --address has been deprecated, see --bind-address instead.
I0729 18:35:03.082970   27170 controllermanager.go:175] Version: v1.21.3+k3s1
I0729 18:35:03.083508   27170 deprecated_insecure_serving.go:53] Serving insecurely on 127.0.0.1:10252
W0729 18:35:03.094669   27170 authorization.go:47] Authorization is disabled
W0729 18:35:03.094789   27170 authentication.go:47] Authentication is disabled
I0729 18:35:03.094865   27170 deprecated_insecure_serving.go:51] Serving healthz insecurely on 127.0.0.1:10251
INFO[2021-07-29T18:35:03.118762259Z] Creating CRD addons.k3s.cattle.io            
INFO[2021-07-29T18:35:03.172900120Z] Creating CRD helmcharts.helm.cattle.io       
INFO[2021-07-29T18:35:03.187654283Z] Creating CRD helmchartconfigs.helm.cattle.io 
INFO[2021-07-29T18:35:03.209154148Z] Waiting for CRD helmcharts.helm.cattle.io to become available 
INFO[2021-07-29T18:35:03.596383892Z] Cluster-Http-Server 2021/07/29 18:35:03 http: TLS handshake error from 172.31.10.82:45362: remote error: tls: bad certificate 
I0729 18:35:03.687158   27170 shared_informer.go:240] Waiting for caches to sync for tokens
I0729 18:35:03.700268   27170 controller.go:611] quota admission added evaluator for: serviceaccounts
I0729 18:35:03.703800   27170 controllermanager.go:574] Started "daemonset"
I0729 18:35:03.704065   27170 daemon_controller.go:285] Starting daemon sets controller
I0729 18:35:03.704143   27170 shared_informer.go:240] Waiting for caches to sync for daemon sets
I0729 18:35:03.715771   27170 controllermanager.go:574] Started "statefulset"
I0729 18:35:03.716035   27170 stateful_set.go:146] Starting stateful set controller
I0729 18:35:03.716111   27170 shared_informer.go:240] Waiting for caches to sync for stateful set
INFO[2021-07-29T18:35:03.716475356Z] Done waiting for CRD helmcharts.helm.cattle.io to become available 
INFO[2021-07-29T18:35:03.716570800Z] Waiting for CRD helmchartconfigs.helm.cattle.io to become available 
I0729 18:35:03.725972   27170 controllermanager.go:574] Started "ttl-after-finished"
I0729 18:35:03.726222   27170 ttlafterfinished_controller.go:109] Starting TTL after finished controller
I0729 18:35:03.726317   27170 shared_informer.go:240] Waiting for caches to sync for TTL after finished
I0729 18:35:03.740865   27170 controllermanager.go:574] Started "endpoint"
I0729 18:35:03.741028   27170 endpoints_controller.go:189] Starting endpoint controller
I0729 18:35:03.741136   27170 shared_informer.go:240] Waiting for caches to sync for endpoint
I0729 18:35:03.761102   27170 controllermanager.go:574] Started "csrapproving"
I0729 18:35:03.761360   27170 certificate_controller.go:118] Starting certificate controller "csrapproving"
I0729 18:35:03.761384   27170 shared_informer.go:240] Waiting for caches to sync for certificate-csrapproving
I0729 18:35:03.778559   27170 controllermanager.go:574] Started "persistentvolume-expander"
I0729 18:35:03.778908   27170 expand_controller.go:327] Starting expand controller
I0729 18:35:03.779139   27170 shared_informer.go:240] Waiting for caches to sync for expand
I0729 18:35:03.787468   27170 shared_informer.go:247] Caches are synced for tokens 
I0729 18:35:03.803602   27170 controllermanager.go:574] Started "ephemeral-volume"
I0729 18:35:03.804037   27170 controller.go:170] Starting ephemeral volume controller
I0729 18:35:03.804065   27170 shared_informer.go:240] Waiting for caches to sync for ephemeral
I0729 18:35:03.868056   27170 node_lifecycle_controller.go:377] Sending events to api server.
I0729 18:35:03.868279   27170 taint_manager.go:163] "Sending events to api server"
I0729 18:35:03.868406   27170 node_lifecycle_controller.go:505] Controller will reconcile labels.
I0729 18:35:03.868474   27170 controllermanager.go:574] Started "nodelifecycle"
I0729 18:35:03.868673   27170 node_lifecycle_controller.go:539] Starting node controller
I0729 18:35:03.868696   27170 shared_informer.go:240] Waiting for caches to sync for taint
I0729 18:35:03.923762   27170 controllermanager.go:574] Started "clusterrole-aggregation"
I0729 18:35:03.923932   27170 clusterroleaggregation_controller.go:194] Starting ClusterRoleAggregator
I0729 18:35:03.923960   27170 shared_informer.go:240] Waiting for caches to sync for ClusterRoleAggregator
I0729 18:35:03.958716   27170 controllermanager.go:574] Started "podgc"
I0729 18:35:03.958979   27170 gc_controller.go:89] Starting GC controller
I0729 18:35:03.959002   27170 shared_informer.go:240] Waiting for caches to sync for GC
I0729 18:35:04.076334   27170 controllermanager.go:574] Started "namespace"
I0729 18:35:04.076615   27170 namespace_controller.go:200] Starting namespace controller
I0729 18:35:04.076705   27170 shared_informer.go:240] Waiting for caches to sync for namespace
I0729 18:35:04.118737   27170 controllermanager.go:574] Started "deployment"
I0729 18:35:04.120736   27170 deployment_controller.go:153] "Starting controller" controller="deployment"
I0729 18:35:04.120839   27170 shared_informer.go:240] Waiting for caches to sync for deployment
INFO[2021-07-29T18:35:04.222187783Z] Done waiting for CRD helmchartconfigs.helm.cattle.io to become available 
INFO[2021-07-29T18:35:04.233601795Z] Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-9.18.2.tgz 
INFO[2021-07-29T18:35:04.234983552Z] Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-crd-9.18.2.tgz 
I0729 18:35:04.397249   27170 controllermanager.go:574] Started "cronjob"
I0729 18:35:04.397583   27170 cronjob_controllerv2.go:125] Starting cronjob controller v2
I0729 18:35:04.397612   27170 shared_informer.go:240] Waiting for caches to sync for cronjob
INFO[2021-07-29T18:35:04.432876296Z] Failed to get existing traefik HelmChart      error="helmcharts.helm.cattle.io \"traefik\" not found"
INFO[2021-07-29T18:35:04.433172630Z] Writing manifest: /var/lib/rancher/k3s/server/manifests/local-storage.yaml 
INFO[2021-07-29T18:35:04.433349137Z] Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/aggregated-metrics-reader.yaml 
INFO[2021-07-29T18:35:04.433474876Z] Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/auth-delegator.yaml 
INFO[2021-07-29T18:35:04.433596124Z] Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/auth-reader.yaml 
INFO[2021-07-29T18:35:04.433732624Z] Writing manifest: /var/lib/rancher/k3s/server/manifests/traefik.yaml 
INFO[2021-07-29T18:35:04.433859473Z] Writing manifest: /var/lib/rancher/k3s/server/manifests/ccm.yaml 
INFO[2021-07-29T18:35:04.434072245Z] Writing manifest: /var/lib/rancher/k3s/server/manifests/coredns.yaml 
INFO[2021-07-29T18:35:04.434194834Z] Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/metrics-server-service.yaml 
INFO[2021-07-29T18:35:04.434319012Z] Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/resource-reader.yaml 
INFO[2021-07-29T18:35:04.434457723Z] Writing manifest: /var/lib/rancher/k3s/server/manifests/rolebindings.yaml 
INFO[2021-07-29T18:35:04.434573770Z] Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/metrics-apiservice.yaml 
INFO[2021-07-29T18:35:04.434716412Z] Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/metrics-server-deployment.yaml 
I0729 18:35:04.545616   27170 controllermanager.go:574] Started "root-ca-cert-publisher"
I0729 18:35:04.545914   27170 publisher.go:102] Starting root CA certificate configmap publisher
I0729 18:35:04.546041   27170 shared_informer.go:240] Waiting for caches to sync for crt configmap
INFO[2021-07-29T18:35:04.639426598Z] Starting k3s.cattle.io/v1, Kind=Addon controller 
INFO[2021-07-29T18:35:04.763366979Z] Waiting for control-plane node ip-172-31-5-153 startup: nodes "ip-172-31-5-153" not found 
I0729 18:35:04.870354   27170 controllermanager.go:574] Started "replicationcontroller"
I0729 18:35:04.870673   27170 replica_set.go:182] Starting replicationcontroller controller
I0729 18:35:04.870755   27170 shared_informer.go:240] Waiting for caches to sync for ReplicationController
INFO[2021-07-29T18:35:04.950473725Z] Cluster dns configmap has been set successfully 
INFO[2021-07-29T18:35:04.963761758Z] Starting helm.cattle.io/v1, Kind=HelmChartConfig controller 
INFO[2021-07-29T18:35:04.964099829Z] Starting helm.cattle.io/v1, Kind=HelmChart controller 
INFO[2021-07-29T18:35:04.964383172Z] Starting batch/v1, Kind=Job controller       
INFO[2021-07-29T18:35:05.201786692Z] Cluster-Http-Server 2021/07/29 18:35:05 http: TLS handshake error from 172.31.10.82:45366: remote error: tls: bad certificate 
INFO[2021-07-29T18:35:05.207661363Z] Cluster-Http-Server 2021/07/29 18:35:05 http: TLS handshake error from 172.31.10.82:45370: remote error: tls: bad certificate 
INFO[2021-07-29T18:35:05.217556788Z] Cluster-Http-Server 2021/07/29 18:35:05 http: TLS handshake error from 172.31.10.82:45374: remote error: tls: bad certificate 
INFO[2021-07-29T18:35:05.235341635Z] Cluster-Http-Server 2021/07/29 18:35:05 http: TLS handshake error from 172.31.10.82:45378: remote error: tls: bad certificate 
INFO[2021-07-29T18:35:05.247342786Z] Cluster-Http-Server 2021/07/29 18:35:05 http: TLS handshake error from 172.31.10.82:45382: remote error: tls: bad certificate 
I0729 18:35:05.312655   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for statefulsets.apps
I0729 18:35:05.312828   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for ingresses.extensions
I0729 18:35:05.312953   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for poddisruptionbudgets.policy
I0729 18:35:05.313143   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for addons.k3s.cattle.io
I0729 18:35:05.313277   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for limitranges
I0729 18:35:05.313388   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for replicasets.apps
I0729 18:35:05.313513   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for helmchartconfigs.helm.cattle.io
I0729 18:35:05.313682   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for daemonsets.apps
I0729 18:35:05.313794   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for jobs.batch
I0729 18:35:05.313949   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for deployments.apps
I0729 18:35:05.314066   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for events.events.k8s.io
I0729 18:35:05.314186   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for helmcharts.helm.cattle.io
I0729 18:35:05.314308   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for ingresses.networking.k8s.io
I0729 18:35:05.314429   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for networkpolicies.networking.k8s.io
I0729 18:35:05.314563   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for rolebindings.rbac.authorization.k8s.io
I0729 18:35:05.314683   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for endpointslices.discovery.k8s.io
I0729 18:35:05.314792   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for leases.coordination.k8s.io
W0729 18:35:05.314896   27170 shared_informer.go:494] resyncPeriod 21h28m24.918934309s is smaller than resyncCheckPeriod 22h37m21.509050895s and the informer has already started. Changing it to 22h37m21.509050895s
I0729 18:35:05.315021   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for serviceaccounts
I0729 18:35:05.315130   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for endpoints
I0729 18:35:05.315277   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for roles.rbac.authorization.k8s.io
I0729 18:35:05.315394   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for controllerrevisions.apps
I0729 18:35:05.315507   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for horizontalpodautoscalers.autoscaling
I0729 18:35:05.315619   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for cronjobs.batch
I0729 18:35:05.315774   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for csistoragecapacities.storage.k8s.io
I0729 18:35:05.315893   27170 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for podtemplates
I0729 18:35:05.315986   27170 controllermanager.go:574] Started "resourcequota"
I0729 18:35:05.317828   27170 resource_quota_controller.go:273] Starting resource quota controller
I0729 18:35:05.317940   27170 shared_informer.go:240] Waiting for caches to sync for resource quota
I0729 18:35:05.318045   27170 resource_quota_monitor.go:304] QuotaMonitor running
INFO[2021-07-29T18:35:05.368294948Z] Starting /v1, Kind=Secret controller         
INFO[2021-07-29T18:35:05.368609415Z] Starting /v1, Kind=Node controller           
INFO[2021-07-29T18:35:05.368741875Z] Starting /v1, Kind=Service controller        
INFO[2021-07-29T18:35:05.368883937Z] Starting /v1, Kind=Pod controller            
INFO[2021-07-29T18:35:05.369017747Z] Starting /v1, Kind=Endpoints controller      
I0729 18:35:05.388707   27170 controllermanager.go:574] Started "serviceaccount"
I0729 18:35:05.388932   27170 serviceaccounts_controller.go:117] Starting service account controller
I0729 18:35:05.389071   27170 shared_informer.go:240] Waiting for caches to sync for service account
I0729 18:35:05.466769   27170 controllermanager.go:574] Started "ttl"
W0729 18:35:05.466935   27170 controllermanager.go:553] "tokencleaner" is disabled
I0729 18:35:05.467189   27170 ttl_controller.go:121] Starting TTL controller
I0729 18:35:05.467294   27170 shared_informer.go:240] Waiting for caches to sync for TTL
I0729 18:35:05.483987   27170 node_ipam_controller.go:91] Sending events to api server.
INFO[2021-07-29T18:35:05.535299989Z] Active TLS secret k3s-serving (ver=275) (count 8): map[listener.cattle.io/cn-10.43.0.1:10.43.0.1 listener.cattle.io/cn-127.0.0.1:127.0.0.1 listener.cattle.io/cn-172.31.5.153:172.31.5.153 listener.cattle.io/cn-kubernetes:kubernetes listener.cattle.io/cn-kubernetes.default:kubernetes.default listener.cattle.io/cn-kubernetes.default.svc:kubernetes.default.svc listener.cattle.io/cn-kubernetes.default.svc.cluster.local:kubernetes.default.svc.cluster.local listener.cattle.io/cn-localhost:localhost listener.cattle.io/fingerprint:SHA1=B05F40177D8FFF8DF3C6B69267C8D94ADFCD845E] 
INFO[2021-07-29T18:35:05.788003274Z] Waiting for control-plane node ip-172-31-5-153 startup: nodes "ip-172-31-5-153" not found 
INFO[2021-07-29T18:35:06.143846421Z] Cluster-Http-Server 2021/07/29 18:35:06 http: TLS handshake error from 172.31.10.82:45386: remote error: tls: bad certificate 
INFO[2021-07-29T18:35:06.550827228Z] Cluster-Http-Server 2021/07/29 18:35:06 http: TLS handshake error from 172.31.10.82:45390: remote error: tls: bad certificate 
I0729 18:35:06.656264   27170 controller.go:611] quota admission added evaluator for: addons.k3s.cattle.io
INFO[2021-07-29T18:35:06.665615376Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"ccm", UID:"920a0074-1f91-4ff4-b9a1-effbae71a93f", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"284", FieldPath:""}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at "/var/lib/rancher/k3s/server/manifests/ccm.yaml" 
INFO[2021-07-29T18:35:06.701033319Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"ccm", UID:"920a0074-1f91-4ff4-b9a1-effbae71a93f", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"284", FieldPath:""}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at "/var/lib/rancher/k3s/server/manifests/ccm.yaml" 
INFO[2021-07-29T18:35:06.720830588Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"coredns", UID:"a459050e-a3d7-4d1a-964d-9316cb2566d7", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"289", FieldPath:""}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at "/var/lib/rancher/k3s/server/manifests/coredns.yaml" 
INFO[2021-07-29T18:35:06.794060353Z] Waiting for control-plane node ip-172-31-5-153 startup: nodes "ip-172-31-5-153" not found 
I0729 18:35:06.823975   27170 controller.go:611] quota admission added evaluator for: deployments.apps
INFO[2021-07-29T18:35:06.852553337Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"coredns", UID:"a459050e-a3d7-4d1a-964d-9316cb2566d7", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"289", FieldPath:""}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at "/var/lib/rancher/k3s/server/manifests/coredns.yaml" 
INFO[2021-07-29T18:35:06.869594243Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"local-storage", UID:"a417cf94-7a1b-4b4c-8295-87c1a45a0059", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"301", FieldPath:""}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at "/var/lib/rancher/k3s/server/manifests/local-storage.yaml" 
INFO[2021-07-29T18:35:06.952810865Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"local-storage", UID:"a417cf94-7a1b-4b4c-8295-87c1a45a0059", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"301", FieldPath:""}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at "/var/lib/rancher/k3s/server/manifests/local-storage.yaml" 
INFO[2021-07-29T18:35:06.965152147Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"aggregated-metrics-reader", UID:"15a954fb-3d0b-46a9-92c3-bd9f1c4c181b", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"312", FieldPath:""}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/aggregated-metrics-reader.yaml" 
INFO[2021-07-29T18:35:06.975885787Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"aggregated-metrics-reader", UID:"15a954fb-3d0b-46a9-92c3-bd9f1c4c181b", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"312", FieldPath:""}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/aggregated-metrics-reader.yaml" 
INFO[2021-07-29T18:35:06.990022877Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"auth-delegator", UID:"3bd4dbfc-2a16-4b6e-81bd-5ef792a842b7", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"315", FieldPath:""}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/auth-delegator.yaml" 
INFO[2021-07-29T18:35:07.003044280Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"auth-delegator", UID:"3bd4dbfc-2a16-4b6e-81bd-5ef792a842b7", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"315", FieldPath:""}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/auth-delegator.yaml" 
INFO[2021-07-29T18:35:07.015680946Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"auth-reader", UID:"a4ac0942-b767-4cb2-a587-1e507036741f", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"318", FieldPath:""}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/auth-reader.yaml" 
INFO[2021-07-29T18:35:07.038219597Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"auth-reader", UID:"a4ac0942-b767-4cb2-a587-1e507036741f", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"318", FieldPath:""}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/auth-reader.yaml" 
INFO[2021-07-29T18:35:07.124138705Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"metrics-apiservice", UID:"1160c51b-fdec-4f6a-9a99-13ec537939c5", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"324", FieldPath:""}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/metrics-apiservice.yaml" 
INFO[2021-07-29T18:35:07.164678595Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"metrics-apiservice", UID:"1160c51b-fdec-4f6a-9a99-13ec537939c5", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"324", FieldPath:""}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/metrics-apiservice.yaml" 
INFO[2021-07-29T18:35:07.199070414Z] Cluster-Http-Server 2021/07/29 18:35:07 http: TLS handshake error from 172.31.10.82:45392: remote error: tls: bad certificate 
INFO[2021-07-29T18:35:07.250416736Z] Cluster-Http-Server 2021/07/29 18:35:07 http: TLS handshake error from 172.31.10.82:45396: remote error: tls: bad certificate 
INFO[2021-07-29T18:35:07.624149726Z] Cluster-Http-Server 2021/07/29 18:35:07 http: TLS handshake error from 172.31.10.82:57002: remote error: tls: bad certificate 
INFO[2021-07-29T18:35:07.645157197Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"metrics-server-deployment", UID:"96ff2c49-5df8-4fe6-b85d-520b109f0541", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"329", FieldPath:""}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/metrics-server-deployment.yaml" 
INFO[2021-07-29T18:35:07.831460383Z] Waiting for control-plane node ip-172-31-5-153 startup: nodes "ip-172-31-5-153" not found 
INFO[2021-07-29T18:35:07.913077175Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"metrics-server-deployment", UID:"96ff2c49-5df8-4fe6-b85d-520b109f0541", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"329", FieldPath:""}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/metrics-server-deployment.yaml" 
INFO[2021-07-29T18:35:08.027063173Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"metrics-server-service", UID:"c0abf699-b53e-40a5-9282-b9e934273637", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"335", FieldPath:""}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/metrics-server-service.yaml" 
INFO[2021-07-29T18:35:08.084718091Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"metrics-server-service", UID:"c0abf699-b53e-40a5-9282-b9e934273637", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"335", FieldPath:""}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/metrics-server-service.yaml" 
INFO[2021-07-29T18:35:08.431750806Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"resource-reader", UID:"7b0b2707-c7a9-4fa2-b8fd-9f9d076e6dc1", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"342", FieldPath:""}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/resource-reader.yaml" 
INFO[2021-07-29T18:35:08.599144035Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"resource-reader", UID:"7b0b2707-c7a9-4fa2-b8fd-9f9d076e6dc1", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"342", FieldPath:""}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/resource-reader.yaml" 
INFO[2021-07-29T18:35:08.725548286Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"rolebindings", UID:"94bdb13f-cf3c-4569-89f5-562ae4fe2ee3", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"347", FieldPath:""}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at "/var/lib/rancher/k3s/server/manifests/rolebindings.yaml" 
INFO[2021-07-29T18:35:08.772283766Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"rolebindings", UID:"94bdb13f-cf3c-4569-89f5-562ae4fe2ee3", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"347", FieldPath:""}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at "/var/lib/rancher/k3s/server/manifests/rolebindings.yaml" 
I0729 18:35:08.892766   27170 serving.go:354] Generated self-signed cert in-memory
INFO[2021-07-29T18:35:08.928111710Z] Waiting for control-plane node ip-172-31-5-153 startup: nodes "ip-172-31-5-153" not found 
INFO[2021-07-29T18:35:09.128129423Z] Event(v1.ObjectReference{Kind:"Addon", Namespace:"kube-system", Name:"traefik", UID:"9ab78c0f-f02e-42b0-8147-224886dee123", APIVersion:"k3s.cattle.io/v1", ResourceVersion:"353", FieldPath:""}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at "/var/lib/rancher/k3s/server/manifests/traefik.yaml" 
INFO[2021-07-29T18:35:09.128711370Z] Imported docker.io/rancher/pause:3.1         
INFO[2021-07-29T18:35:09.128939324Z] Imported docker.io/rancher/coredns-coredns:1.8.3 
INFO[2021-07-29T18:35:09.129095228Z] Imported docker.io/rancher/klipper-helm:v0.6.1-build20210616 
INFO[2021-07-29T18:35:09.129264723Z] Imported docker.io/rancher/klipper-lb:v0.2.0 
INFO[2021-07-29T18:35:09.129411715Z] Imported docker.io/rancher/library-busybox:1.32.1 
INFO[2021-07-29T18:35:09.129611855Z] Imported docker.io/rancher/library-traefik:2.4.8 
INFO[2021-07-29T18:35:09.129779920Z] Imported docker.io/rancher/local-path-provisioner:v0.0.19 
INFO[2021-07-29T18:35:09.129931943Z] Imported docker.io/rancher/metrics-server:v0.3.6 
I0729 18:35:09.174580   27170 controller.go:611] quota admission added evaluator for: helmcharts.helm.cattle.io
INFO[2021-07-29T18:35:09.183526902Z] Connecting to proxy                           url="wss://172.31.5.153:6443/v1-k3s/connect"
INFO[2021-07-29T18:35:09.191222137Z] Handling backend connection request [ip-172-31-5-153]
brandond commented 3 years ago

If I grep for "Import" the lines I shared are the only ones I see, which I think meets the ask?

rancher-max commented 3 years ago

Yeah exactly, it's just not as clean in mine so I didn't see it when looking (I was looking for the output visually like how it is in yours since I thought there was something, but wasn't sure of the exact verbage).

brandond commented 3 years ago

Yeah, you get the first Importing message when the tarball is opened, and then all the Imported messages once processing is complete. That's just sorta how it works with the containerd import API.

rancher-max commented 3 years ago

Cool, I'm happy with this. I'm closing it