DHCP declines DHCP requests every day at 5am

astrakid

hi,
i have a strange behaviour with my dhcp server on pfsense 2.6.0:
every night at 5am it declines dhcp requests.

i have all my known clients as static dhcp entries in my dhcp server configuration. overall it works. but every night at 5am cdhcp negotiation fails.

i have two dhcp servers, one for wan (vtnet1, only for known devices with static dhcp entries), and my "main" dhcp scope for lan (vtnet0).

root@server:/var/log# grep -ci \ 01.*dhcp  syslog-20230329
101
root@server:/var/log# grep -ci \ 02.*dhcp  syslog-20230329
130
root@server:/var/log# grep -ci \ 03.*dhcp  syslog-20230329
102
root@server:/var/log# grep -ci \ 04.*dhcp  syslog-20230329
76
root@server:/var/log# grep -ci \ 05.*dhcp  syslog-20230329
3103
root@server:/var/log# grep -ci \ 06.*dhcp  syslog-20230329
56
root@server:/var/log# grep -ci \ 07.*dhcp  syslog-20230329
16


root@server:/var/log# grep -i c4:5b:be:62:94:0b  syslog-20230329
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPDISCOVER from c4:5b:be:62:94:0b via vtnet1: network 192.168.1.0/24: no free leases
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPDISCOVER from c4:5b:be:62:94:0b via vtnet0
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPOFFER on 10.1.1.109 to c4:5b:be:62:94:0b via vtnet0
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPREQUEST for 10.1.1.109 (10.1.1.4) from c4:5b:be:62:94:0b via vtnet1: wrong network.
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPNAK on 10.1.1.109 to c4:5b:be:62:94:0b via vtnet1
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPREQUEST for 10.1.1.109 (10.1.1.4) from c4:5b:be:62:94:0b via vtnet0
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPACK on 10.1.1.109 to c4:5b:be:62:94:0b via vtnet0
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPDISCOVER from c4:5b:be:62:94:0b via vtnet1: network 192.168.1.0/24: no free leases
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPDISCOVER from c4:5b:be:62:94:0b via vtnet0
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPOFFER on 10.1.1.109 to c4:5b:be:62:94:0b via vtnet0
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPREQUEST for 10.1.1.109 (10.1.1.4) from c4:5b:be:62:94:0b via vtnet1: wrong network.
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPNAK on 10.1.1.109 to c4:5b:be:62:94:0b via vtnet1
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPREQUEST for 10.1.1.109 (10.1.1.4) from c4:5b:be:62:94:0b via vtnet0
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPACK on 10.1.1.109 to c4:5b:be:62:94:0b via vtnet0
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPDISCOVER from c4:5b:be:62:94:0b via vtnet1: network 192.168.1.0/24: no free leases

after some time it works again:

Mar 28 05:23:27 _gateway dhcpd[80811]: DHCPDISCOVER from c4:5b:be:62:94:0b via vtnet1: network 192.168.1.0/24: no free leases
Mar 28 05:23:27 _gateway dhcpd[80811]: DHCPDISCOVER from c4:5b:be:62:94:0b via vtnet0
Mar 28 05:23:27 _gateway dhcpd[80811]: DHCPOFFER on 10.1.1.109 to c4:5b:be:62:94:0b via vtnet0
Mar 28 05:23:27 _gateway dhcpd[80811]: DHCPREQUEST for 10.1.1.109 (10.1.1.4) from c4:5b:be:62:94:0b via vtnet1: wrong network.
Mar 28 05:23:27 _gateway dhcpd[80811]: DHCPNAK on 10.1.1.109 to c4:5b:be:62:94:0b via vtnet1
Mar 28 05:23:27 _gateway dhcpd[80811]: DHCPREQUEST for 10.1.1.109 (10.1.1.4) from c4:5b:be:62:94:0b via vtnet0
Mar 28 05:23:27 _gateway dhcpd[80811]: DHCPACK on 10.1.1.109 to c4:5b:be:62:94:0b via vtnet0
Mar 28 17:23:03 _gateway dhcpd[80811]: DHCPREQUEST for 10.1.1.109 from c4:5b:be:62:94:0b via vtnet0
Mar 28 17:23:03 _gateway dhcpd[80811]: DHCPACK on 10.1.1.109 to c4:5b:be:62:94:0b via vtnet0

any ideas?

regards,
andre

Gertjan

@astrakid said in DHCP declines DHCP requests every day at 5am:

any ideas?

I saw the NAK, both on network "vtnet1".

This is also funny :

Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPDISCOVER from c4:5b:be:62:94:0b via vtnet1: .....
Mar 28 05:00:01 _gateway dhcpd[80811]: DHCPDISCOVER from c4:5b:be:62:94:0b via vtnet0: .....

What is this device doing ? Asking on multiple networks, with the same MAC address, an IP ?

The DHCP doesn't fall in the trap, and sends NAK for one of them.
If I was in a bad mood, I would have send NAK for all the requests.

Btw : the server is telling you :
via vtnet1: wrong network !

A static IP setting = MAC IP pair, is valid for one network.
For example, on LAN, you have 192.168.1.10/24 for "c4:5b:be:62:94:0b"
On network 2, the same MAC c4:5b:be:62:94:0bcan get, for example, a static IP 192.168.2.10/24
But asking "10.1.1.109" on both networks .... noop, that's a fail.

astrakid

@gertjan i have troubles in answering... akismet is blocking my answer...

astrakid

@gertjan said in DHCP declines DHCP requests every day at 5am:

static IP setting = MAC IP pair, is valid for one network.

well i see this behaviour on other days for other clients, so i am suspected that there might be something wrong on pfsense side (80:7d... success, 2c:3a.... unsuccessful):

Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPDISCOVER from 80:7d:3a:74:54:5c via vtnet1: network 192.168.1.0/24: no free leases
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPDISCOVER from 80:7d:3a:74:54:5c via vtnet0
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPOFFER on 10.1.1.75 to 80:7d:3a:74:54:5c via vtnet0
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPREQUEST for 10.1.1.75 (10.1.1.4) from 80:7d:3a:74:54:5c via vtnet1: wrong network.
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPNAK on 10.1.1.75 to 80:7d:3a:74:54:5c via vtnet1
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPREQUEST for 10.1.1.75 (10.1.1.4) from 80:7d:3a:74:54:5c via vtnet0
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPACK on 10.1.1.75 to 80:7d:3a:74:54:5c via vtnet0
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPREQUEST for 10.1.1.70 (10.1.1.4) from 2c:3a:e8:3b:11:24 via vtnet1: wrong network.
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPNAK on 10.1.1.70 to 2c:3a:e8:3b:11:24 via vtnet1
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPREQUEST for 10.1.1.70 (10.1.1.4) from 2c:3a:e8:3b:11:24 via vtnet0
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPACK on 10.1.1.70 to 2c:3a:e8:3b:11:24 via vtnet0
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPDISCOVER from 2c:3a:e8:3b:11:24 via vtnet1: network 192.168.1.0/24: no free leases
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPDISCOVER from 2c:3a:e8:3b:11:24 via vtnet0
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPOFFER on 10.1.1.70 to 2c:3a:e8:3b:11:24 via vtnet0
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPREQUEST for 10.1.1.70 (10.1.1.4) from 2c:3a:e8:3b:11:24 via vtnet1: wrong network.
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPNAK on 10.1.1.70 to 2c:3a:e8:3b:11:24 via vtnet1
[...]
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPREQUEST for 10.1.1.70 (10.1.1.4) from 2c:3a:e8:3b:11:24 via vtnet1: wrong network.
Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPNAK on 10.1.1.70 to 2c:3a:e8:3b:11:24 via vtnet1

the last message is flooding my dhcp server for about 20 minutes or so...

a mac is only configured as static dhcp on LAN. so that is fine.

i have to insert some "good" content i guess, otherwise akismet is complaining.

Gertjan

@astrakid said in DHCP declines DHCP requests every day at 5am:

i have all my known clients as static dhcp entries in my dhcp server configuration

So you've set up something like

Because my LAN uses 192.168.1.0/24 I assigned my PC called bureau2 (uses MAC 00:4e:01:ac:xx:9c) 192.168.1.2.

If I connected my PC to another LAN (OPTx on pfSense), it would know that it couldn't ask for 192.168.1.2 because it knows that it is not on my pfSense LAN network ?
How ? easy : the MAC of my second pfSense LAN is not (should not !!) be identical to the MAC of the pfSense LAN interface.
So my PC is smart ( a windows 11 PC) and doesn't send for DHCPREQUEST with the preferred 192.168.1.2, it will send an open DHCP request, and it will get back an IP in my OPTx LAN pool range, like 192.168.2/100->250 - or, If I used a static MAC DHCP setup, it would receive the IP I assigned, also, of course, in the 192.168.2.0/24 range. Not in the 192.168.1.0/24 range.

Why your device insist on asking the same IP/32 on two different networks that can't have the same network IP range, is beyond my knowledge.
I do know that a lot of "way to not expensive" device sold on known "wish" like sites have a pretty bad or worse DHCP implementation.

So, it's way beyond time where you detail your two vtnet0 and vtnet1 settings and DHCP server settings for these two networks.

Btw : the DHCP server used is this one : https://github.com/isc-projects/dhcp from ISC, world's most know DHCP server. A couple of billions are used right now.
Why your pfSense shows what it shows depends on just one thing : network hardware used and your settings.
So : tell us

johnpoz

@astrakid said in DHCP declines DHCP requests every day at 5am:

192.168.1.0/24: no free leases

dhcp can not give you a IP if there is no free lease to give.

Then this?

Mar 18 05:00:09 _gateway dhcpd[12860]: DHCPREQUEST for 10.1.1.75 (10.1.1.4) from 80:7d:3a:74:54:5c via vtnet1: wrong network.

dhcp will not give you a lease for a network, what are the masks involved?

Gertjan

@johnpoz said in DHCP declines DHCP requests every day at 5am:

no free leases

I was really hoping that these didn't need any explanation.

astrakid

@gertjan this is a desired behaviour: vtnet1 has only static dhcp entries. that is quite fine. but vtnet0 has free ip addresses and should answer it (it even has static dhcp entries for that mac).
it is ok that some devices might have a bad DHCP implementation. for this case it seems to occur by accident to some devidces. so there are times when even my mobile phones (androids) don't get an IP address (all my clients receive an ip address by DHCP server except the servers (proxmox host with VMs running nextcloud, freepbx, pfsense etc.).

regards,
andre