Bug 1067189

Summary:	systemd-fstab-generator creates 20 minute delay in boot
Product:	Red Hat Enterprise Linux 7	Reporter:	Robert Locke <rlocke>
Component:	systemd	Assignee:	Jan Synacek <jsynacek>
Status:	CLOSED ERRATA	QA Contact:	qe-baseos-daemons
Severity:	unspecified	Docs Contact:
Priority:	unspecified
Version:	7.0	CC:	djschaap, jscotka, jsynacek, lnykryn, msekleta, peljasz, rhel, rlocke, systemd-maint-list, yoguma
Target Milestone:	rc
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	systemd-219	Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2015-11-19 14:55:54 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:

Description Robert Locke 2014-02-19 22:31:45 UTC

Description of problem:
/etc/fstab contains two probably conflicting/unusual entries:
172.25.254.254:/content  /content  nfs  ro  0 0
/content/path/isos/file.iso /content/path/dvd  iso9660  loop,ro 0 0

Version-Release number of selected component (if applicable):
systemd-207-14.el7.x86_64


Actual results:
Get numerous messages during boot about "Found dependency", "Breaking ordering", and others that span over 20 minutes. System does eventually boot.

Expected results:
Expect system to recognize the dependency of the "loop" mount on the "nfs" mount, in that the "device" is found on the mountpoint of the "nfs" mount.

Additional info:
I would be happy to have a "workaround" of appropriate "unit" files, but not sure how to start that.

Comment 2 RHEL Program Management 2014-03-22 05:59:42 UTC

This request was not resolved in time for the current release.
Red Hat invites you to ask your support representative to
propose this request, if still desired, for consideration in
the next release of Red Hat Enterprise Linux.

Comment 3 Michal Sekletar 2014-07-01 13:32:32 UTC

Is this report still valid? I did a quick test on my RHEL7 VM (systemd-208-11) and I can't reproduce the issue anymore. Please verify. Thanks.

Comment 4 Robert Locke 2014-07-01 14:54:02 UTC

Short answer yes. systemd-208-11.el7.x86_64

Longer answer:
Watching the console.
After it displays the message about "Relabelled /dev and /run..."
I get 60 second pauses between messages:
60- Found dependency on content-rhel7.0-x86_64-dvd.mount/start
120- Found dependency on content.mount/start
180- Found dependency on network.target/start
240- Found dependency on netcf-transaction.service/start
300- Found dependency on basic.target/start
360- Breaking ordering cycle by deleting job sockets.target/start
420- Job sockets.target/start deleted to break ordering cycle starting with basic.target/start
480- Found ordering cycle on network.target/start
540- Found dependency on firewalld....

Stopped watching as we are up to 9 minutes now....

Comment 5 Michal Sekletar 2014-07-02 12:30:41 UTC

Thanks for verifying that this is indeed still an issue.

Comment 6 lejeczek 2014-07-09 08:57:03 UTC

I have a something like here:

172.25.12.203:/__.aNETexports/WHALE/h200Internal0 /__.aNetStorage/WHALE/h200Internal0  nfs _netdev,vers=3,bg,retry=4,rw,defaults    0 0
/__.aNetStorage/WHALE/h200Internal0/__.live.lsyncd/__.fromLocalhost/__.users.home  /home  none  bind,_netdev  0 0


in my fstab and system takes hours to boot (rhel 6.5 no problems)
if I only change, (and nfs always mount a ok)

/__.aNetStorage/WHALE/h200Internal0/__.live.lsyncd/__.fromLocalhost/__.users.home  /home  none  noauto,bind,_netdev  0 0

system boots as normal and no problems to mount-bind the home later,

Comment 8 Lukáš Nykrýn 2015-06-11 14:14:40 UTC

Can you please retest this with https://copr.fedoraproject.org/coprs/lnykryn/systemd/ ? This should be in 7.2

Comment 9 Jan Synacek 2015-06-12 13:24:22 UTC

I have reproduced this on my RHEL7 testing machine (waited for about 15 minutes, then gave up). I have also verified that the boot *doesn't hang* with systemd-219-3.el7. However, I'm a bit concerned with the resolution that systemd is making:

[...snip...]
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network-online.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on NetworkManager.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on firewalld.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on basic.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Breaking ordering cycle by deleting job rhel-import-state.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Job rhel-import-state.service/start deleted to break ordering cycle starting with basic.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found ordering cycle on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on rhel-autorelabel.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on local-fs.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs-content.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network-online.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on NetworkManager.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on firewalld.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on basic.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sockets.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on iscsid.socket/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Breaking ordering cycle by deleting job rhel-autorelabel.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Job rhel-autorelabel.service/start deleted to break ordering cycle starting with sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found ordering cycle on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on systemd-update-utmp.service/verify-active
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on systemd-tmpfiles-setup.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on local-fs.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs-content.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network-online.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on NetworkManager.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on firewalld.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on basic.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sockets.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on iscsid.socket/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Breaking ordering cycle by deleting job systemd-update-utmp.service/verify-active
Jun 12 15:12:00 rhel7-virt systemd[1]: Job systemd-update-utmp.service/verify-active deleted to break ordering cycle starting with sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found ordering cycle on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on systemd-tmpfiles-setup.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on local-fs.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs-content.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network-online.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on NetworkManager.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on firewalld.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on basic.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sockets.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on iscsid.socket/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Breaking ordering cycle by deleting job systemd-tmpfiles-setup.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Job systemd-tmpfiles-setup.service/start deleted to break ordering cycle starting with sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found ordering cycle on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on plymouth-read-write.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on local-fs.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs-content.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network-online.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on NetworkManager.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on firewalld.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on basic.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sockets.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on iscsid.socket/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Breaking ordering cycle by deleting job plymouth-read-write.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Job plymouth-read-write.service/start deleted to break ordering cycle starting with sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found ordering cycle on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on rhel-autorelabel-mark.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on local-fs.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs-content.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network-online.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on NetworkManager.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on firewalld.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on basic.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sockets.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on iscsid.socket/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Breaking ordering cycle by deleting job rhel-autorelabel-mark.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Job rhel-autorelabel-mark.service/start deleted to break ordering cycle starting with sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found ordering cycle on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on systemd-update-done.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on local-fs.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs-content.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network-online.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on NetworkManager.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on firewalld.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on basic.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sockets.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on iscsid.socket/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Breaking ordering cycle by deleting job systemd-update-done.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Job systemd-update-done.service/start deleted to break ordering cycle starting with sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found ordering cycle on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on systemd-journal-catalog-update.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on local-fs.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs-content.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network-online.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on NetworkManager.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on firewalld.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on basic.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sockets.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on iscsid.socket/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Breaking ordering cycle by deleting job systemd-journal-catalog-update.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Job systemd-journal-catalog-update.service/start deleted to break ordering cycle starting with sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found ordering cycle on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on local-fs.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs-content.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on mnt-nfs.mount/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network-online.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on network.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on NetworkManager.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on firewalld.service/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on basic.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sockets.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on iscsid.socket/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Found dependency on sysinit.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Breaking ordering cycle by deleting job local-fs.target/start
Jun 12 15:12:00 rhel7-virt systemd[1]: Job local-fs.target/start deleted to break ordering cycle starting with sysinit.target/start

[...snip...]

@Michal: Could you please comment? Is it ok that those jobs get deleted?

Comment 10 Lukáš Nykrýn 2015-06-13 05:25:57 UTC

Its fine that systemd deletes a job to break a cycle, but there is too many of them. What was you version of initscripts? The first one looks like https://git.fedorahosted.org/cgit/initscripts.git/commit/?h=rhel7-branch&id=ae89b97af47202b2d7cca3b66996bb0ecc44cc5d

Comment 11 Jan Synacek 2015-06-15 06:18:35 UTC

# rpm -q initscripts
initscripts-9.49.24-1.el7.x86_64

Comment 12 Lukáš Nykrýn 2015-06-15 08:14:34 UTC

Hmm that should be fine.

Comment 13 Jan Synacek 2015-06-17 10:38:38 UTC

See http://lists.freedesktop.org/archives/systemd-devel/2015-June/033006.html. If _netdev is added to the dependent iso mount, the cycle disappears.

This is then fixed in v219.

Comment 18 errata-xmlrpc 2015-11-19 14:55:54 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2015-2092.html