Bug 1027114
| Summary: | nfs mount fails during boot because network is not ready | ||
|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | Kim Bisgaard <kim-rh> |
| Component: | systemd | Assignee: | systemd-maint |
| Status: | CLOSED DUPLICATE | QA Contact: | Fedora Extras Quality Assurance <extras-qa> |
| Severity: | unspecified | Docs Contact: | |
| Priority: | unspecified | ||
| Version: | 20 | CC: | christian, erik-fedora, glaubitz, johannbg, jonabbey, lnykryn, marcus.moeller, msekleta, plautrba, systemd-maint, tilmann, vpavlin, wagnered, zbyszek |
| Target Milestone: | --- | ||
| Target Release: | --- | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | Bug Fix | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2014-06-20 00:06:40 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: | |||
/etc/fstab: jukebox:/home /home nfs defaults 0 0 # mount -va /boot : already mounted /opt : already mounted / : ignored /data : already mounted swap : ignored /dev/shm : already mounted /dev/pts : already mounted /sys : already mounted /proc : already mounted mount.nfs: timeout set for Thu Nov 7 09:26:16 2013 mount.nfs: trying text-based options 'vers=4,addr=192.168.0.5,clientaddr=192.168.0.3' /home : successfully mounted Can you paste the output from 'systemctl list-dependencies --after remote-fs.target'? # systemctl list-dependencies --after remote-fs.target remote-fs.target ├─home.mount ├─misc-data.mount └─remote-fs-pre.target └─nfs-lock.service I see the same problem on a Fedora 19 system I fedup'ed to Fedora 20 beta. [root@xportal3 /]# systemctl list-dependencies --after remote-fs.target remote-fs.target ├─home.mount └─remote-fs-pre.target I saw the following in messages: Dec 3 20:33:35 xportal3 systemd: Started Network Manager. Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> WiFi enabled by radio killswitch; enabled by state file Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> WWAN enabled by radio killswitch; enabled by state file Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> WiMAX enabled by radio killswitch; enabled by state file Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> Networking is enabled by state file Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (lo): link connected Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (lo): carrier is ON Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (lo): new Generic device (driver: 'unknown' ifindex: 1) Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (lo): exported as /org/freedesktop/NetworkManager/Devices/0 Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (lo): No existing connection detected. Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (em1): carrier is OFF Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (em1): new Ethernet device (driver: 'bnx2' ifindex: 2) Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (em1): exported as /org/freedesktop/NetworkManager/Devices/1 Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (em1): No existing connection detected. Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (em1): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (em1): bringing up device. Dec 3 20:33:35 xportal3 systemd: Starting Network Manager Wait Online... Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (em2): carrier is OFF Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (em2): new Ethernet device (driver: 'bnx2' ifindex: 3) Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (em2): exported as /org/freedesktop/NetworkManager/Devices/2 Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (em2): No existing connection detected. Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (em2): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (em2): bringing up device. Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> startup complete Dec 3 20:33:35 xportal3 dbus-daemon: dbus[868]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' Dec 3 20:33:35 xportal3 dbus[868]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' Dec 3 20:33:35 xportal3 dbus[868]: [system] Activation via systemd failed for unit 'dbus-org.bluez.service': Unit dbus-org.bluez.service failed to load: No such file or directory. Dec 3 20:33:35 xportal3 NetworkManager[861]: <warn> Couldn't acquire object manager proxy: Error calling StartServiceByName for org.bluez: GDBus.Error:org.freedesktop.systemd1.LoadFailed: Unit dbus-org.\ bluez.service failed to load: No such file or directory. Dec 3 20:33:35 xportal3 dbus-daemon: dbus[868]: [system] Activation via systemd failed for unit 'dbus-org.bluez.service': Unit dbus-org.bluez.service failed to load: No such file or directory. Dec 3 20:33:35 xportal3 dbus-daemon: dbus[868]: [system] Activating via systemd: service name='org.freedesktop.ModemManager1' unit='dbus-org.freedesktop.ModemManager1.service' Dec 3 20:33:35 xportal3 dbus[868]: [system] Activating via systemd: service name='org.freedesktop.ModemManager1' unit='dbus-org.freedesktop.ModemManager1.service' Dec 3 20:33:35 xportal3 dbus[868]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.ModemManager1.service': Unit dbus-org.freedesktop.ModemManager1.service failed to load: No such f\ ile or directory. Dec 3 20:33:35 xportal3 dbus-daemon: dbus[868]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.ModemManager1.service': Unit dbus-org.freedesktop.ModemManager1.service failed to lo\ ad: No such file or directory. Dec 3 20:33:35 xportal3 systemd: Started Network Manager Wait Online. Dec 3 20:33:35 xportal3 systemd: Starting Network is Online. Dec 3 20:33:35 xportal3 systemd: Reached target Network is Online. Dec 3 20:33:35 xportal3 systemd: Starting Network. Dec 3 20:33:35 xportal3 systemd: Reached target Network. Dec 3 20:33:35 xportal3 systemd: Starting OpenSSH server daemon... Dec 3 20:33:35 xportal3 systemd: Starting Sendmail Mail Transport Agent... Dec 3 20:33:35 xportal3 systemd: Starting RPC bind service... Dec 3 20:33:35 xportal3 systemd: Starting Samba Winbind Daemon... Dec 3 20:33:35 xportal3 systemd: Mounting /home... Dec 3 20:33:35 xportal3 systemd: Started RPC bind service. Dec 3 20:33:35 xportal3 kernel: [ 6.182398] ixgbe 0000:0d:00.0: Multiqueue Enabled: Rx Queue count = 16, Tx Queue count = 16 Dec 3 20:33:35 xportal3 systemd: Started OpenSSH server daemon. Dec 3 20:33:35 xportal3 systemd: Starting Sendmail Mail Transport Agent... Dec 3 20:33:35 xportal3 systemd: Starting RPC bind service... Dec 3 20:33:35 xportal3 systemd: Starting Samba Winbind Daemon... Dec 3 20:33:35 xportal3 systemd: Mounting /home... Dec 3 20:33:35 xportal3 systemd: Started RPC bind service. Dec 3 20:33:35 xportal3 kernel: [ 6.182398] ixgbe 0000:0d:00.0: Multiqueue Enabled: Rx Queue count = 16, Tx Queue count = 16 Dec 3 20:33:35 xportal3 systemd: Started OpenSSH server daemon. Dec 3 20:33:35 xportal3 kernel: [ 6.182597] ixgbe 0000:0d:00.0: (PCI Express:2.5GT/s:Width x8) 68:05:ca:04:6a:b9 Dec 3 20:33:35 xportal3 kernel: [ 6.182677] ixgbe 0000:0d:00.0: MAC: 1, PHY: 2, PBA No: E73052-006 Dec 3 20:33:35 xportal3 kernel: [ 6.184212] ixgbe 0000:0d:00.0: Intel(R) 10 Gigabit Network Connection Dec 3 20:33:35 xportal3 systemd-udevd[676]: renamed network interface eth0 to p3p1 Dec 3 20:33:35 xportal3 winbindd[936]: [2013/12/03 20:33:35.949027, 0] ../source3/lib/interface.c:543(load_interfaces) Dec 3 20:33:35 xportal3 winbindd[936]: WARNING: no network interfaces found Dec 3 20:33:35 xportal3 winbindd[936]: [2013/12/03 20:33:35.949818, 0] ../source3/lib/interface.c:543(load_interfaces) Dec 3 20:33:35 xportal3 winbindd[936]: WARNING: no network interfaces found Dec 3 20:33:35 xportal3 systemd: Started Sendmail Mail Transport Agent. Dec 3 20:33:35 xportal3 winbindd[958]: [2013/12/03 20:33:35.952851, 0] ../source3/winbindd/winbindd_cache.c:3183(initialize_winbindd_cache) Dec 3 20:33:35 xportal3 winbindd[958]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (p3p1): carrier is OFF Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (p3p1): new Ethernet device (driver: 'ixgbe' ifindex: 4) Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (p3p1): exported as /org/freedesktop/NetworkManager/Devices/3 Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (p3p1): No existing connection detected. Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (p3p1): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Dec 3 20:33:35 xportal3 NetworkManager[861]: <info> (p3p1): bringing up device. Dec 3 20:33:35 xportal3 rpc.statd[959]: Version 1.2.7 starting Dec 3 20:33:35 xportal3 rpc.statd[959]: Flags: TI-RPC Dec 3 20:33:35 xportal3 systemd: Started Samba Winbind Daemon. Dec 3 20:33:35 xportal3 systemd: Starting Sendmail Mail Transport Client... Dec 3 20:33:36 xportal3 systemd: Failed to read PID from file /run/sm-client.pid: Invalid argument Dec 3 20:33:36 xportal3 systemd: Started Sendmail Mail Transport Client. Dec 3 20:33:36 xportal3 kernel: [ 6.274714] IPv6: ADDRCONF(NETDEV_UP): p3p1: link is not ready Dec 3 20:33:36 xportal3 mount: mount.nfs: Network is unreachable Dec 3 20:33:36 xportal3 systemd: home.mount mount process exited, code=exited status=32 Dec 3 20:33:36 xportal3 systemd: Failed to mount /home. Dec 3 20:33:36 xportal3 systemd: Dependency failed for Remote File Systems. I see that the /usr/lib/systemd/system/remote-fs-pre.target.wants directory is empty. Oddly, doing # cd /usr/lib/system/remote-fs-pre.target.wants # ln -s ../network-online.target . # systemctl daemon-reload changes the sequence I see to Dec 3 20:54:04 xportal3 systemd: Started Network Manager Wait Online. Dec 3 20:54:04 xportal3 systemd: Starting Network is Online. Dec 3 20:54:04 xportal3 systemd: Reached target Network is Online. Dec 3 20:54:04 xportal3 systemd: Starting Network. Dec 3 20:54:04 xportal3 systemd: Reached target Network. Dec 3 20:54:04 xportal3 systemd: Starting OpenSSH server daemon... Dec 3 20:54:04 xportal3 systemd: Starting Sendmail Mail Transport Agent... Dec 3 20:54:04 xportal3 systemd: Starting RPC bind service... Dec 3 20:54:04 xportal3 systemd: Starting Samba Winbind Daemon... Dec 3 20:54:04 xportal3 systemd: Mounting /home... Dec 3 20:54:04 xportal3 systemd: home.mount: Directory /home to mount over is not empty, mounting anyway. Dec 3 20:54:04 xportal3 systemd: Started OpenSSH server daemon. Dec 3 20:54:04 xportal3 systemd: Started RPC bind service. Dec 3 20:54:04 xportal3 mount: mount.nfs: Failed to resolve server fileportal.arlut.utexas.edu: Name or service not known Dec 3 20:54:04 xportal3 systemd: home.mount mount process exited, code=exited status=32 Dec 3 20:54:04 xportal3 systemd: Failed to mount /home. Dec 3 20:54:04 xportal3 systemd: Dependency failed for Remote File Systems. Dec 3 20:54:04 xportal3 rsyslogd: log message from journal doesn't have MESSAGE Dec 3 20:54:04 xportal3 systemd: Unit home.mount entered failed state. Dec 3 20:54:04 xportal3 systemd: Starting Trigger Flushing of Journal to Persistent Storage... Dec 3 20:54:04 xportal3 systemd-udevd[673]: renamed network interface eth0 to p3p1 Dec 3 20:54:05 xportal3 kernel: [ 6.427394] dm-1: WRITE SAME failed. Manually zeroing. Dec 3 20:54:05 xportal3 winbindd[943]: [2013/12/03 20:54:04.994291, 0] ../source3/lib/interface.c:543(load_interfaces) Dec 3 20:54:05 xportal3 winbindd[943]: WARNING: no network interfaces found Dec 3 20:54:05 xportal3 winbindd[943]: [2013/12/03 20:54:04.994968, 0] ../source3/lib/interface.c:543(load_interfaces) Dec 3 20:54:05 xportal3 winbindd[943]: WARNING: no network interfaces found Dec 3 20:54:05 xportal3 NetworkManager[865]: <info> (p3p1): carrier is OFF Dec 3 20:54:05 xportal3 NetworkManager[865]: <info> (p3p1): new Ethernet device (driver: 'ixgbe' ifindex: 4) Dec 3 20:54:05 xportal3 NetworkManager[865]: <info> (p3p1): exported as /org/freedesktop/NetworkManager/Devices/3 Dec 3 20:54:05 xportal3 NetworkManager[865]: <info> (p3p1): No existing connection detected. Dec 3 20:54:05 xportal3 NetworkManager[865]: <info> (p3p1): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Dec 3 20:54:05 xportal3 NetworkManager[865]: <info> (p3p1): bringing up device. Dec 3 20:54:05 xportal3 winbindd[966]: [2013/12/03 20:54:04.997679, 0] ../source3/winbindd/winbindd_cache.c:3183(initialize_winbindd_cache) Dec 3 20:54:05 xportal3 winbindd[966]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Note that in each case, systemd-udevd seems to be renaming eth0 to p3p1 after the mount for /home has already failed. I'm using NFSv3, SEC=SYS, so there's no GSSAPI issues involved. I've the same problem. I've also upgraded FC19 to FC20, and also tried adding the network-online.target to the remote-fs-pre.target.wants.
$ systemctl list-dependencies --after remote-fs.target
remote-fs.target
├─mnt-backup-mesosphere.lan.mount
├─mnt-nas.mount
└─remote-fs-pre.target
├─iscsi.service
├─iscsid.service
├─iscsiuio.service
├─nfs-lock.service
└─network-online.target
└─NetworkManager-wait-online.service
Still I see network being brought up later than the mounts are being executed. Any way I can help triaging this bug?
(In reply to Kim Bisgaard from comment #0) > Description of problem: > home.mount fails - perhaps it does not wait to get network up? > > No problem switching to a virt-term and doing "mount -va" after graphical > boot. As a quick workaround, you can convert the affected NFS mounts into automounts. As a result, the NFS mounts are performed automatically when accessing the mount point for the first time. To do the conversion, add the following comment to these NFS entries: comment=systemd.automount Thus, in my case: home:/srv/home /home nfs vers=3,nosuid,nodev,intr,tcp,comment=systemd.automount 0 0 I have also run some tests on Debian which is affected by the problem as well. I initially blamed rpcbind for the problem, see [1]. Adrian > [1] http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=679716 (In reply to John Paul Adrian Glaubitz from comment #8) > (In reply to Kim Bisgaard from comment #0) > > Description of problem: > > home.mount fails - perhaps it does not wait to get network up? > > > > No problem switching to a virt-term and doing "mount -va" after graphical > > boot. > > As a quick workaround, you can convert the affected NFS mounts into > automounts. As a result, the NFS mounts are performed automatically when > accessing the mount point for the first time. > > To do the conversion, add the following comment to these NFS entries: > > comment=systemd.automount > > Thus, in my case: > > home:/srv/home /home nfs > vers=3,nosuid,nodev,intr,tcp,comment=systemd.automount 0 0 > > I have also run some tests on Debian which is affected by the problem as > well. I initially blamed rpcbind for the problem, see [1]. > > Adrian > > > [1] http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=679716 My problem just started last week with an update, I believe, I have had Fedora 20 for awhile now, but don't access the NFS shares every day. My problem seems to be on a wireless network. Ethernet NIC is fast enough to connect and allow the NFS shares to be mounted. So attempting to slow down the boot process and wait for the wifi link I created "media-nas4free.mount" including _netdev in the option list. From the messages log, the media.nas4free.mount unit is started long before NetworkManager is actually linked into the network. This seems to indicate that nm-online issued by NetworkManager-wait-online.service is not actually waiting for the wifi connection to be made before successfully exiting. The nm-online man indicates the purpose is to wait for NetworkManager to actually make a connection, not just be up and functional. increasing the timeout of nm-online to 60 seconds in NetworkManager-wit-online did not help. Ernie D (In reply to Ernie D from comment #9) > (In reply to John Paul Adrian Glaubitz from comment #8) > > (In reply to Kim Bisgaard from comment #0) > > > Description of problem: > > > home.mount fails - perhaps it does not wait to get network up? > > > > > > No problem switching to a virt-term and doing "mount -va" after graphical > > > boot. > > > > As a quick workaround, you can convert the affected NFS mounts into > > automounts. As a result, the NFS mounts are performed automatically when > > accessing the mount point for the first time. > > > > To do the conversion, add the following comment to these NFS entries: > > > > comment=systemd.automount > > > > Thus, in my case: > > > > home:/srv/home /home nfs > > vers=3,nosuid,nodev,intr,tcp,comment=systemd.automount 0 0 > > > > I have also run some tests on Debian which is affected by the problem as > > well. I initially blamed rpcbind for the problem, see [1]. > > > > Adrian > > > > > [1] http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=679716 > > My problem just started last week with an update, I believe, I have had > Fedora 20 for awhile now, but don't access the NFS shares every day. > > My problem seems to be on a wireless network. Ethernet NIC is fast enough > to connect and allow the NFS shares to be mounted. > > So attempting to slow down the boot process and wait for the wifi link I > created "media-nas4free.mount" including _netdev in the option list. > > From the messages log, the media.nas4free.mount unit is started long before > NetworkManager is actually linked into the network. > > This seems to indicate that nm-online issued by > NetworkManager-wait-online.service is not actually waiting for the wifi > connection to be made before successfully exiting. The nm-online man > indicates the purpose is to wait for NetworkManager to actually make a > connection, not just be up and functional. > > increasing the timeout of nm-online to 60 seconds in > NetworkManager-wit-online did not help. > > Ernie D Strange, but the last set of updates seems to have corrected the problem and now The NFS shares are mounted on boot via the wireless NIC. Ernie D *** This bug has been marked as a duplicate of bug 1023737 *** |
Description of problem: home.mount fails - perhaps it does not wait to get network up? No problem switching to a virt-term and doing "mount -va" after graphical boot. Version-Release number of selected component (if applicable): nfs-utils-1.2.8-6.0.fc20.x86_64 systemd-208-4.fc20.x86_64 How reproducible: Every time Steps to Reproduce: 1. Boot Additional info: Excerpt fro /var/log/messages: Nov 6 08:34:28 kim systemd: Starting /etc/rc.d/rc.local Compatibility... Nov 6 08:34:28 kim systemd: Started RPC bind service. Nov 6 08:34:28 kim systemd: Started OpenSSH server daemon. Nov 6 08:34:29 kim kernel: [ 16.693240] FS-Cache: Loaded Nov 6 08:34:29 kim systemd: Starting Hostname Service... Nov 6 08:34:29 kim systemd: Started /etc/rc.d/rc.local Compatibility. Nov 6 08:34:29 kim dbus-daemon: dbus[370]: [system] Successfully activated service 'org.freedesktop.hostname1' Nov 6 08:34:29 kim dbus[370]: [system] Successfully activated service 'org.freedesktop.hostname1' Nov 6 08:34:29 kim systemd: Started Hostname Service. Nov 6 08:34:29 kim kernel: [ 17.180790] NFSD: starting 90-second grace period (net ffffffff81cbe3c0) Nov 6 08:34:29 kim kernel: [ 17.205883] FS-Cache: Netfs 'nfs' registered for caching Nov 6 08:34:29 kim systemd: Started NFS Server. Nov 6 08:34:29 kim systemd: Starting NFS Mount Daemon... Nov 6 08:34:29 kim systemd: Starting NFS Remote Quota Server... Nov 6 08:34:29 kim systemd: Starting NFSv4 ID-name mapping daemon... Nov 6 08:34:29 kim kernel: [ 17.231956] Key type dns_resolver registered Nov 6 08:34:29 kim kernel: [ 17.241509] NFS: Registering the id_resolver key type Nov 6 08:34:29 kim kernel: [ 17.241519] Key type id_resolver registered Nov 6 08:34:29 kim kernel: [ 17.241520] Key type id_legacy registered Nov 6 08:34:29 kim sshd: Could not load host key: /etc/ssh/ssh_host_ecdsa_key Nov 6 08:34:29 kim systemd: Started NFSv4 ID-name mapping daemon. Nov 6 08:34:30 kim systemd: Started NFS Remote Quota Server. Nov 6 08:34:30 kim rpc.mountd[720]: Version 1.2.7 starting Nov 6 08:34:30 kim systemd: Started NFS Mount Daemon. Nov 6 08:34:30 kim systemd: Started Automounts filesystems on demand. Nov 6 08:34:30 kim mount: mount.nfs: mount system call failed Nov 6 08:34:30 kim systemd: home.mount mount process exited, code=exited status=32 Nov 6 08:34:30 kim systemd: Failed to mount /home. Nov 6 08:34:30 kim systemd: Dependency failed for Remote File Systems. Nov 6 08:34:30 kim rsyslogd: log message from journal doesn't have MESSAGE Nov 6 08:34:30 kim systemd: Unit home.mount entered failed state. Nov 6 08:34:30 kim systemd: Starting Trigger Flushing of Journal to Persistent Storage... Nov 6 08:34:30 kim kernel: [ 18.468570] r8169 0000:03:00.0 eth3: link up # systemctl status home.mount home.mount - /home Loaded: loaded (/etc/fstab) Active: active (mounted) (Result: exit-code) since Wed 2013-11-06 08:38:01 CET; 13min ago Where: /home What: jukebox:/home Process: 598 ExecMount=/bin/mount jukebox:/home /home -t nfs (code=exited, status=32) Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.