dhcpcd: mysteriously misinterprets DHCP ACK as if the server claims the IP address dhcpcd requested, leading to an ARP defence failure

[deepfire]

Briefly -- a DHCP Request receives a DHCP ACK from the server, but dhcpcd thinks that's a server claim for the address in question. Affected versions are 10.0.3, 9.4.1 and 8.1.4.

The setup is a basic dnsmasq-served ethernet LAN. That setup works fine when the same machine uses the NetworkManager machinery.

The dhcpcd logs are as follows, repeated ad infinitum:

Jan 25 03:23:02 host dhcpcd[14323]: eth0: dh:cp:se:rv:er:mc(dh:cp:se:rv:er:mc) claims 1.2.3.4
Jan 25 03:23:02 host dhcpcd[14323]: eth0: dh:cp:se:rv:er:mc(dh:cp:se:rv:er:mc) claims 1.2.3.4
Jan 25 03:23:02 host dhcpcd[14323]: eth0: 10 second defence failed for 1.2.3.4
Jan 25 03:23:02 host dhcpcd[14323]: eth0: deleting route to 1.0.0.0/8
Jan 25 03:23:02 host dhcpcd[14323]: eth0: deleting default route via 1.0.0.1
Jan 25 03:23:02 host dhcpcd[14323]: eth0: rebinding lease of 1.2.3.4
Jan 25 03:23:02 host dhcpcd[14323]: eth0: probing address 1.2.3.4/8
Jan 25 03:23:07 host dhcpcd[14323]: eth0: leased 1.2.3.4 for infinity
Jan 25 03:23:07 host dhcpcd[14323]: eth0: adding route to 1.0.0.0/8
Jan 25 03:23:07 host dhcpcd[14323]: eth0: adding default route via 1.0.0.1
Jan 25 03:23:08 host dhcpcd[14323]: eth0: dh:cp:se:rv:er:mc(dh:cp:se:rv:er:mc) claims 1.2.3.4
Jan 25 03:23:08 host dhcpcd[14323]: eth0: dh:cp:se:rv:er:mc(dh:cp:se:rv:er:mc) claims 1.2.3.4
Jan 25 03:23:08 host dhcpcd[14323]: eth0: 10 second defence failed for 1.2.3.4
Jan 25 03:23:08 host dhcpcd[14323]: eth0: deleting route to 1.0.0.0/8
Jan 25 03:23:08 host dhcpcd[14323]: eth0: deleting default route via 1.0.0.1
Jan 25 03:23:08 host dhcpcd[14323]: eth0: rebinding lease of 1.2.3.4
Jan 25 03:23:08 host dhcpcd[14323]: eth0: probing address 1.2.3.4/8
Jan 25 03:23:14 host dhcpcd[14323]: eth0: leased 1.2.3.4 for infinity
Jan 25 03:23:14 host dhcpcd[14323]: eth0: adding route to 1.0.0.0/8
Jan 25 03:23:14 host dhcpcd[14323]: eth0: adding default route via 1.0.0.1

Meanwhile, on the wire we see the following:

02:52:41.370524 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from cl:ie:nt:ma:ca:dr (oui Unknown), length 337
02:52:41.371083 IP server.bootps > 1.2.3.4.bootpc: BOOTP/DHCP, Reply, length 308
02:52:47.583527 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from cl:ie:nt:ma:ca:dr (oui Unknown), length 337
02:52:47.584122 IP server.bootps > 1.2.3.4.bootpc: BOOTP/DHCP, Reply, length 308
02:52:53.508164 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from cl:ie:nt:ma:ca:dr (oui Unknown), length 337
02:52:53.508768 IP server.bootps > 1.2.3.4.bootpc: BOOTP/DHCP, Reply, length 308
02:52:58.902490 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from cl:ie:nt:ma:ca:dr (oui Unknown), length 337

..which, upon closer inspection (tcpdump -v) is:

02:55:26.811461 IP (tos 0x0, ttl 64, id 8452, offset 0, flags [none], proto UDP (17), length 365)
    0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from cl:ie:nt:ma:ca:dr (oui Unknown), length 337, xid 0x87654321, Flags [none]
	  Client-Ethernet-Address cl:ie:nt:ma:ca:dr (oui Unknown)
	  Vendor-rfc1048 Extensions
	    Magic Cookie 0x12345678
	    Requested-IP (50), length 4: 1.2.3.4
	    DHCP-Message (53), length 1: Request
	    Parameter-Request (55), length 14:
	      Subnet-Mask (1), Classless-Static-Route (121), Default-Gateway (3), Domain-Name-Server (6)
	      Hostname (12), Domain-Name (15), MTU (26), BR (28)
	      Static-Route (33), NTP (42), Lease-Time (51), RN (58)
	      RB (59), Unknown (119)
	    MSZ (57), length 2: 1472
	    Hostname (12), length 4: "client"
02:55:26.812047 IP (tos 0xc0, ttl 64, id 57327, offset 0, flags [none], proto UDP (17), length 336)
    server.bootps > 1.2.3.4.bootpc: BOOTP/DHCP, Reply, length 308, xid 0x87654321, Flags [none]
	  Your-IP 1.2.3.4
	  Server-IP server
	  Client-Ethernet-Address cl:ie:nt:ma:ca:dr (oui Unknown)
	  Vendor-rfc1048 Extensions
	    Magic Cookie 0x12345678
	    DHCP-Message (53), length 1: ACK
	    Server-ID (54), length 4: server
	    Lease-Time (51), length 4: 131072
	    Subnet-Mask (1), length 4: 255.0.0.0
	    BR (28), length 4: 1.255.255.255
	    Default-Gateway (3), length 4: server
	    Domain-Name-Server (6), length 4: server
	    Domain-Name (15), length 5: "domain"
	    Hostname (12), length 4: "client"

..i.e., a completely legitimate exchange.

IOW, dhcpcd is completely broken in this use case.

NOTE: all IP addresses and hostnames were changed to protect the innocent.

dhcpcd config is:

hostname

option domain_name_servers, domain_name, domain_search, host_name
option classless_static_routes, ntp_servers, interface_mtu

nohook lookup-hostname

denyinterfaces ve-* vb-* lo peth* vif* tap* tun* virbr* vnet* vboxnet* sit*

waitip
noipv6

[deepfire]

Good news is that master fixes the problem halfway. Halfway is because the client manages to get an address, just not what the server offers it in the initial reply.

I'll have a closer look with tcpdump a bit later.

[rsmarples]

So you need to look at ARP ARPOP_REQUESTs on the wire as well. They seem to the the source of your concern, not the DHCP transaction itself.