How to debug unstable WAN
-
I've been using pfSense for a couple of months and had a very stable WAN connection. Infra is modem is in bridge mode and pfSense is PPPoE.
Recently the WAN link has become unstable and I am trying to work out if it is the ISP or pfSense. I think it is pfSense because I have taken pfSense out and put the modem back and the gateway and firewall and it has stabilised.
Interestingly, some months ago I had a different PC running pfSense and after a few months running the WAN link on that also became unstable - I put it down to the network device that was a USB-C dongle going faulty.
I am not sure what I am looking for in the logs to see why the PPPoE connection is dropping out - can anyone suggest what to start looking for to diagnose the issue?
Thanks -
Status>System Logs>System>Gateways
Status>Gateways
-
Thanks Zawi,
Yeah - I knew about that. I guess my question was more about "what do I look for in that log?"
Here is what is showing up in ppp.log for example (I changed all IP addresses). This captures the time of a failure, but I'm not sure where to start to understand it.Apr 17 03:04:11 pfSense ppp: [wan] IPADDR 61.250.208.106 Apr 17 03:04:13 pfSense ppp: [wan] IPCP: SendConfigReq #86 Apr 17 03:04:13 pfSense ppp: [wan] IPADDR 61.250.208.106 Apr 17 03:04:16 pfSense ppp: [wan] IPCP: SendConfigReq #87 Apr 17 03:04:16 pfSense ppp: [wan] IPADDR 61.250.208.106 Apr 17 03:04:18 pfSense ppp: [wan] IPCP: SendConfigReq #88 Apr 17 03:04:18 pfSense ppp: [wan] IPADDR 61.250.208.106 Apr 17 03:04:20 pfSense ppp: [wan] IPCP: SendConfigReq #89 Apr 17 03:04:20 pfSense ppp: [wan] IPADDR 61.250.208.106 Apr 17 03:04:22 pfSense ppp: [wan] IPCP: parameter negotiation failed Apr 17 03:04:22 pfSense ppp: [wan] IPCP: state change Req-Sent --> Stopped Apr 17 03:04:22 pfSense ppp: [wan] IPCP: LayerFinish Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: Up event Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: state change Starting --> Req-Sent Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: SendConfigReq #19 Apr 17 03:02:13 pfSense ppp: [wan] IPCP: rec'd Configure Request #1 (Req-Sent) Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 18.71.83.22 Apr 17 03:02:13 pfSense ppp: [wan] 18.71.83.22 is OK Apr 17 03:02:13 pfSense ppp: [wan] IPCP: SendConfigAck #1 Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 18.71.83.22 Apr 17 03:02:13 pfSense ppp: [wan] IPCP: state change Req-Sent --> Ack-Sent Apr 17 03:02:13 pfSense ppp: [wan] IPCP: rec'd Configure Reject #73 (Ack-Sent) Apr 17 03:02:13 pfSense ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Apr 17 03:02:13 pfSense ppp: [wan] IPCP: SendConfigReq #74 Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 0.0.0.0 Apr 17 03:02:13 pfSense ppp: [wan_link0] LCP: rec'd Protocol Reject #3 (Opened) Apr 17 03:02:13 pfSense ppp: [wan_link0] LCP: protocol IPV6CP was rejected Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: protocol was rejected by peer Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: state change Req-Sent --> Stopped Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: LayerFinish Apr 17 03:02:13 pfSense ppp: [wan] IPCP: rec'd Configure Nak #74 (Ack-Sent) Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 61.250.208.106 Apr 17 03:02:13 pfSense ppp: [wan] 61.250.208.106 is OK Apr 17 03:02:13 pfSense ppp: [wan] IPCP: SendConfigReq #75 Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 61.250.208.106 Apr 17 03:02:13 pfSense ppp: [wan] IPCP: rec'd Configure Ack #75 (Ack-Sent) Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 61.250.208.106 Apr 17 03:02:13 pfSense ppp: [wan] IPCP: state change Ack-Sent --> Opened Apr 17 03:02:13 pfSense ppp: [wan] IPCP: LayerUp Apr 17 03:02:13 pfSense ppp: [wan] 61.250.208.106 -> 18.71.83.22 Apr 17 03:02:13 pfSense ppp: [wan] IFACE: Up event Apr 17 03:02:13 pfSense ppp: [wan] IFACE: Rename interface ng0 to pppoe0 Apr 17 03:02:43 pfSense ppp: [wan_link0] LCP: no reply to 1 echo request(s) Apr 17 03:02:53 pfSense ppp: [wan_link0] LCP: no reply to 2 echo request(s) Apr 17 03:03:03 pfSense ppp: [wan_link0] LCP: no reply to 3 echo request(s) Apr 17 03:03:13 pfSense ppp: [wan_link0] LCP: no reply to 4 echo request(s) Apr 17 03:03:24 pfSense ppp: [wan_link0] LCP: no reply to 5 echo request(s) Apr 17 03:03:24 pfSense ppp: [wan_link0] LCP: peer not responding to echo requests Apr 17 03:03:24 pfSense ppp: [wan_link0] LCP: state change Opened --> Stopping Apr 17 03:03:24 pfSense ppp: [wan_link0] Link: Leave bundle "wan" Apr 17 03:03:24 pfSense ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps Apr 17 03:03:24 pfSense ppp: [wan] IPCP: Close event Apr 17 03:03:24 pfSense ppp: [wan] IPCP: state change Opened --> Closing Apr 17 03:02:13 pfSense ppp: [wan_link0] MRU 1492 Apr 17 03:02:13 pfSense ppp: [wan_link0] AUTHPROTO PAP Apr 17 03:02:13 pfSense ppp: [wan_link0] MAGICNUM 0x98ba6d97 Apr 17 03:02:13 pfSense ppp: [wan_link0] LCP: state change Req-Sent --> Ack-Sent Apr 17 03:02:13 pfSense ppp: [wan_link0] LCP: rec'd Configure Ack #51 (Ack-Sent) Apr 17 03:02:13 pfSense ppp: [wan_link0] PROTOCOMP Apr 17 03:02:13 pfSense ppp: [wan_link0] MRU 1492 Apr 17 03:02:13 pfSense ppp: [wan_link0] MAGICNUM 0xb6841a5e Apr 17 03:02:13 pfSense ppp: [wan_link0] LCP: state change Ack-Sent --> Opened Apr 17 03:02:13 pfSense ppp: [wan_link0] LCP: auth: peer wants PAP, I want nothing Apr 17 03:02:13 pfSense ppp: [wan_link0] PAP: using authname "bryonbakeraus" Apr 17 03:02:13 pfSense ppp: [wan_link0] PAP: sending REQUEST #1 len: 29 Apr 17 03:02:13 pfSense ppp: [wan_link0] LCP: LayerUp Apr 17 03:02:13 pfSense ppp: [wan_link0] PAP: rec'd ACK #1 len: 5 Apr 17 03:02:13 pfSense ppp: [wan_link0] LCP: authorization successful Apr 17 03:02:13 pfSense ppp: [wan_link0] Link: Matched action 'bundle "wan" ""' Apr 17 03:02:13 pfSense ppp: [wan_link0] Link: Join bundle "wan" Apr 17 03:02:13 pfSense ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps Apr 17 03:02:13 pfSense ppp: [wan] IPCP: Open event Apr 17 03:02:13 pfSense ppp: [wan] IPCP: state change Initial --> Starting Apr 17 03:02:13 pfSense ppp: [wan] IPCP: LayerStart Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: Open event Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: state change Initial --> Starting Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: LayerStart Apr 17 03:02:13 pfSense ppp: [wan] IPCP: Up event Apr 17 03:02:13 pfSense ppp: [wan] IPCP: state change Starting --> Req-Sent Apr 17 03:02:13 pfSense ppp: [wan] IPCP: SendConfigReq #73 Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 0.0.0.0 Apr 17 03:02:13 pfSense ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: Up event Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: state change Starting --> Req-Sent Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: SendConfigReq #19 Apr 17 03:02:13 pfSense ppp: [wan] IPCP: rec'd Configure Request #1 (Req-Sent) Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 18.71.83.22 Apr 17 03:02:13 pfSense ppp: [wan] 18.71.83.22 is OK Apr 17 03:02:13 pfSense ppp: [wan] IPCP: SendConfigAck #1 Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 18.71.83.22 Apr 17 03:02:13 pfSense ppp: [wan] IPCP: state change Req-Sent --> Ack-Sent Apr 17 03:02:13 pfSense ppp: [wan] IPCP: rec'd Configure Reject #73 (Ack-Sent) Apr 17 03:02:13 pfSense ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Apr 17 03:02:13 pfSense ppp: [wan] IPCP: SendConfigReq #74 Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 0.0.0.0 Apr 17 03:02:13 pfSense ppp: [wan_link0] LCP: rec'd Protocol Reject #3 (Opened) Apr 17 03:02:13 pfSense ppp: [wan_link0] LCP: protocol IPV6CP was rejected Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: protocol was rejected by peer Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: state change Req-Sent --> Stopped Apr 17 03:02:13 pfSense ppp: [wan] IPV6CP: LayerFinish Apr 17 03:02:13 pfSense ppp: [wan] IPCP: rec'd Configure Nak #74 (Ack-Sent) Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 61.250.208.106 Apr 17 03:02:13 pfSense ppp: [wan] 61.250.208.106 is OK Apr 17 03:02:13 pfSense ppp: [wan] IPCP: SendConfigReq #75 Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 61.250.208.106 Apr 17 03:02:13 pfSense ppp: [wan] IPCP: rec'd Configure Ack #75 (Ack-Sent) Apr 17 03:02:13 pfSense ppp: [wan] IPADDR 61.250.208.106 Apr 17 03:02:13 pfSense ppp: [wan] IPCP: state change Ack-Sent --> Opened Apr 17 03:02:13 pfSense ppp: [wan] IPCP: LayerUp Apr 17 03:02:13 pfSense ppp: [wan] 61.250.208.106 -> 18.71.83.22 Apr 17 03:02:13 pfSense ppp: [wan] IFACE: Up event Apr 17 03:02:13 pfSense ppp: [wan] IFACE: Rename interface ng0 to pppoe0
-
So this comes up OK at boot for exmaple but then fails some time later?
Does it eventually connect by itself? What is required to make it connect if not?
Are you running pfSense 2.4.5?
Steve
-
Hi @stephenw10,
I am running pfSense 2.4.4 Release 3.
The WAN was stable for months and then started playing up. (I had experienced that before when I had a NUC running pfSense with a USB-C NIC - so I had deja vu and maybe pfSense was root cause...)
After being rock solid for months, last week pfSense would drop the connection and then reconnect for 10 minutes or so then drop it again. Rebooting would reconnect and then drop the WAN.
I suspect it was my ISP, but I did have that issue with the NUC so I was not confident with pointing the finger. I don't know what to look for in the logs to diagnose that (hence this question).
To work around the problem I took my modem out of bridge mode and turned off pfSense. The connection was stable after that. There may have been two drop outs but modems are a black box and I could only test that via continuous PING.
Last night I put the modem back into bridge mode and turned on ofSense and the WAN has been stable for over 16 hours. Reinforcing my suspicion that it was the ISP.
So like I said, I think it was an ISP issue, but don't know what to look for to see if it is me or them.
Thanks
-
The timestamps on those ppp logs appear strangely out of order. Do other logs on the firewall also appear like that?
The system time could be being updated if there is some issue with the system clock.
That would usually throw a bunch of other errors though.
Ignoring that though the log appears to show it successfully connect, then the remote side stops responding to LCP causing it to disconnect and start over. Then it successfully connects again.
Steve