Friday, 7 May 2021

Debugging Kubernetes - some things for me to remember ....

 Just making a few notes of things to which I need to refer back on a frequent basis ...

Firstly, debugging kubelet when it's running as a systemd service on Ubuntu ....

journalctl -u kubelet -f

-- Logs begin at Fri 2021-05-07 08:26:28 UTC. --
May 07 08:35:18 49b3d0c825c0 kubelet[8810]: I0507 08:35:18.383575    8810 reconciler.go:224] "operationExecutor.VerifyControllerAttachedVolume started for volume \"host-local-net-dir\" (UniqueName: \"kubernetes.io/host-path/f2f7f941-a88d-421d-919f-48d8faedfb4e-host-local-net-dir\") pod \"calico-node-2csfs\" (UID: \"f2f7f941-a88d-421d-919f-48d8faedfb4e\") "
May 07 08:35:18 49b3d0c825c0 kubelet[8810]: I0507 08:35:18.383603    8810 reconciler.go:224] "operationExecutor.VerifyControllerAttachedVolume started for volume \"policysync\" (UniqueName: \"kubernetes.io/host-path/f2f7f941-a88d-421d-919f-48d8faedfb4e-policysync\") pod \"calico-node-2csfs\" (UID: \"f2f7f941-a88d-421d-919f-48d8faedfb4e\") "
May 07 08:35:18 49b3d0c825c0 kubelet[8810]: I0507 08:35:18.383638    8810 reconciler.go:224] "operationExecutor.VerifyControllerAttachedVolume started for volume \"var-lib-calico\" (UniqueName: \"kubernetes.io/host-path/f2f7f941-a88d-421d-919f-48d8faedfb4e-var-lib-calico\") pod \"calico-node-2csfs\" (UID: \"f2f7f941-a88d-421d-919f-48d8faedfb4e\") "
...


systemctl status kubelet

● kubelet.service - kubelet: The Kubernetes Node Agent
   Loaded: loaded (/lib/systemd/system/kubelet.service; enabled; vendor preset: enabled)
  Drop-In: /etc/systemd/system/kubelet.service.d
           └─10-kubeadm.conf
   Active: active (running) since Fri 2021-05-07 08:33:57 UTC; 3min 34s ago
     Docs: https://kubernetes.io/docs/home/
 Main PID: 8810 (kubelet)
    Tasks: 14 (limit: 4915)
   CGroup: /system.slice/kubelet.service
           └─8810 /usr/bin/kubelet --bootstrap-kubeconfig=/etc/kubernetes/bootstrap-kubelet.conf --kubeconfig=/etc/kubernetes/kubelet.conf --config=/var/lib/kubelet/config.y
...

In my specific case, I'm running K8s on a pair of Ubuntu containers ( which are running on runq on my IBM Z box ), using the containerd runtime.

Previously, I'd been using the docker runtime, and was trying/failing to get logs for specific containers into text files ....

In that context, I discovered ( via Google, of course ), that I could grab the container ID: -

id=$(docker ps -a | grep "kube-apiserver " | awk '{print $1}')

logfile=$(docker inspect --format='{{.LogPath}}' $id)

cat $logfile

...
{"log":"I0427 04:21:53.055167       1 clientconn.go:948] ClientConn switching balancer to \"pick_first\"\n","stream":"stderr","time":"2021-04-27T04:21:53.055185496Z"}
{"log":"I0427 04:22:35.661984       1 client.go:360] parsed scheme: \"passthrough\"\n","stream":"stderr","time":"2021-04-27T04:22:35.662047076Z"}
{"log":"I0427 04:22:35.662127       1 passthrough.go:48] ccResolverWrapper: sending update to cc: {[{https://127.0.0.1:2379  \u003cnil\u003e 0 \u003cnil\u003e}] \u003cnil\u003e \u003cnil\u003e}\n","stream":"stderr","time":"2021-04-27T04:22:35.662147916Z"}
{"log":"I0427 04:22:35.662164       1 clientconn.go:948] ClientConn switching balancer to \"pick_first\"\n","stream":"stderr","time":"2021-04-27T04:22:35.662181568Z"}
{"log":"I0427 04:23:12.096739       1 client.go:360] parsed scheme: \"passthrough\"\n","stream":"stderr","time":"2021-04-27T04:23:12.096825215Z"}
{"log":"I0427 04:23:12.096837       1 passthrough.go:48] ccResolverWrapper: sending update to cc: {[{https://127.0.0.1:2379  \u003cnil\u003e 0 \u003cnil\u003e}] \u003cnil\u003e \u003cnil\u003e}\n","stream":"stderr","time":"2021-04-27T04:23:12.096877914Z"}
...

I've not yet worked out how to do the same in the world of containerd and the ctr command-line tool but ....

I know the logs are located in  /var/log/containers/ so can simply grab the most recent kube-apiserver logs: -

ls -altrct  /var/log/containers/ | grep kube-apiserver | awk '{print $9}'

kube-apiserver-988bcfa294be_kube-system_kube-apiserver-7bb8147ef0be60950cdea7647fd09c404691e3de1d7e40db7d9296b953770cb1.log
kube-apiserver-988bcfa294be_kube-system_kube-apiserver-b66ced00d4c180d11c87df7cd017cb906c0cf6f2d6956f792c82b541d5aab580.log

cat /var/log/containers/kube-apiserver-988bcfa294be_kube-system_kube-apiserver-b66ced00d4c180d11c87df7cd017cb906c0cf6f2d6956f792c82b541d5aab580.log

...
2021-05-07T08:53:40.999115308Z stderr F I0507 08:53:40.998261       1 clientconn.go:948] ClientConn switching balancer to "pick_first"
2021-05-07T08:54:09.450483534Z stderr F I0507 08:54:09.450253       1 client.go:360] parsed scheme: "endpoint"
2021-05-07T08:54:09.450624554Z stderr F I0507 08:54:09.450600       1 endpoint.go:68] ccResolverWrapper: sending new addresses to cc: [{https://127.0.0.1:2379  <nil> 0 <nil>}]
2021-05-07T08:54:09.505302623Z stderr F I0507 08:54:09.505253       1 client.go:360] parsed scheme: "endpoint"
2021-05-07T08:54:09.505314868Z stderr F I0507 08:54:09.505280       1 endpoint.go:68] ccResolverWrapper: sending new addresses to cc: [{https://127.0.0.1:2379  <nil> 0 <nil>}]
...


Other than that, also noting that I can simply use good ole Linux commands to inspect kubelet etc. as per this: -

ps -ef | grep /usr/bin/kubelet | grep -v grep

root     11644     1  1 08:33 ?        00:00:24 /usr/bin/kubelet --bootstrap-kubeconfig=/etc/kubernetes/bootstrap-kubelet.conf --kubeconfig=/etc/kubernetes/kubelet.conf --config=/var/lib/kubelet/config.yaml --cni-conf-dir=/etc/cni/net.d/ --container-runtime=remote --container-runtime-endpoint=/run/containerd/containerd.sock --pod-infra-container-image=k8s.gcr.io/pause:3.4.1

ps -ef | grep kube-apiserver | grep -v grep

root     29843 12033 11 08:53 ?        00:00:28 kube-apiserver --advertise-address=172.16.84.4 --allow-privileged=true --authorization-mode=Node,RBAC --client-ca-file=/etc/kubernetes/pki/ca.crt --enable-admission-plugins=NodeRestriction,AlwaysPullImages,SecurityContextDeny --enable-bootstrap-token-auth=true --etcd-cafile=/etc/kubernetes/pki/etcd/ca.crt --etcd-certfile=/etc/kubernetes/pki/apiserver-etcd-client.crt --etcd-keyfile=/etc/kubernetes/pki/apiserver-etcd-client.key --etcd-servers=https://127.0.0.1:2379 --insecure-port=0 --kubelet-client-certificate=/etc/kubernetes/pki/apiserver-kubelet-client.crt --kubelet-client-key=/etc/kubernetes/pki/apiserver-kubelet-client.key --kubelet-preferred-address-types=InternalIP,ExternalIP,Hostname --proxy-client-cert-file=/etc/kubernetes/pki/front-proxy-client.crt --proxy-client-key-file=/etc/kubernetes/pki/front-proxy-client.key --requestheader-allowed-names=front-proxy-client --requestheader-client-ca-file=/etc/kubernetes/pki/front-proxy-ca.crt --requestheader-extra-headers-prefix=X-Remote-Extra- --requestheader-group-headers=X-Remote-Group --requestheader-username-headers=X-Remote-User --secure-port=6443 --service-account-issuer=https://kubernetes.default.svc.cluster.local --service-account-key-file=/etc/kubernetes/pki/sa.pub --service-account-signing-key-file=/etc/kubernetes/pki/sa.key --service-cluster-ip-range=10.96.0.0/12 --tls-cert-file=/etc/kubernetes/pki/apiserver.crt --tls-private-key-file=/etc/kubernetes/pki/apiserver.key --profiling=false --audit-log-path=/var/log/apiserver/audit.log --audit-log-maxage=30 --audit-log-maxbackup=10 --audit-log-maxsize=100 --anonymous-auth=false --encryption-provider-config=/etc/kubernetes/pki/secrets.yml --tls-cipher-suites=TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305,TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305,TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384

etc.

No comments:

Yay, VMware Fusion and macOS Big Sur - no longer "NAT good friends" - forgive the double negative and the terrible pun ...

After macOS 11 Big Sur was released in 2020, VMware updated their Fusion product to v12 and, sadly, managed to break Network Address Trans...