Gateway monitor down

stephenw10

Yes, most OSes will prefer v6 if the think they have a valid IP and that can introduce lengthy delays whilst it times out.

kevindd992002

@stephenw10 They put it back to bridge mode now and DNS resolving is working properly again. However, my DHCP lease issue is back. So to sum it all up:

Bridge mode: no DNS resolving issue but DHCP lease issue is present
Route mode: No DHCP lease issue but DNS resolving issue is present

I need to be in bridge mode so that's where I'll focus my troubleshooting on. When my gateway went down, this is what I saw:

https://pastebin.com/tP1wm3Uf

However, a new IP was given to my WAN interface (gateway went up) after around 3 minutes of downtime. I'm seeing DHCPNAK's. What does that tell us? Also, why am I seeing frequent "renewal in 1800 seconds" messages? Does that mean the DHCP lease is just every 30 minutes?

I also got a packet capture while this is a happening. Since that contains public IP addresses, do you want me to send it to you?

kevindd992002

Could it be similar to this issue?

https://forum.netgate.com/topic/112869/dhclient-on-wan-occasionally-fails-to-renew-lease-with-cable-isp

kevindd992002

It happened again at 4:10PM. Here's a clearer view of what's happening (I filtered the dhclient process only):

Dec 8 16:44:57 	dhclient 	26504 	bound to {New WAN IP} -- renewal in 1800 seconds.
Dec 8 16:44:57 	dhclient 	17600 	Creating resolv.conf
Dec 8 16:44:57 	dhclient 	16975 	RENEW
Dec 8 16:44:57 	dhclient 	26504 	unknown dhcp option value 0x52
Dec 8 16:44:57 	dhclient 	26504 	DHCPACK from {DHCP Server/WAN interface Gateway}
Dec 8 16:44:57 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:14:57 	dhclient 	26504 	bound to {New WAN IP} -- renewal in 1800 seconds.
Dec 8 16:14:57 	dhclient 	83905 	Creating resolv.conf
Dec 8 16:14:57 	dhclient 	83772 	/sbin/route add default {DHCP Server/WAN interface Gateway}
Dec 8 16:14:57 	dhclient 	83557 	/sbin/route add -host {DHCP Server/WAN interface Gateway} -iface igb0
Dec 8 16:14:57 	dhclient 	82650 	Adding new routes to interface: igb0
Dec 8 16:14:57 	dhclient 	82454 	New Routers (igb0): {DHCP Server/WAN interface Gateway}
Dec 8 16:14:57 	dhclient 	82184 	New Broadcast Address (igb0): {New WAN Broadcast IP}
Dec 8 16:14:57 	dhclient 	81938 	New Subnet Mask (igb0): 255.255.224.0
Dec 8 16:14:57 	dhclient 	81784 	New IP Address (igb0): {New WAN IP}
Dec 8 16:14:57 	dhclient 	81144 	ifconfig igb0 inet {New WAN IP} netmask 255.255.224.0 broadcast {New WAN Broadcast IP}
Dec 8 16:14:57 	dhclient 	80989 	Starting add_new_address()
Dec 8 16:14:57 	dhclient 	80666 	BOUND
Dec 8 16:14:57 	dhclient 	26504 	unknown dhcp option value 0x52
Dec 8 16:14:57 	dhclient 	26504 	DHCPACK from {DHCP Server/WAN interface Gateway}
Dec 8 16:14:56 	dhclient 	26504 	DHCPREQUEST on igb0 to 255.255.255.255 port 67
Dec 8 16:14:56 	dhclient 	80354 	ARPCHECK
Dec 8 16:14:54 	dhclient 	79636 	ARPSEND
Dec 8 16:14:54 	dhclient 	26504 	unknown dhcp option value 0x52
Dec 8 16:14:54 	dhclient 	26504 	DHCPOFFER from {DHCP Server/WAN interface Gateway}
Dec 8 16:14:54 	dhclient 	26504 	DHCPDISCOVER on igb0 to 255.255.255.255 port 67 interval 1
Dec 8 16:14:54 	dhclient 	26504 	DHCPNAK from {DHCP Server/WAN interface Gateway}
Dec 8 16:14:54 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:14:26 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:13:46 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:13:32 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:13:20 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:13:09 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:12:37 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:12:22 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:12:09 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:11:57 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:11:52 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:11:50 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:11:49 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:11:48 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67
Dec 8 16:11:47 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP Server/WAN interface Gateway} port 67

So the client tries to do a DHCPREQUEST for several times until it finally receives a DHCPNAK from the server to initiate the whole DORA process again. At 4:44PM, it does the same thing but the server sends a DHCPACK after the first DHCPREQUEST from the client.

Gertjan

@kevindd992002 said in Gateway monitor down:

I'm seeing DHCPNAK

Looks like the upstream DHCP server send a DHCPNAK. This was with your ISP device in bridge mode ? So it was the DHCP server from the ISP ... ?
" I'm seeing DHCPNAK" => The ISP is seeing your DHCPDISCOVERS and didn't expect them ? It tells the pfSEnse DHCP client 'to shut up'.

@kevindd992002 said in Gateway monitor down:

seeing frequent "renewal in 1800 seconds" messages? Does that mean the DHCP lease is just every 30 minutes?

This part :

Dec 8 12:11:44 	dhclient 	26504 	bound to {WAN IP} -- renewal in 1800 seconds.
Dec 8 12:11:43 	dhclient 	24813 	Creating resolv.conf
Dec 8 12:11:43 	dhclient 	24678 	RENEW
Dec 8 12:11:43 	dhclient 	26504 	unknown dhcp option value 0x52
Dec 8 12:11:43 	dhclient 	26504 	DHCPACK from {DHCP server/WAN interface gateway}
Dec 8 12:11:43 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP server/WAN interface gateway} port 67
Dec 8 11:45:06 	dhcpd 	21997 	DHCPACK on 192.168.20.253 to 0a:d6:94:12:78:5c via igb1
Dec 8 11:45:06 	dhcpd 	21997 	DHCPREQUEST for 192.168.20.253 from 0a:d6:94:12:78:5c via igb1
Dec 8 11:45:06 	dhcpd 	21997 	reuse_lease: lease age 20117 (secs) under 25% threshold, reply with unaltered, existing lease for 192.168.20.253

You're getting a TFC1918 = 192.168.20.253 is an IP from your ISP device in router mode ....
Your ISP would not give ypu a RFC1918 it the device was in bridge mode. It shouldn't.

Btw : the dhcp (pfSense) client receives a option 0x52 = 82 decimal = "Relay Agent Information" and the client doesn't know what that means / isn't aware of that option / doesn't know what to do with it.

You saw several

dhcpleases 	xxxxxSending HUP signal to dns daemo

Go to the Services > DNS Resolver > General Settings and un check "DHCP Registration". You deal with that issue later (it's a very known : evey time a (any) device on your LAN asks for a new IP by DHCO, or renews, the Resolver gets restarted. If you have many devices, or a device that likes to ask a new IP every xx seconds, the resolver (unbound) passes more time with restating as doing its actual job = handling your DNS).
Just un check "DHCP Registration" and have this stopped.

edit :

What about telling the dhcp pfSense client to wait for a minute or two when a WAN UP/DOWN event is detected ?

Check this one :

look up the meaning of the several time out values here https://www.freebsd.org/cgi/man.cgi?query=dhclient.conf&sektion=5&n=1

You could also enter the IP (RFC1918) of your ISP device to be rejected :

Read :

To have the DHCP client reject offers from specific DHCP servers, enter their IP addresses here (separate multiple entries with a comma). This is useful for rejecting leases from cable modems that offer private IP addresses when they lose upstream sync.

So :

if you don't want to accept an IP from your ISP device - it's internal DHCP server (when it is in bridge mode).

kevindd992002

@gertjan said in Gateway monitor down:

@kevindd992002 said in Gateway monitor down:

I'm seeing DHCPNAK

Looks like the upstream DHCP server send a DHCPNAK. This was with your ISP device in bridge mode ? So it was the DHCP server from the ISP ... ?
" I'm seeing DHCPNAK" => The ISP is seeing your DHCPDISCOVERS and didn't expect them ? It tells the pfSEnse DHCP client 'to shut up'.

Correct. That is the upstream DHCP server from the ISP because it is in bridge mode.

You mean the ISP is seeing DHCPREQUESTs and not DHCPDISCOVERs, right? I'm seeing multiple DHCPREQUESTs that aren't being answered.

@kevindd992002 said in Gateway monitor down:

seeing frequent "renewal in 1800 seconds" messages? Does that mean the DHCP lease is just every 30 minutes?

This part :
Dec 8 12:11:44 	dhclient 	26504 	bound to {WAN IP} -- renewal in 1800 seconds.
Dec 8 12:11:43 	dhclient 	24813 	Creating resolv.conf
Dec 8 12:11:43 	dhclient 	24678 	RENEW
Dec 8 12:11:43 	dhclient 	26504 	unknown dhcp option value 0x52
Dec 8 12:11:43 	dhclient 	26504 	DHCPACK from {DHCP server/WAN interface gateway}
Dec 8 12:11:43 	dhclient 	26504 	DHCPREQUEST on igb0 to {DHCP server/WAN interface gateway} port 67
Dec 8 11:45:06 	dhcpd 	21997 	DHCPACK on 192.168.20.253 to 0a:d6:94:12:78:5c via igb1
Dec 8 11:45:06 	dhcpd 	21997 	DHCPREQUEST for 192.168.20.253 from 0a:d6:94:12:78:5c via igb1
Dec 8 11:45:06 	dhcpd 	21997 	reuse_lease: lease age 20117 (secs) under 25% threshold, reply with unaltered, existing lease for 192.168.20.253
You're getting a TFC1918 = 192.168.20.253 is an IP from your ISP device in router mode ....
Your ISP would not give ypu a RFC1918 it the device was in bridge mode. It shouldn't.

Please ignore the dhcpd events on the 1st set of logs that I posted today. Those are for pfsense acting as the DHCP server to my "LAN clients" which is why you see RFC1918 addresses in the logs. This is why I posted a 2nd set of logs that only shows the dhclient entries which is what's important for my WAN DHCP lease renewal issue.

Btw : the dhcp (pfSense) client receives a option 0x52 = 82 decimal = "Relay Agent Information" and the client doesn't know what that means / isn't aware of that option / doesn't know what to do with it.

Yes, I saw that too. So that means that the ISP DHCP server is using DHCP relay which is why this whole issue could be related to this, no?

You saw several
dhcpleases 	xxxxxSending HUP signal to dns daemo
Go to the Services > DNS Resolver > General Settings and un check "DHCP Registration". You deal with that issue later (it's a very known : evey time a (any) device on your LAN asks for a new IP by DHCO, or renews, the Resolver gets restarted. If you have many devices, or a device that likes to ask a new IP every xx seconds, the resolver (unbound) passes more time with restating as doing its actual job = handling your DNS).
Just un check "DHCP Registration" and have this stopped.

I am totally aware of this and this only affects the DHCP server service (dhcpd) in pfsense, not the dhclient. I don't really care if the the DHCP server restarts every now and then because of DHCP registrations. I accept the fact that it does this.

Gertjan

@kevindd992002

I've edited - add another part ot my reply above.

kevindd992002

@gertjan said in Gateway monitor down:

edit :

What about telling the dhcp pfSense client to wait for a minute or two when a WAN UP/DOWN event is detected ?

Check this one :

look up the meaning of the several time out values here https://www.freebsd.org/cgi/man.cgi?query=dhclient.conf&sektion=5&n=1

I'm looking into this too but I don't want to be breaking any RFC rules that aren't supposed to be broken. Not sure if the problem is in the client side or the ISP DHCP server side.

You could also enter the IP (RFC1918) of your ISP device to be rejected :

Read :
To have the DHCP client reject offers from specific DHCP servers, enter their IP addresses here (separate multiple entries with a comma). This is useful for rejecting leases from cable modems that offer private IP addresses when they lose upstream sync.
So :

if you don't want to accept an IP from your ISP device - it's internal DHCP server (when it is in bridge mode).

The IP of my ISP's DHCP server is a public IP which is expected. So not sure if this has some effect.

Gertjan

@kevindd992002 said in Gateway monitor down:

I don't really care if the the DHCP server restarts every now and then because of DHCP registrations. I accept the fact that it does this.

No, no the pfSense DHCP server. It's far worse.
When the pfSense DHCP server gave an IP lease to a LAN based device, it will :

Sending HUP signal to dns daemon

This means : it will restart unbound, the DNS resolver.

Ok if it does so ones in a while.
Not every minute or so, as you will be loosing your DNS cache every time it restarts.
The DNS functionality on your LAN will be not available during restart.
And that's bad ....

kevindd992002

@gertjan said in Gateway monitor down:

@kevindd992002 said in Gateway monitor down:

I don't really care if the the DHCP server restarts every now and then because of DHCP registrations. I accept the fact that it does this.

No, no the pfSense DHCP server. It's far worse.
When the pfSense DHCP server gave an IP lease to a LAN based device, it will :
Sending HUP signal to dns daemon
This means : it will restart unbound, the DNS resolver.

Ok if it does so ones in a while.
Not every minute or so, as you will be loosing your DNS cache every time it restarts.
The DNS functionality on your LAN will be not available during restart.
And that's bad ....

Ohhh, you're right. Yeah, then I should probably disable that if it deletes the cache every single time :) Even though I have my own DNS server (adguard home), it is still pointed to pfsense's unbound for faster resolution.

stephenw10

@kevindd992002 said in Gateway monitor down:

Also, why am I seeing frequent "renewal in 1800 seconds" messages? Does that mean the DHCP lease is just every 30 minutes?

The dhcp client will typically renew at half the lease time to prevent the lease ever expiring. So it looks like the ISP is handing you a 1 hour lease.

Steve

kevindd992002

@stephenw10 said in Gateway monitor down:

@kevindd992002 said in Gateway monitor down:

Also, why am I seeing frequent "renewal in 1800 seconds" messages? Does that mean the DHCP lease is just every 30 minutes?

The dhcp client will typically renew at half the lease time to prevent the lease ever expiring. So it looks like the ISP is handing you a 1 hour lease.

Steve

Right. That makes sense. Checking the logs again, it looks like most of the times the lease get renewed properly but there are random times that the client just sends out a Unicast DHCPREQUEST multiple times until it gets a DHCPNAK like I showed above. Do you think this is an ISP DHCP server issue? If so, do you have any tips on what I should tell them?

kevindd992002

It happened again just this very moment and the logs show the exact same thing.

stephenw10

Does it eventually switch back to broadcast and then get a reply from a different server?

I have seen ISPs with badly configured redundant DHCP servers that can behave like that.

You can set the WAN dhcp client to requests a different lease time. The server can just ignore that though.

Steve

kevindd992002

@stephenw10 said in Gateway monitor down:

Does it eventually switch back to broadcast and then get a reply from a different server?

I have seen ISPs with badly configured redundant DHCP servers that can behave like that.

You can set the WAN dhcp client to requests a different lease time. The server can just ignore that though.

Steve

No, it doesn't. Though I'm reading that it should do broadcast after several tries. Not sure if there has been any update to pfsense about this causing the behavior to change. And from the logs, it's always talking to the same DHCP server IP.

What it does is that the client sends multiple (no exact number) unicast DHCPREQUESTs to the ISP DHCP server and the server responds with a DHCPNAK eventually. As expected, when the client receives a NAK, it starts the whole DORA process. At this point, the DISCOVER will be a broadcast and it gets completed until the clients gets an ACK from the server.

But then, like I said, the usual unicast process works "most of the time". So that tells me that it's not a case of unicast or broadcast but I don't know what's causing it.

And yes, changing the lease time would probably be ignored by the server. I think it's one of the most basic security mechanisms of DHCP.

stephenw10

The DHCP server may have limits set that it ignores requests outside of but it may well accept requests inside that. I have seen similar situations where the DHCP server was handing out a lease that was far too long resolved by doing that. That doesn't fit what you're seeing here exactly though.

Steve

kevindd992002

@stephenw10 said in Gateway monitor down:

The DHCP server may have limits set that it ignores requests outside of but it may well accept requests inside that. I have seen similar situations where the DHCP server was handing out a lease that was far too long resolved by doing that. That doesn't fit what you're seeing here exactly though.

Steve

I see. But what will increasing the lease time do though?

stephenw10

For example it may be something rejecting too frequent requests. Though that seems unlikely at 1800s.

kevindd992002

@stephenw10

So it does look like that they fixed the DHCP lease issue. However, I'm still having issues with gateway monitoring and ping latency in general.

Look how crappy my gateway montioring graph is. It started increasing in latency since Dec. 16:

alt text

When I try pinging even just the WAN gateway (a public router IP on my ISP's network), it's very unstable too. It's very hard to explain this to the ISP support agents because they simply don't understand.

stephenw10

Looks like the graph didn't upload.