#996901 ifupdown: When booting a thin client over the network (NFS-Root) ifup fails

Package:
ifupdown
Source:
ifupdown
Description:
high level tools to configure network interfaces
Submitter:
Ralf Schlatterbeck
Date:
2021-10-23 17:12:02 UTC
Severity:
important
#996901#5
Date:
2021-10-20 13:31:18 UTC
From:
To:
Dear Maintainer,

I'm trying to network-boot a thin client (orange-pi zero) with debian
bullseye and a custom kernel. NFS mount works fine but ifup fails
spectacularly. This works fine on debian buster (but may be kernel
specific, the debian buster setup has an older 5.9 kernel).

When booting with the 'auto eth0' in /etc/network/interfaces I'm getting
a 5 Minute wait and then

[FAILED] Failed to start Raise network interfaces.

And issuing the command 'ip addr ls' will reveal that a lot of IP
addresses have been reserved for the eth0 interface (see below).

When removing the 'auto eth0' line and starting up the interface manually
when the system is up (it already *has* an IP-Address at that point due
to the NFS-Root) I'm getting:

root@sun7i:~# ifup eth0
Internet Systems Consortium DHCP Client 4.4.1
Copyright 2004-2018 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/

Listening on LPF/eth0/02:42:b3:f0:2d:3e
Sending on   LPF/eth0/02:42:b3:f0:2d:3e
Sending on   Socket/fallback
Created duid "\000\001\000\001)\002\266\310\002B\263\360->".
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 8
DHCPOFFER of 10.23.5.173 from 10.23.5.254
DHCPREQUEST for 10.23.5.173 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.173 from 10.23.5.254
RTNETLINK answers: File exists
DHCPDECLINE of 10.23.5.173 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 6
DHCPOFFER of 10.23.5.205 from 10.23.5.254
DHCPREQUEST for 10.23.5.205 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.205 from 10.23.5.254
DHCPDECLINE of 10.23.5.205 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 7
DHCPOFFER of 10.23.5.206 from 10.23.5.254
DHCPREQUEST for 10.23.5.206 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.206 from 10.23.5.254
DHCPDECLINE of 10.23.5.206 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 4
DHCPOFFER of 10.23.5.207 from 10.23.5.254
DHCPREQUEST for 10.23.5.207 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.207 from 10.23.5.254
DHCPDECLINE of 10.23.5.207 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 6
DHCPOFFER of 10.23.5.208 from 10.23.5.254
DHCPREQUEST for 10.23.5.208 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.208 from 10.23.5.254
DHCPDECLINE of 10.23.5.208 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 8
DHCPOFFER of 10.23.5.209 from 10.23.5.254
DHCPREQUEST for 10.23.5.209 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.209 from 10.23.5.254
DHCPDECLINE of 10.23.5.209 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 6
DHCPOFFER of 10.23.5.211 from 10.23.5.254
DHCPREQUEST for 10.23.5.211 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.211 from 10.23.5.254
DHCPDECLINE of 10.23.5.211 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 8
DHCPOFFER of 10.23.5.211 from 10.23.5.254
DHCPREQUEST for 10.23.5.211 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.211 from 10.23.5.254
RTNETLINK answers: File exists
DHCPDECLINE of 10.23.5.211 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 6
DHCPOFFER of 10.23.5.212 from 10.23.5.254
DHCPREQUEST for 10.23.5.212 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.212 from 10.23.5.254
DHCPDECLINE of 10.23.5.212 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 5
DHCPOFFER of 10.23.5.213 from 10.23.5.254
DHCPREQUEST for 10.23.5.213 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.213 from 10.23.5.254
DHCPDECLINE of 10.23.5.213 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 4
DHCPOFFER of 10.23.5.215 from 10.23.5.254
DHCPREQUEST for 10.23.5.215 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.215 from 10.23.5.254
DHCPDECLINE of 10.23.5.215 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 8
DHCPOFFER of 10.23.5.215 from 10.23.5.254
DHCPREQUEST for 10.23.5.215 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.215 from 10.23.5.254
RTNETLINK answers: File exists
DHCPDECLINE of 10.23.5.215 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3
DHCPOFFER of 10.23.5.216 from 10.23.5.254
DHCPREQUEST for 10.23.5.216 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.216 from 10.23.5.254
DHCPDECLINE of 10.23.5.216 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 5
DHCPOFFER of 10.23.5.217 from 10.23.5.254
DHCPREQUEST for 10.23.5.217 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.217 from 10.23.5.254
DHCPDECLINE of 10.23.5.217 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 7
DHCPOFFER of 10.23.5.218 from 10.23.5.254
DHCPREQUEST for 10.23.5.218 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.218 from 10.23.5.254
DHCPDECLINE of 10.23.5.218 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 7
DHCPOFFER of 10.23.5.219 from 10.23.5.254
DHCPREQUEST for 10.23.5.219 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.219 from 10.23.5.254
DHCPDECLINE of 10.23.5.219 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 4
DHCPOFFER of 10.23.5.220 from 10.23.5.254
DHCPREQUEST for 10.23.5.220 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.220 from 10.23.5.254
DHCPDECLINE of 10.23.5.220 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 4
DHCPOFFER of 10.23.5.200 from 10.23.5.254
DHCPREQUEST for 10.23.5.200 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.200 from 10.23.5.254
DHCPDECLINE of 10.23.5.200 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 6
DHCPOFFER of 10.23.5.201 from 10.23.5.254
DHCPREQUEST for 10.23.5.201 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.201 from 10.23.5.254
DHCPDECLINE of 10.23.5.201 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 8
DHCPOFFER of 10.23.5.202 from 10.23.5.254
DHCPREQUEST for 10.23.5.202 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.202 from 10.23.5.254
DHCPDECLINE of 10.23.5.202 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 4
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 10
DHCPOFFER of 10.23.5.204 from 10.23.5.254
DHCPREQUEST for 10.23.5.204 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.204 from 10.23.5.254
DHCPDECLINE of 10.23.5.204 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 5
DHCPOFFER of 10.23.5.204 from 10.23.5.254
DHCPREQUEST for 10.23.5.204 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.204 from 10.23.5.254
RTNETLINK answers: File exists
DHCPDECLINE of 10.23.5.204 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 6
DHCPOFFER of 10.23.5.204 from 10.23.5.254
DHCPREQUEST for 10.23.5.204 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.204 from 10.23.5.254
RTNETLINK answers: File exists
DHCPDECLINE of 10.23.5.204 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 7
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 14
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 18
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 15
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 7
No DHCPOFFERS received.
No working leases in persistent database - sleeping.

After that the interface is still up (from NFS root-filesystem):
root@sun7i:~# ifconfig
eth0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 10.23.5.173  netmask 255.255.255.0  broadcast 10.23.5.255
        inet6 fe80::42:b3ff:fef0:2d3e  prefixlen 64  scopeid 0x20<link>
        ether 02:42:b3:f0:2d:3e  txqueuelen 1000  (Ethernet)
        RX packets 93682  bytes 38803236 (37.0 MiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 65721  bytes 8457832 (8.0 MiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0
        device interrupt 43
[...]

When I look with 'ip addr ls' I'm getting:
root@sun7i:~# ip addr ls
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group defaul
t qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host
       valid_lft forever preferred_lft forever
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group defa
ult qlen 1000
    link/ether 02:42:b3:f0:2d:3e brd ff:ff:ff:ff:ff:ff
    inet 10.23.5.173/24 brd 10.23.5.255 scope global eth0
       valid_lft forever preferred_lft forever
    inet 10.23.5.205/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 2881sec preferred_lft 2881sec
    inet 10.23.5.206/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 2894sec preferred_lft 2894sec
    inet 10.23.5.207/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 2907sec preferred_lft 2907sec
    inet 10.23.5.208/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 2921sec preferred_lft 2921sec
    inet 10.23.5.209/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 2934sec preferred_lft 2934sec
    inet 10.23.5.211/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 2947sec preferred_lft 2947sec
    inet 10.23.5.212/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 2971sec preferred_lft 2971sec
    inet 10.23.5.213/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 2985sec preferred_lft 2985sec
    inet 10.23.5.215/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 2999sec preferred_lft 2999sec
    inet 10.23.5.216/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 3022sec preferred_lft 3022sec
    inet 10.23.5.217/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 3035sec preferred_lft 3035sec
    inet 10.23.5.218/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 3049sec preferred_lft 3049sec
    inet 10.23.5.219/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 3062sec preferred_lft 3062sec
    inet 10.23.5.220/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 3075sec preferred_lft 3075sec
    inet 10.23.5.200/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 3088sec preferred_lft 3088sec
    inet 10.23.5.201/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 3102sec preferred_lft 3102sec
    inet 10.23.5.202/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 3115sec preferred_lft 3115sec
    inet 10.23.5.204/24 brd 10.23.5.255 scope global secondary dynamic eth0
       valid_lft 3129sec preferred_lft 3129sec
    inet6 fe80::42:b3ff:fef0:2d3e/64 scope link
       valid_lft forever preferred_lft forever

On first glance this looks like all dynamic IPs from my network were
reserverd, but looking at the leases file from my dhcp server only one
address is reserved. But it looks like these addresses were somehow
retained. Note that I'm getting the same output from 'ip addr ls' when I
issue that command after a boot with 'auto eth0' enabled in
/etc/network/interfaces (see above).
--- up and down scripts installed:
/etc/network/if-down.d:
total 0

/etc/network/if-post-down.d:
total 4
-rwxr-xr-x 1 root root 1433 Feb  4  2019 vlan

/etc/network/if-pre-up.d:
total 8
-rwxr-xr-x 1 root root 4224 Feb 21  2019 vlan

/etc/network/if-up.d:
total 4
-rwxr-xr-x 1 root root 677 Feb  4  2019 ip
#996901#10
Date:
2021-10-20 15:32:53 UTC
From:
To:
Hi,

El 20/10/21 a las 15:31, Ralf Schlatterbeck escribió:

What are you network mount points?
...

Your dhclient is declining all of the offered IPs…
Are you sure they are available?

Cheers,
#996901#15
Date:
2021-10-20 15:32:53 UTC
From:
To:
Hi,

El 20/10/21 a las 15:31, Ralf Schlatterbeck escribió:

What are you network mount points?
...

Your dhclient is declining all of the offered IPs…
Are you sure they are available?

Cheers,
#996901#20
Date:
2021-10-21 07:30:19 UTC
From:
To:
Hey Santiago, thanks for the quick reaction!

The root filesystem is on NFS. So the mount-point is basically '/'.

Yes they're all available, the dhcp server would not offer them if not.
I *think* this is done by the kernel: It will decline all attempts to
set an IP-Address different from the one where the root-filesystem is
mounted because that would kill the system.
Note that the very-first IP-Address offered above is the one the system
already has, in fact it is configured as a static IP for this MAC
address in the DHCP server. It should accept that even though the
interface is already up with that IP. So the error "RTNETLINK answers:
File exists" is probably the cause of all this. It did not occur on
earlier Debian version such as Buster (or it did occur and was ignored
by dhclient?).  It has worked for me as far back as Debian lenny.

I'll try to boot the system with debian buster but with the same new
kernel and report back.

Ralf
#996901#25
Date:
2021-10-21 07:30:19 UTC
From:
To:
Hey Santiago, thanks for the quick reaction!

The root filesystem is on NFS. So the mount-point is basically '/'.

Yes they're all available, the dhcp server would not offer them if not.
I *think* this is done by the kernel: It will decline all attempts to
set an IP-Address different from the one where the root-filesystem is
mounted because that would kill the system.
Note that the very-first IP-Address offered above is the one the system
already has, in fact it is configured as a static IP for this MAC
address in the DHCP server. It should accept that even though the
interface is already up with that IP. So the error "RTNETLINK answers:
File exists" is probably the cause of all this. It did not occur on
earlier Debian version such as Buster (or it did occur and was ignored
by dhclient?).  It has worked for me as far back as Debian lenny.

I'll try to boot the system with debian buster but with the same new
kernel and report back.

Ralf
#996901#30
Date:
2021-10-23 08:32:08 UTC
From:
To:
I wrote:

Followup: I've tested this with a debian buster root filesystem with the
same new 5.14.12 kernel: The behaviour is identical to the one with
bullseye. So at this time I believe that this is not a regression in the
debian ifupdown mechanisms.  Can we leave this open for some time until
I've verified what the problem is? I currently see two possibilities:

- I've done something differently for my other root-NFS setups
- There is a difference in newer kernels that causes this

The message "RTNETLINK answers: File exists" typically occurs if there
already is a route that some program is trying to set up. I've verified
that it is not the default route: If I remove the default route and
*then* try ifup I'm still getting the same behaviour:

root@sun7i:~# ip route ls
default via 10.23.5.254 dev eth0
10.23.5.0/24 dev eth0 proto kernel scope link src 10.23.5.173

root@sun7i:~# ip route del default
root@sun7i:~# ip route ls
10.23.5.0/24 dev eth0 proto kernel scope link src 10.23.5.173

root@sun7i:~# ifup eth0
Internet Systems Consortium DHCP Client 4.4.1
Copyright 2004-2018 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/

Listening on LPF/eth0/02:42:b3:f0:2d:3e
Sending on   LPF/eth0/02:42:b3:f0:2d:3e
Sending on   Socket/fallback
Created duid "\000\001\000\001#\367\373\240\002B\263\360->".
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 7
DHCPOFFER of 10.23.5.173 from 10.23.5.254
DHCPREQUEST for 10.23.5.173 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.173 from 10.23.5.254
RTNETLINK answers: File exists
DHCPDECLINE of 10.23.5.173 on eth0 to 255.255.255.255 port 67
[...]

Of course I cannot remove the kernel link-scope route to the local
network with NFS-root. So I couldn't check if that route causes the
RTNETLINK message.

All the experiments in this email were with a debian buster rootfs,
they're identical to the behaviour with bullseye.

Ralf
#996901#35
Date:
2021-10-23 17:09:04 UTC
From:
To:
I've finally found it.
I was at the point where I had two (different hardware) embedded
systems. Both with the *same* kernel and mounting the *same* root NFS
filesystem.  Even exchanging the IP-Addresses didn't change the
behaviour, the Orange-Pi issues a DHCPDECLINE, the other system works
fine.

The cause is that on the non-working system the root NFS was mounted
read-only. Note that I mount a (writeable) tmpfs on /var/lib/dhcp where
apparently dhclient puts its leases. So there is another undocumented
location that apparently needs to be writeable.

It would be *very* nice to document which directories dhclient needs to
be writeable and under what circumstances it issues a DHCPDECLINE.
Note that the DHCPDECLINE has an optional message where the client could
tell the server the reason for the decline. It's left empty, I've
checked with tcpdump.

For the record: The message "RTNETLINK answers: File exists" was a red
herring: It is always issued, also in the successful case.

I think we can close this issue unless you want to keep it open as a
reminder that the causes for DHCPDECLINE should be documented.

Oh and dhclient probably should not retry when it detects that something
is unwriteable and effectively perform a denial-of-service attack on the
dhcp server. Instead it should terminate with an error message that is
clearly visible (not just in a log that may not exist at that stage of
booting).

Working example:
root@sun7i:~# mount -oremount,rw 10.23.5.5:/data/project/project/rootfs/A20-OLinuXino_MICRO

root@sun7i:~# ifup eth0
Internet Systems Consortium DHCP Client 4.4.1
Copyright 2004-2018 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/

Listening on LPF/eth0/02:42:b3:f0:2d:3e
Sending on   LPF/eth0/02:42:b3:f0:2d:3e
Sending on   Socket/fallback
Created duid "\000\001\000\001#\367\373\266\002B\263\360->".
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3
DHCPOFFER of 10.23.5.173 from 10.23.5.254
DHCPREQUEST for 10.23.5.173 on eth0 to 255.255.255.255 port 67
DHCPACK of 10.23.5.173 from 10.23.5.254
RTNETLINK answers: File exists
bound to 10.23.5.173 -- renewal in 1396 seconds.
root@sun7i:~#

Ralf