AutoIP/Link Local/169.254.* not assigning new address after an ARP defend failure - version 10.0.6

[TG-Zubby]

Works with 8.1.9, fails on 10.0.6

The call to ipv4ll_start() in ipv4ll_defend_failed() is suppose to pick/assign the new address, however ipv4ll_start() returns early because the state->running is still true.

If I set state->running = false, in ipv4ll_defend_failed() prior to the ipv4ll_start() call, this fixes this specific problem.
I'm unclear if this is a "complete" fix or whether it will cause other problems as I just started looking at this code base.

[TG-Zubby]

The lack of an address also occurs for any AutoIP address collision while negotiating an address. Same problem in that the ipv4ll_start() returns early because of the state->running check. If I remove the check entirely, it fixes both problems...

[deepfire]

To expand on this -- the client fails to acquire the DHCP-server-supplied IP address, which looks in the logs 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 close inspection 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., completely legitimate.

IOW, dhcpcd is completely broken in this use case.

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

[TG-Zubby]

Reverting this fixes the problems I found... the noise has a point:

commit 2d07224
Author: Roy Marples roy@marples.name
Date: Mon Oct 23 15:25:13 2023 +0000

IPv4LL: Don't start if already started

It's just pointless noise.
A follow-on fix for #255.

[TG-Zubby]

Well in the link-local/AutoIP collision case, dhcpcd (10.0.6) just failed to pick a new address after the previous selection had a collision.

dhcpcd[2255]: eth0: b8:ca:3a:80:66:7a(b8:ca:3a:80:66:7a) claims 169.254.157.247
dhcpcd[2255]: eth0: b8:ca:3a:80:66:7a(b8:ca:3a:80:66:7a) claims 169.254.157.247
dhcpcd[2255]: eth0: 10 second defence failed for 169.254.157.247
dhcpcd[2255]: eth0: b8:ca:3a:80:66:7a(b8:ca:3a:80:66:7a) claims 169.254.157.247
dhcpcd[2255]: eth0: 10 second defence failed for 169.254.157.247
dhcpcd[2255]: eth0: b8:ca:3a:80:66:7a(b8:ca:3a:80:66:7a) claims 169.254.157.247
dhcpcd[2255]: eth0: 10 second defence failed for 169.254.157.247
dhcpcd[2255]: eth0: b8:ca:3a:80:66:7a(b8:ca:3a:80:66:7a) claims 169.254.157.247
dhcpcd[2255]: eth0: 10 second defence failed for 169.254.157.247
dhcpcd[2255]: eth0: b8:ca:3a:80:66:7a(b8:ca:3a:80:66:7a) claims 169.254.157.247
dhcpcd[2255]: eth0: 10 second defence failed for 169.254.157.247
dhcpcd[2255]: eth0: b8:ca:3a:80:66:7a(b8:ca:3a:80:66:7a) claims 169.254.157.247
dhcpcd[2255]: eth0: 10 second defence failed for 169.254.157.247
dhcpcd[2255]: eth0: b8:ca:3a:80:66:7a(b8:ca:3a:80:66:7a) claims 169.254.157.247
dhcpcd[2255]: eth0: 10 second defence failed for 169.254.157.247
dhcpcd[2255]: eth0: b8:ca:3a:80:66:7a(b8:ca:3a:80:66:7a) claims 169.254.157.247
dhcpcd[2255]: eth0: 10 second defence failed for 169.254.157.247
dhcpcd[2255]: eth0: b8:ca:3a:80:66:7a(b8:ca:3a:80:66:7a) claims 169.254.157.247
dhcpcd[2255]: eth0: 10 second defence failed for 169.254.157.247

[deepfire]

@TG-Zubby, looks like I have misread the intention of the IPv4LL mechanism, and we have different issues, after all -- apologies for the noise!

I'll move my issue to a separate bug.

[deepfire]

Filed #291 for the issue I'm seeing.