Bug 1159117

Summary: systemd 217 show dependency loop and won't start gdm
Product: [Fedora] Fedora Reporter: Kevin Fenzi <kevin>
Component: systemdAssignee: systemd-maint
Status: CLOSED RAWHIDE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: urgent Docs Contact:
Priority: high    
Version: rawhideCC: dking, johannbg, jsynacek, lnykryn, mattdm, mschmidt, msekleta, s, systemd-maint, twohotis, vpavlin, yaneti, zbyszek
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: systemd-217-2.fc22 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-10-31 22:29:11 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
boot messages none

Description Kevin Fenzi 2014-10-31 02:18:34 UTC
Created attachment 952380 [details]
boot messages

Sorry for this not being too detailed, but I figured I would file it sooner rather than later. 

After updating to systemd-217 in rawhide: 

* gdm doesn't start on boot, it just shows a blank screen. On 'systemctl restart gdm' it comes up. 

* openvpn fails to start complaining about no tmpfiles. On 'systemd-tmpfiles --create' it can be started. 

Booting with enforcing=0 doesn't seem to help. 

In boot messages there's a ton of ordering cycle messages: 

Oct 30 15:50:48 voldemort.scrye.com systemd[1]: Breaking ordering cycle by deleting job systemd-tmpfiles-setup.service/start
Oct 30 15:50:48 voldemort.scrye.com systemd[1]: Job systemd-tmpfiles-setup.service/start deleted to break ordering cycle starting with basic.target/start
Oct 30 15:50:48 voldemort.scrye.com systemd[1]: Cannot find unit for notify message of PID 133.

Will attach full boot messages from 'journalctl -b -l'

Comment 1 Onyeibo Oku 2014-10-31 05:07:09 UTC
Hit this bug this morning after an update.  It severity should be set to "urgent" although this is rawhide. The issue doesn't replicate 100% as "systemctl restart gdm" failed consistently on my machine. 

The approach that worked:
yum downgrade libgudev1* systemd*

Comment 2 Yanko Kaneti 2014-10-31 08:23:34 UTC
Perhaps kmod-18-4.fc22 didn't make it to the compose and could be having effect here

Comment 3 Matthew Miller 2014-10-31 11:24:40 UTC
Yanko: no, I have that version of that package on my system.

Comment 4 Matthew Miller 2014-10-31 12:15:26 UTC
With debug loglevel, this looks like the key part of the log:

Oct 31 07:42:29 ubik systemd[1]: Found ordering cycle on basic.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on sysinit.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on systemd-update-utmp.service/verify-active
Oct 31 07:42:29 ubik systemd[1]: Found dependency on systemd-tmpfiles-setup.service/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on systemd-journal-flush.service/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on remote-fs.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on remote-fs-pre.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on nfs-client.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on gssproxy.service/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on basic.target/start
Oct 31 07:42:29 ubik systemd[1]: Breaking ordering cycle by deleting job systemd-update-utmp.service/verify-active
Oct 31 07:42:29 ubik systemd[1]: Job systemd-update-utmp.service/verify-active deleted to break ordering cycle starting with basic.target/start
Oct 31 07:42:29 ubik systemd[1]: Deleting job systemd-update-utmp-runlevel.service/start as dependency of job systemd-update-utmp.service/verify-active
Oct 31 07:42:29 ubik systemd[1]: Found ordering cycle on basic.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on sysinit.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on auditd.service/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on systemd-tmpfiles-setup.service/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on systemd-journal-flush.service/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on remote-fs.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on remote-fs-pre.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on nfs-client.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on gssproxy.service/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on basic.target/start
Oct 31 07:42:29 ubik systemd[1]: Breaking ordering cycle by deleting job auditd.service/start
Oct 31 07:42:29 ubik systemd[1]: Job auditd.service/start deleted to break ordering cycle starting with basic.target/start
Oct 31 07:42:29 ubik systemd[1]: Found ordering cycle on basic.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on sysinit.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on systemd-tmpfiles-setup.service/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on systemd-journal-flush.service/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on remote-fs.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on remote-fs-pre.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on nfs-client.target/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on gssproxy.service/start
Oct 31 07:42:29 ubik systemd[1]: Found dependency on basic.target/start
Oct 31 07:42:29 ubik systemd[1]: Breaking ordering cycle by deleting job systemd-tmpfiles-setup.service/start
Oct 31 07:42:29 ubik systemd[1]: Job systemd-tmpfiles-setup.service/start deleted to break ordering cycle starting with basic.target/start
Oct 31 07:42:29 ubik systemd[1]: Looking at job sshd-keygen.service/stop conflicted_by=no
Oct 31 07:42:29 ubik systemd[1]: Looking at job sshd-keygen.service/start conflicted_by=no
Oct 31 07:42:29 ubik systemd[1]: Fixing conflicting jobs sshd-keygen.service/stop,sshd-keygen.service/start by deleting job sshd-keygen.service/stop
Oct 31 07:42:29 ubik systemd[1]: Looking at job plymouth-quit.service/stop conflicted_by=yes
Oct 31 07:42:29 ubik systemd[1]: Looking at job plymouth-quit.service/start conflicted_by=no
Oct 31 07:42:29 ubik systemd[1]: Fixing conflicting jobs plymouth-quit.service/stop,plymouth-quit.service/start by deleting job plymouth-quit.service/start
Oct 31 07:42:29 ubik systemd[1]: Looking at job gdm.service/start conflicted_by=no
Oct 31 07:42:29 ubik systemd[1]: Looking at job gdm.service/stop conflicted_by=no
Oct 31 07:42:29 ubik systemd[1]: Fixing conflicting jobs gdm.service/start,gdm.service/stop by deleting job gdm.service/stop
Oct 31 07:42:29 ubik systemd[1]: Looking at job getty/stop conflicted_by=yes
Oct 31 07:42:29 ubik systemd[1]: Looking at job getty/start conflicted_by=no
Oct 31 07:42:29 ubik systemd[1]: Fixing conflicting jobs getty/stop,getty/start by deleting job getty/start

Comment 5 Michal Schmidt 2014-10-31 15:24:05 UTC
Found the problem in systemd v217,
https://lists.fedoraproject.org/pipermail/devel/2014-October/203864.html:

>> I wonder if the new ordering dependency between
>> systemd-journal-flush.service and systemd-tmpfiles-setup.service
>> (added in 74055aa76 "journalctl: add new --flush command and make use
>> of it in systemd-journal-flush.service") participates in the ordering
>> cycles.
>
> Ahh, indeed. It moves remote-fs.target into the early-boot where it
> doesn't belong.
> 
> My fault.
> 
> Will drop the remote-fs.target dep from the flush service.

Comment 7 Kevin Fenzi 2014-10-31 15:26:37 UTC
Excellent. Thanks for the quick debugging. ;) Looking forward to the fixed build...