gathered data URL : shorturl.at/pvE79

Hello,
Customer did an upgrade of his cluster, update is stuck with a random worker node in degraded state.

According to the latest must-gather current and desired config are set to the previous MachineConfig.

~~
2021-04-15T13:51:56.801540297Z I0415 13:51:56.801482    2217 daemon.go:808] Current+desired config: rendered-worker-1d0866ca1672b3108f63cb78ee21e9a5
2021-04-15T13:51:56.808645810Z I0415 13:51:56.808603    2217 update.go:1676] Disk currentConfig rendered-worker-6884f95ab6f02681824be2fe6d68d049 overrides node's currentConfig annotation rendered-worker-1d0866ca1672b3108f63cb78ee21e9a5
2021-04-15T13:51:56.812541252Z I0415 13:51:56.812493    2217 daemon.go:1085] Validating against current config rendered-worker-6884f95ab6f02681824be2fe6d68d049
2021-04-15T13:51:56.812643566Z E0415 13:51:56.812629    2217 writer.go:135] Marking Degraded due to: unexpected on-disk state validating against rendered-worker-6884f95ab6f02681824be2fe6d68d049: expected target osImageURL "quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:3786aa3c566dac65955db229dc20f9f19106046ebe33561bd60cce5538544e6a", have "quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:b69dcece911957dbd617e1a5ca97f7ab0d8f1feab5870f6d6fd9221143f0fc26"
~~~

The MCD still complaining about the osImageURL
--------------------------------------------------------------------
we follow the KCS: https://access.redhat.com/solutions/5598401 and we get
 
sh-4.4# export HTTP_PROXY='http://http-proxy.cezdata.corp:8080'
sh-4.4# export HTTPS_PROXY='http://http-proxy.cezdata.corp:8080'
sh-4.4# /run/bin/machine-config-daemon pivot quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:3786aa3c566dac65955db229dc20f9f19106046ebe33561bd60cce5538544e6a
I0415 15:18:00.786311   85973 run.go:18] Running: nice -- ionice -c 3 oc image extract --path /:/run/mco-machine-os-content/os-content-367690970 --registry-config /var/lib/kubelet/config.json quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:3786aa3c566dac65955db229dc20f9f19106046ebe33561bd60cce5538544e6a
I0415 15:18:45.750981   85973 rpm-ostree.go:261] Running captured: rpm-ostree status --json
I0415 15:18:45.840305   85973 rpm-ostree.go:179] Previous pivot: quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:b69dcece911957dbd617e1a5ca97f7ab0d8f1feab5870f6d6fd9221143f0fc26
I0415 15:18:48.104897   85973 rpm-ostree.go:211] Pivoting to: 46.82.202103050041-0 (d8cb9069afa2946131e033b3da6ad81a49c32642cbec3277a8cc9a1d7c022b06)
I0415 15:18:48.104923   85973 rpm-ostree.go:243] Executing rebase from repo path /run/mco-machine-os-content/os-content-367690970/srv/repo with customImageURL pivot://quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:3786aa3c566dac65955db229dc20f9f19106046ebe33561bd60cce5538544e6a and checksum d8cb9069afa2946131e033b3da6ad81a49c32642cbec3277a8cc9a1d7c022b06
I0415 15:18:48.104935   85973 rpm-ostree.go:261] Running captured: rpm-ostree rebase --experimental /run/mco-machine-os-content/os-content-367690970/srv/repo:d8cb9069afa2946131e033b3da6ad81a49c32642cbec3277a8cc9a1d7c022b06 --custom-origin-url pivot://quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:3786aa3c566dac65955db229dc20f9f19106046ebe33561bd60cce5538544e6a --custom-origin-description Managed by machine-config-operator
error: No enabled repositories
error: with stdout output: : error running rpm-ostree rebase --experimental /run/mco-machine-os-content/os-content-367690970/srv/repo:d8cb9069afa2946131e033b3da6ad81a49c32642cbec3277a8cc9a1d7c022b06 --custom-origin-url pivot://quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:3786aa3c566dac65955db229dc20f9f19106046ebe33561bd60cce5538544e6a --custom-origin-description Managed by machine-config-operator: 0 metadata, 0 content objects imported; 0 bytes content written
Checking out tree d8cb906...done
: exit status 1

--------------------------------------------------------------------
this looks like a bug in rpm-ostree or in information that is passed to rpm-ostree. Additional remarks/observation:

- the workaround is done by using the --cache-only (-C) directive for rpm-ostree rebase. If using this directive, a repo check is skipped altogether, which should be always the case in case of CoreOS upgrade in this situation. In our case /etc/yam.d.repos is empty on all nodes anyway.
- as the actual image is downloaded in the step prior to rpm-ostree rebase, we think this should be a safe option
- once the upgrade is "unstuck", any subsequent upgrade or downgrade, even of the same OS image, runs automatically without this error. This means this problem is gone with first successful rpm-ostree rebase command.
- this situation happens randomly on other clusters as well, may not be bound to these particular versions. Sometimes it does not occur at all.
- all worker nodes on affected clusters are created by Ansible, same Ansible role, running on the same hardware, the only difference is IP address, node name, etc.
- once this error occurs, it persists across multiple attemps, until the workaround (-C) is applied
- we think the condition in rpm-ostree should be investigated, it may not work in a particular set of inputs
- alternatively, you may consider adding -C option to the /run/bin/machine-config-daemon script to circumvent the issue (the assumption is that local repos are not actually defined)

---------------------------------

finally got it working.

sh-4.4# rpm-ostree rebase -C --experimental /run/mco-machine-os-content/os-content-093177341/srv/repo:d8cb9069afa2946131e033b3da6ad81a49c32642cbec3277a8cc9a1d7c022b06 --custom-origin-url pivot://quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:3786aa3c566dac65955db229dc20f9f19106046ebe33561bd60cce5538544e6a --custom-origin-description "Managed by machine-config-operator"
0 metadata, 0 content objects imported; 0 bytes content written
Checking out tree d8cb906... done
Resolving dependencies... done
Checking out packages... done
Running pre scripts... done
Running post scripts... done
Running posttrans scripts... done
Writing rpmdb... done
Writing OSTree commit... done
Staging deployment... done
Freed: 52.0 MB (pkgcache branches: 0)
Upgraded:
  cri-o 1.19.1-7.rhaos4.6.git6377f68.el8 -> 1.19.1-10.rhaos4.6.git27e71a0.el8
  criu 3.12-9.module+el8.2.0+9347+d4fa9cbb -> 3.12-9.module+el8.2.0+9938+46853747
  fuse-overlayfs 0.7.2-5.module+el8.2.0+9347+d4fa9cbb -> 0.7.2-5.module+el8.2.0+9938+46853747
  grub2-common 1:2.02-87.el8_2.2 -> 1:2.02-87.el8_2.3
  grub2-efi-x64 1:2.02-87.el8_2.2 -> 1:2.02-87.el8_2.3
  grub2-pc 1:2.02-87.el8_2.2 -> 1:2.02-87.el8_2.3
  grub2-pc-modules 1:2.02-87.el8_2.2 -> 1:2.02-87.el8_2.3
  grub2-tools 1:2.02-87.el8_2.2 -> 1:2.02-87.el8_2.3
  grub2-tools-extra 1:2.02-87.el8_2.2 -> 1:2.02-87.el8_2.3
  grub2-tools-minimal 1:2.02-87.el8_2.2 -> 1:2.02-87.el8_2.3
  microcode_ctl 4:20191115-4.20201112.1.el8_2 -> 4:20191115-4.20210216.1.el8_2
  openshift-hyperkube 4.6.0-202102120001.p0.git.94272.41c57c9.el8 -> 4.6.0-202102261508.p0.git.94279.27a8e35.el8
  runc 1.0.0-82.rhaos4.6.git086e841.el8 -> 1.0.0-83.rhaos4.6.git8c2e7c8.el8
  slirp4netns 0.4.2-3.git21fdece.module+el8.2.0+9347+d4fa9cbb -> 0.4.2-3.git21fdece.module+el8.2.0+9938+46853747
Added:
  bootupd-0.2.4-3.el8.x86_64
Run "systemctl reboot" to start a reboot

customer made it work by using the --cache-only (-C) switch, as he downloaded the image in the previous step. 

This circumvents a check on line 797 (see below).
What I found was this:
https://github.com/coreos/rpm-ostree/issues/780

Which made him look into the code of rpm-ostree.

The problematic tests seems to be here, on line 803:
https://github.com/coreos/rpm-ostree/blob/master/src/libpriv/rpmostree-core.cxx

It seems this test may sometimes fail even if it is not supposed to:

if (g_variant_dict_lookup (self->spec->dict, "packages", "^a&s", &pkgs) &&
          g_strv_length (pkgs) > 0)

After doing this, the infra node was upgraded, rebooted, downgraded to previous version because ot the patch we tried, then upgraded back to the version it is supposed to be.

Maybe rpm-ostree maintainers should check this. Unfortunately, with the problem fixed (and even subsequent upgrade to the problematic version went without problems), we can no longer reproduce, so hopefully must-gather will contain necessary information as to why the condition above failed even if it is clearly not supposed to.


---------------------------------------------------
Could you please help us check this eventual bug and it's the root cause which may reoccur any time?