Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

rebasing to another stream fails when deployment is staged #1150

Closed
jdoss opened this issue Apr 1, 2022 · 8 comments
Closed

rebasing to another stream fails when deployment is staged #1150

jdoss opened this issue Apr 1, 2022 · 8 comments
Labels

Comments

@jdoss
Copy link
Contributor

jdoss commented Apr 1, 2022

Describe the bug
I have a FCOS server on 35.20220227.3.0 that has an update staged to 35.20220313.3.1 which refuses to update. Trying to update to the next stream also fails. When you reboot, it dumps you back into 35.20220227.3.0.

# rpm-ostree status      
State: idle
AutomaticUpdatesDriver: Zincati
  DriverState: active; update staged: 35.20220313.3.1; reboot pending due to update strategy
Deployments:
  fedora:fedora/x86_64/coreos/stable
                   Version: 35.20220313.3.1 (2022-03-28T19:24:40Z)
                BaseCommit: 4a21b7876e42f223bb70b00eedef698c34a8e72b5ffbfc597aec36f40d149a58
              GPGSignature: Valid signature by 787EA6AE1147EEE56C40B30CDB4639719867C58F
                      Diff: 30 upgraded
           LayeredPackages: iftop ipmitool pam_yubico pciutils strace systemd-oomd-defaults tcpdump

* fedora:fedora/x86_64/coreos/stable
                   Version: 35.20220227.3.0 (2022-03-14T19:06:29Z)
                BaseCommit: 60d938261803ef4f9d927e774db51a96c75073eff81744ee5f528ab33f985ecd
              GPGSignature: Valid signature by 787EA6AE1147EEE56C40B30CDB4639719867C58F
           LayeredPackages: iftop ipmitool pam_yubico pciutils strace systemd-oomd-defaults tcpdump

  fedora:fedora/x86_64/coreos/stable
                   Version: 35.20220213.3.0 (2022-03-01T01:45:12Z)
                BaseCommit: 16afaa9af694537aa00cb3e259eeca549908696dbc8d7d548f1f49cf2d0f693e
              GPGSignature: Valid signature by 787EA6AE1147EEE56C40B30CDB4639719867C58F
           LayeredPackages: iftop ipmitool pam_yubico pciutils strace systemd-oomd-defaults tcpdump
-- Boot bbdbaf125d0046af87bfda3d39cd770c --
Mar 20 04:04:26 hubot systemd[1]: Starting Zincati Update Agent...
Mar 20 04:04:26 hubot zincati[924]: [INFO  zincati::cli::agent] starting update agent (zincati 0.0.24)
Mar 20 04:04:32 hubot zincati[924]: [INFO  zincati::cincinnati] Cincinnati service: https://updates.coreos.fedoraproject.org
Mar 20 04:04:32 hubot zincati[924]: [INFO  zincati::cli::agent] agent running on node '27806985b0e248c99925b6048ef20119', in update group 'default'
Mar 20 04:04:32 hubot zincati[924]: [INFO  zincati::update_agent::actor] registering as the update driver for rpm-ostree
Mar 20 04:04:36 hubot zincati[924]: [INFO  zincati::update_agent::actor] found 1 other finalized deployment
Mar 20 04:04:36 hubot zincati[924]: [INFO  zincati::update_agent::actor] deployment 35.20220213.3.0 (16afaa9af694537aa00cb3e259eeca549908696dbc8d7d548f1f49cf2d0f693e) will be excluded from being a future update target
Mar 20 04:04:36 hubot zincati[924]: [INFO  zincati::update_agent::actor] initialization complete, auto-updates logic enabled
Mar 20 04:04:36 hubot zincati[924]: [INFO  zincati::strategy] update strategy: periodic, total schedule length 60 minutes; next window at 4:4 on Sun (UTC), subject to time zone caveats.
Mar 20 04:04:36 hubot systemd[1]: Started Zincati Update Agent.
Mar 20 04:04:36 hubot zincati[924]: [INFO  zincati::update_agent::actor] reached steady state, periodically polling for updates
Mar 20 04:04:36 hubot zincati[924]: [INFO  zincati::cincinnati] current release detected as not a dead-end
Mar 21 00:43:47 hubot zincati[924]: [ERROR zincati::cincinnati] failed to check Cincinnati for updates: client-side error: error sending request for url (https://updates.coreos.fedoraproject.org/v1/graph?stream=stable&rollout_wariness=0.500000&basearch=x86_64&node_uuid=27806985b0e248c99925b6048ef20119&os_checksum=60d938261803ef4f9d927e774db51a96c75073eff81744ee5f528ab33f985ecd&group=default&platform=digitalocean&os_version=35.20220227.3.0): error trying to connect: dns error: failed to lookup address information: Name or service not known
Mar 22 03:12:05 hubot zincati[924]: [ERROR zincati::cincinnati] failed to check Cincinnati for updates: client-side error: error sending request for url (https://updates.coreos.fedoraproject.org/v1/graph?os_checksum=60d938261803ef4f9d927e774db51a96c75073eff81744ee5f528ab33f985ecd&rollout_wariness=0.500000&stream=stable&platform=digitalocean&group=default&basearch=x86_64&os_version=35.20220227.3.0&node_uuid=27806985b0e248c99925b6048ef20119): error trying to connect: dns error: failed to lookup address information: Name or service not known
Mar 27 00:09:05 hubot zincati[924]: [ERROR zincati::cincinnati] failed to check Cincinnati for updates: client-side error: error sending request for url (https://updates.coreos.fedoraproject.org/v1/graph?rollout_wariness=0.500000&basearch=x86_64&node_uuid=27806985b0e248c99925b6048ef20119&stream=stable&group=default&os_checksum=60d938261803ef4f9d927e774db51a96c75073eff81744ee5f528ab33f985ecd&platform=digitalocean&os_version=35.20220227.3.0): error trying to connect: dns error: failed to lookup address information: Name or service not known
Mar 27 04:57:29 hubot zincati[924]: [ERROR zincati::cincinnati] failed to check Cincinnati for updates: client-side error: error sending request for url (https://updates.coreos.fedoraproject.org/v1/graph?basearch=x86_64&rollout_wariness=0.500000&os_version=35.20220227.3.0&stream=stable&platform=digitalocean&node_uuid=27806985b0e248c99925b6048ef20119&os_checksum=60d938261803ef4f9d927e774db51a96c75073eff81744ee5f528ab33f985ecd&group=default): error trying to connect: dns error: failed to lookup address information: Name or service not known
Mar 27 10:17:45 hubot zincati[924]: [ERROR zincati::cincinnati] failed to check Cincinnati for updates: client-side error: error sending request for url (https://updates.coreos.fedoraproject.org/v1/graph?os_checksum=60d938261803ef4f9d927e774db51a96c75073eff81744ee5f528ab33f985ecd&basearch=x86_64&group=default&node_uuid=27806985b0e248c99925b6048ef20119&platform=digitalocean&os_version=35.20220227.3.0&rollout_wariness=0.500000&stream=stable): error trying to connect: dns error: failed to lookup address information: Name or service not known
Mar 28 20:10:48 hubot zincati[924]: [ERROR zincati::cincinnati] failed to check Cincinnati for updates: client-side error: error sending request for url (https://updates.coreos.fedoraproject.org/v1/graph?os_version=35.20220227.3.0&rollout_wariness=0.500000&node_uuid=27806985b0e248c99925b6048ef20119&os_checksum=60d938261803ef4f9d927e774db51a96c75073eff81744ee5f528ab33f985ecd&basearch=x86_64&platform=digitalocean&group=default&stream=stable): error trying to connect: dns error: failed to lookup address information: Name or service not known
Mar 28 22:28:53 hubot zincati[924]: [ERROR zincati::cincinnati] failed to check Cincinnati for updates: client-side error: error sending request for url (https://updates.coreos.fedoraproject.org/v1/graph?basearch=x86_64&platform=digitalocean&os_checksum=60d938261803ef4f9d927e774db51a96c75073eff81744ee5f528ab33f985ecd&node_uuid=27806985b0e248c99925b6048ef20119&group=default&stream=stable&os_version=35.20220227.3.0&rollout_wariness=0.500000): error trying to connect: dns error: failed to lookup address information: Name or service not known
Mar 30 00:30:33 hubot zincati[924]: [ERROR zincati::cincinnati] failed to check Cincinnati for updates: client-side error: error sending request for url (https://updates.coreos.fedoraproject.org/v1/graph?platform=digitalocean&os_checksum=60d938261803ef4f9d927e774db51a96c75073eff81744ee5f528ab33f985ecd&group=default&basearch=x86_64&stream=stable&os_version=35.20220227.3.0&rollout_wariness=0.500000&node_uuid=27806985b0e248c99925b6048ef20119): error trying to connect: dns error: failed to lookup address information: Name or service not known
Mar 30 03:07:32 hubot zincati[924]: [ERROR zincati::cincinnati] failed to check Cincinnati for updates: client-side error: error sending request for url (https://updates.coreos.fedoraproject.org/v1/graph?rollout_wariness=0.500000&stream=stable&basearch=x86_64&node_uuid=27806985b0e248c99925b6048ef20119&platform=digitalocean&os_version=35.20220227.3.0&os_checksum=60d938261803ef4f9d927e774db51a96c75073eff81744ee5f528ab33f985ecd&group=default): error trying to connect: dns error: failed to lookup address information: Name or service not known
Mar 30 16:01:49 hubot zincati[924]: [INFO  zincati::update_agent::actor] target release '35.20220313.3.1' selected, proceeding to stage it
Mar 30 16:04:03 hubot zincati[924]: [INFO  zincati::update_agent::actor] update staged: 35.20220313.3.1
Apr 01 16:31:57 hubot systemd[1]: Stopping Zincati Update Agent...
Apr 01 16:31:57 hubot systemd[1]: zincati.service: Deactivated successfully.
Apr 01 16:31:57 hubot systemd[1]: Stopped Zincati Update Agent.
Apr 01 16:31:57 hubot systemd[1]: zincati.service: Consumed 48.585s CPU time.
-- Boot e7873827b7654722aeb09587b44c0580 --
Apr 01 16:32:18 hubot systemd[1]: Starting Zincati Update Agent...
Apr 01 16:32:18 hubot zincati[915]: [INFO  zincati::cli::agent] starting update agent (zincati 0.0.24)
Apr 01 16:32:24 hubot zincati[915]: [INFO  zincati::cincinnati] Cincinnati service: https://updates.coreos.fedoraproject.org
Apr 01 16:32:24 hubot zincati[915]: [INFO  zincati::cli::agent] agent running on node '27806985b0e248c99925b6048ef20119', in update group 'default'
Apr 01 16:32:24 hubot zincati[915]: [INFO  zincati::update_agent::actor] registering as the update driver for rpm-ostree
Apr 01 16:32:29 hubot zincati[915]: [INFO  zincati::update_agent::actor] found 1 other finalized deployment
Apr 01 16:32:29 hubot zincati[915]: [INFO  zincati::update_agent::actor] deployment 35.20220213.3.0 (16afaa9af694537aa00cb3e259eeca549908696dbc8d7d548f1f49cf2d0f693e) will be excluded from being a future update target
Apr 01 16:32:29 hubot zincati[915]: [INFO  zincati::update_agent::actor] initialization complete, auto-updates logic enabled
Apr 01 16:32:29 hubot zincati[915]: [INFO  zincati::strategy] update strategy: periodic, total schedule length 60 minutes; next window at 4:0 on Sun (UTC), subject to time zone caveats.
Apr 01 16:32:29 hubot systemd[1]: Started Zincati Update Agent.
Apr 01 16:32:29 hubot zincati[915]: [INFO  zincati::update_agent::actor] reached steady state, periodically polling for updates
Apr 01 16:32:29 hubot zincati[915]: [INFO  zincati::cincinnati] current release detected as not a dead-end
Apr 01 16:32:30 hubot zincati[915]: [INFO  zincati::update_agent::actor] target release '35.20220313.3.1' selected, proceeding to stage it
Apr 01 16:34:35 hubot zincati[915]: [INFO  zincati::update_agent::actor] update staged: 35.20220313.3.1
Apr 01 18:15:42 hubot systemd[1]: Stopping Zincati Update Agent...
Apr 01 18:15:42 hubot systemd[1]: zincati.service: Deactivated successfully.
Apr 01 18:15:42 hubot systemd[1]: Stopped Zincati Update Agent.
-- Boot 32f1604611234d6ab3a7b9e2d7c1a328 --
Apr 01 18:19:47 hubot systemd[1]: Starting Zincati Update Agent...
Apr 01 18:19:47 hubot zincati[917]: [INFO  zincati::cli::agent] starting update agent (zincati 0.0.24)
Apr 01 18:19:54 hubot zincati[917]: [INFO  zincati::cincinnati] Cincinnati service: https://updates.coreos.fedoraproject.org
Apr 01 18:19:54 hubot zincati[917]: [INFO  zincati::cli::agent] agent running on node '27806985b0e248c99925b6048ef20119', in update group 'default'
Apr 01 18:19:54 hubot zincati[917]: [INFO  zincati::update_agent::actor] registering as the update driver for rpm-ostree
Apr 01 18:19:59 hubot zincati[917]: [INFO  zincati::update_agent::actor] found 1 other finalized deployment
Apr 01 18:19:59 hubot zincati[917]: [INFO  zincati::update_agent::actor] deployment 35.20220213.3.0 (16afaa9af694537aa00cb3e259eeca549908696dbc8d7d548f1f49cf2d0f693e) will be excluded from being a future update target
Apr 01 18:19:59 hubot zincati[917]: [INFO  zincati::update_agent::actor] initialization complete, auto-updates logic enabled
Apr 01 18:19:59 hubot zincati[917]: [INFO  zincati::strategy] update strategy: periodic, total schedule length 60 minutes; next window at 4:0 on Sun (UTC), subject to time zone caveats.
Apr 01 18:19:59 hubot systemd[1]: Started Zincati Update Agent.
Apr 01 18:19:59 hubot zincati[917]: [INFO  zincati::update_agent::actor] reached steady state, periodically polling for updates
Apr 01 18:19:59 hubot zincati[917]: [INFO  zincati::cincinnati] current release detected as not a dead-end
Apr 01 18:20:00 hubot zincati[917]: [INFO  zincati::update_agent::actor] target release '35.20220313.3.1' selected, proceeding to stage it
Apr 01 18:22:42 hubot zincati[917]: [INFO  zincati::update_agent::actor] update staged: 35.20220313.3.1
Apr 01 18:25:49 hubot systemd[1]: Stopping Zincati Update Agent...
Apr 01 18:25:49 hubot systemd[1]: zincati.service: Deactivated successfully.
Apr 01 18:25:49 hubot systemd[1]: Stopped Zincati Update Agent.
-- Boot 19b325c20e0343358d163e5ac6038749 --

Reproduction steps
Steps to reproduce the behavior:

  1. Install 35.20220227.3.0
  2. Stage update to 35.20220313.1
  3. Reboot

Expected behavior
Booted into next on Fedora 36

Actual behavior
Booted into 35.20220227.3.0

System details

  • DigitalOcean
# cat /etc/os-release |grep VERSION
VERSION="35.20220227.3.0 (CoreOS)"
VERSION_ID=35
VERSION_CODENAME=""
REDHAT_BUGZILLA_PRODUCT_VERSION=35
REDHAT_SUPPORT_PRODUCT_VERSION=35
OSTREE_VERSION='35.20220227.3.0'
@jdoss jdoss added the kind/bug label Apr 1, 2022
@dustymabe
Copy link
Member

dustymabe commented Apr 1, 2022

There are two pieces here that are at play:

  1. You have a staged update because there is an update available. It is just staged and not finalized+rebooted yet because your periodic update window is on Sunday. State like this has led to confusion in the past (see Surprising behavior trying to manually change kargs while an update is already queued #963). Ultimately there is a feature request to Zincati to enable pushing through an update from the CLI even if you have a periodic window set: RFE: Allow manual update checks and reboots zincati#498
  2. Because you have a staged update there's some state that needs to be unwound in order to perform a rebase. I would argue that this is something that should be fixed. See workaround below:
sudo systemctl stop zincati.service
sudo rm /run/ostree/staged-deployment-locked
sudo rpm-ostree cleanup -p
ARCH="$(arch)"
STREAM="next"
sudo rpm-ostree rebase "fedora/${ARCH}/coreos/${STREAM}"

@dustymabe dustymabe changed the title Update from 35.20220227.3.0 to 35.20220313.3.1 stuck. rebasing to another stream fails when deployment is staged Apr 1, 2022
@jdoss
Copy link
Contributor Author

jdoss commented Apr 1, 2022

I followed your workaround and it reverted back to 35.20220327.2.0 and didn't move to next:

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

Last login: Fri Apr  1 18:40:53 2022 from 71.201.101.213
$ sudo su -
Last login: Fri Apr  1 18:42:14 UTC 2022 on pts/0
# rpm-ostree status
State: idle
AutomaticUpdatesDriver: Zincati
  DriverState: active; periodically polling for updates (last checked Fri 2022-04-01 19:42:41 UTC)
Deployments:
* fedora:fedora/x86_64/coreos/testing
                   Version: 35.20220327.2.0 (2022-03-28T13:39:37Z)
                BaseCommit: 61052698af6316774ffd9bfb1becb40b7d709a22e728c3af677737034c3fb07d
              GPGSignature: Valid signature by 787EA6AE1147EEE56C40B30CDB4639719867C58F
           LayeredPackages: iftop ipmitool pam_yubico pciutils strace systemd-oomd-defaults tcpdump

  fedora:fedora/x86_64/coreos/stable
                   Version: 35.20220227.3.0 (2022-03-14T19:06:29Z)
                BaseCommit: 60d938261803ef4f9d927e774db51a96c75073eff81744ee5f528ab33f985ecd
              GPGSignature: Valid signature by 787EA6AE1147EEE56C40B30CDB4639719867C58F
           LayeredPackages: iftop ipmitool pam_yubico pciutils strace systemd-oomd-defaults tcpdump

@dustymabe
Copy link
Member

yeah. That was my fault because I originally did STREAM="testing" in the workaround text (copy/paste from the docs). So you did successfully rebase, you're just on testing and not next like you expected 😄

@jdoss
Copy link
Contributor Author

jdoss commented Apr 1, 2022

I totally missed it too lol. The Friday copypasta is strong.

@dustymabe dustymabe added the meeting topics for meetings label Apr 13, 2022
@jlebon
Copy link
Member

jlebon commented Apr 13, 2022

We discussed this in the community meeting today:

  * this UX issue should be fixed by ostree 2022.2
    (https://github.com/ostreedev/ostree/pull/2524)  (jlebon, 16:53:05)

@dustymabe dustymabe added status/pending-next-release Fixed upstream. Waiting on a next release. status/pending-testing-release Fixed upstream. Waiting on a testing release. and removed status/pending-next-release Fixed upstream. Waiting on a next release. labels Apr 13, 2022
@dustymabe
Copy link
Member

fast-tracking this into testing-devel: coreos/fedora-coreos-config#1675

@jlebon jlebon removed the meeting topics for meetings label Apr 20, 2022
@dustymabe
Copy link
Member

The fix for this went into testing stream release 35.20220424.2.0. Please try out the new release and report issues.

@dustymabe dustymabe added status/pending-stable-release Fixed upstream and in testing. Waiting on stable release. and removed status/pending-testing-release Fixed upstream. Waiting on a testing release. labels Apr 28, 2022
@dustymabe
Copy link
Member

The fix for this went into stable stream release 35.20220424.3.0.

@dustymabe dustymabe removed the status/pending-stable-release Fixed upstream and in testing. Waiting on stable release. label May 11, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants