problem when upgrading worker nodes from 4.11.0-0.okd-2022-07-29-154152 to 4.12.0-0.okd-2023-03-18-084815

[ascherbakov686]

Hello, have problem when upgrading worker nodes from 4.11.0-0.okd-2022-07-29-154152 to 4.12.0-0.okd-2023-03-18-084815, need help or some workaround,

# ssh core@sog-prod-ocpc-ldc-176
Fedora CoreOS 37.20230218.3.0

 

############################################################################
WARNING: This system is using cgroups v1. For increased reliability
it is strongly recommended to migrate this system and your workloads
to use cgroups v2. For instructions on how to adjust kernel arguments
to use cgroups v2, see:
https://docs.fedoraproject.org/en-US/fedora-coreos/kernel-args/

 

To disable this warning, use:
sudo systemctl disable coreos-check-cgroups.service
############################################################################

 

Tracker: https://github.com/coreos/fedora-coreos-tracker
Discuss: https://discussion.fedoraproject.org/tag/coreos

 

Last login: Tue Jul  4 15:19:31 2023 from 10.68.161.14
[systemd]
Failed Units: 2
  kubelet.service
  ovs-configuration.service


# systemctl status kubelet.service
× kubelet.service - Kubernetes Kubelet
     Loaded: loaded (/etc/systemd/system/kubelet.service; enabled; preset: disabled)
    Drop-In: /etc/systemd/system/kubelet.service.d
             └─01-kubens.conf, 10-mco-default-env.conf, 10-mco-default-madv.conf, 20-logging.conf, 20-nodenet.conf
     Active: failed (Result: exit-code) since Tue 2023-07-04 15:46:21 UTC; 5min ago
    Process: 1573 ExecStartPre=/bin/mkdir --parents /etc/kubernetes/manifests (code=exited, status=0/SUCCESS)
    Process: 1575 ExecStartPre=/bin/rm -f /var/lib/kubelet/cpu_manager_state (code=exited, status=0/SUCCESS)
    Process: 1576 ExecStartPre=/bin/rm -f /var/lib/kubelet/memory_manager_state (code=exited, status=0/SUCCESS)
    Process: 1579 ExecStart=/usr/local/bin/kubenswrapper /usr/bin/kubelet --config=/etc/kubernetes/kubelet.conf --bootstrap-kubeconfig=/etc/kubernetes/kubeconfig --kubeconfig=/var/lib/kubelet/kubeconfig --c>
   Main PID: 1579 (code=exited, status=127)
        CPU: 12ms

 

Jul 04 15:46:11 sog-prod-ocpc-ldc-176 kubenswrapper[1579]: /usr/local/bin/kubenswrapper: line 5: /usr/bin/kubelet: No such file or directory
Jul 04 15:46:11 sog-prod-ocpc-ldc-176 systemd[1]: Starting kubelet.service - Kubernetes Kubelet...
Jul 04 15:46:11 sog-prod-ocpc-ldc-176 systemd[1]: kubelet.service: Main process exited, code=exited, status=127/n/a
Jul 04 15:46:11 sog-prod-ocpc-ldc-176 systemd[1]: kubelet.service: Failed with result 'exit-code'.
Jul 04 15:46:11 sog-prod-ocpc-ldc-176 systemd[1]: Failed to start kubelet.service - Kubernetes Kubelet.
Jul 04 15:46:21 sog-prod-ocpc-ldc-176 systemd[1]: kubelet.service: Failed to schedule restart job: Unit crio.service not found.
Jul 04 15:46:21 sog-prod-ocpc-ldc-176 systemd[1]: kubelet.service: Failed with result 'exit-code'.

When reboot to previos ostree shows that:

# rpm-ostree status
State: idle
Deployments:
  d34ff10be925c01aad7d088fa2dcc18aaa3e9d7ead12081a18fb6883a94385d7
                  Version: 37.20230218.3.0 (2023-03-06T20:02:24Z)
                     Diff: 396 upgraded, 44 removed, 18 added

● pivot://quay.io/openshift/okd-content@sha256:a77c75b002aa480b9dc834a8c0cb38ccce347f528f1d27118c08da2bb2e199b1
             CustomOrigin: Managed by machine-config-operator
                  Version: 411.36.202207291018-0 (2022-07-29T10:22:03Z)

[ascherbakov686]

• machine-config log for one more problem worker node

# oc logs -f machine-config-daemon-vclsm -c machine-config-daemon -n openshift-machine-config-operator
I0704 11:54:28.812760 3155129 start.go:112] Version: machine-config-daemon-4.6.0-202006240615.p0-1806-ge7a5af3f-dirty (e7a5af3faec663f877cc39b582f7ad38120ebd1e)
I0704 11:54:28.815698 3155129 start.go:125] Calling chroot("/rootfs")
I0704 11:54:29.165740 3155129 daemon.go:245] Booted osImageURL: quay.io/openshift/okd-content@sha256:a77c75b002aa480b9dc834a8c0cb38ccce347f528f1d27118c08da2bb2e199b1 (411.36.202207291018-0) 0963e94a2b72628afd746d73162280e3d72fa8bd38970abb663956a9d4aff06f
I0704 11:54:29.229071 3155129 start.go:101] Copied self to /run/bin/machine-config-daemon on host
I0704 11:54:29.231212 3155129 start.go:188] overriding kubernetes api to https://api-int.prod.oc4-l:6443
I0704 11:54:29.232687 3155129 metrics.go:106] Registering Prometheus metrics
I0704 11:54:29.232797 3155129 metrics.go:111] Starting metrics listener on 127.0.0.1:8797
I0704 11:54:29.236117 3155129 writer.go:93] NodeWriter initialized with credentials from /var/lib/kubelet/kubeconfig
I0704 11:54:29.236368 3155129 update.go:2118] Starting to manage node: sog-prod-ocpc-ldc-177
I0704 11:54:29.241849 3155129 rpm-ostree.go:394] Running captured: rpm-ostree status
I0704 11:54:29.312185 3155129 daemon.go:1302] State: idle
Deployments:
* pivot://quay.io/openshift/okd-content@sha256:a77c75b002aa480b9dc834a8c0cb38ccce347f528f1d27118c08da2bb2e199b1
             CustomOrigin: Managed by machine-config-operator
                  Version: 411.36.202207291018-0 (2022-07-29T10:22:03Z)
I0704 11:54:29.312353 3155129 coreos.go:54] CoreOS aleph version: mtime=2021-11-09 00:42:36.227 +0000 UTC build=34.20211031.3.0 imgid=fedora-coreos-34.20211031.3.0-metal.x86_64.raw
I0704 11:54:29.312475 3155129 coreos.go:71] Ignition provisioning: time=2022-04-21T13:35:20Z
I0704 11:54:29.312495 3155129 rpm-ostree.go:394] Running captured: journalctl --list-boots
I0704 11:54:29.333325 3155129 daemon.go:1311] journalctl --list-boots:
  0 3befd978433a47b6b95ddda371ce6e09 Tue 2023-06-20 09:32:27 UTC—Tue 2023-07-04 11:54:29 UTC
I0704 11:54:29.333362 3155129 rpm-ostree.go:394] Running captured: systemctl list-units --state=failed --no-legend
I0704 11:54:29.347612 3155129 daemon.go:1326] systemd service state: OK
I0704 11:54:29.347666 3155129 daemon.go:991] Starting MachineConfigDaemon
I0704 11:54:29.347862 3155129 daemon.go:998] Enabling Kubelet Healthz Monitor
I0704 11:54:30.353390 3155129 daemon.go:461] Node sog-prod-ocpc-ldc-177 is not labeled node-role.kubernetes.io/master
I0704 11:54:30.364375 3155129 daemon.go:1247] Current+desired config: rendered-worker-39b451cb385c17fdd52607eed9b9bbfe
I0704 11:54:30.364405 3155129 daemon.go:1257] state: Done
I0704 11:54:30.376476 3155129 update.go:2103] Running: rpm-ostree cleanup -r
Deployments unchanged.
I0704 11:54:30.802902 3155129 daemon.go:1567] Validating against current config rendered-worker-39b451cb385c17fdd52607eed9b9bbfe
I0704 11:54:31.028230 3155129 rpm-ostree.go:394] Running captured: rpm-ostree kargs
I0704 11:54:31.115677 3155129 update.go:2118] Validated on-disk state
I0704 11:54:31.118612 3155129 daemon.go:1650] In desired config rendered-worker-39b451cb385c17fdd52607eed9b9bbfe
I0704 11:54:31.139827 3155129 config_drift_monitor.go:246] Config Drift Monitor started
I0705 12:37:04.591067 3155129 rpm-ostree.go:394] Running captured: rpm-ostree kargs
I0705 12:37:05.091717 3155129 daemon.go:593] Preflight config drift check successful (took 3.142619844s)
I0705 12:37:05.095083 3155129 config_drift_monitor.go:255] Config Drift Monitor has shut down
I0705 12:37:05.128097 3155129 update.go:2140] Adding SIGTERM protection
I0705 12:37:05.159332 3155129 update.go:542] Checking Reconcilable for config rendered-worker-39b451cb385c17fdd52607eed9b9bbfe to rendered-worker-6149c7270354f222935e38329825a83a
I0705 12:37:05.225100 3155129 update.go:2118] Starting update from rendered-worker-39b451cb385c17fdd52607eed9b9bbfe to rendered-worker-6149c7270354f222935e38329825a83a: &{osUpdate:true kargs:false fips:false passwd:false files:true units:true kernelType:false extensions:false}
I0705 12:37:05.241619 3155129 helpers.go:896] File diff: detected change to /etc/node-sizing-enabled.env
I0705 12:37:05.241668 3155129 helpers.go:896] File diff: detected change to /etc/crio/crio.conf.d/00-default
I0705 12:37:05.241697 3155129 helpers.go:896] File diff: detected change to /etc/kubernetes/kubelet.conf
I0705 12:37:05.241730 3155129 helpers.go:892] File diff: /etc/crio/crio.conf.d/01-mc-addInheritableCapabilities was added
I0705 12:37:05.241741 3155129 helpers.go:892] File diff: /usr/local/bin/nm-clean-initrd-state.sh was added
I0705 12:37:05.241761 3155129 helpers.go:896] File diff: detected change to /usr/local/sbin/dynamic-system-reserved-calc.sh
I0705 12:37:05.241792 3155129 helpers.go:896] File diff: detected change to /usr/local/bin/configure-ovs.sh
I0705 12:37:05.241838 3155129 helpers.go:892] File diff: /usr/local/bin/kubenswrapper was added
I0705 12:37:05.241879 3155129 update.go:2118] Update prepared; requesting cordon and drain via annotation to controller
I0705 12:37:45.274457 3155129 update.go:2118] drain complete
I0705 12:37:45.276799 3155129 drain.go:95] Successful drain took 40.032429173 seconds
I0705 12:37:45.276822 3155129 update.go:1244] Updating files
I0705 12:37:45.276833 3155129 update.go:1650] Writing file "/usr/local/bin/nm-clean-initrd-state.sh"
I0705 12:37:45.983619 3155129 update.go:1650] Writing file "/etc/NetworkManager/conf.d/20-keyfiles.conf"
I0705 12:37:46.098423 3155129 update.go:1650] Writing file "/etc/pki/ca-trust/source/anchors/openshift-config-user-ca-bundle.crt"
I0705 12:37:47.349638 3155129 update.go:1650] Writing file "/etc/audit/rules.d/mco-audit-quiet-containers.rules"
I0705 12:37:53.439259 3155129 update.go:1650] Writing file "/etc/tmpfiles.d/cleanup-cni.conf"
I0705 12:37:56.423249 3155129 update.go:1650] Writing file "/etc/kubernetes/static-pod-resources/configmaps/cloud-config/ca-bundle.pem"
I0705 12:37:56.692737 3155129 update.go:1650] Writing file "/usr/local/bin/configure-ovs.sh"
I0705 12:37:58.512399 3155129 update.go:1650] Writing file "/etc/containers/storage.conf"
I0705 12:37:59.200299 3155129 update.go:1650] Writing file "/etc/mco/proxy.env"
I0705 12:38:06.972196 3155129 update.go:1650] Writing file "/etc/systemd/system.conf.d/10-default-env-godebug.conf"
I0705 12:38:07.162889 3155129 update.go:1650] Writing file "/etc/modules-load.d/iptables.conf"
I0705 12:38:14.577477 3155129 update.go:1650] Writing file "/etc/node-sizing-enabled.env"
I0705 12:38:15.316192 3155129 update.go:1650] Writing file "/usr/local/sbin/dynamic-system-reserved-calc.sh"
I0705 12:38:22.403123 3155129 update.go:1650] Writing file "/etc/kubernetes/kubelet-ca.crt"
I0705 12:38:24.105505 3155129 update.go:1650] Writing file "/etc/systemd/system.conf.d/kubelet-cgroups.conf"
I0705 12:38:30.111412 3155129 update.go:1650] Writing file "/etc/systemd/system/kubelet.service.d/20-logging.conf"
I0705 12:38:30.983932 3155129 update.go:1650] Writing file "/etc/NetworkManager/conf.d/sdn.conf"
I0705 12:38:36.266231 3155129 update.go:1650] Writing file "/etc/NetworkManager/dispatcher.d/pre-up.d/10-ofport-request.sh"
I0705 12:38:41.340024 3155129 update.go:1650] Writing file "/var/lib/kubelet/config.json"
I0705 12:38:49.703563 3155129 update.go:1650] Writing file "/etc/kubernetes/ca.crt"
I0705 12:38:53.762671 3155129 update.go:1650] Writing file "/etc/sysctl.d/forward.conf"
I0705 12:38:55.933674 3155129 update.go:1650] Writing file "/etc/sysctl.d/inotify.conf"
I0705 12:38:57.174849 3155129 update.go:1650] Writing file "/usr/local/bin/mco-hostname"
I0705 12:39:09.063904 3155129 update.go:1650] Writing file "/etc/kubernetes/kubelet-plugins/volume/exec/.dummy"
I0705 12:39:09.077320 3155129 update.go:1650] Writing file "/etc/NetworkManager/dispatcher.d/99-vsphere-disable-tx-udp-tnl"
I0705 12:39:13.618935 3155129 update.go:1650] Writing file "/etc/containers/registries.conf"
I0705 12:39:28.494902 3155129 update.go:1650] Writing file "/etc/crio/crio.conf.d/00-default"
I0705 12:39:30.643106 3155129 update.go:1650] Writing file "/etc/containers/policy.json"
I0705 12:39:33.365440 3155129 update.go:1650] Writing file "/etc/kubernetes/cloud.conf"
I0705 12:39:33.424762 3155129 update.go:1650] Writing file "/etc/kubernetes/kubelet.conf"
I0705 12:39:37.085187 3155129 update.go:1650] Writing file "/usr/local/bin/kubenswrapper"
I0705 12:39:39.145833 3155129 update.go:1650] Writing file "/etc/chrony.conf"
I0705 12:39:46.439200 3155129 update.go:1650] Writing file "/etc/pivot/kernel-args"
I0705 12:39:53.147753 3155129 update.go:1650] Writing file "/etc/crio/crio.conf.d/01-mc-addInheritableCapabilities"
I0705 12:39:56.102667 3155129 update.go:1650] Writing file "/etc/crio/crio.conf.d/01-mc-seccompUseDefault"
I0705 12:39:56.133196 3155129 update.go:1582] Writing systemd unit "NetworkManager-clean-initrd-state.service"
I0705 12:39:56.794870 3155129 update.go:1537] Writing systemd unit dropin "01-kubens.conf"
I0705 12:39:56.828502 3155129 update.go:1537] Writing systemd unit dropin "10-mco-default-env.conf"
I0705 12:39:57.435399 3155129 update.go:1537] Writing systemd unit dropin "10-mco-profile-unix-socket.conf"
I0705 12:39:57.567157 3155129 update.go:1537] Writing systemd unit dropin "10-mco-default-madv.conf"
I0705 12:39:58.331743 3155129 update.go:1514] Preset systemd unit crio.service
I0705 12:39:58.331774 3155129 update.go:1537] Writing systemd unit dropin "mco-disabled.conf"
I0705 12:40:01.319838 3155129 update.go:1628] Could not reset unit preset for docker.socket, skipping. (Error msg: error running preset on unit: Failed to preset unit: Unit file docker.socket does not exist.
)
I0705 12:40:01.319871 3155129 update.go:1582] Writing systemd unit "kubelet-auto-node-size.service"
I0705 12:40:02.460351 3155129 update.go:1537] Writing systemd unit dropin "01-kubens.conf"
I0705 12:40:02.898512 3155129 update.go:1537] Writing systemd unit dropin "10-mco-default-env.conf"
I0705 12:40:03.276659 3155129 update.go:1537] Writing systemd unit dropin "10-mco-default-madv.conf"
I0705 12:40:04.109248 3155129 update.go:1582] Writing systemd unit "kubelet.service"
I0705 12:40:04.176817 3155129 update.go:1582] Writing systemd unit "kubens.service"
I0705 12:40:04.198471 3155129 update.go:1582] Writing systemd unit "machine-config-daemon-firstboot.service"
I0705 12:40:04.551842 3155129 update.go:1582] Writing systemd unit "machine-config-daemon-pull.service"
I0705 12:40:04.575861 3155129 update.go:1582] Writing systemd unit "node-valid-hostname.service"
I0705 12:40:04.606614 3155129 update.go:1582] Writing systemd unit "nodeip-configuration.service"
I0705 12:40:04.630687 3155129 update.go:1582] Writing systemd unit "ovs-configuration.service"
I0705 12:40:04.668597 3155129 update.go:1537] Writing systemd unit dropin "10-ovs-vswitchd-restart.conf"
I0705 12:40:05.286514 3155129 update.go:1514] Preset systemd unit ovs-vswitchd.service
I0705 12:40:05.286554 3155129 update.go:1537] Writing systemd unit dropin "10-ovsdb-restart.conf"
I0705 12:40:05.303151 3155129 update.go:1537] Writing systemd unit dropin "10-mco-default-env.conf"
I0705 12:40:05.358800 3155129 update.go:1628] Could not reset unit preset for pivot.service, skipping. (Error msg: error running preset on unit: Failed to preset unit: Unit file pivot.service does not exist.
)
I0705 12:40:05.358836 3155129 update.go:1537] Writing systemd unit dropin "10-mco-default-env.conf"
I0705 12:40:05.965150 3155129 update.go:1514] Preset systemd unit rpm-ostreed.service
I0705 12:40:05.965182 3155129 update.go:1537] Writing systemd unit dropin "mco-disabled.conf"
I0705 12:40:06.005271 3155129 update.go:1628] Could not reset unit preset for zincati.service, skipping. (Error msg: error running preset on unit: Failed to preset unit: Unit file zincati.service does not exist.
)
I0705 12:40:06.649719 3155129 update.go:1492] Enabled systemd units: [NetworkManager-clean-initrd-state.service kubelet-auto-node-size.service kubelet.service machine-config-daemon-firstboot.service machine-config-daemon-pull.service node-valid-hostname.service nodeip-configuration.service openvswitch.service ovs-configuration.service ovsdb-server.service]
I0705 12:40:07.246683 3155129 update.go:1503] Disabled systemd units [kubens.service]
I0705 12:40:07.246735 3155129 update.go:1310] Deleting stale data
I0705 12:40:07.263858 3155129 update.go:1806] Writing SSHKeys at "/home/core/.ssh/authorized_keys.d/ignition"
I0705 12:40:08.308212 3155129 update.go:1967] Updating OS to layered image quay.io/openshift/okd-content@sha256:125e94f63520330aa50e85bcfd55e429d3051498c9ff3936628edd0d4ea5696b
I0705 12:40:08.308269 3155129 rpm-ostree.go:394] Running captured: rpm-ostree --version
I0705 12:40:08.332930 3155129 update.go:2118] rpm-ostree is not new enough for layering; forcing an update via container
I0705 12:40:08.334926 3155129 update.go:1939] SELinux is not enforcing
I0705 12:40:08.334947 3155129 update.go:2103] Running: systemd-run --unit machine-config-daemon-update-rpmostree-via-container -p EnvironmentFile=-/etc/mco/proxy.env --collect --wait -- podman pull --authfile /var/lib/kubelet/config.json quay.io/openshift/okd-content@sha256:125e94f63520330aa50e85bcfd55e429d3051498c9ff3936628edd0d4ea5696b
I0705 12:43:53.183413 3155129 update.go:2103] Running: systemd-run --unit machine-config-daemon-update-rpmostree-via-container -p EnvironmentFile=-/etc/mco/proxy.env --collect --wait -- podman run --env-file /etc/mco/proxy.env --authfile /var/lib/kubelet/config.json --privileged --pid=host --net=host --rm -v /:/run/host quay.io/openshift/okd-content@sha256:125e94f63520330aa50e85bcfd55e429d3051498c9ff3936628edd0d4ea5696b rpm-ostree ex deploy-from-self /run/host
I0705 12:46:05.432835 3155129 update.go:1179] updating kernel on non-RHCOS nodes is not supported
I0705 12:46:05.440952 3155129 kernelargs.go:126] skipping "mitigations=auto,nosmt" as it is not present in the current argument list
I0705 12:46:05.441057 3155129 kernelargs.go:105] skipping "systemd.unified_cgroup_hierarchy=0" as it is already in use
I0705 12:46:05.468832 3155129 update.go:2118] Rebooting node
I0705 12:46:05.470818 3155129 update.go:2148] Removing SIGTERM protection
I0705 12:46:05.470842 3155129 update.go:2118] initiating reboot: Node will reboot into config rendered-worker-6149c7270354f222935e38329825a83a
I0705 12:46:05.565287 3155129 daemon.go:1016] Shutting down MachineConfigDaemon

[vrutkovs]

Please attach (or upload to the public file sharing service) must-gather archive

[ascherbakov686]

Hello, here link to archive
https://drive.google.com/file/d/1F3aEz_VV1aVAGC2aVj6y-w3pftVPubEq/view?usp=sharing

[imdmahajankanika]

I also faced the same issue

[theanotherwise]

@vrutkovs same issue, from
4.11.0-0.okd-2022-12-02-145640 -> 4.12.0-0.okd-2023-03-18-084815

[vrutkovs]

Please attach (or upload to the public file sharing service) must-gather archive

[therealak12]

We're experiencing the same issue. Also, I've tried the oc adm must-gather, however, the must-gather pod gets stuck in Pending state cause there's no crio on the master node.
@vrutkovs