[Bug 744293] New: systemd: vdr starts before nfs-client-mount ?!
https://bugzilla.novell.com/show_bug.cgi?id=744293 https://bugzilla.novell.com/show_bug.cgi?id=744293#c0 Summary: systemd: vdr starts before nfs-client-mount ?! Classification: openSUSE Product: openSUSE 12.1 Version: Final Platform: x86-64 OS/Version: Other Status: NEW Severity: Normal Priority: P5 - None Component: Basesystem AssignedTo: bnc-team-screening@forge.provo.novell.com ReportedBy: koenig@linux.de QAContact: qa@suse.de Found By: --- Blocker: --- I've setup a new PC with 12.1 running VDR, the video storage is on a NFS4 server. after reboot vdr did not start, because NFS (and local network on eth0) is not yet ready. from /var/log/messages (no lines missing between): Jan 31 08:35:19 t2 lirc[745]: Starting lircd (/dev/lirc0)..done Jan 31 08:35:19 t2 network[887]: lo Jan 31 08:35:19 t2 ifup: lo Jan 31 08:35:19 t2 ifup: lo Jan 31 08:35:19 t2 ifup: IP address: 127.0.0.1/8 Jan 31 08:35:19 t2 network[887]: lo IP address: 127.0.0.1/8 Jan 31 08:35:19 t2 ifup: Jan 31 08:35:20 t2 vdr: [1136] cTimeMs: using monotonic clock (resolution is 1 ns) Jan 31 08:35:20 t2 vdr: [1174] cTimeMs: using monotonic clock (resolution is 1 ns) Jan 31 08:35:20 t2 vdr: [1174] ERROR: /var/spool/video: No such file or directory Jan 31 08:35:20 t2 network[887]: ..done eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Jan 31 08:35:20 t2 ifup: eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Jan 31 08:35:20 t2 vdr[1083]: Starting Video Disk Recorder ..missing Jan 31 08:35:20 t2 systemd[1]: vdr.service: control process exited, code=exited status=3 Jan 31 08:35:20 t2 systemd[1]: Unit vdr.service entered failed state. Jan 31 08:35:21 t2 kernel: [ 17.683974] e1000e 0000:01:00.0: irq 45 for MSI/MSI-X Jan 31 08:35:21 t2 kernel: [ 17.735108] e1000e 0000:01:00.0: irq 45 for MSI/MSI-X Jan 31 08:35:21 t2 kernel: [ 17.736697] ADDRCONF(NETDEV_UP): eth0: link is not ready Jan 31 08:35:21 t2 ifup-dhcp: eth0 Starting DHCP4+DHCP6 client Jan 31 08:35:21 t2 dhcpcd[1310]: eth0: dhcpcd 3.2.3 starting Jan 31 08:35:21 t2 dhcpcd[1310]: eth0: hardware address = 00:13:20:e0:6c:1c Jan 31 08:35:21 t2 kernel: [ 17.792870] NET: Registered protocol family 17 Jan 31 08:35:21 t2 dhcpcd[1310]: eth0: broadcasting for a lease Jan 31 08:35:21 t2 ifup-dhcp: . Jan 31 08:35:22 t2 dhclient[1328]: send_packet6: Network is unreachable Jan 31 08:35:22 t2 dhclient[1328]: dhc6: send_packet6() sent -1 of 58 bytes Jan 31 08:35:23 t2 dhclient[1328]: send_packet6: Network is unreachable Jan 31 08:35:23 t2 dhclient[1328]: dhc6: send_packet6() sent -1 of 58 bytes Jan 31 08:35:24 t2 ifup-dhcp: . Jan 31 08:35:24 t2 kernel: [ 21.170991] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx Jan 31 08:35:24 t2 kernel: [ 21.171709] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready Jan 31 08:35:25 t2 dhclient[1328]: send_packet6: Cannot assign requested address Jan 31 08:35:25 t2 dhclient[1328]: dhc6: send_packet6() sent -1 of 58 bytes Jan 31 08:35:26 t2 avahi-daemon[819]: Registering new address record for fe80::213:20ff:fee0:6c1c on eth0.*. Jan 31 08:35:26 t2 ifup-dhcp: . Jan 31 08:35:29 t2 ifup-dhcp: . Jan 31 08:35:31 t2 dhcpcd[1310]: eth0: offered 192.168.178.47 from 192.168.178.1 Jan 31 08:35:31 t2 ifup-dhcp: . Jan 31 08:35:34 t2 ifup-dhcp: . Jan 31 08:35:35 t2 kernel: [ 32.162016] eth0: no IPv6 routers present Jan 31 08:35:36 t2 dhcpcd[1310]: eth0: checking 192.168.178.47 is available on attached networks Jan 31 08:35:36 t2 ifup-dhcp: . Jan 31 08:35:37 t2 dhcpcd[1310]: eth0: leased 192.168.178.47 for 864000 seconds Jan 31 08:35:37 t2 dhcpcd[1310]: eth0: adding IP address 192.168.178.47/24 Jan 31 08:35:37 t2 avahi-daemon[819]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.178.47. Jan 31 08:35:37 t2 dhcpcd[1310]: eth0: adding default route via 192.168.178.1 metric 0 Jan 31 08:35:37 t2 avahi-daemon[819]: New relevant interface eth0.IPv4 for mDNS. Jan 31 08:35:37 t2 avahi-daemon[819]: Registering new address record for 192.168.178.47 on eth0.IPv4. Jan 31 08:35:38 t2 ifdown: eth0 device: Intel Corporation 82573E Gigabit Ethernet Controller (Copper) (rev 03) Jan 31 08:35:38 t2 dhcpcd[1310]: eth0: setting hostname to `t2' Jan 31 08:35:38 t2 rsyslogd: [origin software="rsyslogd" swVersion="5.8.5" x-pid="803" x-info="http://www.rsyslog.com"] rsyslogd was HUPed Jan 31 08:35:38 t2 ifup: eth0 device: Intel Corporation 82573E Gigabit Ethernet Controller (Copper) (rev 03) Jan 31 08:35:39 t2 ifup-dhcp: . Jan 31 08:35:40 t2 network[887]: eth0 Starting DHCP4+DHCP6 client. . . . . . . Jan 31 08:35:40 t2 ifup-dhcp: Jan 31 08:35:40 t2 network[887]: eth0 DHCP4 continues in background Jan 31 08:35:40 t2 ifup-dhcp: eth0 DHCP4 continues in background Jan 31 08:35:40 t2 network[887]: eth0 DHCP6 continues in background Jan 31 08:35:40 t2 ifup-dhcp: eth0 DHCP6 continues in background Jan 31 08:35:40 t2 network[887]: [1Awaiting Jan 31 08:35:41 t2 network[887]: Waiting for mandatory devices: eth0 Jan 31 08:35:50 t2 network[887]: 8 7 5 4 3 1 0 Jan 31 08:35:50 t2 network[887]: eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Jan 31 08:35:50 t2 network[887]: eth0 . . . is just beeing set up Jan 31 08:35:50 t2 network[887]: eth0 IP address: 192.168.178.47/24 Jan 31 08:35:50 t2 network[887]: eth0 is up Jan 31 08:35:50 t2 network[887]: [1Awaiting Jan 31 08:35:50 t2 network[887]: eth0 interface could not be set up until now Jan 31 08:35:50 t2 network[887]: ..failedSetting up service (localfs) network . . . . . . . . ...failed Jan 31 08:35:50 t2 systemd[1]: network.service: control process exited, code=exited status=7 Jan 31 08:35:50 t2 systemd[1]: Unit network.service entered failed state. when I finally logged in, the network was up, NFS was mounted and "rcvdr start" worked fine. why does vdr get started before local net/nfs_client (aka remote-fs.target?!) ? # systemctl show vdr.service | grep After After=lirc.service dvb.service earlysyslog.service remote-fs.target systemd-stdout-syslog-bridge.socket basic.target ^^^^^^^^^^^^^^^^ but: # systemctl | grep fail network.service loaded failed failed LSB: Configure the localfs depending network interfaces NetworkManager.service loaded failed failed Network Manager systemd-...s-load.service loaded failed failed Load Kernel Modules how can I get/provide more information ? -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c1
Frederic Crozat
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c2
--- Comment #2 from Harald Koenig
network failing might be cause by bug in samba-client or sysconfig. Try upgrading samba-client from http://download.opensuse.org/repositories/home:/fcrozat:/systemd/openSUSE_12...
I'm not using samba at all (neither client nor server, no windows at all), so I did not install that samba-client (yet): # chkconfig 2>&1 | egrep 'cifs|smb|nmb' cifs off nmb off smb off
and sysconfig package from http://download.opensuse.org/repositories/home:/mtomaschewski:/branches:/ope...
I've installed the new sysconfig # rpm -q sysconfig sysconfig-0.75.4-2.6.test.1.x86_64 but that does not help:vdr still gets started before eth0: Jan 31 17:45:45 t3 network[876]: lo Jan 31 17:45:45 t3 ifup: lo Jan 31 17:45:45 t3 kernel: [ 16.004046] lirc_serial: auto-detected active low receiver Jan 31 17:45:45 t3 kernel: [ 16.004230] lirc_serial lirc_serial.0: lirc_dev: driver lirc_serial registered at minor = 0 Jan 31 17:45:45 t3 lirc[754]: Starting lircd (/dev/lirc0)..done Jan 31 17:45:45 t3 lircd-0.8.7[1094]: lircd(default) ready, using /var/run/lirc/lircd Jan 31 17:45:45 t3 ifup: lo Jan 31 17:45:45 t3 ifup: IP address: 127.0.0.1/8 Jan 31 17:45:45 t3 network[876]: lo IP address: 127.0.0.1/8 Jan 31 17:45:45 t3 ifup: Jan 31 17:45:45 t3 vdr: [1138] cTimeMs: using monotonic clock (resolution is 1 ns) Jan 31 17:45:45 t3 vdr: [1141] cTimeMs: using monotonic clock (resolution is 1 ns) Jan 31 17:45:45 t3 vdr: [1141] ERROR: /var/spool/video: No such file or directory Jan 31 17:45:45 t3 network[876]: ..done eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Jan 31 17:45:45 t3 ifup: eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Jan 31 17:45:46 t3 vdr[1095]: Starting Video Disk Recorder ..missing Jan 31 17:45:46 t3 systemd[1]: vdr.service: control process exited, code=exited status=3 Jan 31 17:45:46 t3 systemd[1]: Unit vdr.service entered failed state. Jan 31 17:45:46 t3 kernel: [ 17.327967] e1000e 0000:01:00.0: irq 45 for MSI/MSI-X Jan 31 17:45:46 t3 kernel: [ 17.379133] e1000e 0000:01:00.0: irq 45 for MSI/MSI-X Jan 31 17:45:46 t3 kernel: [ 17.380683] ADDRCONF(NETDEV_UP): eth0: link is not ready Jan 31 17:45:50 t3 kernel: [ 20.585997] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx Jan 31 17:45:50 t3 kernel: [ 20.586734] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready Jan 31 17:45:50 t3 ifup-dhcp: eth0 Starting DHCP4+DHCP6 client Jan 31 17:45:50 t3 dhcpcd[1943]: eth0: dhcpcd 3.2.3 starting Jan 31 17:45:50 t3 dhcpcd[1943]: eth0: hardware address = 00:13:20:e0:6c:1c Jan 31 17:45:50 t3 kernel: [ 20.627813] NET: Registered protocol family 17 Jan 31 17:45:50 t3 dhcpcd[1943]: eth0: broadcasting for a lease Jan 31 17:45:50 t3 dhcpcd[1943]: eth0: offered 192.168.178.47 from 192.168.178.1 Jan 31 17:45:50 t3 ifup-dhcp: . Jan 31 17:45:50 t3 dhcpcd[1943]: eth0: checking 192.168.178.47 is available on attached networks Jan 31 17:45:51 t3 avahi-daemon[829]: Registering new address record for fe80::213:20ff:fee0:6c1c on eth0.*. Jan 31 17:45:51 t3 dhcpcd[1943]: eth0: leased 192.168.178.47 for 864000 seconds Jan 31 17:45:51 t3 dhcpcd[1943]: eth0: adding IP address 192.168.178.47/24 Jan 31 17:45:51 t3 avahi-daemon[829]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.178.47. Jan 31 17:45:51 t3 dhcpcd[1943]: eth0: adding default route via 192.168.178.1 metric 0 Jan 31 17:45:51 t3 avahi-daemon[829]: New relevant interface eth0.IPv4 for mDNS. Jan 31 17:45:51 t3 avahi-daemon[829]: Registering new address record for 192.168.178.47 on eth0.IPv4. Jan 31 17:45:52 t3 ifdown: eth0 device: Intel Corporation 82573E Gigabit Ethernet Controller (Copper) (rev 03) Jan 31 17:45:52 t3 dhcpcd[1943]: eth0: setting hostname to `t3' Jan 31 17:45:52 t3 ifup: eth0 device: Intel Corporation 82573E Gigabit Ethernet Controller (Copper) (rev 03) Jan 31 17:45:53 t3 ifup-dhcp: . Jan 31 17:45:55 t3 ifup-dhcp: . Jan 31 17:45:58 t3 ifup-dhcp: . Jan 31 17:46:00 t3 kernel: [ 31.010022] eth0: no IPv6 routers present Jan 31 17:46:00 t3 ifup-dhcp: . Jan 31 17:46:03 t3 ifup-dhcp: . Jan 31 17:46:05 t3 ifup-dhcp: . Jan 31 17:46:08 t3 ifup-dhcp: . Jan 31 17:46:09 t3 network[876]: eth0 Starting DHCP4+DHCP6 client. . . . . . . Jan 31 17:46:09 t3 ifup-dhcp: Jan 31 17:46:09 t3 network[876]: eth0 DHCP4 continues in background Jan 31 17:46:09 t3 ifup-dhcp: eth0 DHCP4 continues in background Jan 31 17:46:09 t3 network[876]: eth0 DHCP6 continues in background Jan 31 17:46:09 t3 ifup-dhcp: eth0 DHCP6 continues in background Jan 31 17:46:09 t3 network[876]: [1Awaiting Jan 31 17:46:10 t3 network[876]: Waiting for mandatory devices: eth0 Jan 31 17:46:16 t3 network[876]: 5 4 2 1 0 Jan 31 17:46:16 t3 network[876]: eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Jan 31 17:46:16 t3 network[876]: eth0 . . . is just beeing set up Jan 31 17:46:16 t3 network[876]: eth0 IP address: 192.168.178.47/24 Jan 31 17:46:16 t3 network[876]: eth0 is up Jan 31 17:46:16 t3 network[876]: [1Awaiting Jan 31 17:46:16 t3 network[876]: eth0 interface could not be set up until now Jan 31 17:46:16 t3 network[876]: ..failedSetting up service (localfs) network . . . . . . . . ...failed Jan 31 17:46:16 t3 systemd[1]: network.service: control process exited, code=exited status=7 Jan 31 17:46:16 t3 systemd[1]: Unit network.service entered failed state. -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c3
--- Comment #3 from Marius Tomaschewski
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c4
Marius Tomaschewski
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c5
Marius Tomaschewski
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c6
--- Comment #6 from Marius Tomaschewski
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c7
--- Comment #7 from Marius Tomaschewski
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c8
Harald Koenig
Do you have an DHCPv6 server in your network or only DHCPv4?
no, only v4
When you don't have DHCPv6 server, change to use BOOTPROTO=dhcp4 in /etc/sysconfig/network/ifcfg-eth0 -- this will speed up the network start / cause to not wait for DHCPv6.
ok, I'll change that. but (a) it should work anyway and (b) that small speedup should be no significant help if you check the timestamps in my syslog output...
It looks like systemd would start vdr after network, but would not wait until it finished...?
maybe it only waits for the "lo" device setup being finished ?! that's at least the sequence which syslog shows. maybe lo-setup is just "too fast" doesn't let vdr pass ?!?
The error message is:
Jan 31 17:45:45 t3 vdr: [1141] ERROR: /var/spool/video: No such file or directory
this means that the mount-point is not there, so nfs script can't even mount the nfs export.
vdr shall not start before NFS is available. period. once NFS is up, that directory exists (as a later successfull "rcvdr start" proofs)
Please fix it using:
mkdir /var/spool/video
NAK: /var/spool/video is a symlink pointing into the NFS share: lrwxrwxrwx 1 koenig root 26 Jan 19 08:39 /var/spool/video -> /data.hps/video.m2.3/video # df /data.hps/video.m2.3/video Filesystem 1K-blocks Used Available Use% Mounted on hps1:/t2 5768579072 1460928512 4014623744 27% /data.hps (In reply to comment #5)
Harald, are you using autofs to mount it or nfs script? Can you provide the fstab entry / autofs config please?
nothing magic, just plain fstab. voila (using nfs3 aka nfs makes no difference, just in case... ;-) # grep data /etc/fstab hps1:/t2 /data.hps nfs4 please have another look into my syslog messages and the timetamps (selected line in original sequence): 17:45:45 t3 vdr: [1141] ERROR: /var/spool/video: No such file or directory 17:45:45 t3 ifup: eth0 device: Intel Corporation 82573E Gigabit Ethernet Con 17:45:46 t3 kernel: [ 17.380683] ADDRCONF(NETDEV_UP): eth0: link is not ready 17:45:50 t3 kernel: [ 20.586734] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready vdr starts even before "ifup eth0", and way before "link becomes ready", no way this can be fixed by e.g. not waiting for dhcpv6;) -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c9
--- Comment #9 from Harald Koenig
I've attached my work in progress -- please save and try out them:
install -m755 bug-734676_network /etc/init.d/network install -m755 bug-734676_network-remotefs /etc/init.d/network-remotefs
thanks! will try and reboot later... -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c10
--- Comment #10 from Harald Koenig
(In reply to comment #6)
I've attached my work in progress -- please save and try out them:
install -m755 bug-734676_network /etc/init.d/network install -m755 bug-734676_network-remotefs /etc/init.d/network-remotefs
thanks! will try and reboot later...
NAK: no change:-( Feb 1 22:15:43 t3 network[865]: lo Feb 1 22:15:43 t3 ifup: lo Feb 1 22:15:43 t3 vdr: [1099] cTimeMs: using monotonic clock (resolution is 1 ns) Feb 1 22:15:43 t3 ifup: lo Feb 1 22:15:43 t3 ifup: IP address: 127.0.0.1/8 Feb 1 22:15:43 t3 network[865]: lo IP address: 127.0.0.1/8 Feb 1 22:15:43 t3 ifup: Feb 1 22:15:43 t3 vdr: [1113] cTimeMs: using monotonic clock (resolution is 1 ns) Feb 1 22:15:43 t3 vdr: [1113] ERROR: /var/spool/video: No such file or directory Feb 1 22:15:43 t3 network[865]: ..done eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Feb 1 22:15:43 t3 ifup: eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Feb 1 22:15:44 t3 kernel: [ 19.519579] e1000e 0000:01:00.0: irq 45 for MSI/MSI-X Feb 1 22:15:44 t3 vdr[1062]: Starting Video Disk Recorder ..missing Feb 1 22:15:44 t3 systemd[1]: vdr.service: control process exited, code=exited status=3 Feb 1 22:15:44 t3 systemd[1]: Unit vdr.service entered failed state. Feb 1 22:15:44 t3 kernel: [ 19.570132] e1000e 0000:01:00.0: irq 45 for MSI/MSI-X Feb 1 22:15:44 t3 kernel: [ 19.571752] ADDRCONF(NETDEV_UP): eth0: link is not ready Feb 1 22:15:47 t3 kernel: [ 23.302039] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx Feb 1 22:15:47 t3 kernel: [ 23.303192] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready Feb 1 22:15:47 t3 ifup-dhcp: eth0 Starting DHCP4 client Feb 1 22:15:47 t3 dhcpcd[2028]: eth0: dhcpcd 3.2.3 starting Feb 1 22:15:47 t3 dhcpcd[2028]: eth0: hardware address = 00:13:20:e0:6c:1c Feb 1 22:15:47 t3 kernel: [ 23.363252] NET: Registered protocol family 17 Feb 1 22:15:47 t3 dhcpcd[2028]: eth0: broadcasting for a lease Feb 1 22:15:48 t3 ifup-dhcp: . Feb 1 22:15:48 t3 avahi-daemon[822]: Registering new address record for fe80::213:20ff:fee0:6c1c on eth0.*. Feb 1 22:15:49 t3 dhcpcd[2028]: eth0: offered 192.168.178.47 from 192.168.178.1 Feb 1 22:15:49 t3 dhcpcd[2028]: eth0: checking 192.168.178.47 is available on attached networks Feb 1 22:15:50 t3 ifup-dhcp: . Feb 1 22:15:50 t3 dhcpcd[2028]: eth0: leased 192.168.178.47 for 864000 seconds Feb 1 22:15:50 t3 dhcpcd[2028]: eth0: adding IP address 192.168.178.47/24 Feb 1 22:15:50 t3 avahi-daemon[822]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.178.47. Feb 1 22:15:50 t3 dhcpcd[2028]: eth0: adding default route via 192.168.178.1 metric 0 Feb 1 22:15:50 t3 avahi-daemon[822]: New relevant interface eth0.IPv4 for mDNS. Feb 1 22:15:50 t3 avahi-daemon[822]: Registering new address record for 192.168.178.47 on eth0.IPv4. Feb 1 22:15:50 t3 ifdown: eth0 device: Intel Corporation 82573E Gigabit Ethernet Controller (Copper) (rev 03) Feb 1 22:15:51 t3 dhcpcd[2028]: eth0: setting hostname to `t3' Feb 1 22:15:51 t3 ifup: eth0 device: Intel Corporation 82573E Gigabit Ethernet Controller (Copper) (rev 03) Feb 1 22:15:52 t3 ifup-dhcp: . Feb 1 22:15:55 t3 ifup-dhcp: . Feb 1 22:15:57 t3 ifup-dhcp: . Feb 1 22:15:57 t3 kernel: [ 33.330610] eth0: no IPv6 routers present Feb 1 22:15:59 t3 ifup-dhcp: . Feb 1 22:16:01 t3 ifup-dhcp: . Feb 1 22:16:04 t3 ifup-dhcp: . Feb 1 22:16:05 t3 network[865]: eth0 Starting DHCP4 client. . . . . . . . Feb 1 22:16:05 t3 ifup-dhcp: Feb 1 22:16:05 t3 network[865]: eth0 DHCP4 continues in background Feb 1 22:16:05 t3 ifup-dhcp: eth0 DHCP4 continues in background Feb 1 22:16:05 t3 network[865]: [1Awaiting Feb 1 22:16:05 t3 network[865]: Waiting for mandatory devices: eth0 Feb 1 22:16:14 t3 network[865]: 7 6 5 3 2 1 0 Feb 1 22:16:14 t3 network[865]: eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Feb 1 22:16:14 t3 network[865]: eth0 . . . is just beeing set up Feb 1 22:16:14 t3 network[865]: eth0 IP address: 192.168.178.47/24 Feb 1 22:16:14 t3 network[865]: eth0 is up Feb 1 22:16:15 t3 network[865]: [1Awaiting Feb 1 22:16:05 t3 network[865]: Waiting for mandatory devices: eth0 Feb 1 22:16:14 t3 network[865]: 7 6 5 3 2 1 0 Feb 1 22:16:14 t3 network[865]: eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Feb 1 22:16:14 t3 network[865]: eth0 . . . is just beeing set up Feb 1 22:16:14 t3 network[865]: eth0 IP address: 192.168.178.47/24 Feb 1 22:16:14 t3 network[865]: eth0 is up Feb 1 22:16:15 t3 network[865]: [1Awaiting Feb 1 22:16:15 t3 network[865]: eth0 interface could not be set up until now Feb 1 22:16:15 t3 network[865]: ..failedSetting up service (localfs) network . . . . . . . . ...failed Feb 1 22:16:15 t3 systemd[1]: network.service: control process exited, code=exited status=7 Feb 1 22:16:15 t3 systemd[1]: Unit network.service entered failed state. -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c11
--- Comment #11 from Harald Koenig
NAK: no change:-(
just to be sure I did a reboot with "init=/sbin/sysvinit" and here the vdr startup works fine *after* eth0/nfs. here is some syslog blurb for the timing: Feb 1 22:25:50 t3 ifup: lo Feb 1 22:25:50 t3 ifup: lo Feb 1 22:25:50 t3 ifup: IP address: 127.0.0.1/8 Feb 1 22:25:50 t3 ifup: Feb 1 22:25:50 t3 ifup: eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Feb 1 22:25:51 t3 kernel: [ 10.697420] e1000e 0000:01:00.0: irq 45 for MSI/MSI-X Feb 1 22:25:51 t3 kernel: [ 10.748133] e1000e 0000:01:00.0: irq 45 for MSI/MSI-X Feb 1 22:25:51 t3 kernel: [ 10.749650] ADDRCONF(NETDEV_UP): eth0: link is not ready Feb 1 22:25:54 t3 kernel: [ 14.394034] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx Feb 1 22:25:54 t3 kernel: [ 14.394743] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready Feb 1 22:25:54 t3 ifup-dhcp: eth0 Starting DHCP4 client Feb 1 22:25:54 t3 dhcpcd[2071]: eth0: dhcpcd 3.2.3 starting Feb 1 22:25:54 t3 dhcpcd[2071]: eth0: hardware address = 00:13:20:e0:6c:1c Feb 1 22:25:55 t3 kernel: [ 14.484894] NET: Registered protocol family 17 Feb 1 22:25:55 t3 dhcpcd[2071]: eth0: broadcasting for a lease Feb 1 22:25:55 t3 ifup-dhcp: . Feb 1 22:25:56 t3 dhcpcd[2071]: eth0: offered 192.168.178.47 from 192.168.178.1 Feb 1 22:25:56 t3 dhcpcd[2071]: eth0: checking 192.168.178.47 is available on attached networks Feb 1 22:25:57 t3 ifup-dhcp: . Feb 1 22:25:57 t3 dhcpcd[2071]: eth0: leased 192.168.178.47 for 864000 seconds Feb 1 22:25:57 t3 dhcpcd[2071]: eth0: adding IP address 192.168.178.47/24 Feb 1 22:25:57 t3 dhcpcd[2071]: eth0: adding default route via 192.168.178.1 metric 0 Feb 1 22:25:57 t3 ifdown: eth0 device: Intel Corporation 82573E Gigabit Ethernet Controller (Copper) (rev 03) Feb 1 22:25:58 t3 dhcpcd[2071]: eth0: setting hostname to `t3' Feb 1 22:25:58 t3 ifup: eth0 device: Intel Corporation 82573E Gigabit Ethernet Controller (Copper) (rev 03) Feb 1 22:25:58 t3 SuSEfirewall2: /var/lock/SuSEfirewall2.booting exists which means system boot in progress, exit. Feb 1 22:25:59 t3 dhcpcd[2071]: eth0: exiting Feb 1 22:25:59 t3 ifup-dhcp: Feb 1 22:25:59 t3 ifup-dhcp: eth0 IP address: 192.168.178.47/24 Feb 1 22:25:59 t3 kernel: Kernel logging (proc) stopped. .. Feb 1 22:26:03 t3 vdr: [3151] cTimeMs: using monotonic clock (resolution is 1 ns) Feb 1 22:26:03 t3 vdr: [3197] cTimeMs: using monotonic clock (resolution is 1 ns) Feb 1 22:26:03 t3 vdr: [3197] VDR version 1.6.0-2 started Feb 1 22:26:03 t3 vdr: [3197] switched to user 'vdr' Feb 1 22:26:03 t3 vdr: [3197] codeset is 'UTF-8' - known -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c12
Marius Tomaschewski
(In reply to comment #3)
Do you have an DHCPv6 server in your network or only DHCPv4?
no, only v4
When you don't have DHCPv6 server, change to use BOOTPROTO=dhcp4 in /etc/sysconfig/network/ifcfg-eth0 -- this will speed up the network start / cause to not wait for DHCPv6.
ok, I'll change that. but (a) it should work anyway and (b) that small speedup should be no significant help if you check the timestamps in my syslog output...
Yes, you're right -- it should work anyway and under sysvinit it does, as everything else :-) This were just a try to minimize the times and skip unneeded steps.
It looks like systemd would start vdr after network, but would not wait until it finished...?
maybe it only waits for the "lo" device setup being finished ?! that's at least the sequence which syslog shows. maybe lo-setup is just "too fast" doesn't let vdr pass ?!?
Even I can reproduce some of the problems from time to time, they never happened with enabled debug :-/
The error message is:
Jan 31 17:45:45 t3 vdr: [1141] ERROR: /var/spool/video: No such file or directory
this means that the mount-point is not there, so nfs script can't even mount the nfs export.
vdr shall not start before NFS is available. period.
sure.
once NFS is up, that directory exists (as a later successfull "rcvdr start" proofs)
Please fix it using:
mkdir /var/spool/video
NAK: /var/spool/video is a symlink pointing into the NFS share:
lrwxrwxrwx 1 koenig root 26 Jan 19 08:39 /var/spool/video -> /data.hps/video.m2.3/video
# df /data.hps/video.m2.3/video Filesystem 1K-blocks Used Available Use% Mounted on hps1:/t2 5768579072 1460928512 4014623744 27% /data.hps
Ah... OK.
(In reply to comment #5)
Harald, are you using autofs to mount it or nfs script? Can you provide the fstab entry / autofs config please?
nothing magic, just plain fstab. voila (using nfs3 aka nfs makes no difference, just in case... ;-)
# grep data /etc/fstab hps1:/t2 /data.hps nfs4
Is hps1 defined with IP address in /etc/hosts ?
please have another look into my syslog messages and the timetamps (selected line in original sequence):
17:45:45 t3 vdr: [1141] ERROR: /var/spool/video: No such file or directory 17:45:45 t3 ifup: eth0 device: Intel Corporation 82573E Gigabit Ethernet Con 17:45:46 t3 kernel: [ 17.380683] ADDRCONF(NETDEV_UP): eth0: link is not ready 17:45:50 t3 kernel: [ 20.586734] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
vdr starts even before "ifup eth0", and way before "link becomes ready", no way this can be fixed by e.g. not waiting for dhcpv6;)
Yes. (In reply to comment #11)
(In reply to comment #10)
NAK: no change:-(
just to be sure I did a reboot with "init=/sbin/sysvinit" and here the vdr startup works fine *after* eth0/nfs. here is some syslog blurb for the timing:
Yes, as expected. I've installed a test box that I can "stress" and will try to reproduce it with nfs and vdr [I've a DBV card somewhere here too ;)]. We'll see. But before I rewrite the network script once again ;), lets verify some another known issues with systemd: 1) Please verify that this is not same problem as in Bug 724777: The samba-client package installs some hooks, that trigger two "systemctl" commands for one service at same time, what causes a kind of deadlock in systemd that needs a lot of time to recover. There is a workaround in: http://download.opensuse.org/repositories/home:/fcrozat:/systemd/openSUSE_12... You can also move the hooks away: /etc/sysconfig/network/if-down.d/21-cifs /etc/sysconfig/network/if-down.d/21-dhcpcd-hook-samba /etc/sysconfig/network/if-up.d/21-cifs /etc/sysconfig/network/if-up.d/21-dhcpcd-hook-samba 2) Try if this happens with enabled debug and/or disabled resume from swap: First, reboot and add the "systemd.log_level=debug systemd.log_target=kmsg" boot options When it still happens, please attach logs & dmesg output. Further, set also the "noresume" and remove the "resume=..." boot option. Please attach the logs / dmesg output when the problem still occurs. At least my _impression_ is, that some "optimized paths" are used when resume is active... 3) Further, try out if disabling of ntp makes any difference Disable it also the "ntp-runtime" module in /etc/sysconfig/network/config, removing the module name from NETCONFIG_MODULES_ORDER variable. The reason may be as above + yast2 may add e.g. 2.opensuse.pool.ntp.org as server to /etc/ntp.conf, that resolves also with IPv6 addresses and ntp is trying then to sync time with, even there is no IPv6 connectivity what causes at least long timeouts and delays some actions. ntp starts after network, but it caused at least more complications in my tests... inclusive SEGV as in bug 739931. -> Just to verify that ntp is not involved in this problem. -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c13
--- Comment #13 from Marius Tomaschewski
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c14
--- Comment #14 from Marius Tomaschewski
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c15
Marius Tomaschewski
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c16
--- Comment #16 from Frederic Crozat
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c17
--- Comment #17 from Marius Tomaschewski
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c18
--- Comment #18 from Marius Tomaschewski
could you give output of : systemctl status nfs.service
I'm wondering if nfs as a client is correctly enabled
When I login after the boot, it is and it will be started via init script, but _after_ network... again? nighean:~ # systemctl status nfs.service nfs.service - LSB: NFS client services Loaded: loaded (/etc/init.d/nfs) Active: active (running) since Fri, 03 Feb 2012 15:05:00 +0100; 9min ago Process: 2380 ExecStart=/etc/init.d/nfs start (code=exited, status=0/SUCCESS) CGroup: name=systemd:/system/nfs.service └ 2409 /usr/sbin/rpc.idmapd Does systemd read/understand the /etc/insserv.conf and e.g. "$network" at all? -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c19
--- Comment #19 from Frederic Crozat
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c20
--- Comment #20 from Frederic Crozat
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c21
--- Comment #21 from Bernhard Wiedemann
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c22
Harald Koenig
I pushed a slighly different fix, please test systemd >= 37-3.146 (it works fine for my test)
ACK! works for me, too! for syslog details see below. thanks for fixing!!!! but I still get a failure for network.service (which I don't care too much as long as everything seems to work fine;) # systemctl | grep failed network.service loaded failed failed LSB: Configure the localfs depending network interfaces NetworkManager.service loaded failed failed Network Manager and the "failed" recoreds from syslog: Feb 7 17:20:36 t3 systemd[1]: Job NetworkManager-wait-online.service/start failed with result 'dependency'. Feb 7 17:20:36 t3 systemd[1]: Unit NetworkManager.service entered failed state. Feb 7 17:21:07 t3 network[866]: ..failedSetting up service (localfs) network . . . . . . . . ...failed Feb 7 17:21:07 t3 systemd[1]: Unit network.service entered failed state. if I understand some more systemctl output correctly that's because of # grep -r NETWORKMANAGER /etc/sysconfig/ /etc/sysconfig/network/config:NETWORKMANAGER="no" and thus(?!) # systemctl status NetworkManager.service network.service NetworkManager.service - Network Manager Loaded: loaded (/lib/systemd/system/NetworkManager.service; enabled) Active: failed since Tue, 07 Feb 2012 17:20:36 +0100; 40min ago Process: 818 ExecStartPre=/usr/bin/test x${NETWORKMANAGER} = xyes (code=exited, status=1/FAILURE) CGroup: name=systemd:/system/NetworkManager.service network.service - LSB: Configure the localfs depending network interfaces Loaded: loaded (/etc/init.d/network) Active: failed since Tue, 07 Feb 2012 17:21:07 +0100; 40min ago Process: 866 ExecStart=/etc/init.d/network start (code=exited, status=7/NOTRUNNING) CGroup: name=systemd:/system/network.service ? 5111 /sbin/dhcpcd --netconfig -L -E -HHH -c /etc/sysconfig/network/scripts/dhcpcd-hook -t 0 -h t3 eth0 finally, here some more syslog for the new and correct eth0/nfs/vdr startup sequence: Feb 7 17:20:37 t3 network[866]: Setting up (localfs) network interfaces: Feb 7 17:20:37 t3 network[866]: lo Feb 7 17:20:37 t3 ifup: lo Feb 7 17:20:37 t3 ifup: lo Feb 7 17:20:37 t3 ifup: IP address: 127.0.0.1/8 Feb 7 17:20:37 t3 network[866]: lo IP address: 127.0.0.1/8 Feb 7 17:20:37 t3 ifup: Feb 7 17:20:38 t3 network[866]: ..done eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Feb 7 17:20:38 t3 ifup: eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Feb 7 17:20:38 t3 kernel: [ 19.354979] e1000e 0000:01:00.0: irq 46 for MSI/MSI-X Feb 7 17:20:38 t3 kernel: [ 19.406121] e1000e 0000:01:00.0: irq 46 for MSI/MSI-X Feb 7 17:20:38 t3 kernel: [ 19.407667] ADDRCONF(NETDEV_UP): eth0: link is not ready Feb 7 17:20:42 t3 kernel: [ 22.656993] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx Feb 7 17:20:42 t3 kernel: [ 22.657887] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready Feb 7 17:20:42 t3 ifup-dhcp: eth0 Starting DHCP4 client Feb 7 17:20:42 t3 dhcpcd[1900]: eth0: dhcpcd 3.2.3 starting .. Feb 7 17:21:07 t3 network[866]: eth0 device: Intel Corporation 82573E Gigabit Ethernet Con Feb 7 17:21:07 t3 network[866]: eth0 . . . is just beeing set up Feb 7 17:21:07 t3 network[866]: eth0 IP address: 192.168.178.47/24 Feb 7 17:21:07 t3 network[866]: eth0 is up Feb 7 17:21:07 t3 network[866]: [1Awaiting Feb 7 17:21:07 t3 network[866]: eth0 interface could not be set up until now Feb 7 17:21:07 t3 network[866]: ..failedSetting up service (localfs) network . . . . . . . . ...failed Feb 7 17:21:07 t3 systemd[1]: network.service: control process exited, code=exited status=7 Feb 7 17:21:07 t3 systemd[1]: Unit network.service entered failed state. Feb 7 17:21:08 t3 rpcbind[3690]: Starting rpcbind ..done Feb 7 17:21:08 t3 kernel: [ 48.550585] RPC: Registered named UNIX socket transport module. Feb 7 17:21:08 t3 kernel: [ 48.550592] RPC: Registered udp transport module. Feb 7 17:21:08 t3 kernel: [ 48.550598] RPC: Registered tcp transport module. Feb 7 17:21:08 t3 kernel: [ 48.550602] RPC: Registered tcp NFSv4.1 backchannel transport module. Feb 7 17:21:08 t3 kernel: [ 48.554414] FS-Cache: Loaded Feb 7 17:21:08 t3 kernel: [ 48.562982] FS-Cache: Netfs 'nfs' registered for caching Feb 7 17:21:08 t3 sm-notify[3721]: Version 1.2.5 starting Feb 7 17:21:08 t3 nfs[3707]: Starting NFS client services: sm-notify idmapd..done Feb 7 17:21:08 t3 nfs[3707]: Mounting network file systems .....done .. Feb 7 17:21:09 t3 vdr: [4285] cTimeMs: using monotonic clock (resolution is 1 ns) Feb 7 17:21:09 t3 ctl_cyrusdb[4154]: archiving log file: /var/lib/imap/db/log.0000000001 Feb 7 17:21:09 t3 vdr: [4323] cTimeMs: using monotonic clock (resolution is 1 ns) Feb 7 17:21:09 t3 vdr: [4323] VDR version 1.6.0-2 started Feb 7 17:21:09 t3 vdr: [4323] switched to user 'vdr' Feb 7 17:21:09 t3 vdr: [4323] codeset is 'UTF-8' - known -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c23
--- Comment #23 from Frederic Crozat
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c
Marius Tomaschewski
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c24
Marius Tomaschewski
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c25
--- Comment #25 from Frederic Crozat
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c26
Marcus Meissner
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c27
--- Comment #27 from Harald Koenig
Harald, I've cloned the network failure into a separate bug report: bnc#745859, so we can close and release this fix [I think, we have some dups of it].
I've already opened the new bug #745653. but since that one got closed as "INVALID" for now (what I don't understand, maybe due to lack of verbose explanation or my missing networking skills?) I'll keep reporting to bnc#745859 for now ;-) thanks again! -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c28
Frederic Crozat
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c29
--- Comment #29 from Bernhard Wiedemann
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c30
Benjamin Brunner
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c31
Marius Tomaschewski
https://bugzilla.novell.com/show_bug.cgi?id=744293
https://bugzilla.novell.com/show_bug.cgi?id=744293#c32
Frederic Crozat
participants (1)
-
bugzilla_noreply＠novell.com