Description of problem: I have a fresh install of Fedora 18. When I install (via yum) and enable (via systemctl) autofs, it causes systemd ordering cycle problems on system shutdown. I feel that this problem is urgent since it results in many (most? all?) of the services to not be properly shut down, especially the local filesystems. Version-Release number of selected component (if applicable): autofs.x86_64 1:5.0.7-16.fc18 systemd.x86_64 201-2.fc18.7 systemd-sysv.x86_64 201-2.fc18.7 How reproducible: Unknown. It seems to be somewhat random on exactly what errors occur at shutdown, but I've not seen what I would consider a normal shutdown yet. Steps to Reproduce: 1. Installed F18 from DVD using a kickstart file (with many packages included) 2. install autofs (yum install autofs) 3. enable & start autofs (systemctl enable autofs; systemctl start autofs) 4. ls an automounted directory 5. shutdown -h now Actual results: System seems to boot OK, although I have seen instances where some of the SysV init scripts do not start their processes (at least logs are missing from /var/log/messages) On Shutdown (shutdown -h now), I don't see messages for most/all of the system services being shut down. Expected results: No ordering cycle found by systemd and all of the system services properly shut down. Additional info: From /var/log/messages: 1st shutdown produced (immediately after enabling, w/ autofs mounted dirs): Aug 6 17:13:36 pot systemd[1]: Found ordering cycle on dbus.socket/stop Aug 6 17:13:36 pot systemd[1]: Walked on cycle path to sysinit.target/stop Aug 6 17:13:36 pot systemd[1]: Walked on cycle path to local-fs.target/stop Aug 6 17:13:36 pot systemd[1]: Walked on cycle path to software-linux.mount/stop Aug 6 17:13:36 pot systemd[1]: Walked on cycle path to network.target/stop Aug 6 17:13:36 pot systemd[1]: Walked on cycle path to NetworkManager.service/stop Aug 6 17:13:36 pot systemd[1]: Walked on cycle path to basic.target/stop Aug 6 17:13:36 pot systemd[1]: Walked on cycle path to sockets.target/stop Aug 6 17:13:36 pot systemd[1]: Walked on cycle path to dbus.socket/stop Aug 6 17:13:36 pot systemd[1]: Breaking ordering cycle by deleting job sysinit.target/stop Aug 6 17:13:36 pot rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="580" x-info="http://www.rsyslog.com"] exiting on signal 15. 2nd shutdown produced (no dirs autofs-mounted): <<NOTE: no ordering cycle reported by systemd!!>> Aug 6 17:24:34 pot systemd[1]: Starting Show Plymouth Power Off Screen... Aug 6 17:24:34 pot systemd[1]: Deactivating swap /dev/dm-0... Aug 6 17:24:34 pot systemd[1]: Deactivating swap /dev/dm-0... Aug 6 17:24:34 pot systemd[1]: Deactivating swap /dev/dm-0... Aug 6 17:24:34 pot systemd[1]: Deactivating swap /dev/dm-0... 3rd shutdown produced (w/ autofs-mounted dirs): Aug 6 17:30:10 pot systemd[1]: Found ordering cycle on dbus.socket/stop Aug 6 17:30:10 pot systemd[1]: Walked on cycle path to sysinit.target/stop Aug 6 17:30:10 pot systemd[1]: Walked on cycle path to local-fs.target/stop Aug 6 17:30:10 pot systemd[1]: Walked on cycle path to software-linux.mount/stop Aug 6 17:30:10 pot systemd[1]: Walked on cycle path to network.target/stop Aug 6 17:30:10 pot systemd[1]: Walked on cycle path to NetworkManager.service/stop Aug 6 17:30:10 pot systemd[1]: Walked on cycle path to basic.target/stop Aug 6 17:30:10 pot systemd[1]: Walked on cycle path to sockets.target/stop Aug 6 17:30:10 pot systemd[1]: Walked on cycle path to dbus.socket/stop Aug 6 17:30:10 pot systemd[1]: Breaking ordering cycle by deleting job sysinit.target/stop Aug 6 17:30:10 pot systemd[1]: Job sysinit.target/stop deleted to break ordering cycle starting with dbus.socket/stop Aug 6 17:30:10 pot systemd[1]: Starting Show Plymouth Power Off Screen... Aug 6 17:30:10 pot systemd[1]: Deactivating swap /dev/dm-0... Aug 6 17:30:10 pot systemd[1]: Deactivating swap /dev/dm-0... Aug 6 17:30:10 pot systemd[1]: Stopping Load legacy module configuration... Aug 6 17:30:10 pot systemd[1]: Stopped Load Kernel Modules. Aug 6 17:30:10 pot systemd[1]: Stopping Daemon for power management... Aug 6 17:30:10 pot rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="579" x-info="http://www.rsyslog.com"] exiting on signal 15.
How is software-linux.mount configured? Via fstab? Can you provide the precise line?
Lennart, No, /software/linux is automounted via NIS. So, to walk down the tree.... /etc/auto.master has (I'm only including the pertinent lines for clarity): /software yp:auto_software --timeout=0 Doing a ypcat -k auto_software shows: Linux -rw,hard,retry=0,noatime,nodiratime pie:/vol0/software/linux linux -rw,hard,retry=0,noatime,nodiratime pie:/vol0/software/linux (I'm implementing an "alias" for Linux to "point to" linux) My /etc/fstab has no entries related to /software/linux at all. The output from mount | grep -i linux shows: pie:/vol0/software/linux on /software/Linux type nfs4 (rw,noatime,nodiratime,vers=4.0,rsize=1048576,wsize=1048576,namlen=255,hard,proto=tcp,port=0,timeo=600,retrans=2,sec=sys,clientaddr=192.168.1.164,local_lock=none,addr=192.168.1.60) pie:/vol0/software/linux on /software/linux type nfs4 (rw,noatime,nodiratime,vers=4.0,rsize=1048576,wsize=1048576,namlen=255,hard,proto=tcp,port=0,timeo=600,retrans=2,sec=sys,clientaddr=192.168.1.164,local_lock=none,addr=192.168.1.60) Note that this all worked just fine in F16...
This should be fixed by http://cgit.freedesktop.org/systemd/systemd/commit/?id=7700945. I guess we need to backport this here too.
systemd-204-17.fc19 has been submitted as an update for Fedora 19. https://admin.fedoraproject.org/updates/systemd-204-17.fc19
Any chance that the fix will be ported back to F18?
It should be. I'll try to produce an update, but because of the version gap, backporting stuff isn't easy.
Package systemd-204-17.fc19: * should fix your issue, * was pushed to the Fedora 19 testing repository, * should be available at your local mirror within two days. Update it with: # su -c 'yum update --enablerepo=updates-testing systemd-204-17.fc19' as soon as you are able to. Please go to the following url: https://admin.fedoraproject.org/updates/FEDORA-2013-19730/systemd-204-17.fc19 then log in and leave karma (feedback).
systemd-204-17.fc19 has been pushed to the Fedora 19 stable repository. If problems still persist, please make note of it in this bug report.
systemd-201-2.fc18.9 has been submitted as an update for Fedora 18. https://admin.fedoraproject.org/updates/systemd-201-2.fc18.9
Package systemd-201-2.fc18.9: * should fix your issue, * was pushed to the Fedora 18 testing repository, * should be available at your local mirror within two days. Update it with: # su -c 'yum update --enablerepo=updates-testing systemd-201-2.fc18.9' as soon as you are able to. Please go to the following url: https://admin.fedoraproject.org/updates/FEDORA-2013-20267/systemd-201-2.fc18.9 then log in and leave karma (feedback).
Tested with: systemd.x86_64 201-2.fc18.9 @updates-testing (Thanks for porting the fix back!!) Fix does solve the ordering cycle problem, which is a big improvement. However, being admittedly somewhat naive here, shouldn't the shutdown messages in /var/log/messages be the same each time? I'm guessing that there might be timing issues with syslogd... Is there a reliable place to see all of the messages output during shutdown? What is stored in the messages file doesn't match what I see on the screen (momentarily) while the system shuts down. Anyway, to document the testing that I did, here's the pertinent output from /var/log/messages, with my comments: # # Previous shutdown without fix # Oct 28 14:17:57 security systemd-logind[14668]: System is powering down. Oct 28 14:17:57 security systemd[1]: Found ordering cycle on network.target/stop Oct 28 14:17:57 security systemd[1]: Walked on cycle path to NetworkManager.service/stop Oct 28 14:17:57 security systemd[1]: Walked on cycle path to dbus.socket/stop Oct 28 14:17:57 security systemd[1]: Walked on cycle path to sysinit.target/stop Oct 28 14:17:57 security systemd[1]: Walked on cycle path to local-fs.target/stop Oct 28 14:17:57 security systemd[1]: Walked on cycle path to software-FedoraMirror.mount/stop Oct 28 14:17:57 security systemd[1]: Walked on cycle path to network.target/stop Oct 28 14:17:57 security systemd[1]: Breaking ordering cycle by deleting job NetworkManager.service/stop Oct 28 14:17:57 security systemd[1]: Job NetworkManager.service/stop deleted to break ordering cycle starting with network.target/stop Oct 28 14:17:57 security systemd[1]: Starting Show Plymouth Power Off Screen... Oct 28 14:17:57 security systemd[1]: Deactivating swap /dev/dm-0... Oct 28 14:17:57 security systemd[1]: Deactivating swap /dev/dm-0... Oct 28 14:17:57 security systemd[1]: Deactivating swap /dev/dm-0... Oct 28 14:17:57 security systemd[1]: Deactivating swap /dev/dm-0... Oct 28 14:17:57 security systemd[1]: Deactivating swap /dev/dm-0... Oct 28 14:17:57 security systemd[1]: Stopping Sound Card. Oct 28 14:17:57 security systemd[1]: Stopping Sockets. Oct 28 14:17:57 security rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="606" x-info="http://www.rsyslog.com"] exiting on signal 15. # # First shutdown immediately after installing new systemd packages # NFS directories are automount'ed # Oct 31 13:11:35 security systemd-logind[26978]: System is powering down. Oct 31 13:11:35 security systemd[1]: Starting Show Plymouth Power Off Screen... Oct 31 13:11:35 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:11:35 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:11:35 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:11:35 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:11:35 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:11:35 security systemd[1]: Stopping Sound Card. Oct 31 13:11:35 security systemd[1]: Stopped target Sound Card. ct 31 13:11:35 security systemd[1]: Stopping Import network configuration from initramfs... Oct 31 13:11:35 security systemd[1]: Stopped Import network configuration from initramfs. Oct 31 13:11:35 security rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="731" x-info="http://www.rsyslog.com"] exiting on signal 15. # # 2nd shutdown after install, no NFS directories mounted # Oct 31 13:13:24 security systemd-logind[667]: System is powering down. Oct 31 13:13:24 security systemd[1]: Starting Show Plymouth Power Off Screen... Oct 31 13:13:24 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:13:24 security rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="726" x-info="http://www.rsyslog.com"] exiting on signal 15. # # 3rd shutdown after install, NFS directories are automount'ed # Oct 31 13:16:15 security systemd-logind[666]: System is powering down. Oct 31 13:16:15 security systemd[1]: Starting Show Plymouth Power Off Screen... Oct 31 13:16:15 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:16:15 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:16:15 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:16:15 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:16:15 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:16:15 security systemd[1]: Stopping Sound Card. Oct 31 13:16:15 security systemd[1]: Stopped target Sound Card. Oct 31 13:16:15 security systemd[1]: Stopping Import network configuration from initramfs... Oct 31 13:16:15 security systemd[1]: Stopped Import network configuration from initramfs. Oct 31 13:16:15 security systemd[1]: Stopping Stop Read-Ahead Data Collection 10s After Completed Startup. Oct 31 13:16:15 security systemd[1]: Stopped Stop Read-Ahead Data Collection 10s After Completed Startup. Oct 31 13:16:15 security systemd[1]: Stopping CUPS Printing Service... Oct 31 13:16:15 security systemd[1]: Stopping Graphical Interface. Oct 31 13:16:15 security systemd[1]: Stopped target Graphical Interface. Oct 31 13:16:15 security rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="677" x-info="http://www.rsyslog.com"] exiting on signal 15. # # 4th shutdown, NFS directories automount'ed # Oct 31 13:23:22 security systemd-logind[674]: System is powering down. Oct 31 13:23:22 security systemd[1]: Starting Show Plymouth Power Off Screen... Oct 31 13:23:22 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:23:22 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:23:22 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:23:22 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:23:22 security systemd[1]: Deactivating swap /dev/dm-0... Oct 31 13:23:22 security systemd[1]: Stopping Sound Card. Oct 31 13:23:22 security systemd[1]: Stopped target Sound Card. Oct 31 13:23:22 security systemd[1]: Stopping Import network configuration from initramfs... Oct 31 13:23:22 security systemd[1]: Stopped Import network configuration from initramfs. Oct 31 13:23:22 security systemd[1]: Stopping Stop Read-Ahead Data Collection 10s After Completed Startup. Oct 31 13:23:22 security systemd[1]: Stopped Stop Read-Ahead Data Collection 10s After Completed Startup. Oct 31 13:23:22 security systemd[1]: Stopping CUPS Printing Service... Oct 31 13:23:22 security systemd[1]: Stopping Graphical Interface. Oct 31 13:23:22 security systemd[1]: Stopped target Graphical Interface. Oct 31 13:23:22 security systemd[1]: Stopping Restorecon maintaining path file context... Oct 31 13:23:22 security systemd[1]: Stopping ACPI Event Daemon... Oct 31 13:23:22 security systemd[1]: Stopping Console Mouse manager... Oct 31 13:23:22 security systemd[1]: Stopping Virtualization daemon... Oct 31 13:23:22 security systemd[1]: Stopping Kernel Samepage Merging (KSM) Tuning Daemon... Oct 31 13:23:22 security rsyslogd: [origin software="rsyslogd" swVersion="7.2.6" x-pid="682" x-info="http://www.rsyslog.com"] exiting on signal 15.
(In reply to Ray Mikkelson from comment #11) > Tested with: > systemd.x86_64 201-2.fc18.9 > @updates-testing > > (Thanks for porting the fix back!!) > > Fix does solve the ordering cycle problem, which is a big improvement. Great. > However, being admittedly somewhat naive here, shouldn't the shutdown > messages in /var/log/messages be the same each time? I'm guessing that > there might be timing issues with syslogd... Is there a reliable place to > see all of the messages output during shutdown? What is stored in the > messages file doesn't match what I see on the screen (momentarily) while the > system shuts down. No, messages can be lost. The problem is that because of a kernel limitation, the message queue length cannot be changed, and is on 10 packets long. This means that at times when many messages are logged (like shutdown), journald cannot keep up with the flow. We can either lose messages, or make the message passing blocking. In later versions, it is blocking, but the downside is that it slows things down, and can even dead-lock if important stuff is waiting for logging, so special care must be taken. And the same thing happens on the interface between journald and syslog. If syslog is slow for whatever reason, it'll lose messages. You might have better luck with journalctl output.
systemd-201-2.fc18.9 has been pushed to the Fedora 18 stable repository. If problems still persist, please make note of it in this bug report.