zincati not updating CoreOS

[apinter]

Describe the bug
Not sure if this is a bug or user error, but it seems that zincati is not upgrading the system and getting a 502 error. The server hasn't been updated for 11 days now. Possbile that the server is indeed not available or I made a mistake in the zincati config. Not even sure if this is the right platform to post this anymore so I apologize in advance.

systemctl status zincati.service 
● zincati.service - Zincati Update Agent
     Loaded: loaded (/usr/lib/systemd/system/zincati.service; enabled; vendor preset: enabled)
     Active: active (running) since Wed 2022-01-19 16:12:44 UTC; 1 week 4 days ago
       Docs: https://github.com/coreos/zincati
   Main PID: 835 (zincati)
     Status: "periodically polling for updates (last checked Mon 2022-01-31 05:31:53 UTC)"
      Tasks: 4 (limit: 4592)
     Memory: 14.1M
        CPU: 49.441s
     CGroup: /system.slice/zincati.service
             └─835 /usr/libexec/zincati agent -v

Jan 19 16:12:41 kimera zincati[835]: [INFO  zincati::cli::agent] agent running on node 'e0bbf17e0b8b4dd1bce88c44696ef946', in update group 'default'
Jan 19 16:12:41 kimera zincati[835]: [INFO  zincati::update_agent::actor] registering as the update driver for rpm-ostree
Jan 19 16:12:44 kimera zincati[835]: [INFO  zincati::update_agent::actor] found 1 other finalized deployment
Jan 19 16:12:44 kimera zincati[835]: [INFO  zincati::update_agent::actor] deployment 35.20211215.3.0 (30c82ee684674b9a552ffee709501f981f35f36408085f089686e43b09aeca1b) will be excluded from being a future update target
Jan 19 16:12:44 kimera zincati[835]: [INFO  zincati::update_agent::actor] initialization complete, auto-updates logic enabled
Jan 19 16:12:44 kimera zincati[835]: [INFO  zincati::strategy] update strategy: immediate
Jan 19 16:12:44 kimera systemd[1]: Started Zincati Update Agent.
Jan 19 16:12:44 kimera zincati[835]: [INFO  zincati::update_agent::actor] reached steady state, periodically polling for updates
Jan 19 16:12:46 kimera zincati[835]: [INFO  zincati::cincinnati] current release detected as not a dead-end
Jan 27 15:25:15 kimera zincati[835]: [ERROR zincati::cincinnati] failed to check Cincinnati for updates: server-side error, code 502: (unknown/generic server error)

rpm-ostree status
State: idle
AutomaticUpdatesDriver: Zincati
  DriverState: active; periodically polling for updates (last checked Mon 2022-01-31 05:44:38 UTC)
Deployments:
● fedora:fedora/x86_64/coreos/stable
                   Version: 35.20220103.3.0 (2022-01-17T15:41:41Z)
                    Commit: 83f5d39fbf539a1e5edd21747899480e11710b351d25d5790e15e1930f51e2b9
              GPGSignature: Valid signature by 787EA6AE1147EEE56C40B30CDB4639719867C58F

  fedora:fedora/x86_64/coreos/stable
                   Version: 35.20211215.3.0 (2022-01-04T18:57:51Z)
                    Commit: 30c82ee684674b9a552ffee709501f981f35f36408085f089686e43b09aeca1b
              GPGSignature: Valid signature by 787EA6AE1147EEE56C40B30CDB4639719867C58F

Reproduction steps
Steps to reproduce the behavior:

1. Deploy FCOS with the provided ignitionfile,
2. Let it run for a while and monitor the activities of zincati

Expected behavior
zincati should pull the update, stage the new deployment and reboot the box immediately.

Actual behavior
zincati runs into a 502 error and unable to execute the update procedure.

System details

• GCP VM
• Fedora CoreOS version:

cat /etc/os-release 
NAME="Fedora Linux"
VERSION="35.20220103.3.0 (CoreOS)"
ID=fedora
VERSION_ID=35
VERSION_CODENAME=""
PLATFORM_ID="platform:f35"
PRETTY_NAME="Fedora CoreOS 35.20220103.3.0"
ANSI_COLOR="0;38;2;60;110;180"
LOGO=fedora-logo-icon
CPE_NAME="cpe:/o:fedoraproject:fedora:35"
HOME_URL="https://getfedora.org/coreos/"
DOCUMENTATION_URL="https://docs.fedoraproject.org/en-US/fedora-coreos/"
SUPPORT_URL="https://github.com/coreos/fedora-coreos-tracker/"
BUG_REPORT_URL="https://github.com/coreos/fedora-coreos-tracker/"
REDHAT_BUGZILLA_PRODUCT="Fedora"
REDHAT_BUGZILLA_PRODUCT_VERSION=35
REDHAT_SUPPORT_PRODUCT="Fedora"
REDHAT_SUPPORT_PRODUCT_VERSION=35
PRIVACY_POLICY_URL="https://fedoraproject.org/wiki/Legal:PrivacyPolicy"
VARIANT="CoreOS"
VARIANT_ID=coreos
OSTREE_VERSION='35.20220103.3.0'
DEFAULT_HOSTNAME=localhost

Ignition config
Users and public keys are deleted, everything else is valid. Posting the butane config as well.

variant: fcos
version: 1.4.0
passwd:
  users:
    - name: core
      ssh_authorized_keys:
        - [KEY]
storage:
  files:
    - path: /etc/ssh/sshd_config.d/00-port.conf
      contents:
        inline: |
          Port 51643
    - path: /etc/zincati/config.d/55-updates-strategy.toml
      contents:
        inline: |
          [cincinnati]
          base_url= "https://updates.coreos.fedoraproject.org"
          [updates]
          strategy = "immediate"
    - path: /etc/profile.d/systemd-pager.sh
      mode: 0644
      contents:
        inline: |
          export SYSTEMD_PAGER=cat
    - path: /etc/sysctl.d/20-silence-audit.conf
      mode: 0644
      contents:
        inline: |
          kernel.printk=4

{
  "ignition": {
    "version": "3.3.0"
  },
  "passwd": {
    "users": [
      {
        "name": "core",
        "sshAuthorizedKeys": [
          "KEY"
        ]
      },
    ]
  },
  "storage": {
    "files": [
      {
        "path": "/etc/ssh/sshd_config.d/20-sshd-port.conf",
        "contents": {
          "source": "data:,Port%2051643%0A"
        }
      },
      {
        "path": "/etc/zincati/config.d/55-updates-strategy.toml",
        "contents": {
          "source": "data:;base64,W3VwZGF0ZXNdCnN0cmF0ZWd5ID0gInBlcmlvZGljIgpbW3VwZGF0ZXMucGVyaW9kaWMud2luZG93XV0KZGF5cyA9IFsgIlNhdCIsICJTdW4iIF0Kc3RhcnRfdGltZSA9ICIyMjozMCIKbGVuZ3RoX21pbnV0ZXMgPSA2MAo="
        }
      },
      {
        "path": "/etc/profile.d/systemd-pager.sh",
        "contents": {
          "source": "data:,export%20SYSTEMD_PAGER%3Dcat%0A"
        },
        "mode": 420
      },
      {
        "path": "/etc/sysctl.d/20-silence-audit.conf",
        "contents": {
          "source": "data:,kernel.printk%3D4"
        },
        "mode": 420
      }
    ]
  }
}

Additional information
N/A

[lucab]

Thanks for the report, but I can't spot the issue.

From your logs:

DriverState: active; periodically polling for updates (last checked Mon 2022-01-31 05:44:38 UTC)
Deployments:
● fedora:fedora/x86_64/coreos/stable
                  Version: 35.20220103.3.0 (2022-01-17T15:41:41Z)

As we speak, the latest FCOS stable version is 35.20220103.3.0, which your node is currently running.
Last Zincati check from the status is timestamped Mon 2022-01-31 05:44:38 UTC, which is a few minutes before this ticket timestamp.

Additionally, the node has a 35.20211215.3.0 rollback deployment, so it seems it successfully upgraded from the previous stable release. Last logged backend error is from 2022-01-27, which was 4 days ago.
This node auto-updates seem healthy to me from the logs you provided, but you can double-check your service metrics monitoring to make sure of that.

[apinter]

Hey @lucab, big thanks for your guidance on the matter. I guess I overreacted a bit then ^-^
Going to keep a close eye on this matter and report back if anything actually goes wrong. Sorry for wasting your time.

[lucab]

@apinter no problem, I think you got confused due to a suboptimal UX arrangement, which got previously reported at coreos/zincati#407.