dhcpcd-discuss

Roy,

I started with v8.0.2 (what is normally packaged with Yocto Zeus), then tried v8.1.6 (Yocto Dunfell's version), then v9.0.2 last week, then I saw v9.1.0 just got posted and tried that.  All of them fail in the same way during the IPv4LL tests... :/


> On Jun 2, 2020, at 3:05 PM, Roy Marples <roy@xxxxxxxxxxxx> wrote:
> ...
>> I've been digging through the source but am still coming up to speed to understand how dhcpcd decides to stop trying new IPv4LL addresses, and how this might be fixed (or if this is even the problem...)  I was also wondering why dhcpcd only chooses 169.254.x.0 addresses on my Pi - the code looks like it should have randomness in the entire lower 16 bits of the IPv4 address...
> 
> Hmmmmm, it should use the entire lower 16 bits of the address.
> At least it does on litle endian machines. I'll try and test a BE machine later - but might take some time as it's an ERLITE router running NetBSD.

I did a little testing and it looks like the first random number out of random() has a lower 8 bits of zeroes - probably just coincidental on this particular hardware...  

Most of the time all I can get are the initial probes with dhcpcd not seeing any of the deny messages:

  Bonjour Conformance Test Version 1.5.1(15100)
  Starting Test: 2020-06-02 18:16:19.665838-0400
  *** Please Power On Device ***

  *** Beginning Link-Local Address Allocation Test ***
  START (INITIAL PROBING)
  NOTICE  2020-06-02 18:16:24.025271-0400: Received probe for 169.254.194.0 [b8:27:eb:15:f4:fd].
  PASSED (INITIAL PROBING)

  START (PROBING)
  NOTICE  2020-06-02 18:16:24.026110-0400: Denying probe for              169.254.194.0
  ERROR   2020-06-02 18:16:25.168398-0400: Device did not probe for new address after it's chosen address was denied.
  NOTICE  2020-06-02 18:16:25.168451-0400: Denying probe for              169.254.194.0
  ERROR   2020-06-02 18:16:26.372102-0400: Device did not probe for new address after it's chosen address was denied.
  NOTICE  2020-06-02 18:16:26.372140-0400: Denying probe for              169.254.194.0
  WARNING 2020-06-02 18:16:28.407480-0400: Source address non-zero 169.254.194.0
  WARNING 2020-06-02 18:16:28.615814-0400: Received address record query (name: pieb15f4fd.local., address: 169.254.194.0) before device successfully acquired a link-local IP address in subtest PROBING.
  WARNING 2020-06-02 18:16:30.422856-0400: Source address non-zero 169.254.194.0
  WARNING 2020-06-02 18:17:03.301368-0400: Have not received initial probe from device.  Listening...

The debug log from dhcpcd has the following (ignore the dates/times - clock isn't set on the 'Pi):

  May 21 21:26:06 [236]: dhcpcd-9.1.0 starting
  May 21 21:26:06 [236]: no such user dhcpcd
  May 21 21:26:06 [238]: DUID 00:01:00:01:26:59:ac:41:b8:27:eb:15:f4:fd
  May 21 21:26:06 [238]: wlan0: executing `/usr/libexec/dhcpcd-run-hooks' PREINIT
  May 21 21:26:06 [238]: wlan0: executing `/usr/libexec/dhcpcd-run-hooks' NOCARRIER
  May 21 21:26:06 [238]: wlan0: waiting for carrier
  May 21 21:26:07 [238]: wlan0: carrier acquired
  May 21 21:26:07 [238]: wlan0: connected to Access Point `Lakeside Test'
  May 21 21:26:07 [238]: wlan0: executing `/usr/libexec/dhcpcd-run-hooks' CARRIER
  May 21 21:26:07 [238]: wlan0: IAID eb:15:f4:fd
  May 21 21:26:07 [238]: wlan0: adding address fe80::1d96:c613:8cdd:4ba8
  May 21 21:26:07 [238]: wlan0: pltime infinity, vltime infinity
  May 21 21:26:07 [238]: wlan0: soliciting an IPv6 router
  May 21 21:26:07 [238]: wlan0: delaying Router Solicitation for LL address
  May 21 21:26:07 [238]: wlan0: reading lease `/var/db/dhcpcd/wlan0-Lakeside\040Test.lease'
  May 21 21:26:07 [238]: wlan0: soliciting a DHCP lease
  May 21 21:26:07 [238]: wlan0: sending DISCOVER (xid 0x978005e7), next in 4.1 seconds
  May 21 21:26:08 [238]: wlan0: probing for an IPv4LL address
  May 21 21:26:08 [238]: wlan0: probing for 169.254.194.0
  May 21 21:26:08 [238]: wlan0: ARP probing 169.254.194.0 (1 of 3), next in 1.1 seconds
  May 21 21:26:08 [238]: wlan0: sending Router Solicitation
  May 21 21:26:09 [238]: wlan0: ARP probing 169.254.194.0 (2 of 3), next in 1.2 seconds
  May 21 21:26:10 [238]: wlan0: ARP probing 169.254.194.0 (3 of 3), next in 2.0 seconds
  May 21 21:26:11 [238]: wlan0: sending DISCOVER (xid 0x978005e7), next in 7.4 seconds
  May 21 21:26:12 [238]: wlan0: using IPv4LL address 169.254.194.0
  May 21 21:26:12 [238]: wlan0: adding IP address 169.254.194.0/16 broadcast 169.254.255.255
  May 21 21:26:12 [238]: wlan0: adding route to 169.254.0.0/16
  May 21 21:26:12 [238]: wlan0: adding default route
  May 21 21:26:12 [238]: wlan0: ARP announcing 169.254.194.0 (1 of 2), next in 2.0 seconds
  May 21 21:26:12 [238]: wlan0: executing `/usr/libexec/dhcpcd-run-hooks' IPV4LL
  May 21 21:26:13 [238]: wlan0: sending Router Solicitation
  May 21 21:26:14 [238]: wlan0: ARP announcing 169.254.194.0 (2 of 2)
  May 21 21:26:17 [238]: wlan0: sending Router Solicitation
  May 21 21:26:18 [238]: wlan0: sending DISCOVER (xid 0x978005e7), next in 15.5 seconds
  May 21 21:26:21 [238]: wlan0: sending Router Solicitation
  May 21 21:26:21 [238]: wlan0: no IPv6 Routers available
  May 21 21:26:34 [238]: wlan0: sending DISCOVER (xid 0x978005e7), next in 31.4 seconds
  May 21 21:27:05 [238]: wlan0: sending DISCOVER (xid 0x978005e7), next in 64.6 seconds
  May 21 21:28:10 [238]: wlan0: sending DISCOVER (xid 0x978005e7), next in 64.2 seconds
  May 21 21:29:14 [238]: wlan0: sending DISCOVER (xid 0x978005e7), next in 63.7 seconds

I also have a dump of the network traffic showing my MacBook Pro claiming the 169.254.194.0 address each time but the 'Pi either isn't seeing it or it isn't getting to dhcpcd for some reason...  (I'm in the process of getting tcpdump on my Yocto image so I can record the network traffic from its perspective as well...)

For reference, the MacBook Pro is connected via Ethernet to an AirPort Time Capsule, and the Pi Zero is connected via Wi-Fi to the Time Capsule (as required by the BCT manual).  I have also tested with a Pi 3b over Wi-Fi and Ethernet, with the same results...

The only patch to the dhcpcd software is the Yocto "INCLUDEDIR" patch (so that dhcpcd builds against the embedded system/SDK headers).

________________________
Michael Sweet