PPP won't reconnect after outage
-
Hello
The following bug ticket is closed but I am still experiencing the issue.
https://redmine.pfsense.org/issues/1811
As suggested in the ticket I start a forum topic with the correct subject.My pfSense deployments are able to survive packet losses and PPP recover most of the time, however I have experienced on multiple SG-1100 devices that after ISP outage the PPP client won't reconnect.
What I see is in the PPP logs are the same as in the bug ticket above.
After numerous "IPCP: SendConfigReq" messages
there is a "IPCP: parameter negotiation failed" message
then the link closing down and there is no more attempt from the PPP client to reconnect.Because of this, after the outage is over the netgate box needs to be rebooted than the PPP client successfully connects. (The bug ticket says clicking on the connect wan button on the status > interfaces page also restores the service)
I have a box currently in this state, the outage is over but pfSense is not connecting and the PPP log is silent.
RFC 1132 says: "It is suggested that an implementation give up only after user intervention or a configurable amount of time."
Netgate support just opened a bug ticket
https://redmine.pfsense.org/issues/13092
for this issue but the subject might "fails to establish after long upstream outages" be not correct, because I've seen in other cases that PPP client stops retry within a minute after the outage started.Jun 30 00:45:00 ppp [wan] IFACE: Rename interface ng0 to pppoe0 Jul 2 02:21:46 ppp [wan] IPCP: rec'd Configure Request #2 (Opened) Jul 2 02:21:46 ppp [wan] IPADDR 202.138.4.64 Jul 2 02:21:46 ppp [wan] 202.138.4.64 is OK Jul 2 02:21:46 ppp [wan] IPCP: LayerDown Jul 2 02:21:47 ppp [wan] IFACE: Down event Jul 2 02:21:47 ppp [wan] IFACE: Rename interface pppoe0 to pppoe0 Jul 2 02:21:47 ppp [wan] IPCP: SendConfigReq #76 Jul 2 02:21:47 ppp [wan] IPADDR 218.214.186.153 Jul 2 02:21:47 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:21:47 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:21:47 ppp [wan] IPCP: SendConfigAck #2 Jul 2 02:21:47 ppp [wan] IPADDR 202.138.4.64 Jul 2 02:21:47 ppp [wan] IPCP: state change Opened --> Ack-Sent Jul 2 02:21:50 ppp [wan] IPCP: SendConfigReq #77 Jul 2 02:21:50 ppp [wan] IPADDR 218.214.186.153 Jul 2 02:21:50 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:21:50 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:21:52 ppp [wan] IPCP: SendConfigReq #78 Jul 2 02:21:52 ppp [wan] IPADDR 218.214.186.153 Jul 2 02:21:52 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:21:52 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:21:54 ppp [wan] IPCP: SendConfigReq #79 Jul 2 02:21:54 ppp [wan] IPADDR 218.214.186.153 Jul 2 02:21:54 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:21:54 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:21:56 ppp [wan] IPCP: rec'd Configure Request #3 (Ack-Sent) Jul 2 02:21:56 ppp [wan] IPADDR 202.138.4.64 Jul 2 02:21:56 ppp [wan] 202.138.4.64 is OK Jul 2 02:21:56 ppp [wan] IPCP: SendConfigAck #3 Jul 2 02:21:56 ppp [wan] IPADDR 202.138.4.64 Jul 2 02:21:56 ppp [wan] IPCP: SendConfigReq #80 Jul 2 02:21:56 ppp [wan] IPADDR 218.214.186.153 Jul 2 02:21:56 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:21:56 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:21:58 ppp [wan] IPCP: SendConfigReq #81 Jul 2 02:21:58 ppp [wan] IPADDR 218.214.186.153 Jul 2 02:21:58 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:21:58 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:00 ppp [wan] IPCP: SendConfigReq #82 Jul 2 02:22:00 ppp [wan] IPADDR 218.214.186.153 Jul 2 02:22:00 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:00 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:02 ppp [wan] IPCP: SendConfigReq #83 Jul 2 02:22:02 ppp [wan] IPADDR 218.214.186.153 Jul 2 02:22:02 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:02 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:04 ppp [wan] IPCP: SendConfigReq #84 Jul 2 02:22:04 ppp [wan] IPADDR 218.214.186.153 Jul 2 02:22:04 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:04 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:06 ppp [wan] IPCP: rec'd Configure Request #4 (Ack-Sent) Jul 2 02:22:06 ppp [wan] IPADDR 202.138.4.64 Jul 2 02:22:06 ppp [wan] 202.138.4.64 is OK Jul 2 02:22:06 ppp [wan] IPCP: SendConfigAck #4 Jul 2 02:22:06 ppp [wan] IPADDR 202.138.4.64 Jul 2 02:22:06 ppp [wan] IPCP: SendConfigReq #85 Jul 2 02:22:06 ppp [wan] IPADDR 218.214.186.153 Jul 2 02:22:06 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:06 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:08 ppp [wan] IPCP: parameter negotiation failed Jul 2 02:22:08 ppp [wan] IPCP: state change Ack-Sent --> Stopped Jul 2 02:22:08 ppp [wan] IPCP: LayerFinish Jul 2 02:22:08 ppp [wan] Bundle: No NCPs left. Closing links... Jul 2 02:22:08 ppp [wan] Bundle: closing link "wan_link0"... Jul 2 02:22:08 ppp [wan_link0] Link: CLOSE event Jul 2 02:22:08 ppp [wan_link0] LCP: Close event Jul 2 02:22:08 ppp [wan_link0] LCP: state change Opened --> Closing Jul 2 02:22:08 ppp [wan_link0] Link: Leave bundle "wan" Jul 2 02:22:08 ppp [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps Jul 2 02:22:08 ppp [wan] IPCP: Close event Jul 2 02:22:08 ppp [wan] IPCP: state change Stopped --> Closed Jul 2 02:22:08 ppp [wan] IPV6CP: Close event Jul 2 02:22:08 ppp [wan] IPV6CP: state change Stopped --> Closed Jul 2 02:22:08 ppp [wan] IPCP: Down event Jul 2 02:22:08 ppp [wan] IPCP: state change Closed --> Initial Jul 2 02:22:08 ppp [wan] IPV6CP: Down event Jul 2 02:22:08 ppp [wan] IPV6CP: state change Closed --> Initial Jul 2 02:22:08 ppp [wan_link0] LCP: SendTerminateReq #42 Jul 2 02:22:08 ppp [wan_link0] LCP: LayerDown Jul 2 02:22:10 ppp [wan_link0] LCP: SendTerminateReq #43 Jul 2 02:22:12 ppp [wan_link0] LCP: state change Closing --> Closed Jul 2 02:22:12 ppp [wan_link0] LCP: LayerFinish Jul 2 02:22:12 ppp [wan_link0] Link: DOWN event Jul 2 02:22:12 ppp [wan_link0] LCP: Down event Jul 2 02:22:12 ppp [wan_link0] LCP: state change Closed --> Initial Jul 2 12:01:11 ppp Multi-link PPP daemon for FreeBSD Jul 2 12:01:11 ppp process 22725 started, version 5.8 (root@pfSense_factory-v2_4_5_aarch64-pfSense_factory-v2_4_5-job-14 19:37 28-Jan-2020)Jun 25 00:27:36 ppp [wan] IFACE: Rename interface ng0 to pppoe0 Jul 2 02:22:18 ppp [wan] IPCP: rec'd Configure Request #2 (Opened) Jul 2 02:22:18 ppp [wan] IPADDR 202.138.4.64 Jul 2 02:22:18 ppp [wan] 202.138.4.64 is OK Jul 2 02:22:18 ppp [wan] IPCP: LayerDown Jul 2 02:22:19 ppp [wan] IFACE: Down event Jul 2 02:22:19 ppp [wan] IFACE: Rename interface pppoe0 to pppoe0 Jul 2 02:22:19 ppp [wan] IPCP: SendConfigReq #208 Jul 2 02:22:19 ppp [wan] IPADDR 125.168.227.112 Jul 2 02:22:19 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:19 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:19 ppp [wan] IPCP: SendConfigAck #2 Jul 2 02:22:19 ppp [wan] IPADDR 202.138.4.64 Jul 2 02:22:19 ppp [wan] IPCP: state change Opened --> Ack-Sent Jul 2 02:22:21 ppp [wan] IPCP: SendConfigReq #209 Jul 2 02:22:21 ppp [wan] IPADDR 125.168.227.112 Jul 2 02:22:21 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:21 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:23 ppp [wan] IPCP: SendConfigReq #210 Jul 2 02:22:23 ppp [wan] IPADDR 125.168.227.112 Jul 2 02:22:23 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:23 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:25 ppp [wan] IPCP: SendConfigReq #211 Jul 2 02:22:25 ppp [wan] IPADDR 125.168.227.112 Jul 2 02:22:25 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:25 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:27 ppp [wan] IPCP: SendConfigReq #212 Jul 2 02:22:27 ppp [wan] IPADDR 125.168.227.112 Jul 2 02:22:27 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:27 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:29 ppp [wan] IPCP: SendConfigReq #213 Jul 2 02:22:29 ppp [wan] IPADDR 125.168.227.112 Jul 2 02:22:29 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:29 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:31 ppp [wan] IPCP: SendConfigReq #214 Jul 2 02:22:31 ppp [wan] IPADDR 125.168.227.112 Jul 2 02:22:31 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:31 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:31 ppp [wan] IPCP: rec'd Configure Request #3 (Ack-Sent) Jul 2 02:22:31 ppp [wan] IPADDR 202.138.4.64 Jul 2 02:22:31 ppp [wan] 202.138.4.64 is OK Jul 2 02:22:31 ppp [wan] IPCP: SendConfigAck #3 Jul 2 02:22:31 ppp [wan] IPADDR 202.138.4.64 Jul 2 02:22:33 ppp [wan] IPCP: SendConfigReq #215 Jul 2 02:22:33 ppp [wan] IPADDR 125.168.227.112 Jul 2 02:22:33 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:33 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:35 ppp [wan] IPCP: SendConfigReq #216 Jul 2 02:22:35 ppp [wan] IPADDR 125.168.227.112 Jul 2 02:22:35 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:35 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:37 ppp [wan] IPCP: SendConfigReq #217 Jul 2 02:22:37 ppp [wan] IPADDR 125.168.227.112 Jul 2 02:22:37 ppp [wan] PRIDNS 203.134.24.70 Jul 2 02:22:37 ppp [wan] SECDNS 203.134.26.70 Jul 2 02:22:39 ppp [wan] IPCP: parameter negotiation failed Jul 2 02:22:39 ppp [wan] IPCP: state change Ack-Sent --> Stopped Jul 2 02:22:39 ppp [wan] IPCP: LayerFinish Jul 2 02:22:39 ppp [wan] Bundle: No NCPs left. Closing links... Jul 2 02:22:39 ppp [wan] Bundle: closing link "wan_link0"... Jul 2 02:22:39 ppp [wan_link0] Link: CLOSE event Jul 2 02:22:39 ppp [wan_link0] LCP: Close event Jul 2 02:22:39 ppp [wan_link0] LCP: state change Opened --> Closing Jul 2 02:22:39 ppp [wan_link0] Link: Leave bundle "wan" Jul 2 02:22:39 ppp [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps Jul 2 02:22:39 ppp [wan] IPCP: Close event Jul 2 02:22:39 ppp [wan] IPCP: state change Stopped --> Closed Jul 2 02:22:39 ppp [wan] IPV6CP: Close event Jul 2 02:22:39 ppp [wan] IPV6CP: state change Stopped --> Closed Jul 2 02:22:39 ppp [wan] IPCP: Down event Jul 2 02:22:39 ppp [wan] IPCP: state change Closed --> Initial Jul 2 02:22:39 ppp [wan] IPV6CP: Down event Jul 2 02:22:39 ppp [wan] IPV6CP: state change Closed --> Initial Jul 2 02:22:39 ppp [wan_link0] LCP: SendTerminateReq #105 Jul 2 02:22:39 ppp [wan_link0] LCP: LayerDown Jul 2 02:22:41 ppp [wan_link0] rec'd proto IPCP during terminate phase Jul 2 02:22:41 ppp [wan_link0] LCP: SendTerminateReq #106 Jul 2 02:22:43 ppp [wan_link0] LCP: state change Closing --> Closed Jul 2 02:22:43 ppp [wan_link0] LCP: LayerFinish Jul 2 02:22:43 ppp [wan_link0] Link: DOWN event Jul 2 02:22:43 ppp [wan_link0] LCP: Down event Jul 2 02:22:43 ppp [wan_link0] LCP: state change Closed --> Initial Jul 2 09:45:30 ppp Multi-link PPP daemon for FreeBSD Jul 2 09:45:30 ppp process 17703 started, version 5.8 (root@pfSense_factory-v2_4_5_aarch64-pfSense_factory-v2_4_5-job-14 19:37 28-Jan-2020) -
-
@stephenw10
Sure. I've tried to apply the patch and received the following messageThe following input errors were detected: The uploaded file must be in unified diff format. -
You tried it via the System Patches package? Against 2.6?
That works fine for me:
Although it's a one line change, you could easily apply it manually.
Steve
-
@stephenw10
I was using the "Patch file upload" option.
Copy pasting the content worked.Thank you!
-
Hmm, interesting. It uploads OK here though I also initially copy and pasted it in.
Let us know of that helps with the reconnects.
Steve
-
I can't find "noretry" option in the MPD 5.9 user manual.
http://mpd.sourceforge.net/doc5/mpd22.html#22Is this option valid?
-
Is it showing errors loading the config? In the logs?
-
The log says unknown option.
Apr 29 09:34:20 pfSense ppp[17480]: Multi-link PPP daemon for FreeBSD Apr 29 09:34:20 pfSense ppp[17480]: Apr 29 09:34:20 pfSense ppp[17480]: process 17480 started, version 5.9 Apr 29 09:34:20 pfSense ppp[17480]: web: web is not running Apr 29 09:34:20 pfSense ppp[17480]: [wan] Bundle: Interface ng0 created Apr 29 09:34:20 pfSense ppp[17480]: option "noretry" unknown Apr 29 09:34:20 pfSense ppp[17480]: option "noretry" unknown -
Ok, well that's a problem!
-
I assume you were able to test your provided workaround patch? And it works as expected?
-
Yes I added the lines in the config. The PPP connection was established without problem and there are no errors in the log file.
I haven't had outage since than, therefore I couldn't test the reconnect part.
Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.