On 09/24/2012 12:56 PM, Lennart Poettering wrote: > On Sun, 23.09.12 17:21, Bardur Arantsson (s...@scientician.net) wrote: > >> Hi all, >> [--snip--] > > This indicates a bug i systemd actually. For some reason systemd appears > to believe that your NFS share is a device to wait for. > > I tried to fix this in git with two commits. Please test! > > Lennart >
It seems to work perfectly now (v194) when I do the mounting post-boot in a shell, using # systemctl start data.mount However, it still hangs during boot, waits for the defined timeout period and then... proceeds to work perfectly. I'm not sure, but could it have something to do with my use of two automounts where one is nested inside the other? I have /data and /data/music mounted inside that. Here's what I hope is the relevant portion of the boot log from journalctl: Oct 07 11:20:05 gwendolyn systemd[1]: Reached target Remote File Systems (Pre). Oct 07 11:20:05 gwendolyn systemd[1]: Mounting /data... Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> WiFi enabled by radio killswitch; enabled by state file Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> WWAN enabled by radio killswitch; enabled by state file Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> WiMAX enabled by radio killswitch; enabled by state file Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> Networking is enabled by state file Oct 07 11:20:05 gwendolyn NetworkManager[297]: <warn> failed to allocate link cache: (-10) Operation not supported Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth0): carrier is OFF Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth0): new Ethernet device (driver: 'r8169' ifindex: 2) Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/0 Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth0): now managed Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth0): bringing up device. Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth0): preparing device. Oct 07 11:20:05 gwendolyn ntpd[314]: ntpd 4.2.6p5@1.2349-o Tue Aug 21 15:06:24 UTC 2012 (1) Oct 07 11:20:05 gwendolyn ntpd[317]: proto: precision = 0.489 usec Oct 07 11:20:05 gwendolyn ntpd[317]: ntp_io: estimated max descriptors: 1024, initial socket boundary: 16 Oct 07 11:20:05 gwendolyn ntpd[317]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123 Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth0): deactivating device (reason 'managed') [2] Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> Added default wired connection 'Wired connection 1' for /sys/devices/pci0000:00/0000:00:1c.4/0000:04:00.0/net/eth Oct 07 11:20:05 gwendolyn kernel: r8169 0000:04:00.0: >eth0: link down Oct 07 11:20:05 gwendolyn systemd[1]: Started Network Time Service. Oct 07 11:20:05 gwendolyn systemd[1]: Started RPC Bind. Oct 07 11:20:05 gwendolyn systemd[1]: Starting RPC Port Mapper. Oct 07 11:20:05 gwendolyn systemd[1]: Reached target RPC Port Mapper. Oct 07 11:20:05 gwendolyn kernel: r8169 0000:04:00.0: >eth0: link down Oct 07 11:20:05 gwendolyn kernel: IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready Oct 07 11:20:05 gwendolyn NetworkManager[297]: <warn> failed to allocate link cache: (-10) Operation not supported Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth1): carrier is OFF Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth1): new Ethernet device (driver: 'r8169' ifindex: 3) Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth1): exported as /org/freedesktop/NetworkManager/Devices/1 Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth1): now managed Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth1): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth1): bringing up device. Oct 07 11:20:05 gwendolyn ntpd[317]: Listen and drop on 1 v6wildcard :: UDP 123 Oct 07 11:20:05 gwendolyn ntpd[317]: Listen normally on 2 lo 127.0.0.1 UDP 123 Oct 07 11:20:05 gwendolyn ntpd[317]: Listen normally on 3 lo ::1 UDP 123 Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth1): preparing device. Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> (eth1): deactivating device (reason 'managed') [2] Oct 07 11:20:05 gwendolyn ntpd[317]: peers refreshed Oct 07 11:20:05 gwendolyn ntpd[317]: Listening on routing socket on fd #20 for interface updates Oct 07 11:20:05 gwendolyn NetworkManager[297]: <info> Added default wired connection 'Wired connection 2' for /sys/devices/pci0000:00/0000:00:1c.5/0000:05:00.0/net/eth Oct 07 11:20:05 gwendolyn NetworkManager[297]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring... Oct 07 11:20:05 gwendolyn NetworkManager[297]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring... Oct 07 11:20:05 gwendolyn kernel: r8169 0000:05:00.0: >eth1: link down Oct 07 11:20:05 gwendolyn kernel: IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready Oct 07 11:20:05 gwendolyn colord[306]: (colord:306): Cd-WARNING **: CdProfileStore: failed to add profile '/usr/share/color/icc/krita/README': failed to parse /usr/sha Oct 07 11:20:05 gwendolyn dbus-daemon[302]: dbus[302]: [system] Activating via systemd: service name='org.freedesktop.colord-sane' unit='colord-sane.service' Oct 07 11:20:05 gwendolyn dbus[302]: [system] Activating via systemd: service name='org.freedesktop.colord-sane' unit='colord-sane.service' Oct 07 11:20:05 gwendolyn systemd[1]: Starting Daemon for monitoring attached scanners and registering them with colord... Oct 07 11:20:05 gwendolyn dbus-daemon[302]: dbus[302]: [system] Successfully activated service 'org.freedesktop.colord-sane' Oct 07 11:20:05 gwendolyn dbus[302]: [system] Successfully activated service 'org.freedesktop.colord-sane' Oct 07 11:20:05 gwendolyn systemd[1]: Started Daemon for monitoring attached scanners and registering them with colord. Oct 07 11:20:06 gwendolyn dbus-daemon[302]: dbus[302]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' Oct 07 11:20:06 gwendolyn dbus-daemon[302]: dbus[302]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop. Oct 07 11:20:06 gwendolyn dbus[302]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' Oct 07 11:20:06 gwendolyn dbus[302]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop.Avahi.service fail Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> (eth0): carrier now ON (device state 20) Oct 07 11:20:07 gwendolyn kernel: r8169 0000:04:00.0: >eth0: link up Oct 07 11:20:07 gwendolyn kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> (eth0): device state change: unavailable -> disconnected (reason 'carrier-changed') [20 30 40] Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Auto-activating connection 'Wired connection 1'. Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) starting connection 'Wired connection 1' Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> (eth0): device state change: disconnected -> prepare (reason 'none') [30 40 0] Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled... Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started... Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled... Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete. Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting... Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> (eth0): device state change: prepare -> config (reason 'none') [40 50 0] Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful. Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled. Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete. Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started... Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> (eth0): device state change: config -> ip-config (reason 'none') [50 70 0] Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) Beginning DHCPv4 transaction (timeout in 45 seconds) Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> dhcpcd started with pid 326 Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) Beginning IP6 addrconf. Oct 07 11:20:07 gwendolyn dhcpcd[326]: version 5.6.2 starting Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete. Oct 07 11:20:07 gwendolyn dhcpcd[326]: eth0: sending IPv6 Router Solicitation Oct 07 11:20:07 gwendolyn dhcpcd[326]: eth0: sendmsg: Cannot assign requested address Oct 07 11:20:07 gwendolyn NetworkManager[297]: <info> (eth0): DHCPv4 state changed nbi -> preinit Oct 07 11:20:07 gwendolyn dhcpcd[326]: eth0: rebinding lease of 192.168.0.10 Oct 07 11:20:07 gwendolyn dhcpcd[326]: eth0: acknowledged 192.168.0.10 from 192.168.0.1 Oct 07 11:20:07 gwendolyn dhcpcd[326]: eth0: checking for 192.168.0.10 Oct 07 11:20:07 gwendolyn dbus-daemon[302]: dbus[302]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' Oct 07 11:20:07 gwendolyn dbus[302]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' Oct 07 11:20:07 gwendolyn dbus[302]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop.Avahi.service fail Oct 07 11:20:07 gwendolyn dbus-daemon[302]: dbus[302]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop. Oct 07 11:20:09 gwendolyn dbus-daemon[302]: dbus[302]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' Oct 07 11:20:09 gwendolyn dbus[302]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' Oct 07 11:20:09 gwendolyn dbus[302]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop.Avahi.service fail Oct 07 11:20:09 gwendolyn dbus-daemon[302]: dbus[302]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop. Oct 07 11:20:10 gwendolyn dbus-daemon[302]: dbus[302]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' Oct 07 11:20:10 gwendolyn dbus[302]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' Oct 07 11:20:10 gwendolyn dbus[302]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop.Avahi.service fail Oct 07 11:20:10 gwendolyn dbus-daemon[302]: dbus[302]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop. Oct 07 11:20:11 gwendolyn dhcpcd[326]: eth0: sending IPv6 Router Solicitation Oct 07 11:20:12 gwendolyn dhcpcd[326]: eth0: leased 192.168.0.10 for 43200 seconds Oct 07 11:20:12 gwendolyn NetworkManager[297]: <info> (eth0): DHCPv4 state changed preinit -> bound Oct 07 11:20:12 gwendolyn NetworkManager[297]: <info> address 192.168.0.10 Oct 07 11:20:12 gwendolyn NetworkManager[297]: <info> prefix 24 (255.255.255.0) Oct 07 11:20:12 gwendolyn NetworkManager[297]: <info> gateway 192.168.0.1 Oct 07 11:20:12 gwendolyn NetworkManager[297]: <info> hostname 'gwendolyn' Oct 07 11:20:12 gwendolyn NetworkManager[297]: <info> nameserver '192.168.0.1' Oct 07 11:20:12 gwendolyn NetworkManager[297]: <info> domain name 'scientician.net' Oct 07 11:20:12 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 5 of 5 (IPv4 Configure Commit) scheduled... Oct 07 11:20:12 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 5 of 5 (IPv4 Commit) started... Oct 07 11:20:13 gwendolyn NetworkManager[297]: <info> (eth0): device state change: ip-config -> activated (reason 'none') [70 100 0] Oct 07 11:20:13 gwendolyn NetworkManager[297]: <info> Policy set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS. Oct 07 11:20:13 gwendolyn NetworkManager[297]: <info> Activation (eth0) successful, device activated. Oct 07 11:20:13 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 5 of 5 (IPv4 Commit) complete. Oct 07 11:20:13 gwendolyn dbus[302]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper) Oct 07 11:20:13 gwendolyn dbus-daemon[302]: dbus[302]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper) Oct 07 11:20:14 gwendolyn dbus-daemon[302]: dbus[302]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Oct 07 11:20:13 gwendolyn dbus[302]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Oct 07 11:20:15 gwendolyn dhcpcd[326]: eth0: sending IPv6 Router Solicitation Oct 07 11:20:19 gwendolyn dhcpcd[326]: eth0: sending IPv6 Router Solicitation Oct 07 11:20:19 gwendolyn dhcpcd[326]: eth0: no IPv6 Routers available Oct 07 11:20:27 gwendolyn NetworkManager[297]: <info> (eth0): IP6 addrconf timed out or failed. Oct 07 11:20:27 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled... Oct 07 11:20:27 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 4 of 5 (IPv6 Configure Timeout) started... Oct 07 11:20:27 gwendolyn NetworkManager[297]: <info> Activation (eth0) Stage 4 of 5 (IPv6 Configure Timeout) complete. Oct 07 11:21:05 gwendolyn systemd[1]: Mounted /data. Oct 07 11:21:05 gwendolyn systemd[1]: Starting data-music.automount. Oct 07 11:21:05 gwendolyn systemd[1]: Set up automount data-music.automount. Oct 07 11:21:05 gwendolyn systemd[1]: Starting Remote File Systems. Oct 07 11:21:05 gwendolyn systemd[1]: Reached target Remote File Systems. Oct 07 11:21:05 gwendolyn systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage... Oct 07 11:21:05 gwendolyn systemd[1]: Started Trigger Flushing of Journal to Persistent Storage. Oct 07 11:21:05 gwendolyn systemd[1]: Starting Permit User Sessions... I'll just note that the two lines are quite odd in that the apparent time delay doesn't correspond to any particularly logical multiplier of the configured timeout (15s at the moment). Oct 07 11:20:05 gwendolyn systemd[1]: Mounting /data... Oct 07 11:21:05 gwendolyn systemd[1]: Mounted /data. It also seems that there's some attempt to configure IPv6 which is quite slow (and finally times out), but there's still a looong delay after that. Regards, _______________________________________________ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel