DHCP Server and Raspberry Pi clients

Debug Token: https://tricorder.pi-hole.net/R3xGptDa/

Over the weekend I wanted to play with Raspberry Pi clusters. I purchased a ClusterHat which I've put on a raspberry Pi 4 and I have some old Model 3s laying around. For clarity, there are other RPis on my network but they all have manually assigned IP addresses. I also have other devices like laptops, phones, TVs and so on - the usual stuff everyone has.

I also definitely only have one DHCP server. If I disable the PiHole DHCP server nothing can get an address.

There are two specific behaviours, probably related, that are giving me problems. First one is this

Sep 30 20:55:22 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.54 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:00:26 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.54 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:00:27 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.54 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:00:43 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:00:50 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:05:58 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:11:16 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:11:16 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:16:37 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:16:37 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:21:57 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:22:01 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:27:11 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:27:18 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:32:40 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:37:51 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:37:52 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.59 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:38:04 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.82 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:38:04 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.82 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:43:34 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.82 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:48:43 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.82 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:53:55 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.82 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:53:56 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.82 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:54:08 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.93 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:54:08 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.93 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:59:27 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.93 dc:a6:32:7d:c2:57 cbridge
Sep 30 21:59:27 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.93 dc:a6:32:7d:c2:57 cbridge
Sep 30 22:04:37 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.93 dc:a6:32:7d:c2:57 cbridge
Sep 30 22:04:39 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.93 dc:a6:32:7d:c2:57 cbridge

Over the space of an hour this Pi had 4 different IP addresses. This is the RPi 4 but the others do this as well. Here's an example:

16:49:45 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.161 b8:27:eb:7e:02:3c node3
16:49:53 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.163 b8:27:eb:7e:02:3c node3
16:50:01 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.165 b8:27:eb:7e:02:3c node3
16:55:00 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.165 b8:27:eb:7e:02:3c node3
16:55:02 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.165 b8:27:eb:7e:02:3c node3
16:55:10 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.168 b8:27:eb:7e:02:3c node3
17:00:21 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.43 b8:27:eb:7e:02:3c node3
17:00:25 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.168 b8:27:eb:7e:02:3c node3
17:00:34 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.174 b8:27:eb:7e:02:3c node3
17:05:41 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.174 b8:27:eb:7e:02:3c node3
17:05:43 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.174 b8:27:eb:7e:02:3c node3
17:05:51 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.180 b8:27:eb:7e:02:3c node3

For verification, here's an example - my laptop not doing this

00:36:34 dnsmasq-dhcp[627]: DHCPACK(eth0) 192.168.1.130 f8:e4:3b:5c:c1:9c Steves-MBP
11:49:38 dnsmasq-dhcp[627]: DHCPACK(eth0) 192.168.1.130 f8:e4:3b:5c:c1:9c Steves-MBP
18:19:19 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.130 f8:e4:3b:5c:c1:9c Steves-MBP

This leads to unexpected behaviour 2 - if I use Pihole to set a static IP for these devices this happens

17:32:24 dnsmasq-dhcp[628]: DHCPOFFER(eth0) 192.168.1.43 b8:27:eb:7e:02:3c
17:32:24 dnsmasq-dhcp[628]: DHCPREQUEST(eth0) 192.168.1.43 b8:27:eb:7e:02:3c
17:32:24 dnsmasq-dhcp[628]: DHCPACK(eth0) 192.168.1.43 b8:27:eb:7e:02:3c node3
17:32:24 dnsmasq-dhcp[628]: DHCPDECLINE(eth0) 192.168.1.43 b8:27:eb:7e:02:3c
17:32:24 dnsmasq-dhcp[628]: disabling DHCP static address 192.168.1.43 for 10m
17:32:25 dnsmasq-dhcp[628]: not using configured address 192.168.1.43 because it was previously declined
17:32:29 dnsmasq-dhcp[628]: not using configured address 192.168.1.43 because it was previously declined
17:32:34 dnsmasq-dhcp[628]: not using configured address 192.168.1.43 because it was previously declined
17:32:38 dnsmasq-dhcp[628]: not using configured address 192.168.1.43 because it was previously declined
17:53:50 dnsmasq[629]: config 192.168.1.43 is NXDOMAIN

All the Pis are running fully updated Raspbian Bullseye.

The fact that I'm only seeing this with the RPis makes me think it's the RPis that are the problem but apart from one post on here about the "because it was previously declined" message I've failed to find anything that has helped me understand why this is happening.

Can anyone shed some light?

Thanks

Steve

On first glance, this doesn't seem like a Pi-hole issue.

It would seem you are only sharing parts of your logs?

A complete, successful DHCP negotiation sequence would have DHCPDISCOVER (client), DHCPOFFER (server), DHCPREQUEST (client), DHCPACK (server).
A client's request to renew a lease about to expire would be shorter, starting with DHCPREQUEST.

From what you've shared, it can just be concluded that your client's requests for those four IPs have been acknowledged by Pi-hole's DHCP server.
The lines do not tell us whether the client did actually use them.

On the contrary - one of your excerpt shows:

Your client has declined the IP address that has just been acknowledged by Pi-hole (which prompts Pi-hole's DHCP server to cease issuing that IP for a while).

That may indicate that the client's duplicate address check has been positive, i.e. another host with that IP is already active, which in turn could happen if that host would have acquired its IP through a different DHCP server or would use a static IP assignment.

On first glance, this doesn't seem like a Pi-hole issue.

I didn't say it was. However, PiHole is my DHCP server and it's a common factor in this problem. To be clear, there are over 100 devices both wired and wireless on my network that all get their IP addresses from this DHCP server without a problem - it is only RPis that exhibit this problem.

It would seem you are only sharing parts of your logs?
A complete, successful DHCP negotiation sequence would have DHCPDISCOVER (client), >DHCPOFFER (server), DHCPREQUEST (client), DHCPACK (server).

I'm sharing relevant parts. Successful DORAs with devices that aren't having problems wouldn't help much in the diagnostic process and this is happening 24/7 so I removed the date column, job number and file name for brevity. The snippet in the post came from cut -d' ' -f-1,2-4,6- pihole.log | grep -i b8:27:eb:7e:02:3c | grep -i dhcp because I thought it would be more readable.

Your client has declined the IP address that has just been acknowledged by Pi-hole (which prompts Pi-hole's DHCP server to cease issuing that IP for a while ).

I understand that. I just want to clarify a couple of things - (1) It's clientS - plural. And all of them are Raspberry Pis. (2) You've taken two separate problems and mashed them in to one. DHCPDECLINEs only happen if I set a static IP for the MAC address of that Pi as I have explained in my original post. If I don't set a static IP the devices will keep requesting IP addresses even after a successful DORA. As shown in the first log snippet.

That may indicate that the client's duplicate address check has been positive, i.e. another host with that IP is already active, which in turn could happen if that host would have acquired its IP through a different DHCP server or would use a static IP assignment.

I addressed that in my original post including confirmation that I don't have another DHCP server. My DHCP server has a pool of 150 addresses. What you're suggesting is that every device on my network successfully gets a free address except the Raspberry Pis which are constantly being offered addresses that are already in use. Only the Pis. Not the printers. Not the laptops. Not the Nest smoke alarms or the Ring cameras. Just the Raspberry Pis. Not only is that unlikely but if it is what's happening that's a PiHole problem since it's handing out the addresses.

The lines do not tell us whether the client did actually use them.

Look at the time column. It does use them and I can SSH to the device but it soon drops of the network and gets another IP. I can post the full logs if you want but it doesn't add anything to what I posted. There's nothing on the RPi's kern.log or on the PiHole RPi that explains why the device is requisiting a new address every minute even though the lease time is 6 hours or to explain why PiHole won't give it the address it previously gave out. That is until I set a static IP and then you see the DHCPDECLINE message. But when assignment is dynamic - there's no decline message. And - to be absolutely clear - I have edited out the DOR in the snippet in my original post FROM THE ORIGINAL TRANSACTION. To put it another way, what is happening is DORAAA.........

grep -i b8:27:eb:7e:02:3c pihole.log| grep -i dhcp | grep DHCPDISCOVER | wc -l
430
grep -i b8:27:eb:7e:02:3c pihole.log| grep -i dhcp | grep DHCPOFFER | wc -l
430
grep -i b8:27:eb:7e:02:3c pihole.log| grep -i dhcp | grep DHCPREQUEST | wc -l
430
grep -i b8:27:eb:7e:02:3c pihole.log| grep -i dhcp | grep DHCPACK | wc -l
475
grep -i b8:27:eb:7e:02:3c pihole.log| grep -i dhcp | grep DHCPDECLINE | wc -l
3 #This was me putting in a static lease again at about 10am. If I do
grep DHCPDECLINE pihole.log | wc -l
3 #I get the same number

And to clarify - it's currently 2pm where I am, the pihole.log file rotated at midnight and the first entry is at 00:00:00. Here's my laptop in the same 14 hour period

grep DHCPACK pihole.log | grep -i steve-mbp |  wc -l
2

But as I said in this post and my first post - I don't think it's a PiHole problem and I don't say that. What I am asking is: it's a problem that involves PiHole - has anyone seen this before?

Can anyone shed some light?

I'm back home - here's an unedited sample but cut short due to character limit

grep b8:27:eb:7e:02:3c pihole.log 
Oct  3 00:03:08 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.190 b8:27:eb:7e:02:3c
Oct  3 00:03:08 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.190 b8:27:eb:7e:02:3c node4
Oct  3 00:03:09 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:03:09 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.190 b8:27:eb:7e:02:3c
Oct  3 00:03:09 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.190 b8:27:eb:7e:02:3c
Oct  3 00:03:09 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.190 b8:27:eb:7e:02:3c node4
Oct  3 00:03:17 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:03:17 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.192 b8:27:eb:7e:02:3c
Oct  3 00:03:17 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:03:17 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.192 b8:27:eb:7e:02:3c
Oct  3 00:03:17 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.192 b8:27:eb:7e:02:3c
Oct  3 00:03:17 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.192 b8:27:eb:7e:02:3c node4
Oct  3 00:08:29 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.192 b8:27:eb:7e:02:3c
Oct  3 00:08:29 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.192 b8:27:eb:7e:02:3c node4
Oct  3 00:08:31 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:08:31 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.192 b8:27:eb:7e:02:3c
Oct  3 00:08:31 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.192 b8:27:eb:7e:02:3c
Oct  3 00:08:31 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.192 b8:27:eb:7e:02:3c node4
Oct  3 00:08:39 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:08:39 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.194 b8:27:eb:7e:02:3c
Oct  3 00:08:39 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:08:39 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.194 b8:27:eb:7e:02:3c
Oct  3 00:08:39 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.194 b8:27:eb:7e:02:3c
Oct  3 00:08:39 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.194 b8:27:eb:7e:02:3c node4
Oct  3 00:13:51 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.194 b8:27:eb:7e:02:3c
Oct  3 00:13:51 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.194 b8:27:eb:7e:02:3c node4
Oct  3 00:13:52 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:13:52 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.194 b8:27:eb:7e:02:3c
Oct  3 00:13:52 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.194 b8:27:eb:7e:02:3c
Oct  3 00:13:52 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.194 b8:27:eb:7e:02:3c node4
Oct  3 00:14:00 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:14:00 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.197 b8:27:eb:7e:02:3c
Oct  3 00:14:00 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:14:00 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.197 b8:27:eb:7e:02:3c
Oct  3 00:14:00 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.197 b8:27:eb:7e:02:3c
Oct  3 00:14:00 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.197 b8:27:eb:7e:02:3c node4
Oct  3 00:19:13 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.197 b8:27:eb:7e:02:3c
Oct  3 00:19:13 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.197 b8:27:eb:7e:02:3c node4
Oct  3 00:19:14 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:19:14 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.197 b8:27:eb:7e:02:3c
Oct  3 00:19:14 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.197 b8:27:eb:7e:02:3c
Oct  3 00:19:14 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.197 b8:27:eb:7e:02:3c node4
Oct  3 00:19:21 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:19:21 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.198 b8:27:eb:7e:02:3c
Oct  3 00:19:21 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:19:21 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.198 b8:27:eb:7e:02:3c
Oct  3 00:19:21 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.198 b8:27:eb:7e:02:3c
Oct  3 00:19:21 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.198 b8:27:eb:7e:02:3c node4
Oct  3 00:24:33 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.198 b8:27:eb:7e:02:3c
Oct  3 00:24:33 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.198 b8:27:eb:7e:02:3c node4
Oct  3 00:24:34 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:24:34 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.198 b8:27:eb:7e:02:3c
Oct  3 00:24:34 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.198 b8:27:eb:7e:02:3c
Oct  3 00:24:34 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.198 b8:27:eb:7e:02:3c node4
Oct  3 00:24:43 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:24:43 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.200 b8:27:eb:7e:02:3c
Oct  3 00:24:43 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:24:43 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.200 b8:27:eb:7e:02:3c
Oct  3 00:24:43 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.200 b8:27:eb:7e:02:3c
Oct  3 00:24:43 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.200 b8:27:eb:7e:02:3c node4
Oct  3 00:29:55 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.200 b8:27:eb:7e:02:3c
Oct  3 00:29:55 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.200 b8:27:eb:7e:02:3c node4
Oct  3 00:29:56 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:29:56 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.200 b8:27:eb:7e:02:3c
Oct  3 00:29:56 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.200 b8:27:eb:7e:02:3c
Oct  3 00:29:56 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.200 b8:27:eb:7e:02:3c node4
Oct  3 00:30:05 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:30:05 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.54 b8:27:eb:7e:02:3c
Oct  3 00:30:05 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:30:05 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.54 b8:27:eb:7e:02:3c
Oct  3 00:30:05 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.54 b8:27:eb:7e:02:3c
Oct  3 00:30:05 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.54 b8:27:eb:7e:02:3c node4
Oct  3 00:35:16 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.54 b8:27:eb:7e:02:3c
Oct  3 00:35:16 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.54 b8:27:eb:7e:02:3c node4
Oct  3 00:35:17 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:35:17 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.54 b8:27:eb:7e:02:3c
Oct  3 00:35:17 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.54 b8:27:eb:7e:02:3c
Oct  3 00:35:17 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.54 b8:27:eb:7e:02:3c node4
Oct  3 00:35:22 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:35:22 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.54 b8:27:eb:7e:02:3c
Oct  3 00:35:25 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.54 b8:27:eb:7e:02:3c
Oct  3 00:35:25 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.54 b8:27:eb:7e:02:3c node4
Oct  3 00:40:34 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.54 b8:27:eb:7e:02:3c
Oct  3 00:40:34 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.54 b8:27:eb:7e:02:3c node4
Oct  3 00:40:35 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:40:35 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.54 b8:27:eb:7e:02:3c
Oct  3 00:40:35 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.54 b8:27:eb:7e:02:3c
Oct  3 00:40:35 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.54 b8:27:eb:7e:02:3c node4
Oct  3 00:40:40 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:40:40 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.56 b8:27:eb:7e:02:3c
Oct  3 00:40:43 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.56 b8:27:eb:7e:02:3c
Oct  3 00:40:43 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.56 b8:27:eb:7e:02:3c node4
Oct  3 00:45:55 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.56 b8:27:eb:7e:02:3c
Oct  3 00:45:55 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.56 b8:27:eb:7e:02:3c node4
Oct  3 00:45:57 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:45:57 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.56 b8:27:eb:7e:02:3c
Oct  3 00:45:57 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.56 b8:27:eb:7e:02:3c
Oct  3 00:45:57 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.56 b8:27:eb:7e:02:3c node4
Oct  3 00:46:02 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:46:02 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.58 b8:27:eb:7e:02:3c
Oct  3 00:46:05 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.58 b8:27:eb:7e:02:3c
Oct  3 00:46:05 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.58 b8:27:eb:7e:02:3c node4
Oct  3 00:51:17 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.58 b8:27:eb:7e:02:3c
Oct  3 00:51:17 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.58 b8:27:eb:7e:02:3c node4
Oct  3 00:51:18 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:51:18 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.58 b8:27:eb:7e:02:3c
Oct  3 00:51:18 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.58 b8:27:eb:7e:02:3c
Oct  3 00:51:18 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.58 b8:27:eb:7e:02:3c node4
Oct  3 00:51:26 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:51:26 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.61 b8:27:eb:7e:02:3c
Oct  3 00:51:26 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:51:26 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.61 b8:27:eb:7e:02:3c
Oct  3 00:51:26 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.61 b8:27:eb:7e:02:3c
Oct  3 00:51:26 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.61 b8:27:eb:7e:02:3c node4
Oct  3 00:56:37 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.61 b8:27:eb:7e:02:3c
Oct  3 00:56:37 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.61 b8:27:eb:7e:02:3c node4
Oct  3 00:56:39 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:56:39 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.61 b8:27:eb:7e:02:3c
Oct  3 00:56:39 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.61 b8:27:eb:7e:02:3c
Oct  3 00:56:39 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.61 b8:27:eb:7e:02:3c node4
Oct  3 00:56:43 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:56:43 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.62 b8:27:eb:7e:02:3c
Oct  3 00:56:47 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 00:56:47 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.62 b8:27:eb:7e:02:3c
Oct  3 00:56:47 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.62 b8:27:eb:7e:02:3c
Oct  3 00:56:47 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.62 b8:27:eb:7e:02:3c node4
Oct  3 01:01:59 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.62 b8:27:eb:7e:02:3c
Oct  3 01:01:59 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.62 b8:27:eb:7e:02:3c node4
Oct  3 01:02:00 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:02:00 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.62 b8:27:eb:7e:02:3c
Oct  3 01:02:00 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.62 b8:27:eb:7e:02:3c
Oct  3 01:02:00 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.62 b8:27:eb:7e:02:3c node4
Oct  3 01:02:05 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:02:05 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.64 b8:27:eb:7e:02:3c
Oct  3 01:02:08 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.64 b8:27:eb:7e:02:3c
Oct  3 01:02:08 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.64 b8:27:eb:7e:02:3c node4
Oct  3 01:07:19 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.64 b8:27:eb:7e:02:3c
Oct  3 01:07:19 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.64 b8:27:eb:7e:02:3c node4
Oct  3 01:07:21 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:07:21 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.64 b8:27:eb:7e:02:3c
Oct  3 01:07:21 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.64 b8:27:eb:7e:02:3c
Oct  3 01:07:21 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.64 b8:27:eb:7e:02:3c node4
Oct  3 01:07:25 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:07:25 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:07:28 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:07:28 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.73 b8:27:eb:7e:02:3c node4
Oct  3 01:12:40 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:12:40 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.73 b8:27:eb:7e:02:3c node4
Oct  3 01:12:41 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:12:41 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:12:41 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:12:41 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.73 b8:27:eb:7e:02:3c node4
Oct  3 01:12:46 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:12:46 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:12:49 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:12:49 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:12:49 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:12:49 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.73 b8:27:eb:7e:02:3c node4
Oct  3 01:18:01 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:18:01 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.73 b8:27:eb:7e:02:3c node4
Oct  3 01:18:02 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:18:02 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:18:02 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:18:02 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.73 b8:27:eb:7e:02:3c node4
Oct  3 01:18:07 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:18:07 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:18:10 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:18:10 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.73 b8:27:eb:7e:02:3c node4
Oct  3 01:18:10 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:18:10 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.73 b8:27:eb:7e:02:3c node4
Oct  3 01:23:21 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:23:21 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.73 b8:27:eb:7e:02:3c node4
Oct  3 01:23:23 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:23:23 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:23:23 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.73 b8:27:eb:7e:02:3c
Oct  3 01:23:23 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.73 b8:27:eb:7e:02:3c node4
Oct  3 01:23:27 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:23:27 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.74 b8:27:eb:7e:02:3c
Oct  3 01:23:30 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.74 b8:27:eb:7e:02:3c
Oct  3 01:23:30 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.74 b8:27:eb:7e:02:3c node4
Oct  3 01:28:42 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.74 b8:27:eb:7e:02:3c
Oct  3 01:28:42 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.74 b8:27:eb:7e:02:3c node4
Oct  3 01:28:44 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:28:44 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.74 b8:27:eb:7e:02:3c
Oct  3 01:28:44 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.74 b8:27:eb:7e:02:3c
Oct  3 01:28:44 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.74 b8:27:eb:7e:02:3c node4
Oct  3 01:28:48 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:28:48 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.76 b8:27:eb:7e:02:3c
Oct  3 01:28:51 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.76 b8:27:eb:7e:02:3c
Oct  3 01:28:51 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.76 b8:27:eb:7e:02:3c node4
Oct  3 01:28:51 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.76 b8:27:eb:7e:02:3c
Oct  3 01:28:51 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.76 b8:27:eb:7e:02:3c node4
Oct  3 01:34:03 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.76 b8:27:eb:7e:02:3c
Oct  3 01:34:03 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.76 b8:27:eb:7e:02:3c node4
Oct  3 01:34:04 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:34:04 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.76 b8:27:eb:7e:02:3c
Oct  3 01:34:04 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.76 b8:27:eb:7e:02:3c
Oct  3 01:34:04 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.76 b8:27:eb:7e:02:3c node4
Oct  3 01:34:09 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:34:09 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.79 b8:27:eb:7e:02:3c
Oct  3 01:34:12 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.79 b8:27:eb:7e:02:3c
Oct  3 01:34:12 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.79 b8:27:eb:7e:02:3c node4
Oct  3 01:39:24 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.79 b8:27:eb:7e:02:3c
Oct  3 01:39:24 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.79 b8:27:eb:7e:02:3c node4
Oct  3 01:39:25 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:39:25 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.79 b8:27:eb:7e:02:3c
Oct  3 01:39:25 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.79 b8:27:eb:7e:02:3c
Oct  3 01:39:25 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.79 b8:27:eb:7e:02:3c node4
Oct  3 01:39:29 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:39:29 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.80 b8:27:eb:7e:02:3c
Oct  3 01:39:33 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.80 b8:27:eb:7e:02:3c
Oct  3 01:39:33 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.80 b8:27:eb:7e:02:3c node4
Oct  3 01:44:44 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.80 b8:27:eb:7e:02:3c
Oct  3 01:44:44 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.80 b8:27:eb:7e:02:3c node4
Oct  3 01:44:46 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:44:46 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.80 b8:27:eb:7e:02:3c
Oct  3 01:44:46 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.80 b8:27:eb:7e:02:3c
Oct  3 01:44:46 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.80 b8:27:eb:7e:02:3c node4
Oct  3 01:44:54 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:44:54 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.82 b8:27:eb:7e:02:3c
Oct  3 01:44:54 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:44:54 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.82 b8:27:eb:7e:02:3c
Oct  3 01:44:54 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.82 b8:27:eb:7e:02:3c
Oct  3 01:44:54 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.82 b8:27:eb:7e:02:3c node4
Oct  3 01:50:06 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.82 b8:27:eb:7e:02:3c
Oct  3 01:50:06 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.82 b8:27:eb:7e:02:3c node4
Oct  3 01:50:08 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:50:08 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.82 b8:27:eb:7e:02:3c
Oct  3 01:50:08 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.82 b8:27:eb:7e:02:3c
Oct  3 01:50:08 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.82 b8:27:eb:7e:02:3c node4
Oct  3 01:50:12 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:50:12 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.84 b8:27:eb:7e:02:3c
Oct  3 01:50:16 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.84 b8:27:eb:7e:02:3c
Oct  3 01:50:16 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.84 b8:27:eb:7e:02:3c node4
Oct  3 01:55:27 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.84 b8:27:eb:7e:02:3c
Oct  3 01:55:27 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.84 b8:27:eb:7e:02:3c node4
Oct  3 01:55:29 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
Oct  3 01:55:29 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.84 b8:27:eb:7e:02:3c
Oct  3 01:55:29 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.84 b8:27:eb:7e:02:3c
Oct  3 01:55:29 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.84 b8:27:eb:7e:02:3c node4
Oct  3 01:55:33 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) b8:27:eb:7e:02:3c
1 Like

The exact sequence would also be relevant.

I'd consider a sample of such a sequence for an offending client, noting the frequency of occurence, to better suit analysis than the stream of just the DHCPACKs you've shared so far, so thanks for sharing a more extensive client log. :wink:

Your most current log excerpts show the following pattern:

t+0     DHCPDISCOVER(eth0) b8:27:eb
t+0     DHCPOFFER(eth0) 192.168.1.194 b8:27:eb
t+0     DHCPREQUEST(eth0) 192.168.1.194 b8:27:eb
t+0     DHCPACK(eth0) 192.168.1.194 b8:27:eb node4

t+5mins DHCPREQUEST(eth0) 192.168.1.194 b8:27:eb
t+5mins DHCPACK(eth0) 192.168.1.194 b8:27:eb node4
  (or less often)
t+5mins DHCPDISCOVER(eth0) b8:27:eb
t+5mins DHCPOFFER(eth0) 192.168.1.194 b8:27:eb

On a few occasions, the client started another DHCPDISCOVER cycle, about 5 seconds after the preceeding one seems successfully concluded.

There are two notable observations here:
a. DHCP negotiations are initiated by the client every 5 minutes, give or take a few seconds
This is in contrast to your stated DHCP leasetime of 6 hours.

b. In some cases, after 5 minutes, your client broadcasts a DHCPDISCOVER, rather than sending a unicast DHCPREQUEST for renewal directly to the server.
That would suggest that your client considers it has lost its network connection, requiring it to initiate a full DHCP cycle.

Does the client's perceived liftetime from ip address match the one distributed by your router?

On that client, is there something scheduled for every 5 minutes?

In case the client is connecting via wifi: Is wifi power save enabled, probably dropping the connection after 5 minutes?

Are perhaps all of your offending clients connecting through some extra piece of network equipment (like a managed switch or additional router) only they would use?

Thanks for sticking with me on this. I have some further observations. But first

Are perhaps all of your offending clients connecting through some extra piece of network equipment

No - and the node1...4 RPis are connected to a different switch than the cbridge (Pi 4) RPi.

In case the client is connecting via wifi

All connected by ethernet (hence the eth0 in the logs)

Yesterday evening I disabled the DHCP server on PiHole and enabled the DHCP server on my router as an experiment. The cbridge Pi picked up an address and I was able to SSH to it and stay connected. The thing is...

Oct  3 20:48:22 cbridge dhcpcd[903]: eth0: hardware address 00:11:32:9e:65:27 claims 192.168.1.157

... time passes

Oct  4 15:30:39 cbridge dhcpcd[913]: eth0: hardware address 00:11:32:9e:65:27 claims 192.168.1.157

...and I'm still connected.

Going back further though I found this - as an example

Oct  1 11:11:25 cbridge dhcpcd[891]: eth0: soliciting a DHCP lease
Oct  1 11:11:25 cbridge dhcpcd[891]: eth0: offered 192.168.1.111 from 192.168.1.2
Oct  1 11:11:25 cbridge dhcpcd[891]: eth0: probing address 192.168.1.111/24
Oct  1 11:11:25 cbridge dhcpcd[891]: eth0: hardware address 00:11:32:9e:65:27 claims 192.168.1.111
Oct  1 11:11:25 cbridge dhcpcd[891]: eth0: DAD detected 192.168.1.111

Looking at the corresponding PiHole logs I found this

pihole.log.3.gz:Oct  1 10:49:34 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.111 18:b4:30:a6:b1:a1

So 20 minutes before it offered 192.168.1.111 to cbridge it offered it to a Nest Protect. The problem there is that I can't see the logs on the Nest Protect but I also can't see a log entry on October 1st for the Protect requesting its address multiple times. In fact, I decided to check -

zgrep 18:b4:30:a6:b1:a1 pihole.log*

returns a DORA every 6 hours until the point I turned off DHCP as I would expect - random example

pihole.log.1:Oct  3 11:15:36 dnsmasq-dhcp[629]: DHCPDISCOVER(eth0) 18:b4:30:a6:b1:a1
pihole.log.1:Oct  3 11:15:36 dnsmasq-dhcp[629]: DHCPOFFER(eth0) 192.168.1.111 18:b4:30:a6:b1:a1
pihole.log.1:Oct  3 11:15:36 dnsmasq-dhcp[629]: DHCPREQUEST(eth0) 192.168.1.111 18:b4:30:a6:b1:a1
pihole.log.1:Oct  3 11:15:36 dnsmasq-dhcp[629]: DHCPACK(eth0) 192.168.1.111 18:b4:30:a6:b1:a1

And every time it gets 192.168.1.111

So now I have more information I'm even more lost. What this seems to say is that for some reason PiHole DHCP is offering addresses that aren't free to Raspberry Pis. And only RPis.

If it wasn't for the fact that PiHole is offering in use addresses I'd think this is a bug in DHCPCD on the clients. But I'm not certain.

The eth0 from Pi-hole's log denotes the interface on the Pi-hole host machine.
It is only from your latest dhcpcd client logs that I can see what that client is using. :wink:

Those two lines do not show the IP of your cbridge.
They show that your router's DHCP server has offered 192.168.1.157 to your cbridge, which is already claimed by a device at 00:11:32:<redacted> - some Synology equipment, judging by that OUI.
Your cbrigde client has logged that as a result of its duplicate address detection, and consequently would have declined that IP address.

Your cbridge logs from Oct 1st 11:11:25 shows the same to happen, only with a different IP of 192.168.1.111, and with Pi-hole's DHCP server (at 192.168.1.2?) - but its again that `00:11:32' device that claims that address.

Yes, but by itself, that line just shows that IP was offered, which is the same situation as on Oct 1st 11:11:25.
It does not tell you whether the client declined that IP.
You'd need to check the logs after that entry.

So far, those observations seem in line with DHCP protocols.

That's not what I'd expect to see.

With a leasetime of 6 hours, a client should start to renew its lease after 3 hours.
As mentioned before, it would do so in a shorter way, by sending a unicast DHCPREQUEST to the same DHCP server IP that it has acquired its lease through.

For a permanently connected client, you should see a full DORA only once. After a lease was successfully acquired, there should be DHCPREQUEST/DHCPACK renewals at roughly half the leasetime intervals.

Did your router also distribute a leasetime of 6 hours?

To collate this with our earlier findings:
It seems that at times, the client is initiating a full DHCP cycle instead of just renewing its existing lease.

This could be prompted by a loss of connectivity, i.e. your client would consider it has disconnected from your network and needs to join the network by broadcasting for a DHCP server.

It is also remarkable that your client would do so roughly every 5 minutes when acquiring its lease through Pi-hole's DHCP server.

Did you get a chance to inspect the client side lease times via ip address yet?

And although I'm not sure whether the Synology device would just be a red herring:
Why/How does that device claim IP addresses that presumably have not been issued by the DHCP server currently in charge?

No, fair enough. I meant that the logs I've added were also showing eth0. To be clear, there are lots of Wifi devices on my network but every device involved in this problem is using ethernet.

This could be prompted by a loss of connectivity,

I don't disagree but why is it only a handful of Raspberry Pis?

some Synology equipment, judging by that OUI.

So that makes even less sense. I'm just getting more lost in this problem. I do have a Synology and that is its MAC address. It has a static IP of 192.168.1.15. So it has no reason to be requesting an IP address. AND the reason I didn't spot that it was the wrong MAC address - it's now 9:51 pm where I am...

root@cbridge:/var/log# grep hardware\ address\ 00:11:32:9e:65:27 daemon.log | tail -1
Oct  4 21:50:37 cbridge dhcpcd[913]: eth00: hardware address 00:11:32:9e:65:27 claims 192.168.1.157
root@cbridge:/var/log# ip addr | grep 192
    inet 192.168.1.157/24 brd 192.168.1.255 scope global dynamic noprefixroute eth0

I am still connected to cbridge - this is the longest I've stayed connected now that I'm not using the PiHole DHCP server. And I'm connected on 192.168.1.157 which is the address that the Synology appears to be claiming - except it's not.

Did your router also distribute a leasetime of 6 hours?

I didn't change it from the default for this testing - 24 hours. eth0 on cbridge currently says

valid_lft 5554sec preferred_lft 4193sec

You should check those lifetimes for numbers in line with your 6hrs/21600secs when Pi-hole is your DHCP server, right after your client acquired the lease (as ip address shows the remaining lifetimes).

Or rather: That dhcpcd reported it as claiming on Oct 4th 15:30:39.

To check the current situation, you could inspect your client's neighbour table:

ip neighbour

Run from your client, you could also check the results of a DAD:

arping -D 192.168.1.157 -w 10

EDIT:
Just a thought: Does that Synology perhaps have more than one network interface also connected to your router?

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