DCHP failing to give IP

mainlake · May 25, 2020, 12:20pm

Expected Behaviour:

Device gets an IP immediately.

Actual Behaviour:

It takes up to few minutes for device to connect.

Debug Token:

https://tricorder.pi-hole.net/2cpq06j642

What happens is that device doesn't connect directly to WLAN, but takes few minutes before connection is working. My network consist of Google Wifi (X3) and pihole raspberry. Set up is the same as in option 2 How to run Pi-Hole with Google WiFi (Raspberry Pi 4) – MBReviews. And Mesh activated.

pihole.log when this occured:

May 25 11:05:50 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:05:50 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:05:51 dnsmasq-dhcp[30824]: RTR-SOLICIT(wlan0) X:X:X:X:X:80
May 25 11:05:52 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:05:52 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:05:55 dnsmasq-dhcp[30824]: RTR-SOLICIT(wlan0) X:X:X:X:X:80
May 25 11:05:56 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:05:56 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:06:04 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:06:04 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:06:04 dnsmasq-dhcp[30824]: RTR-SOLICIT(wlan0) X:X:X:X:X:80
May 25 11:06:21 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:06:21 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:06:22 dnsmasq-dhcp[30824]: RTR-SOLICIT(wlan0) X:X:X:X:X:80
May 25 11:06:47 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:06:47 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:06:48 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:06:48 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:06:51 dnsmasq-dhcp[30824]: RTR-SOLICIT(wlan0) X:X:X:X:X:80
May 25 11:06:52 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:06:52 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:07:01 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:07:01 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:07:15 dnsmasq-dhcp[30824]: RTR-SOLICIT(wlan0) X:X:X:X:X:80
May 25 11:07:15 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:07:15 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:07:26 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:07:26 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:07:28 dnsmasq-dhcp[30824]: RTR-SOLICIT(wlan0) X:X:X:X:X:80
May 25 11:07:28 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:07:28 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:07:32 dnsmasq-dhcp[30824]: RTR-SOLICIT(wlan0) X:X:X:X:X:80
May 25 11:07:32 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:07:32 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:07:40 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:07:40 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:07:40 dnsmasq-dhcp[30824]: RTR-SOLICIT(wlan0) X:X:X:X:X:80
May 25 11:07:56 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:07:56 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:03 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:08:03 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:03 dnsmasq-dhcp[30824]: DHCPREQUEST(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:03 dnsmasq-dhcp[30824]: DHCPACK(wlan0) 192.168.86.39 X:X:X:X:X:80 OnePlus7
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPREQUEST(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPACK(wlan0) 192.168.86.39 X:X:X:X:X:80 OnePlus7
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPREQUEST(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPACK(wlan0) 192.168.86.39 X:X:X:X:X:80 OnePlus7
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPREQUEST(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPACK(wlan0) 192.168.86.39 X:X:X:X:X:80 OnePlus7
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPREQUEST(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:05 dnsmasq-dhcp[30824]: DHCPACK(wlan0) 192.168.86.39 X:X:X:X:X:80 OnePlus7
May 25 11:08:05 dnsmasq-dhcp[30824]: RTR-SOLICIT(wlan0) X:X:X:X:X:80
May 25 11:08:09 dnsmasq-dhcp[30824]: RTR-SOLICIT(wlan0) X:X:X:X:X:80
May 25 11:08:23 dnsmasq-dhcp[30824]: DHCPREQUEST(wlan0) 192.168.86.39 X:X:X:X:X:80 
May 25 11:08:23 dnsmasq-dhcp[30824]: DHCPACK(wlan0) 192.168.86.39 X:X:X:X:X:80 OnePlus7
May 25 11:08:33 dnsmasq-dhcp[30824]: RTR-SOLICIT(wlan0) X:X:X:X:X:80

Bucking_Horn · May 26, 2020, 8:59am

Contrary to your topic's title, this looks very much like your client failing to accept a DHCPOFFER. (click for details)

Your client broadcasts to discover DHCP servers:

11:05:50 dnsmasq-dhcp[30824]: DHCPDISCOVER(wlan0) X:X:X:X:X:80

Pi-hole then suggests an IP address for your client:

11:05:50 dnsmasq-dhcp[30824]: DHCPOFFER(wlan0) 192.168.86.39 X:X:X:X:X:80

However, your client keeps repeating its DHCPDISCOVER, until it choses to request assignment of the address as offered:

11:08:03 dnsmasq-dhcp[30824]: DHCPREQUEST(wlan0) 192.168.86.39 X:X:X:X:X:80

Pi-hole then acknowledges the lease:

11:08:03 dnsmasq-dhcp[30824]: DHCPACK(wlan0) 192.168.86.39 X:X:X:X:X:80 OnePlus7

So Pi-hole is exhibiting correct behaviour as far as DHCP is concerned.

Your client is either not receiving Pi-hole's DHCP answers (unlikely, as it works after some time, proving your client does read Pi-hole), or it is actively discarding the offer.

The latter would happen if another DHCP server is active on your network and your client prefers that alternate server's offer over Pi-hole.
However, your client wouldn't repeat its discovery broadcasts in that case, which in turn could mean IP address assignment has been acknowledged by that server, but your client declined it because it failed the final collision test.

My guess is that your alternate DHCP server (likely, your Google WiFi) is handing out an IP address that is already taken by another device, and your client struggles to prefer Pi-hole over that other server (presumably because your Mesh steers it towards that alternate, but that is a far call on my behalf).

It's not entirely clear to me whether "Google Wifi (X3)" means you are using one model X3 Google Wifi in your network or some unspecified but identical Google WiFi times 3.

If you are indeed running three Google APs in your network, consider running only the one that's connected to the Internet as DHCP server, as that has to take care of Pi-hole's IP (and preferably, Pi-hole's IP only). If possible, disable DHCP on the other APs.

In any case, you should always verify that IP address ranges on individual DHCP servers do not overlap when running multiple DHCP servers for the same network segment.

mainlake · May 26, 2020, 9:55am

Thanks for the detailed explanation, now I'm able understand the logs better
More detailed information: GW (X3) means three GW pucks with mesh enabled, and one of them is connected to ISP. GW is using pihole as DHCP server, i.e. pool starts and ends to pihole static ip (given by GW). Device connecting itself has static IP set in pihole DHCP.
I've now given static IP's for the 2X mesh GW pucks as well, let see if that changes anything...

mainlake · May 27, 2020, 5:36pm

Static IP for GW pucks didn't help.
It seems that when the connection changes from puck to another this issue appears, this it might have something to do with the mesh functionality.

Bucking_Horn · May 27, 2020, 6:18pm

In that case, see if you can get a hold of a DHCP activity log on those GW pucks (though I fear it maybe wishful thinking on my behalf to assume that would be as accessible as Pi-hole in that regard).

Also, what device are your two slave GW using for DHCP - the master GW or Pi-hole?

mainlake · May 28, 2020, 4:01pm

Yeah, I'd need to "root" GW in order to access the logs. I assume that they are using pi-hole as they are visible in the pi-hole DHCP list.
One solution would be to let GW handle DHCP and see if it works, but then I'd lose exact information on which devices are sending the requests. On the other hand this might not be relevant information for me, only nice to know...

system · June 18, 2020, 4:10pm

This topic was automatically closed 21 days after the last reply. New replies are no longer allowed.