dhcpcd-discuss

I'm seeing some strange behavior with dhcpcd built from tag 9.0.2 and 
Comcast DOCSIS transport with modem in bridged/transparent mode.

While the initial IPv4 rebind succeeds, later rebind attempts seem to 
not be acknowledged by dhcpcd. DHCP ACK packets from each rebind attempt 
can be seen coming from the Comcast DHCP server with wireshark.

It may be due to the IP address of the DHCP server "changing" between 
the initial Request/ACK (fro the IP address which answered 
255.255.255.255) and that used at rebind attempt (consistent with the 
Option 54 DHCP Server Identifier in that initial ACK).

How can I further diagnose this or resolve this?

(I'd prefer not to resolve it without restarting dhcpcd every hour)

TIA,

Jeff


In detail:


Built and running on Debian 10 (Buster) commit 92a4102b (HEAD, tag: 
dhcpcd-9.0.2, tag: build-2020-05-02)

I restarted dhcpcd this morning and it appears to properly rebind the 
existing leases

May 20 07:11:38 systemd[1]: Stopping DHCP Client Daemon...
May 20 07:11:38 dhcpcd[658]: received SIGTERM, stopping
May 20 07:11:38 dhcpcd[658]: enp0s0f0: removing interface
May 20 07:11:38 dhcpcd[658]: dhcpcd exited
May 20 07:11:38 systemd[1]: dhcpcd.service: Succeeded.
May 20 07:11:38 systemd[1]: Stopped DHCP Client Daemon.
May 20 07:11:38 systemd[1]: Starting DHCP Client Daemon...
May 20 07:11:38 dhcpcd[17134]: dhcpcd-9.0.2 starting
May 20 07:11:38 dhcpcd[17134]: dhcpcd-9.0.2 starting
May 20 07:11:38 dhcpcd[17134]: no such user dhcpcd
May 20 07:11:38 dhcpcd[17134]: no such user dhcpcd
May 20 07:11:38 dhcpcd[17134]: DUID <redacted>
May 20 07:11:38 dhcpcd[17134]: enp0s0f0: IAID <redacted>
May 20 07:11:38 dhcpcd[17134]: enp0s0f0: IA type 3 IAID 00:00:00:01
May 20 07:11:38 dhcpcd[17134]: enp0s0f0: IA type 25 IAID <redacted>
May 20 07:11:38 dhcpcd[17134]: enp0s0f0: rebinding prior DHCPv6 lease
May 20 07:11:38 dhcpcd[17134]: enp0s0f0: cannot delegate to <redacted>: 
No such device or address
May 20 07:11:38 dhcpcd[17136]: DUID<redacted>
May 20 07:11:38 dhcpcd[17136]: enp0s0f0: IAID <redacted>
May 20 07:11:38 dhcpcd[17136]: enp0s0f0: IA type 3 IAID 00:00:00:01
May 20 07:11:38 dhcpcd[17136]: enp0s0f0: IA type 25 IAID <redacted>
May 20 07:11:38 dhcpcd[17136]: enp0s0f0: rebinding prior DHCPv6 lease
May 20 07:11:38 dhcpcd[17136]: enp0s0f0: cannot delegate to <redacted>: 
No such device or address
May 20 07:11:38 dhcpcd[17134]: enp0s0f0: soliciting an IPv6 router
May 20 07:11:38 dhcpcd[17136]: enp0s0f0: soliciting an IPv6 router
May 20 07:11:38 dhcpcd[17134]: enp0s0f0: rebinding lease of <my-ip4-ip>
May 20 07:11:38 dhcpcd[17136]: enp0s0f0: rebinding lease of <my-ip4-ip>
May 20 07:11:38 dhcpcd[17134]: enp0s0f0: leased <my-ip4-ip> for 5545 seconds
May 20 07:11:38 dhcpcd[17134]: enp0s0f0: adding route to <my-ip4-net>
May 20 07:11:38 dhcpcd[17134]: enp0s0f0: adding default route via 
<my-ip4-router>
May 20 07:11:38 dhcpcd[17136]: enp0s0f0: leased <my-ip4-ip> for 5545 seconds
May 20 07:11:38 dhcpcd[17136]: enp0s0f0: adding route to <my-ip4-net>
May 20 07:11:38 dhcpcd[17136]: enp0s0f0: adding default route via 
<my-ip4-router>
May 20 07:11:38 dhcpcd[17134]: forked to background, child pid 17136
May 20 07:11:38 systemd[1]: Started DHCP Client Daemon.

(I don't know why there are log entries from both 17134 and 17136)

The wireshark traces look reasonable at this point

07:11:38.891 DHCP Request 0.0.0.0 to 255.255.255.255
07:11:38.956 DHCP ACK 96.120.88.229 to <my-ip4-ip>

DHCP Server 76.96.19.203 (IP address seen prior to dhcpcd restart -- 
note different than where ACK originated)
Lease time 1:32:25 (h:m:s)
Renewal time at 46:12
Rebind at 1:20:12

The a couple ARPs to check <my-ip4-ip> and find the assigned router


Then, sometime later, with REPLY6 and associated messages suggesting 
success of IPv6

May 20 08:32:29 dhcpcd[17136]: enp0s0f0: failed to renew DHCP, rebinding 
(corresponding to the rebind time in the DHCP ACK)

Prior to this, starting at 07:57:51, (corresponding to the renewal time 
in the DHCP ACK), there are pairs of DHCP Request / ACK seen on the 
wire, though it seems that dhcpcd isn't "seeing" the DHCP ACK. The first 
few pairs are "quick", then they slow down to about once every 64 
seconds (probably 4, 8, 16, 32, 64, 64, ...).

07:57:50.958 DHCP Request <my-ip4-ip> to 76.96.19.203
07:57:51.021 DHCP ACK 76.96.19.203 to <my-ip4-ip>

The ACK includes:


DHCP Server Identifier 76.96.19.203
IP Address Lease Time 7200 s (2 hours)
Renewal Time Value 3600 s (1 hour)
Rebinding Time Value 6300 s (1 hour 45 min)
<my-ip4-ip>
<my-ip4-net-mask>
<my-ip4-router>


Here's the logs that continue to suggest that IPv6 is "working", but 
IPv4 is not.

May 20 07:47:54 dhcpcd[17136]: enp0s0f0: REPLY6 received from 
fe80::201:5cff:fe65:bc46
May 20 07:47:54 dhcpcd[17136]: enp0s0f0: adding address <my-ipv6-addr>/128
May 20 07:47:54 dhcpcd[17136]: enp0s0f0: renew in 3600, rebind in 5760, 
expire in 7200 seconds
May 20 07:47:54 dhcpcd[17136]: enp0s0f0: delegated prefix<my-ipv6-pd>::/60
May 20 08:32:29 dhcpcd[17136]: enp0s0f0: failed to renew DHCP, rebinding
May 20 08:47:54 dhcpcd[17136]: enp0s0f0: REPLY6 received from 
fe80::201:5cff:fe65:bc46
May 20 08:47:54 dhcpcd[17136]: enp0s0f0: renew in 3600, rebind in 5760, 
expire in 7200 seconds
May 20 09:47:10 dhcpcd[17136]: enp0s0f0: failed to renew DHCP, rebinding
May 20 09:47:54 dhcpcd[17136]: enp0s0f0: REPLY6 received from 
fe80::201:5cff:fe65:bc46
May 20 09:47:54 dhcpcd[17136]: enp0s0f0: renew in 3600, rebind in 5760, 
expire in 7200 seconds




Current conf:

$ egrep -v '^#|^$' /usr/local/etc/dhcpcd/dhcpcd.conf
controlgroup root
duid
persistent
option rapid_commit
option classless_static_routes
option interface_mtu
require dhcp_server_identifier
slaac private
nohook resolv.conf hostname ntp.conf
allowinterfaces enp0s0f0
denyinterfaces  *.* *:*
noipv4ll
interface enp0s0f0
    clientid <4 bytes, aa:bb:cc:dd format; confirmed seen in DHCP 
Request Option (61), Client identifier>
    ia_na 1
    ia_pd <redacted-prefix>/::/60 <redacted-interface-that-is-not-up>/0/64
    ipv6rs
    ipv6ra_noautoconf
interface eth1
    noipv4


I do have tcpdump captures for several days (loss of DHCP lease has been 
a problem in the past) from the interface with

"arp or (udp portrange 67-68) or (udp portrange 546-547) or (ip6 
multicast) or (net fe80::/10)"

so I can examine things in detail.