Gentoo Forums
Gentoo Forums
Gentoo Forums
Quick Search: in
[Solved] DHCPcd says it gets a lease and then uses an IPv4LL
View unanswered posts
View posts from last 24 hours

 
Reply to topic    Gentoo Forums Forum Index Networking & Security
View previous topic :: View next topic  
Author Message
ManDay
Apprentice
Apprentice


Joined: 22 Jan 2008
Posts: 247

PostPosted: Tue Mar 09, 2021 2:37 pm    Post subject: [Solved] DHCPcd says it gets a lease and then uses an IPv4LL Reply with quote

I start `dhcpcd`, which depends on in `iwd` with OpenRC, and there a ca. 50-50 chance that it either works flawlessly or uses a linklocal address for the next minutes until it spontaneously reconfigures. /var/log/messages says:
Code:
Mar  9 16:24:16 air dhcpcd[21407]: dev: loaded udev
Mar  9 16:24:16 air kernel: ath10k_pci 0000:03:00.0: unsupported HTC service id: 1536
Mar  9 16:24:17 air dhcpcd[21407]: no interfaces have a carrier
Mar  9 16:24:17 air dhcpcd[21407]: forked to background, child pid 21425
Mar  9 16:24:17 air dhcpcd[21425]: enp2s0: waiting for carrier
Mar  9 16:24:17 air dhcpcd[21425]: wlp3s0: waiting for carrier
Mar  9 16:24:17 air kernel: wlp3s0: authenticate with c8:3a:35:13:73:b8
Mar  9 16:24:18 air kernel: wlp3s0: send auth to c8:3a:35:13:73:b8 (try 1/3)
Mar  9 16:24:18 air kernel: wlp3s0: authenticated
Mar  9 16:24:18 air kernel: wlp3s0: associate with c8:3a:35:13:73:b8 (try 1/3)
Mar  9 16:24:18 air kernel: wlp3s0: RX AssocResp from c8:3a:35:13:73:b8 (capab=0x411 status=0 aid=4)
Mar  9 16:24:18 air kernel: wlp3s0: associated
Mar  9 16:24:18 air dhcpcd[21425]: wlp3s0: carrier acquired
Mar  9 16:24:18 air kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlp3s0: link becomes ready
Mar  9 16:24:18 air dhcpcd[21425]: wlp3s0: connected to Access Point `Todorovi'
Mar  9 16:24:18 air dhcpcd[21425]: DUID 00:01:00:01:1e:db:b3:2b:30:65:ec:9f:09:ab
Mar  9 16:24:18 air dhcpcd[21425]: wlp3s0: IAID 28:29:4d:fb
Mar  9 16:24:18 air dhcpcd[21425]: wlp3s0: rebinding lease of 192.168.0.104
Mar  9 16:24:20 air ntpd[1640]: Listen normally on 13 wlp3s0 192.168.0.104:123
Mar  9 16:24:20 air ntpd[1640]: Listen normally on 14 wlp3s0 [fe80::caff:28ff:fe29:4dfb%5]:123
Mar  9 16:24:23 air dhcpcd[21425]: wlp3s0: probing for an IPv4LL address
Mar  9 16:24:23 air dhcpcd[21425]: wlp3s0: DHCP lease expired
Mar  9 16:24:23 air dhcpcd[21425]: wlp3s0: soliciting a DHCP lease
Mar  9 16:24:24 air dhcpcd[21425]: wlp3s0: offered 192.168.0.104 from 192.168.0.1
Mar  9 16:24:24 air ntpd[1640]: Deleting interface #13 wlp3s0, 192.168.0.104#123, interface stats: received=0, sent=0, dropped=0, active_time=4 secs
Mar  9 16:24:28 air dhcpcd[21425]: wlp3s0: using IPv4LL address 169.254.222.17
Mar  9 16:24:28 air dhcpcd[21425]: wlp3s0: adding route to 169.254.0.0/16
Mar  9 16:24:28 air dhcpcd[21425]: wlp3s0: adding default route
Mar  9 16:24:29 air ntpd[1640]: Listen normally on 15 wlp3s0 169.254.222.17:123
Mar  9 16:28:36 air dhcpcd[21425]: wlp3s0: probing address 192.168.0.104/24
Mar  9 16:28:41 air dhcpcd[21425]: wlp3s0: leased 192.168.0.104 for 86400 seconds
Mar  9 16:28:41 air dhcpcd[21425]: wlp3s0: adding route to 192.168.0.0/24
Mar  9 16:28:41 air dhcpcd[21425]: wlp3s0: changing default route via 192.168.0.1
Mar  9 16:28:41 air dhcpcd[21425]: wlp3s0: deleting route to 169.254.0.0/16
Mar  9 16:28:41 air dhcpcd[21425]: wlp3s0: pid 21425 deleted default route via 192.168.0.1
Mar  9 16:28:42 air ntpd[1640]: Listen normally on 16 wlp3s0 192.168.0.104:123
Mar  9 16:28:42 air ntpd[1640]: Deleting interface #15 wlp3s0, 169.254.222.17#123, interface stats: received=0, sent=0, dropped=0, active_time=253 secs


Does anyone know why this is happening or how to fix it?


Last edited by ManDay on Mon Mar 29, 2021 9:14 am; edited 3 times in total
Back to top
View user's profile Send private message
turtles
Veteran
Veteran


Joined: 31 Dec 2004
Posts: 1656

PostPosted: Tue Mar 09, 2021 6:44 pm    Post subject: Reply with quote

Turn off IP4LL I think yo just lines at the end of /etc/dhcpcd.conf
Code:
noipv4ll

or noarp
see man /etc/dhcpcd.conf for more info
_________________
Donate to Gentoo
Back to top
View user's profile Send private message
UberLord
Retired Dev
Retired Dev


Joined: 18 Sep 2003
Posts: 6835
Location: Blighty

PostPosted: Wed Mar 10, 2021 6:53 am    Post subject: Re: DHCPcd says it gets a lease, and then uses an IPv4LL Reply with quote

ManDay wrote:
I start `dhcpcd`, which depends on in `iwd` with OpenRC, and there a ca. 50-50 chance that it either works flawlessly or uses a linklocal address for the next minutes until it spontaneously reconfigures. /var/log/messages says:
Code:
Mar  9 16:28:41 air dhcpcd[21425]: wlp3s0: adding route to 192.168.0.0/24
Mar  9 16:28:41 air dhcpcd[21425]: wlp3s0: changing default route via 192.168.0.1
Mar  9 16:28:41 air dhcpcd[21425]: wlp3s0: deleting route to 169.254.0.0/16
Mar  9 16:28:41 air dhcpcd[21425]: wlp3s0: pid 21425 deleted default route via 192.168.0.1


Does anyone know why this is happening or how to fix it?


Looks like a bug in dhcpcd.
What version is that please? If dhcpcd-8, can you test dhcpcd-9 please?
_________________
Use dhcpcd for all your automated network configuration needs
Use dhcpcd-ui (GTK+/Qt) as your System Tray Network tool
Back to top
View user's profile Send private message
ManDay
Apprentice
Apprentice


Joined: 22 Jan 2008
Posts: 247

PostPosted: Wed Mar 10, 2021 11:35 am    Post subject: Reply with quote

turtles: Thanks, I'll try that.
UberLord: I've updated to 9.4.0::gentoo and it still happens. (I've also removed ntpd but that didn't seem to matter):

Code:
Mar 10 13:31:33 air dhcpcd[5247]: main: control_open: Connection refused
Mar 10 13:31:33 air dhcpcd[5247]: dhcpcd-9.4.0 starting
Mar 10 13:31:33 air dhcpcd[5249]: dev: loaded udev
Mar 10 13:31:33 air dhcpcd[5249]: DUID 00:01:00:01:1e:db:b3:2b:30:65:ec:9f:09:ab
Mar 10 13:31:33 air kernel: ath10k_pci 0000:03:00.0: unsupported HTC service id: 1536
Mar 10 13:31:33 air dhcpcd[5249]: no interfaces have a carrier
Mar 10 13:31:33 air dhcpcd[5249]: enp2s0: waiting for carrier
Mar 10 13:31:33 air dhcpcd[5249]: wlp3s0: waiting for carrier
Mar 10 13:31:34 air kernel: wlp3s0: authenticate with c8:3a:35:13:73:b8
Mar 10 13:31:34 air kernel: wlp3s0: send auth to c8:3a:35:13:73:b8 (try 1/3)
Mar 10 13:31:34 air kernel: wlp3s0: send auth to c8:3a:35:13:73:b8 (try 2/3)
Mar 10 13:31:34 air kernel: wlp3s0: authenticated
Mar 10 13:31:34 air kernel: wlp3s0: associate with c8:3a:35:13:73:b8 (try 1/3)
Mar 10 13:31:34 air kernel: wlp3s0: RX AssocResp from c8:3a:35:13:73:b8 (capab=0x411 status=0 aid=5)
Mar 10 13:31:34 air kernel: wlp3s0: associated
Mar 10 13:31:34 air dhcpcd[5249]: wlp3s0: carrier acquired
Mar 10 13:31:34 air dhcpcd[5249]: wlp3s0: connected to Access Point: Todorovi
Mar 10 13:31:34 air kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlp3s0: link becomes ready
Mar 10 13:31:34 air dhcpcd[5249]: wlp3s0: IAID 28:29:4d:fb
Mar 10 13:31:36 air dhcpcd[5249]: wlp3s0: rebinding lease of 192.168.0.104
Mar 10 13:31:41 air dhcpcd[5249]: wlp3s0: probing for an IPv4LL address
Mar 10 13:31:41 air dhcpcd[5249]: wlp3s0: DHCP lease expired
Mar 10 13:31:41 air dhcpcd[5249]: wlp3s0: soliciting a DHCP lease
Mar 10 13:31:42 air dhcpcd[5249]: wlp3s0: offered 192.168.0.104 from 192.168.0.1
Mar 10 13:31:46 air dhcpcd[5249]: wlp3s0: probing for an IPv4LL address
Mar 10 13:31:51 air dhcpcd[5249]: wlp3s0: using IPv4LL address 169.254.222.17
Mar 10 13:31:51 air dhcpcd[5249]: wlp3s0: adding route to 169.254.0.0/16
Mar 10 13:31:51 air dhcpcd[5249]: wlp3s0: adding default route
Mar 10 13:31:53 air dhcpcd[5249]: wlp3s0: probing address 192.168.0.104/24
Mar 10 13:31:59 air dhcpcd[5249]: wlp3s0: leased 192.168.0.104 for 86400 seconds
Mar 10 13:31:59 air dhcpcd[5249]: wlp3s0: adding route to 192.168.0.0/24
Mar 10 13:31:59 air dhcpcd[5249]: wlp3s0: changing default route via 192.168.0.1
Mar 10 13:31:59 air dhcpcd[5249]: wlp3s0: deleting route to 169.254.0.0/16
Back to top
View user's profile Send private message
UberLord
Retired Dev
Retired Dev


Joined: 18 Sep 2003
Posts: 6835
Location: Blighty

PostPosted: Wed Mar 10, 2021 12:00 pm    Post subject: Reply with quote

That log looks ok to me - the key part is that the older version was deleting it's own default route here

Code:
dhcpcd[21425]: wlp3s0: pid 21425 deleted default route via 192.168.0.1


What you are seeing is that for some reason your DHCP server is not responding to the initial REBIND request.
When this happens dhcpcd starts IPv4LL and resquests a new lease.
What we now see is that it takes 11 seconds for the DHCP server to respond to the REQUEST we got from the DISCOVER.
IPv4LL takes less than 11 seconds, so this wins.

In a nutshell your DHCP server is very very slow or something is dropping packets or DHCP packets.
I had a bad experience of Ubiquiti wireless AP firmware dropping DHCP packets a few months ago and had to use beta firmware to work around it.

The key takeaway is that dhcpcd is doing the best it can and the real issue is in your infrastructure.
_________________
Use dhcpcd for all your automated network configuration needs
Use dhcpcd-ui (GTK+/Qt) as your System Tray Network tool
Back to top
View user's profile Send private message
ManDay
Apprentice
Apprentice


Joined: 22 Jan 2008
Posts: 247

PostPosted: Wed Mar 10, 2021 12:33 pm    Post subject: Reply with quote

Oh I see. I misinterpreted the log pessimistically, although it only took a couple of seconds for setup to complete successfully. Thanks very much!
Back to top
View user's profile Send private message
UberLord
Retired Dev
Retired Dev


Joined: 18 Sep 2003
Posts: 6835
Location: Blighty

PostPosted: Wed Mar 10, 2021 2:55 pm    Post subject: Reply with quote

As turtles said, if you cannot use IPv4LL then disable it in dhcpcd.conf and dhcpcd will then only fork once it gets a DHCP lease.
_________________
Use dhcpcd for all your automated network configuration needs
Use dhcpcd-ui (GTK+/Qt) as your System Tray Network tool
Back to top
View user's profile Send private message
ManDay
Apprentice
Apprentice


Joined: 22 Jan 2008
Posts: 247

PostPosted: Thu Mar 25, 2021 11:11 am    Post subject: Reply with quote

I still occasionally have this problem. Less often now, I think, but the logs still look like it get a lease which doesn't supersede IPv4LL (this time, I think, I'm not misinterpreting it). The version of dhcpcd is 9.3.4:

Code:
Mar 25 13:04:31 air dhcpcd[5497]: main: control_open: Connection refused
Mar 25 13:04:31 air dhcpcd[5497]: dhcpcd-9.3.4 starting
Mar 25 13:04:31 air dhcpcd[5499]: dev: loaded udev
Mar 25 13:04:31 air dhcpcd[5499]: DUID 00:01:00:01:1e:db:b3:2b:30:65:ec:9f:09:bb
Mar 25 13:04:31 air kernel: ath10k_pci 0000:03:00.0: unsupported HTC service id: 1536
Mar 25 13:04:31 air dhcpcd[5499]: no interfaces have a carrier
Mar 25 13:04:31 air dhcpcd[5499]: enp2s0: waiting for carrier
Mar 25 13:04:31 air dhcpcd[5499]: wlp3s0: waiting for carrier
Mar 25 13:04:32 air kernel: wlp3s0: authenticate with c8:3a:35:13:73:b8
Mar 25 13:04:32 air kernel: wlp3s0: send auth to c8:3a:35:13:73:b8 (try 1/3)
Mar 25 13:04:32 air kernel: wlp3s0: authenticated
Mar 25 13:04:32 air kernel: wlp3s0: associate with c8:3a:35:13:73:b8 (try 1/3)
Mar 25 13:04:32 air kernel: wlp3s0: RX AssocResp from c8:3a:35:13:73:b8 (capab=0x411 status=0 aid=4)
Mar 25 13:04:32 air kernel: wlp3s0: associated
Mar 25 13:04:32 air dhcpcd[5499]: wlp3s0: carrier acquired
Mar 25 13:04:32 air dhcpcd[5499]: wlp3s0: connected to Access Point: Todorovi
Mar 25 13:04:32 air kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlp3s0: link becomes ready
Mar 25 13:04:32 air dhcpcd[5499]: wlp3s0: IAID 28:29:4d:fb
Mar 25 13:04:34 air dhcpcd[5499]: wlp3s0: rebinding lease of 192.168.0.104
Mar 25 13:04:39 air dhcpcd[5499]: wlp3s0: probing for an IPv4LL address
Mar 25 13:04:39 air dhcpcd[5499]: wlp3s0: DHCP lease expired
Mar 25 13:04:39 air dhcpcd[5499]: wlp3s0: soliciting a DHCP lease
Mar 25 13:04:44 air dhcpcd[5499]: wlp3s0: probing for an IPv4LL address
Mar 25 13:04:44 air dhcpcd[5499]: wlp3s0: offered 192.168.0.104 from 192.168.0.1
Mar 25 13:04:48 air dhcpcd[5499]: wlp3s0: using IPv4LL address 169.254.222.17
Mar 25 13:04:48 air dhcpcd[5499]: wlp3s0: adding route to 169.254.0.0/16
Mar 25 13:04:48 air dhcpcd[5499]: wlp3s0: adding default route
Back to top
View user's profile Send private message
turtles
Veteran
Veteran


Joined: 31 Dec 2004
Posts: 1656

PostPosted: Fri Mar 26, 2021 12:39 am    Post subject: Reply with quote

post your dhcpcd.conf
_________________
Donate to Gentoo
Back to top
View user's profile Send private message
ManDay
Apprentice
Apprentice


Joined: 22 Jan 2008
Posts: 247

PostPosted: Sat Mar 27, 2021 4:35 pm    Post subject: Reply with quote

Code:
hostname
ipv4only
nohook resolv.conf
duid
timeout 90
persistent
option rapid_commit
option domain_name_servers, domain_name, domain_search, host_name
option classless_static_routes
option ntp_servers
option interface_mtu
define 81 embed fqdn
embed byte flags
embed byte flags
embed byte rcode1
embed byte rcode2
embed domain fqdn
Back to top
View user's profile Send private message
turtles
Veteran
Veteran


Joined: 31 Dec 2004
Posts: 1656

PostPosted: Sat Mar 27, 2021 10:20 pm    Post subject: Reply with quote

Add
noipv4ll
to the end of the file
_________________
Donate to Gentoo
Back to top
View user's profile Send private message
ManDay
Apprentice
Apprentice


Joined: 22 Jan 2008
Posts: 247

PostPosted: Sun Mar 28, 2021 5:39 am    Post subject: Reply with quote

Sorry, I should have been clearer: I understand that would "solve" my problem, but it should also work with IPv4LL enabled, no?
Back to top
View user's profile Send private message
UberLord
Retired Dev
Retired Dev


Joined: 18 Sep 2003
Posts: 6835
Location: Blighty

PostPosted: Sun Mar 28, 2021 3:29 pm    Post subject: Reply with quote

Because the DHCP lease expires, getting a new one is a 4 step process

client sends discover -> server replies with an address - > client requests address - > server acknowledges the address
Unless you have `noarp` in your config, dhcpcd will then spent several seconds ensuring the address is not in use by someone else.

Because your DHCP server is slow, dhcpcd is also handling IPv4LL at the same time.
It's not superceeding DHCP at all, but working alongside.

Once dhcpcd binds the address, it will remove the IPv4LL address. But it needs to go through all the above steps which could take upto 11 seconds or so on a bad day with high randomisation values.

For reference here are the two lines where the DHCP process above starts and stops.
Code:
wlp3s0: soliciting a DHCP lease
wlp3s0: leased 192.168.0.104 for 86400 seconds


According to your most recent log, you got the IPv4LL address at step 2/4 above.

There really is nothing wrong with dhcpcd here.
What is wrong is the length of time between dhcpcd sending a request and your DHCP server replying.
You should investigate that really. tcpdump is your friend here, especially if you can run that on the DHCP server as well.
_________________
Use dhcpcd for all your automated network configuration needs
Use dhcpcd-ui (GTK+/Qt) as your System Tray Network tool
Back to top
View user's profile Send private message
Tony0945
Watchman
Watchman


Joined: 25 Jul 2006
Posts: 5127
Location: Illinois, USA

PostPosted: Sun Mar 28, 2021 4:07 pm    Post subject: Reply with quote

Ah! I see from Uberlord's response that the DHCP server seems to be at fault. Are you using your router for DHCP? I'm using DNSmasq on a separate computer but you can use it on your computer or indeed establish a fixed ip address.
What is your router model? I went to DNSmasq because my ISP's DNS, in a word, sucked. I went the further step to using DNSMasq for DHCP because it gave me more flexibility over the router.
Back to top
View user's profile Send private message
ManDay
Apprentice
Apprentice


Joined: 22 Jan 2008
Posts: 247

PostPosted: Sun Mar 28, 2021 4:16 pm    Post subject: Reply with quote

Thanks. Just to be clear: The IPv4LL address did not stay around for mere seconds (in the above case with log), but I did not get a LAN address for several minutes, after which point I got tired of waiting and restarted.

So, from what you say I understand the server sent the offer (step 2), my requesting the address (step 3) happend but does not actually show up in the log, and the server for some reason never got around to acknowledge the address (step 4), so dhcpcd stuck with the LL address. Is that about right?

I will try (knowing that nothing's wrong on my end), but I suspect in that case desactivating IPv4LL will not help, if the server does not comply with step 4.

(no idea what the router is and I don't have access to it either; it's some ISP provided box and it's not my network, either)
Back to top
View user's profile Send private message
UberLord
Retired Dev
Retired Dev


Joined: 18 Sep 2003
Posts: 6835
Location: Blighty

PostPosted: Sun Mar 28, 2021 6:30 pm    Post subject: Reply with quote

ManDay wrote:
Thanks. Just to be clear: The IPv4LL address did not stay around for mere seconds (in the above case with log), but I did not get a LAN address for several minutes, after which point I got tired of waiting and restarted.

So, from what you say I understand the server sent the offer (step 2), my requesting the address (step 3) happend but does not actually show up in the log, and the server for some reason never got around to acknowledge the address (step 4), so dhcpcd stuck with the LL address. Is that about right?

I will try (knowing that nothing's wrong on my end), but I suspect in that case desactivating IPv4LL will not help, if the server does not comply with step 4.


Correct.
It will just take a long time to get an address via DHCP.

Quote:
(no idea what the router is and I don't have access to it either; it's some ISP provided box and it's not my network, either)


Well, I would speak with the network owner about the issue :)

If it's a crappy router you could try swapping duid for clientid in dhcpcd.conf or removing both altogether.
If that works then then answer is simple - it's a crappy router that doesn't respect RFC's.
_________________
Use dhcpcd for all your automated network configuration needs
Use dhcpcd-ui (GTK+/Qt) as your System Tray Network tool
Back to top
View user's profile Send private message
turtles
Veteran
Veteran


Joined: 31 Dec 2004
Posts: 1656

PostPosted: Sun Mar 28, 2021 9:18 pm    Post subject: Reply with quote

Agreed
having dealt with many crappy internet connections,
I keep IP4LL disabled unless I am trying to use it, that forces me to dig into the other issues.

It never forwards anything to the internet and gives you system a false sense of connection.
https://tools.ietf.org/html/rfc3927#section-2.7

Run some tcpdump commands and we'll see whats going on.
Probably on the edge of WIFI range?
Or if its wired could be a bad cable or NIC.
_________________
Donate to Gentoo
Back to top
View user's profile Send private message
ManDay
Apprentice
Apprentice


Joined: 22 Jan 2008
Posts: 247

PostPosted: Mon Mar 29, 2021 9:14 am    Post subject: Reply with quote

I will try what you said. Since the update to >=dhcpcd-9 the problem occurs rarely, though, so it's kind of difficult to analyze (with tcpdump or changing settings).
Back to top
View user's profile Send private message
Display posts from previous:   
Reply to topic    Gentoo Forums Forum Index Networking & Security All times are GMT
Page 1 of 1

 
Jump to:  
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum