DHCP Clients don't get addesses

Help
1

As in previous post, DHCP clients don't Request

I’ve installed Pi-hole in a VM (again, from scrach) running CentOS, with bridged network and static IP assigned.

This time, in the logs I see that it receives Discover, but replies with DHCPNAK, wrong address, although the address is correct and within the configured range. Yet somehow it is in the ‘active leases’ list

I checked all possible firewalls, ran pcap on differnt points, disabled Wi-Fi rekey, with no luck, eventually, I deployed another VM with another DHCP software, on the same host and vSwitch, and worked without any issue.

Any ideas?

https://tricorder.pi-hole.net/VuXi6Cgw

2

Although I can see (DHCPDISCOVER, DHCPREQUEST, DHCPACK, DHCPOFFER) messages, sometimes I get the error (dnsmasq-dhcp: DHCP packet received on eth0 which has no address) and suffice to say that the server has one network on eth0 where the above DHCP messages where received!

3

This seems expected:
If a client sends a DHCPREQUEST for an IP address that a DHCP server has already assigned to another active lease, it won't acknowledge that request.

How did you configure your Pi-hole host machine's IPv4 address?

If that message isn't just showing during boot, this would suggest that eth0 would still be configured to dynamically acquire an IP address.
As a DHCP server cannot assign an IP to its own host, that would require another active DHCP server on your network.
While that's possible (provided both DHCP servers are configured with appropriate care), it would be preferred to instead configure a static IP directly on your host OS, via that OS's network management tool.

4

No client was assigned any IP address, and the configured range on Pi-hole is free, no IP address was used in any way.

IP address is assigned on CentOS statically, and message was not shown during boot.

5

Please provide a fresh debug token.

6

https://tricorder.pi-hole.net/KNrFmQ8b

7

Your debug log indicates that you run your VM on a Microsoft hypervisor, and it shows that your CentOS VM is correctly making use of a static IP:

*** [ DIAGNOSING ]: Network interfaces and addresses
   (…)
   2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group default qlen 1000
       altname enx00<redacted>
       inet 192.168.0.4/24 brd 192.168.0.255 scope global noprefixroute eth0
          valid_lft forever preferred_lft forever

Pi-hole's DHCP server is enabled, but the debug log does not show any DHCP replies on its host's eth0 link:

*** [ DIAGNOSING ]: Discovering active DHCP servers (takes 6 seconds)
   Scanning all your interfaces for DHCP servers and IPv6 routers
   Timeout: 6 seconds
   
   No answer on eth0

By chance, the debug log also contains the respective complete DHCP exchange (even a detailed one, since dhcp.logging is enabled):

-----tail of pihole.log------
   (…)
   Sep 27 18:46:51 dnsmasq-dhcp[917]: 262836907 available DHCP range: 192.168.0.214 -- 192.168.0.245
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 DHCPDISCOVER(eth0) 00:<redacted>c 
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 tags: eth0
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 DHCPOFFER(eth0) 192.168.0.242 00:<redacted>c 
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 next server: 192.168.0.4
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 broadcast response
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 sent size:  1 option: 53 message-type  2
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 sent size:  4 option: 54 server-identifier  192.168.0.4
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 sent size:  4 option: 51 lease-time  14d
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 sent size:  4 option: 58 T1  7d
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 sent size:  4 option: 59 T2  12d6h
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 sent size:  4 option:  1 netmask  255.255.255.0
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 sent size:  4 option: 28 broadcast  192.168.0.255
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 sent size:  4 option:  6 dns-server  192.168.0.4
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 sent size:  3 option: 15 domain-name  lan
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 sent size:  4 option: 42 ntp-server  192.168.0.4
   Sep 27 18:46:54 dnsmasq-dhcp[917]: 262836907 sent size:  4 option:  3 router  192.168.0.1

This demonstrates that Pi-hole's DHCP server has received the debug log triggered client's DHCPDISCOVER broadcast, and it has correcly sent a corresponding DHCPOFFER.
However, the debug log client did not react on that, which would suggest that it has never received that DHCPOFFER (which is what above No answer on eth0 confirms).

This would indicate that something has interfered with the DHCPOFFER.

As those are same-link exchanges on a virtual NIC provided by your VM, it would be interesting to see an actual DHCP exchange with a real network client, specifically one that is neither your VM host nor a VM hosted by it.

You could extract those DHCP exchanges from your log, e.g.

sudo grep -e "Sep 29 08:2.*dnsmasq-dhcp" /var/log/pihole.log > extract.log

Adopt the time part Sep 29 08:2 as required - above example would extract all DHCP lines logged from Sep 29 08:20:00 until Sep 29 08:29:59 to a file extract.log.

You can then upload that file to share its token, e.g. via:

cat extract.log | pihole tricorder

Afterwards, please share the token.

8

Using the command without date:

grep -e "dnsmasq-dhcp" /var/log/pihole/pihole*.log > extract.log

The result is what you have shown above, nothing else. And this is the exchange with the Hyper-V host.

I’d like to clarify that in my original post, The other VM I mentioned is Sophos Firewall, which is in the same vSwitch as Pi-hole, and when I disabled all DHCP servers and enabled DHCP server on Sophos firewall, it worked like charm with all devices on the network.

I did that to check if anything on vSwitch or Hyper-V host machine had anything to interfere with DHCP exchange.

I previously moved from Debian to CentOS for Pi-hole trying to solve this issue.

Any thoughts?

9

Did one of your real network clients actually try to acquire a DHCP release?

If so, that would demonstrate that your network's DHCP broadcasts never make it to your Pi-hole VM.

10

Of course, and here is an example of the logs for two of them, MAC addresses and hostnames are masked:

Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 DHCPDISCOVER(eth0) 192.168.0.191 xx:xx:xx:xx:xx:xx
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 tags: eth0
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 DHCPOFFER(eth0) 192.168.0.241 xx:xx:xx:xx:xx:xx
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 requested options: 1:netmask, 3:router, 6:dns-server, 12:hostname, 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 requested options: 15:domain-name, 28:broadcast, 42:ntp-server
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 next server: 192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 broadcast response
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  1 option: 53 message-type  2
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option: 54 server-identifier  192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option: 51 lease-time  14d
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option: 58 T1  7d
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option: 59 T2  12d6h
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option:  1 netmask  255.255.255.0
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option: 28 broadcast  192.168.0.255
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option:  6 dns-server  192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  3 option: 15 domain-name  lan
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option: 42 ntp-server  192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option:  3 router  192.168.0.1
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 available DHCP range: 192.168.0.214 -- 192.168.0.245
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 vendor class: android-dhcp-16
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 client provides name: xxx
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 DHCPDISCOVER(eth0)  
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 tags: eth0
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 DHCPOFFER(eth0) 192.168.0.226 yy:yy:yy:yy:yy:yy 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 requested options: 1:netmask, 3:router, 6:dns-server, 15:domain-name, 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 requested options: 26:mtu, 28:broadcast, 51:lease-time, 58:T1, 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 requested options: 59:T2, 43:vendor-encap, 114, 108:ipv6-only
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 next server: 192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  1 option: 53 message-type  2
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 54 server-identifier  192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 51 lease-time  14d
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 58 T1  7d
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 59 T2  12d6h
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option:  1 netmask  255.255.255.0
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 28 broadcast  192.168.0.255
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option:  6 dns-server  192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  3 option: 15 domain-name  lan
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option:  3 router  192.168.0.1
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 available DHCP range: 192.168.0.214 -- 192.168.0.245
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 vendor class: android-dhcp-16
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 client provides name: xxx
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 DHCPDISCOVER(eth0) yy:yy:yy:yy:yy:yy 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 tags: eth0
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 DHCPOFFER(eth0) 192.168.0.226 yy:yy:yy:yy:yy:yy 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 requested options: 1:netmask, 3:router, 6:dns-server, 15:domain-name, 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 requested options: 26:mtu, 28:broadcast, 51:lease-time, 58:T1, 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 requested options: 59:T2, 43:vendor-encap, 114, 108:ipv6-only
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 next server: 192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  1 option: 53 message-type  2
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 54 server-identifier  192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 51 lease-time  14d
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 58 T1  7d
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 59 T2  12d6h
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option:  1 netmask  255.255.255.0
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 28 broadcast  192.168.0.255
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option:  6 dns-server  192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  3 option: 15 domain-name  lan
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option:  3 router  192.168.0.1
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 available DHCP range: 192.168.0.214 -- 192.168.0.245
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 vendor class: android-dhcp-16
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 client provides name: xxx
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 DHCPDISCOVER(eth0) yy:yy:yy:yy:yy:yy 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 tags: eth0
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 DHCPOFFER(eth0) 192.168.0.226 yy:yy:yy:yy:yy:yy 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 requested options: 1:netmask, 3:router, 6:dns-server, 15:domain-name, 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 requested options: 26:mtu, 28:broadcast, 51:lease-time, 58:T1, 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 requested options: 59:T2, 43:vendor-encap, 114, 108:ipv6-only
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 next server: 192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  1 option: 53 message-type  2
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 54 server-identifier  192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 51 lease-time  14d
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 58 T1  7d
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 59 T2  12d6h
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option:  1 netmask  255.255.255.0
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option: 28 broadcast  192.168.0.255
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option:  6 dns-server  192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  3 option: 15 domain-name  lan
Sep 27 18:45:49 dnsmasq-dhcp[917]: 1305183617 sent size:  4 option:  3 router  192.168.0.1
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 available DHCP range: 192.168.0.214 -- 192.168.0.245
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 vendor class: udhcp 1.12.1
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 DHCPDISCOVER(eth0) 192.168.0.191 xx:xx:xx:xx:xx:xx
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 tags: eth0
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 DHCPOFFER(eth0) 192.168.0.241 xx:xx:xx:xx:xx:xx
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 requested options: 1:netmask, 3:router, 6:dns-server, 12:hostname, 
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 requested options: 15:domain-name, 28:broadcast, 42:ntp-server
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 next server: 192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 broadcast response
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  1 option: 53 message-type  2
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option: 54 server-identifier  192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option: 51 lease-time  14d
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option: 58 T1  7d
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option: 59 T2  12d6h
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option:  1 netmask  255.255.255.0
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option: 28 broadcast  192.168.0.255
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option:  6 dns-server  192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  3 option: 15 domain-name  lan
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option: 42 ntp-server  192.168.0.4
Sep 27 18:45:49 dnsmasq-dhcp[917]: 2256860722 sent size:  4 option:  3 router  192.168.0.1
11

My request was to grep relevant lines to a file, to upload that and then share the token, so you wouldn't have to sanitise your output, and I could still see IDs.

Your output dates back to Sep 27, showing the same lack of client reactions to Pi-hole's DHCPOFFER as in your debug log.

That would suggest that clients have never received that DHCPOFFER (or -unlikely- that they have ignored it).

Apparently, something in your network is interfering with those DHCPOFFERs.

Note that commonly, a DHCPOFFER is an unusual(!) unicast to an existent level 2 hardware id and a yet unassigned IPv4 address.

There are quite a few reasons why this could fail, e.g. your VM's network stack is not prepared to deliver them (e.g. if the hardware id may be on a different link, or because it doesn't support unicasts to non-existing IPs), or your host's network stack may drop it due to the non-existent IP, or a firewall in your network is discarding it altogether.

12

There are quite a few reasons why this could fail, e.g. your VM's network stack is not prepared to deliver them (e.g. if the hardware id may be on a different link, or because it doesn't support unicasts to non-existing IPs), or your host's network stack may drop it due to the non-existent IP, or a firewall in your network is discarding it altogether.

Alright, I did the ultimate test! Just installed and configured kea-dhcp4 server in CentOS, same VM/OS where Pi-hole lives, et Voila! It worked!
So hypervisor host, VM network, or any firewall are no longer related, as they are the SAME as Pi-hole’s.

13

So far, your Pi-hole's dnsmasq-dhcp log excerpts clearly show that Pi-hole correctly has sent its DHCPOFFER, but clients never follow up with a corresponding DHCPREQUEST.
The debug log output further suggests that the DHCPOFFER did not make it to the client.

We could try to have a look what's actually going on the wire.

While clients request a DHCP lease, you could capture DHCP traffic for a 15 second period to dhcp.txt, by running the following command in your Pi-hole VM:

timeout 15 sudo tcpdump -i eth0 -vne port 67 and port 68 > dhcp.txt

Make sure you did capture some DHCP exchange and then upload it to share its token:

cat dhcp.txt | sudo pihole tricorder

Afterwards, please share the token.

14

When I tried again to do the pcap, Pi-hole DHCP worked. Issue is finally resolved!

However, I’m not sure what solved it, as these changes happened between successful and unsuccessful tries:
1- I ran the command:

dnf update

2- Kea DHCP was installed, configured, enabled, started, stopped, then disabled.

3- Tcpdump was installed.

4- When I ran the command:

nmcli device show eth0

There was the following warning:

Warning: nmcli (1.55.4) and NetworkManager (1.54.0) versions don't match. Restarting NetworkManager is advised.

NetworkManager was restarted, and no more warnings.

systemctl restart NetworkManager

It is worth mentioning that I installed Kea DHCP previously on Debian, but didn’t configure it or start it, tcpdump was already there.

It might be also worth mentioning that SELinux is disabled on CentOS from the begining.

I’ll try to re-produce the issue with a fresh VM, but it will take time.

Thanks!