We have an openQA test which tests enabling automatic updates in Cockpit. On current Rawhide (20191024.n.0 was the last tested compose), this seems to be failing. When openQA clicks the slider that should enable automatic updates, it prompts to install dnf-automatic as we expect, and that works - but then once the dnf-automatic install is complete, the slider remains in 'inactive' state, it does not switch to 'active' as expected: https://openqa.fedoraproject.org/tests/476823#step/server_cockpit_autoupdate/17 at that point the slider should show as 'active'. I don't see anything much in the logs relating to this, but it should be fairly straightforward to reproduce. I checked it happens each time the test runs, it wasn't a one-off failure.
I tried to upgrade a Fedora 31 VM to Rawhide. Neither of the two recipes [1][2] work out of the box, but with [2] and --releasever=32 it succeeded. Our `test/verify/check-packagekit TestAutoUpdates.testInstall` integration test still works, but that installs a mock dnf-automatic package (as the test runs offline). So it looks like the PackageKit etc. bits still work. The real dnf-automatic package still contains the expected timers, and if it is already installed, the On/Off switch works. So I ran `dnf remove dnf-automatic`, stopped cockpit (just in case), ran "systemctl daemon-reload". I logged into Cockpit, enabled the On/Off switch, saw dnf-automatic being installed, and after some 10 seconds the button got enabled again and switched to "On". So I'm afraid I can't reproduce this directly. Is there a way to get the systemd journal and/or browser JS log from that test? Or run that part of the test locally in a VM, where it can be inspected? [1] https://fedoraproject.org/wiki/Upgrading_Fedora_using_package_manager#To_Rawhide Fails with "GPG Error", but the referenced URL does not actually have a GPG key for Rawhide [2] https://docs.fedoraproject.org/en-US/quick-docs/dnf-system-upgrade/ Error: Failed to download metadata for repo 'updates-modular'
I tried again with removing the package, rebooting, and trying to install/enable it through cockpit. That still worked fine, i. e. rebooting doesn't help to reproduce that either. Observation: The page isn't just "stuck", as that is the Switch in the "Off" position, but *not* disabled. It gets disabled while the operation is pending, but first it's dark gray then, and second it will have the target state "On", i. e. one would see a checkmark. So it's not just an issue of waiting longer. After installing the package, Cockpit runs systemctl enable --now dnf-automatic-install.timer That triggers a UI refresh, which checks systemctl is-enabled dnf-automatic-install.timer If that is enabled, the button turns to "On". If it's not enabled, it checks an alternative way of enabling: systemctl is-enabled dnf-automatic.timer grep apply_updates.*yes /etc/dnf/automatic.conf (The real commands are a bit refined, with tighter regexp matching, but I doubt that the openQA test case uses that approach) So for now the theory is that enabling dnf-automatic-install.timer fails somehow.
Failed again in today's Rawhide compose: https://openqa.fedoraproject.org/tests/477300#step/server_cockpit_autoupdate/17 I'll try and reproduce it manually myself today and see if I can figure anything out. You can't really execute parts of openQA tests in VMs directly (well...you probably could, but it'd be a real hack job), when I want to reproduce a failure I usually just manually *mimic* the test. You can click the name of any test module in the openQA web UI to see the code for that module - e.g. click 'server_cockpit_autoupdate' and it'll show you the code for that module - though you can't always entirely understand what's going on just from that, as we use quite a lot of utility functions, it helps to keep a checkout of https://pagure.io/fedora-qa/os-autoinst-distri-fedora around so you can see what these do (they're mostly defined in files in lib/ ). The logs from failed tests are found on the 'Logs & Assets' tab, e.g. https://openqa.fedoraproject.org/tests/477300#downloads for today's failed test. https://openqa.fedoraproject.org/tests/477300/file/server_cockpit_autoupdate-var_log.tar.gz is the contents of /var/log , including the journal (use journalctl --file to see it). I didn't find much useful there, though. We do not have the browser JS log at present, I'd have to hack up the test to stash it.
(oh, btw, openQA does have a cool trick where you can run a test in interactive mode then just VNC into the running system and fiddle around with it, but unfortunately we can't really use that because of firewalls and stuff in the infra network, it's pretty hard to hook up a VNC connection from anywhere useful all the way into one of the test VMs).
So I've been fiddling about with this today, and best I can figure, it's some kind of race. If I stick a 15 second sleep in after the test reaches the 'software updates' page but before it clicks the 'Automatic Updates' slider, the test passes. Every time I tried so far. Without the timeout it always fails. Without any manually added timeouts, the test will move quite fast after log in (which goes slowly because we intentionally have openQA type very slowly in some cases, including graphical logins). It will click on the 'Software Updates' link very quickly after the main screen appears and then click on the 'Automatic Updates' slider very quickly after that. I did also hack up the test to activate the JS debugging console but didn't see anything particularly illuminating there.
In today's compose it seems broken differently: https://bugzilla.redhat.com/show_bug.cgi?id=1780791 .
I noticed this yesterday after applying latest updates to a Fedora 31 machine. The machine was running Fedora 30 and already had automatic updates enabled. The last time I checked it, it was working. I upgraded another box from Fedora 30 to Fedora 31 and afterwards noticed it also had Automatic Updates missing. I tried downgrading to version 203 and Automatic Updates showed, so I thought, right I'll pull down every version in Koji until I get to 208 and see where it broke... however as I updated and went back down, suddenly version 203 stopped working too. I tried in private browser window, same thing. So yeah, maybe some kind of race condition.
Just adding that I built upstream from master and it seems to work correctly, I've added comments in bz 1780791#c2
The current test run succeeds: https://openqa.fedoraproject.org/tests/499694 Does that still use some kind of hack, or did it fix itself as mysteriously as it broke?
The test code still has the 15 second delay to workaround this bug ATM. I can run a quick test with it taken out to see if the bug's still happening...
I did that, looks like this is still happening.
> If I stick a 15 second sleep in after the test reaches the 'software updates' page but before it clicks the 'Automatic Updates' slider, the test passes. As explained in comment #2, cockpit runs "systemctl enable --now dnf-automatic-install.timer" after installing the package, and runs "systemctl is-enabled dnf-automatic-install.timer" to determine if auto updates are enabled. The latter failing suggests that either the timer unit failed (then `systemctl --failed` should show it), or it's still waiting for a dependency to happen (then `systemctl list-jobs` should show it). AFAICS, we haven't yet found out what happens there exactly, i. e. why it fails without the sleep. Would it be possible to stick these two into the test right after package installation fails? Waiting an extra 15s *before* installing the package could perhaps advance a still incomplete boot (some early boot unit failing and blocking timers.target), so that the early failed unit eventually times out and allows timers to proceed. But that's just a shot into the dark right now. In either case, checking failed and blocked units after booting a machine is a nice generic test and helpful to find a lot of regressions.
Hum, I must have missed or forgotten about that comment - thanks for the reminder. It can be tricky to 'quickly' check anything in openQA unfortunately, but I'll give it a shot...15 seconds should be a big enough window to get some commands run. (Or I can always fall back on my favourite trick of having a script just run them every second and dump the output in a timestamped file...) "In either case, checking failed and blocked units after booting a machine is a nice generic test and helpful to find a lot of regressions." We do check for failed services after a clean install and boot, but I didn't actually think about checking for ones which are 'stuck'. We could enhance the failed services test to cover that, I guess, at least we could try (it feels like the kind of thing which might be subject to corner cases)...
Okay, so, I went with that trick, and it tells me that when this bug happens, this is the status of dnf-automatic-install.timer: ● dnf-automatic-install.timer - dnf-automatic-install timer Loaded: loaded (/usr/lib/systemd/system/dnf-automatic-install.timer; disabled; vendor preset: disabled) Active: inactive (dead) Trigger: n/a Triggers: ● dnf-automatic-install.service that seems odd. So I hacked the test a bit more to boot with systemd.log_level=debug, and got a ton of output like this: Dec 20 14:37:41 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Failed to load configuration: No such file or directory Dec 20 14:37:41 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 20 14:37:41 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Failed to send unit change signal for dnf-automatic-install.timer: Connection reset by peer Dec 20 14:37:42 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Failed to load configuration: No such file or directory Dec 20 14:37:42 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 20 14:37:43 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Failed to load configuration: No such file or directory Dec 20 14:37:43 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 20 14:37:43 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Failed to send unit remove signal for dnf-automatic-install.timer: Connection reset by peer Dec 20 14:37:44 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Failed to load configuration: No such file or directory Dec 20 14:37:44 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 20 14:37:45 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Failed to load configuration: No such file or directory Dec 20 14:37:45 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 20 14:37:46 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Failed to load configuration: No such file or directory Dec 20 14:37:46 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. ... I'm still poking into what's going on. I need to re-run the test first, as it would be useful to correlate the system log with the test execution log, but the timestamps don't match on a 'normal' run of the test because we snapshot/restore the system in the middle and the system clock doesn't get reset, so the test execution timestamps get ahead of the system timestamps. I've tweaked the test so that doesn't happen and am running it again now, that should help me see what errors we're getting at what times.
OK, so a lot of the messages I was getting were just responses to the 'systemctl status dnf-automatic-installer.timer' in my check script. With the check script turned off again but systemd debugging on, here are the significant timings from the test execution log: 00:26:20: test clicks on the button to enter the Updates screen 00:26:50: all refresh operations clear and we see the 'check for updates' button 00:26:55: test clicks the slider to enable automatic updates 00:27:06: test sees and clicks the button to install dnf-automatic package after that, it waits to see the slider in on state, but never does, and the test fails. Here are the logs we get: [adamw@adam tmp]$ journalctl --file var/log/journal/87e6a2a8ab4b463687ea01d7b4ce15df/system.journal --utc | grep dnf-automatic-install Dec 21 00:26:49 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Cannot find unit dnf-automatic-install.timer. Dec 21 00:26:49 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Failed to discover unit dnf-automatic-install.timer: No such file or directory Dec 21 00:26:49 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Failed to load configuration: No such file or directory Dec 21 00:26:49 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 00:26:49 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Failed to load configuration: No such file or directory Dec 21 00:26:49 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 00:27:06 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Preset files say disable dnf-automatic-install.timer. Dec 21 00:27:07 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/dnf-automatic-install.service Dec 21 00:27:07 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/dnf-automatic-install.timer Dec 21 00:27:08 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/dnf-automatic-install.service Dec 21 00:27:08 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/dnf-automatic-install.timer Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.service at /usr/lib/systemd/system/dnf-automatic-install.service (regular file) Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.timer at /usr/lib/systemd/system/dnf-automatic-install.timer (regular file) Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.timer at /usr/lib/systemd/system/dnf-automatic-install.timer (regular file) Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.timer at /usr/lib/systemd/system/dnf-automatic-install.timer (regular file) Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Preset files say disable dnf-automatic-install.timer. Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Sent message type=error sender=org.freedesktop.systemd1 destination=n/a path=n/a interface=n/a member=n/a cookie=40 reply_cookie=4 signature=s error-name=org.freedesktop.systemd1.NoSuchUnit error-message=Unit dnf-automatic-install.timer not loaded. Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Failed to process message type=method_call sender=n/a destination=org.freedesktop.systemd1 path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=GetUnit cookie=4 reply_cookie=0 signature=s error-name=n/a error-message=n/a: Unit dnf-automatic-install.timer not loaded. Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.service cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 00:27:10 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Sent message type=error sender=org.freedesktop.systemd1 destination=n/a path=n/a interface=n/a member=n/a cookie=40 reply_cookie=4 signature=s error-name=org.freedesktop.systemd1.NoSuchUnit error-message=Unit dnf-automatic-install.timer not loaded. Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Failed to process message type=method_call sender=n/a destination=org.freedesktop.systemd1 path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=GetUnit cookie=4 reply_cookie=0 signature=s error-name=n/a error-message=n/a: Unit dnf-automatic-install.timer not loaded. Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.service cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.service at /usr/lib/systemd/system/dnf-automatic-install.service (regular file) Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Preset files say disable dnf-automatic-install.service. Dec 21 00:27:11 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Per the packagekit service log, the dnf-automatic package install finished at 00:27:09. Still not really sure what's going on here. I think I'll get debug logs from the success case to compare.
Created attachment 1646952 [details] /var/log with systemd debug logging enabled (failure case)
So, here's the success case, for comparison. Timings: 06:32:55: test clicks on the button to enter the Updates screen 06:33:31: all refresh operations clear and we see the 'check for updates' button ** 15 SECOND WAIT HAPPENS HERE ** 06:33:50: test clicks the slider to enable automatic updates 06:33:55: test sees and clicks the button to install dnf-automatic package 06:34:04: test sees the 'automatic updates on' slider, success! Here's the grepped log messages: Dec 21 06:33:29 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Cannot find unit dnf-automatic-install.timer. Dec 21 06:33:29 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Failed to discover unit dnf-automatic-install.timer: No such file or directory Dec 21 06:33:29 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Failed to load configuration: No such file or directory Dec 21 06:33:29 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 06:33:30 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Failed to load configuration: No such file or directory Dec 21 06:33:30 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 06:33:56 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Preset files say disable dnf-automatic-install.timer. Dec 21 06:33:56 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/dnf-automatic-install.service Dec 21 06:33:56 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/dnf-automatic-install.timer Dec 21 06:33:56 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/dnf-automatic-install.service Dec 21 06:33:56 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/dnf-automatic-install.timer Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.service at /usr/lib/systemd/system/dnf-automatic-install.service (regular file) Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.timer at /usr/lib/systemd/system/dnf-automatic-install.timer (regular file) Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.timer at /usr/lib/systemd/system/dnf-automatic-install.timer (regular file) Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.timer at /usr/lib/systemd/system/dnf-automatic-install.timer (regular file) Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Preset files say disable dnf-automatic-install.timer. Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.service cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Sent message type=error sender=org.freedesktop.systemd1 destination=n/a path=n/a interface=n/a member=n/a cookie=40 reply_cookie=4 signature=s error-name=org.freedesktop.systemd1.NoSuchUnit error-message=Unit dnf-automatic-install.timer not loaded. Dec 21 06:33:59 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Failed to process message type=method_call sender=n/a destination=org.freedesktop.systemd1 path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=GetUnit cookie=4 reply_cookie=0 signature=s error-name=n/a error-message=n/a: Unit dnf-automatic-install.timer not loaded. Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Collecting. Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Sent message type=error sender=org.freedesktop.systemd1 destination=n/a path=n/a interface=n/a member=n/a cookie=52 reply_cookie=4 signature=s error-name=org.freedesktop.systemd1.NoSuchUnit error-message=Unit dnf-automatic-install.timer not loaded. Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Failed to process message type=method_call sender=n/a destination=org.freedesktop.systemd1 path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=GetUnit cookie=4 reply_cookie=0 signature=s error-name=n/a error-message=n/a: Unit dnf-automatic-install.timer not loaded. Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.service cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.service at /usr/lib/systemd/system/dnf-automatic-install.service (regular file) Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Preset files say disable dnf-automatic-install.service. Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.service: Collecting. Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com cockpit-bridge[1484]: Created symlink /etc/systemd/system/multi-user.target.wants/dnf-automatic-install.timer → /usr/lib/systemd/system/dnf-automatic-install.timer. Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/dnf-automatic-install.service Dec 21 06:34:00 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/dnf-automatic-install.timer Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com cockpit-bridge[1484]: Executing dbus call org.freedesktop.systemd1.Manager StartUnit(dnf-automatic-install.timer, replace) Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=start path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=start path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Trying to enqueue job dnf-automatic-install.timer/start/replace Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Added job dnf-automatic-install.timer/start to transaction. Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Pulling in -.mount/start from dnf-automatic-install.timer/start Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Pulling in sysinit.target/start from dnf-automatic-install.timer/start Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com cockpit-bridge[1484]: Got result done/Success for job dnf-automatic-install.timer Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Pulling in network-online.target/start from dnf-automatic-install.timer/start Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Pulling in shutdown.target/stop from dnf-automatic-install.timer/start Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Installed new job dnf-automatic-install.timer/start as 2133 Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Enqueued job dnf-automatic-install.timer/start as 2133 Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: ConditionPathExists=!/run/ostree-booted succeeded. Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Adding 16min 27.882611s random time. Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Realtime timer elapses at Sat 2019-12-21 06:16:27 EST. Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Changed dead -> waiting Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Job 2133 dnf-automatic-install.timer/start finished, result=done Dec 21 06:34:01 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Started dnf-automatic-install timer. Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/dnf-automatic-install.service Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/dnf-automatic-install.timer Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Adding 34min 39.489871s random time. Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Realtime timer elapses at Sat 2019-12-21 06:34:39 EST. Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: dnf-automatic-install.timer: Changed dead -> waiting Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.timer at /usr/lib/systemd/system/dnf-automatic-install.timer (regular file) Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Preset files say disable dnf-automatic-install.timer. Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:02 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=/usr/bin/cockpit-bridge --privileged: 0 Dec 21 06:34:04 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.service at /usr/lib/systemd/system/dnf-automatic-install.service (regular file) Dec 21 06:34:04 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: Found unit dnf-automatic-install.timer at /usr/lib/systemd/system/dnf-automatic-install.timer (regular file) Dec 21 06:34:12 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0 Dec 21 06:34:21 ibm-p8-kvm-03-guest-02.virt.pnr.lab.eng.rdu2.redhat.com systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=status path=/usr/lib/systemd/system/dnf-automatic-install.timer cmdline=: 0
Created attachment 1646975 [details] /var/log with systemd debug logging enabled (success case)
This bug appears to have been reported against 'rawhide' during the Fedora 32 development cycle. Changing version to 32.
FWIW - I noticed today we're seeing something that looks a lot like this bug on F30 and F31 update tests *even with the 15 second sleep*. It seems to have started happening on F30 about 14 days ago and on F31 about 22 days ago. I cannot identify an update that hit both distros at the respective time that seems like a likely culprit, yet. F32 and Rawhide tests seem OK lately; not sure if it's because the 15 second timeout is still sufficient there or if the bug has actually gone away entirely there, somehow. I'm bumping the sleep from 15 seconds to 30 seconds to see if it helps the F30/F31 cases.
This message is a reminder that Fedora 32 is nearing its end of life. Fedora will stop maintaining and issuing updates for Fedora 32 on 2021-05-25. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a Fedora 'version' of '32'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 32 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete.
Fedora 32 changed to end-of-life (EOL) status on 2021-05-25. Fedora 32 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. If you are unable to reopen this bug, please file a new report against the current release. If you experience problems, please add a comment to this bug. Thank you for reporting this bug and we are sorry it could not be fixed.
I just dropped the 30 second wait and retried the test on a recent F34 update. It failed. https://openqa.stg.fedoraproject.org/tests/1198302#step/server_cockpit_autoupdate/13
This message is a reminder that Fedora Linux 34 is nearing its end of life. Fedora will stop maintaining and issuing updates for Fedora Linux 34 on 2022-06-07. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a 'version' of '34'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, change the 'version' to a later Fedora Linux version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora Linux 34 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora Linux, you are encouraged to change the 'version' to a later version prior to this bug being closed.
I took the 30 second wait out and tried five runs on an F36 update and it passed every time, so this may be fixed as of F36 at least. I'll test a bit further next week.
So I tested a bit harder today. I did 10 runs each on F34, F35 and F36. F35 and F36 got ten passes each. F34 got two failures. So I suspect this is still an issue in F34, but we can let it die with F34 EOL, and I'll drop the 30 second wait from the openQA test when F34 goes EOL.
Fedora Linux 34 entered end-of-life (EOL) status on 2022-06-07. Fedora Linux 34 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. If you are unable to reopen this bug, please file a new report against the current release. Thank you for reporting this bug and we are sorry it could not be fixed.
Sad news: as part of the F35 EOL cleanup I dropped this workaround, and the test immediately failed twice on an F36 update: https://openqa.stg.fedoraproject.org/tests/2430336 https://openqa.stg.fedoraproject.org/tests/2430176 so it looks like this wasn't fixed at least in F36 :( I'll put the workaround (30s wait at the start of the autoupdate test) back in again. :/
This message is a reminder that Fedora Linux 36 is nearing its end of life. Fedora will stop maintaining and issuing updates for Fedora Linux 36 on 2023-05-16. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a 'version' of '36'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, change the 'version' to a later Fedora Linux version. Note that the version field may be hidden. Click the "Show advanced fields" button if you do not see it. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora Linux 36 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora Linux, you are encouraged to change the 'version' to a later version prior to this bug being closed.
I tested again, and it failed again on the second try :( https://openqa.stg.fedoraproject.org/tests/2831030#step/server_cockpit_autoupdate/13 that's an F37 update so this is still an issue at least as of F37. Testing on Rawhide now.
I don't see any fails on Rawhide from the time I turned the workaround off (it's back on now), but there were a couple on F38, e.g. https://openqa.stg.fedoraproject.org/tests/2833563# . So this is valid at least up to F38.