|
Bugzilla – Full Text Bug Listing |
| Summary: | systemd: vdr starts before nfs-client-mount ?! | ||
|---|---|---|---|
| Product: | [openSUSE] openSUSE 12.1 | Reporter: | Harald Koenig <koenig> |
| Component: | Basesystem | Assignee: | Frederic Crozat <fcrozat> |
| Status: | RESOLVED FIXED | QA Contact: | E-mail List <qa-bugs> |
| Severity: | Normal | ||
| Priority: | P5 - None | CC: | fcrozat, forgotten_cI3FYhfYTs, meissner, mt |
| Version: | Final | ||
| Target Milestone: | --- | ||
| Hardware: | x86-64 | ||
| OS: | Other | ||
| Whiteboard: | |||
| Found By: | --- | Services Priority: | |
| Business Priority: | Blocker: | --- | |
| Marketing QA Status: | --- | IT Deployment: | --- |
| Bug Depends on: | |||
| Bug Blocks: | 745859 | ||
| Attachments: | screenlog.0 | ||
|
Description
Harald Koenig
2012-01-31 13:21:34 UTC
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.1/ and sysconfig package from http://download.opensuse.org/repositories/home:/mtomaschewski:/branches:/openSUSE:/12.1:/Update:/Test/openSUSE_12.1/ (In reply to comment #1) > 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.1/ 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:/openSUSE:/12.1:/Update:/Test/openSUSE_12.1/ 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. Do you have an DHCPv6 server in your network or only DHCPv4? 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. vdr deps are: # Required-Start: $remote_fs nfs deps are: # Required-Start: $network $portmap that means (/etc/insserv.conf): $network network $remote_fs $local_fs +nfs +cifs vdr waits for the mandatory $local_fs and when enabled also for nfs and cifs. nfs waits for network (that waits for $local_fs). So the dependencies are IMO correct. It looks like systemd would start vdr after network, but would not wait until it finished...? I've an "evil" suspicion, that I'll verify... 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. Please fix it using: mkdir /var/spool/video Reassigning to me at least for now... Harald, are you using autofs to mount it or nfs script? Can you provide the fstab entry / autofs config please? https://bugzilla.novell.com/attachment.cgi?id=473817 (/etc/init.d/network) https://bugzilla.novell.com/attachment.cgi?id=473818 (/etc/init.d/network-remotefs) It looks like the exec in network-remotefs confuses systemd ... 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 BTW: Bug 734676 is about bonding too. (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... > 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;) (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... (In reply to comment #9) > (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. (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: 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 (In reply to comment #8) > (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.1/ 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. I've applied my current set of changes to http://download.opensuse.org/repositories/home:/mtomaschewski:/branches:/openSUSE:/12.1:/Update:/Test/openSUSE_12.1/ I've also improved the /etc/sysconfig/network/config: DEBUG=EXTRA (bash -vx) tracing to include all ifup args and pid... Can you remove "quiet" and set the following boot time options? : splash=0 showopts systemd.log_level=debug systemd.log_target=kmsg systemd.sysv_console=1 systemd.show_status=1 I've put a dvb card into my test box, and configured -- when I start it
manually everything works fine, sysvinit too.
vdr complained a bit about the /var/spool/video link, so I've changed to
use:
exodus:/srv/temp /nfs nfs rw,rsize=8192,wsize=8192 0 0
/nfs/video /var/spool/video none bind 0 0
But when I try to boot under systemd, crap happens. AFAIS, systemd is trying
to start _nfs_ together with localfs, just after udev & co (/etc/init.d/boot.*
scripts) and seems to ignore any network dependency:
Boot with:
noresume console=ttyS0,115200n8 splash=0 showopts systemd.log_level=debug systemd.log_target=kmsg systemd.sysv_console=1 systemd.show_status=1
[...]
mount -o rw,acl,user_xattr -t ext4 /dev/disk/by-id/ata-WDC_WD3200AAKS-75L9A0_WD-WCAV2M787380-part3 /root
[ 4.828089] EXT4-fs (sda3): mounted filesystem with ordered data mode. Opts: acl,user_xattr
[ 4.939332] EXT4-fs (sda3): re-mounted. Opts: acl,user_xattr
[ 5.468061] systemd[1]: systemd 37 running in system mode. (+PAM +LIBWRAP +AUDIT +SELINUX +SYSVINIT +LIBCRYPTSETUP; suse)
Welcome to openSUSE 12.1 (Asparagus) (x86_64)!
Starting MD RAID Started udev Coldplug all Devices [
OK ]
Started Remount API VFS [ OK ]
[ 7.654732] systemd[1]: systemd-modules-load.service: main process exited, code=exited, status=1
Failed to start [ 7.671136] systemd[1]: Unit systemd-modules-load.service entered failed state.
Load Kernel Modules [FAILED]
See 'systemctl status systemd-modules-load.service' for details.
Started FUSE Control File System [ OK ]
Started Configuration File System [ OK ]
Started Apply Kernel Variables [ OK ]
[ 7.884592] RPC: Registered named UNIX socket transport module.
[ 7.890691] RPC: Registered udp transport module.
[ 7.890693] RPC: Registered tcp transport module.
[ 7.890694] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 7.892402] FS-Cache: Loaded
[ 7.914454] FS-Cache: Netfs 'nfs' registered for caching
[ 7.922566] mount[449]: mount.nfs: mount system call failed
[ 7.922798] systemd[1]: nfs.mount mount process exited, code=exited status=32
Using boot-specified hostname 'nighean.mat-home.net'
Setting up hostname 'nighean'..done
Setting up loopback interface RTNETLINK answers: File exists
..done
Failed to start [ 7.973216] systemd[1]: Job remote-fs.target/start failed with result 'dependency'.
/nfs [ 7.982690] systemd[1]: Job local-fs.target/start failed with result 'dependency'.
[ 7.991495] systemd[1]: Triggering OnFailure= dependencies of local-fs.target.
[ 8.001142] systemd[1]: Job getty@tty1.service/start failed with result 'dependency'.
[[ 8.010040] systemd[1]: Job serial-getty@ttyS0.service/start failed with result 'dependency'.
FAILED]
See[ 8.020324] systemd[1]: Job var-spool-video.mount/start failed with result 'dependency'.
'systemctl status nfs.mount' for details.
Dependency failed. A[ 8.034072] systemd[1]: Unit nfs.mount entered failed state.
borted start of [ 8.040777] EXT4-fs (sda3): re-mounted. Opts: acl,user_xattr
/var/spool/video [ ABORT]
Dependency failed. Aborted start of Getty on tty1 [ ABORT]
Dependency failed. Aborted start of Serial Getty on ttyS0 [ parport_pc 00:06: reported by Plug and Play ACPI
[...]
I've attached a serial console cable and added the console kernel parameter
to capture it -- without, same thing happens, just without the serial console failure ...
Sorry, but this is nothing for me -> reassigning to Frederic. IMO systemd
just makes complete crap here. I guess, just a bit different variant than
in Haralds case.
could you give output of : systemctl status nfs.service I'm wondering if nfs as a client is correctly enabled Created attachment 474312 [details]
screenlog.0
OK, I've changed to mount via nfs directly to /var/spool/video and now
I've quite similar effect with Harald: vdr starts before network.
But it is also visible in the attached screenlog: nfs is started together
with localfs (boot.*) and fails of course, because network is not started.
So as I meant in previous comments -> this has nothing do do with the
network scripts/nmb triggered systemd deadlock we've observed in the past.
(In reply to comment #16) > 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? please test systemd >= 37-3.144 from home:fcrozat:systemd / systemd I've added a fix which ensure nfs / cifs mount points from /etc/fstab are scheduled after starting nfs / cifs services but before $remote_fs target (/etc/insserv.conf was correctly parsed but the order between all services was not serialized properly) I pushed a slighly different fix, please test systemd >= 37-3.146 (it works fine for my test) This is an autogenerated message for OBS integration: This bug (744293) was mentioned in https://build.opensuse.org/request/show/103077 Factory / systemd https://build.opensuse.org/request/show/103083 Factory / systemd (In reply to comment #20) > 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 - NM failing is not a bug, since you disabled using NetworkManager - can't comment on network.service but it is outside the scope of this bug report. I'll close this bug report once the fix is pushed to 12.1 maintenance update. I've tested it yesterday and it works fine for me. I'd say, Frederic, please submit the fix to 12.1:Update:Test. Mr Maintenance, ACK? 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]. It will be part of the next 12.1 maintenance update, I'm still waiting for one or two other reports from other fixes before asking for maintenance ACK (but we can start the process already ;) OK, feel free to submit incremental change to openSUSE:12.1:Update:Test (In reply to comment #24) > 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! requesting maintenance update for 12.1 sr done on openSUSE:12.1:Update:Test : 106032 This is an autogenerated message for OBS integration: This bug (744293) was mentioned in https://build.opensuse.org/request/show/106032 12.1 / systemd The update is already started. Thanks for the submission. *** Bug 737636 has been marked as a duplicate of this bug. *** update released |