Arch Linux

Enverex

Member

From: UK

Registered: 2007-06-13

Posts: 159

Website

DHCPCD Delay and False "Lease Expired" Message

I'm having two problems with DHCPCD at the moment. First is that it's taking roughly 30 seconds to get a lease. The second issue is that it's falsely reporting that the lease has expired every single time I boot (or run DHCPCD) despite it being well within the actual lease time.

Here's the output from the first run:

● dhcpcd.service - dhcpcd on all interfaces
   Loaded: loaded (/usr/lib/systemd/system/dhcpcd.service; enabled; vendor preset: disabled)
   Active: active (running) since Mon 2015-08-10 11:26:10 BST; 12min ago
 Main PID: 219 (dhcpcd)
   CGroup: /system.slice/dhcpcd.service
           └─219 /usr/bin/dhcpcd -q -b

Aug 10 11:26:10 ce00 systemd[1]: Starting dhcpcd on all interfaces...
Aug 10 11:26:10 ce00 systemd[1]: Started dhcpcd on all interfaces.
Aug 10 11:26:11 ce00 dhcpcd[219]: all: IPv6 kernel autoconf disabled
Aug 10 11:26:11 ce00 dhcpcd[219]: eth0: adding address fe80::e1e5:7896:6c49:e92b
Aug 10 11:26:11 ce00 dhcpcd[219]: if_addaddress6: Operation not supported
Aug 10 11:26:11 ce00 dhcpcd[219]: eth0: if_up: No such device
Aug 10 11:26:11 ce00 dhcpcd[219]: eth0: waiting for carrier
Aug 10 11:26:11 ce00 dhcpcd[219]: eth0: removing interface
Aug 10 11:26:11 ce00 dhcpcd[219]: all: IPv6 kernel autoconf disabled
Aug 10 11:26:11 ce00 dhcpcd[219]: enp0s25: adding address fe80::e1e5:7896:6c49:e92b
Aug 10 11:26:11 ce00 dhcpcd[219]: if_addaddress6: Operation not supported
Aug 10 11:26:11 ce00 dhcpcd[219]: enp0s25: waiting for carrier
Aug 10 11:26:13 ce00 dhcpcd[219]: enp0s25: carrier acquired
Aug 10 11:26:13 ce00 dhcpcd[219]: all: IPv6 kernel autoconf disabled
Aug 10 11:26:13 ce00 dhcpcd[219]: DUID 00:01:00:01:1d:4b:81:f3:78:2b:cb:87:4d:00
Aug 10 11:26:13 ce00 dhcpcd[219]: enp0s25: IAID cb:87:4d:00
Aug 10 11:26:14 ce00 dhcpcd[219]: enp0s25: rebinding lease of 192.168.5.34
Aug 10 11:26:19 ce00 dhcpcd[219]: enp0s25: DHCP lease expired
Aug 10 11:26:19 ce00 dhcpcd[219]: enp0s25: soliciting a DHCP lease
Aug 10 11:26:47 ce00 dhcpcd[219]: enp0s25: offered 192.168.5.34 from 192.168.0.47
Aug 10 11:26:47 ce00 dhcpcd[219]: enp0s25: leased 192.168.5.34 for 432000 seconds
Aug 10 11:26:47 ce00 dhcpcd[219]: enp0s25: adding route to 192.168.0.0/21
Aug 10 11:26:47 ce00 dhcpcd[219]: enp0s25: adding default route via 192.168.0.1
Aug 10 11:26:47 ce00 dhcpcd[219]: enp0s25: removing route to 192.168.0.0/21

And then the code from the second run:

● dhcpcd.service - dhcpcd on all interfaces
   Loaded: loaded (/usr/lib/systemd/system/dhcpcd.service; enabled; vendor preset: disabled)
   Active: active (running) since Mon 2015-08-10 11:39:56 BST; 1min 31s ago
  Process: 209 ExecStart=/usr/bin/dhcpcd -q -b (code=exited, status=0/SUCCESS)
 Main PID: 215 (dhcpcd)
   CGroup: /system.slice/dhcpcd.service
           └─215 /usr/bin/dhcpcd -q -b

Aug 10 11:39:56 ce00 systemd[1]: Starting dhcpcd on all interfaces...
Aug 10 11:39:56 ce00 dhcpcd[209]: no valid interfaces found
Aug 10 11:39:56 ce00 systemd[1]: Started dhcpcd on all interfaces.
Aug 10 11:39:57 ce00 dhcpcd[215]: eth0: adding address fe80::e1e5:7896:6c49:e92b
Aug 10 11:39:57 ce00 dhcpcd[215]: if_addaddress6: Operation not supported
Aug 10 11:39:57 ce00 dhcpcd[215]: eth0: if_up: No such device
Aug 10 11:39:57 ce00 dhcpcd[215]: eth0: waiting for carrier
Aug 10 11:39:57 ce00 dhcpcd[215]: eth0: removing interface
Aug 10 11:39:57 ce00 dhcpcd[215]: enp0s25: adding address fe80::e1e5:7896:6c49:e92b
Aug 10 11:39:57 ce00 dhcpcd[215]: if_addaddress6: Operation not supported
Aug 10 11:39:57 ce00 dhcpcd[215]: enp0s25: waiting for carrier
Aug 10 11:39:59 ce00 dhcpcd[215]: enp0s25: carrier acquired
Aug 10 11:39:59 ce00 dhcpcd[215]: DUID 00:01:00:01:1d:4b:81:f3:78:2b:cb:87:4d:00
Aug 10 11:39:59 ce00 dhcpcd[215]: enp0s25: IAID cb:87:4d:00
Aug 10 11:40:00 ce00 dhcpcd[215]: enp0s25: rebinding lease of 192.168.5.34
Aug 10 11:40:05 ce00 dhcpcd[215]: enp0s25: DHCP lease expired
Aug 10 11:40:05 ce00 dhcpcd[215]: enp0s25: soliciting a DHCP lease
Aug 10 11:40:32 ce00 dhcpcd[215]: enp0s25: offered 192.168.5.34 from 192.168.0.47
Aug 10 11:40:32 ce00 dhcpcd[215]: enp0s25: leased 192.168.5.34 for 432000 seconds
Aug 10 11:40:32 ce00 dhcpcd[215]: enp0s25: adding route to 192.168.0.0/21
Aug 10 11:40:32 ce00 dhcpcd[215]: enp0s25: adding default route via 192.168.0.1
Aug 10 11:40:32 ce00 dhcpcd[215]: enp0s25: removing route to 192.168.0.0/21

Notice it's given a lease time of 432000 seconds, yet claims it's expired when the machine is restarted 12 minutes later.

Also it requests a lease at 11:40:05 and it takes until 11:40:32 before it actually gets one.

rsmarples

Member

Registered: 2009-05-12

Posts: 287

Re: DHCPCD Delay and False "Lease Expired" Message

enp0s25: adding address fe80::e1e5:7896:6c49:e92b
if_addaddress6: Operation not supported

That is the only error of concern that I can see. What version of dhcpcd do you have?
How is dhcpcd built? Does your kernel have IPv6 enabled?

As to the lease "expiring", it's because your router is taking a long time to get back to you when dhcpcd starts up.
We expire the lease so we can move from the REBIND phase to the DISCOVER phase quickly because if you move to a different network, a correct DHCP server will still remain silent if you REBIND a lease that is incorrect.

I can't do anything about your router being slow to respond though.