dhcpcd-discuss

Lease renewal requests every 60 s with dhcpcd 8.1.9

Thomas Albers

Tue Jan 19 18:41:16 2021

Hello!

I am using dhcpcd-8.1.9 under Gentoo Linux, and once the leasetime is
50 % expired, dhcpcd continually requests a new lease every 60
seconds, or so, continuously. The DHCP server is dhcpd-7.2.2 on an
Openwrt router.

This behaviour seems similar to that seen in the mailing list post
"Problematic Buster dhcpcd lease renewal behavior", dated Sat Dec 19
22:50:17 2020. The patches in the reply dated Sun Dec 20 07:19:06 2020
are already present in dhcpcd-8.1.9, so it's a problem with similar
symptoms or the patch does not solve this bug.

Please see log excerpts below. Leasetime on DHCP server is set to 12
h. Anything else I can do to help, please let me know.

Regards,
Thomas


Syslog from router:
Sun Jan 17 13:02:51 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPDISCOVER(br-lan) bc:5f:f4:0b:8b:7e
Sun Jan 17 13:02:51 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPOFFER(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e
Sun Jan 17 13:02:51 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPREQUEST(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e
Sun Jan 17 13:02:51 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPACK(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e pythia
...
Sun Jan 17 19:02:56 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPREQUEST(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e
Sun Jan 17 19:02:56 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPACK(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e pythia
Sun Jan 17 19:02:59 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPREQUEST(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e
Sun Jan 17 19:02:59 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPACK(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e pythia
Sun Jan 17 19:03:07 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPREQUEST(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e
Sun Jan 17 19:03:07 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPACK(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e pythia
Sun Jan 17 19:03:22 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPREQUEST(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e
Sun Jan 17 19:03:22 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPACK(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e pythia
Sun Jan 17 19:03:54 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPREQUEST(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e
Sun Jan 17 19:03:54 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPACK(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e pythia
Sun Jan 17 19:04:59 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPREQUEST(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e
Sun Jan 17 19:04:59 2021 daemon.info dnsmasq-dhcp[5272]:
DHCPACK(br-lan) 192.168.1.171 bc:5f:f4:0b:8b:7e pythia

dhcpcd.log:
Jan 17 13:02:49 [2677]: dhcpcd-8.1.9 starting
Jan 17 13:02:49 [2677]: enp5s0: executing `/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
Jan 17 13:02:49 [2677]: enp5s0: executing `/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
Jan 17 13:02:49 [2677]: DUID 00:01:00:01:23:05:83:2a:bc:5f:f4:0b:8b:7e
Jan 17 13:02:49 [2677]: enp5s0: IAID f4:0b:8b:7e
Jan 17 13:02:49 [2677]: enp5s0: delaying IPv4 for 0.4 seconds
Jan 17 13:02:49 [2677]: enp5s0: reading lease `/var/lib/dhcpcd/enp5s0.lease'
Jan 17 13:02:49 [2677]: enp5s0: discarding expired lease
Jan 17 13:02:49 [2677]: enp5s0: soliciting a DHCP lease
Jan 17 13:02:49 [2677]: enp5s0: sending DISCOVER (xid 0x4fc0b4fa),
next in 4.2 seconds
Jan 17 13:02:52 [2677]: enp5s0: offered 192.168.1.171 from 192.168.1.1
Jan 17 13:02:52 [2677]: enp5s0: sending REQUEST (xid 0x4fc0b4fa), next
in 4.6 seconds
Jan 17 13:02:52 [2677]: enp5s0: acknowledged 192.168.1.171 from 192.168.1.1
Jan 17 13:02:52 [2677]: enp5s0: probing address 192.168.1.171/24
Jan 17 13:02:52 [2677]: enp5s0: probing for 192.168.1.171
Jan 17 13:02:52 [2677]: enp5s0: ARP probing 192.168.1.171 (1 of 3),
next in 1.8 seconds
Jan 17 13:02:54 [2677]: enp5s0: ARP probing 192.168.1.171 (2 of 3),
next in 1.2 seconds
Jan 17 13:02:55 [2677]: enp5s0: ARP probing 192.168.1.171 (3 of 3),
next in 2.0 seconds
Jan 17 13:02:57 [2677]: enp5s0: DAD completed for 192.168.1.171
Jan 17 13:02:57 [2677]: enp5s0: leased 192.168.1.171 for 43200 seconds
Jan 17 13:02:57 [2677]: enp5s0: renew in 21600 seconds, rebind in 37800 seconds
Jan 17 13:02:57 [2677]: enp5s0: writing lease `/var/lib/dhcpcd/enp5s0.lease'
Jan 17 13:02:57 [2677]: enp5s0: adding IP address 192.168.1.171/24
broadcast 192.168.1.255
Jan 17 13:02:57 [2677]: enp5s0: adding route to 192.168.1.0/24
Jan 17 13:02:57 [2677]: enp5s0: adding default route via 192.168.1.1
Jan 17 13:02:57 [2677]: enp5s0: ARP announcing 192.168.1.171 (1 of 2),
next in 2.0 seconds
Jan 17 13:02:57 [2677]: enp5s0: executing `/lib/dhcpcd/dhcpcd-run-hooks' BOUND
Jan 17 13:02:57 [2677]: forking to background
Jan 17 13:02:57 [2677]: forked to background, child pid 2692
Jan 17 13:02:59 [2692]: enp5s0: ARP announcing 192.168.1.171 (2 of 2)
Jan 17 19:02:56 [2692]: enp5s0: renewing lease of 192.168.1.171
Jan 17 19:02:56 [2692]: enp5s0: sending REQUEST (xid 0x83f093dd), next
in 3.4 seconds
Jan 17 19:02:59 [2692]: enp5s0: sending REQUEST (xid 0x83f093dd), next
in 7.8 seconds
Jan 17 19:03:07 [2692]: enp5s0: sending REQUEST (xid 0x83f093dd), next
in 15.3 seconds
Jan 17 19:03:22 [2692]: enp5s0: sending REQUEST (xid 0x83f093dd), next
in 32.3 seconds
Jan 17 19:03:54 [2692]: enp5s0: sending REQUEST (xid 0x83f093dd), next
in 64.7 seconds
Jan 17 19:04:59 [2692]: enp5s0: sending REQUEST (xid 0x83f093dd), next
in 64.7 seconds

Follow-Ups:
Re: Lease renewal requests every 60 s with dhcpcd 8.1.9Roy Marples
Archive administrator: postmaster@marples.name