PPPoE disconnects requiring reboot

Hoji

Hi All,

I run five pfsense boxes across various sites as the WAN gateway using various hardware, mostly Intel N3160 / 1037U type systems, all with either the em or igb ethernet adapters. For they run flawlessley for months at a time, apart from regular issues with PPPoE disconnections. This problem I'm currently having on 2.3.3, and has been happening since 2.2.x, possibly even 2.1.x.

Because this problem is somewhat intermittent it's difficult to pin down to get good debug, and more often than not the connection in question needs getting back online ASAP, so there's no time to sit there and tinker to see what's happened. Suffice to say that the following usually occurs:

1. Report of internet connection going up and down on a minute-by-minute basis
2. PPP syslog shows lots of reconnections
3. In some cases the connection never reconnects; the state it's in is shown in the log below
4. Rebooting the VDSL bridge makes no difference, and after restarting the pfsense box the problem stops completely

Ordinarily I would blame the ISP for PPP issues, but it's very difficult to do so because:

1. Various UK ISPs are in use; BT, Sky, Plusnet and Demon
2. Various types of connection, both ADSL and VDSL
3. Various modem hardware; Two Draytek Vigor 130s, one Netgear something-or-other in bridge mode, one BT Openreach modem, one Zyxel modem in bridge mode.

Needless to say the ISPs are not interested as I'm not using their wonderful hardware.

The logs below show one such event which required the pfsense box to be rebooted, subsequently everything worked fine. It's frustrating because, apart from this, I LOVE PFSENSE, but I have the constant thorn-in-the-side worry bacuase this crops up so regularly. It's stopped me rolling it out to commercial customers and instead I'm specifying and configuring the horribly expensive, arbitrarily-crippled, and far less useful Cisco ISR4321 / 4331 routers.

If any of the developers could point me in the direction of collecting more useful information once this happens I'm very happy to go through as much harvesting and debugging as possible, as fixing this would be wonderful.

Is this in fact and issue common to all the ISPs above, who all use the same BT OpenReach network? Is this an issue with the LCP configuration? Please, ask me questions!

Anyway, here's some logs…

This one required a reboot:

Apr 22 00:56:50 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 00:56:50 	ppp 		[wan_link0] Link: reconnection attempt 3
Apr 22 00:56:46 	ppp 		[wan_link0] Link: reconnection attempt 3 in 4 seconds
Apr 22 00:56:46 	ppp 		[wan_link0] LCP: Down event
Apr 22 00:56:46 	ppp 		[wan_link0] Link: DOWN event
Apr 22 00:56:46 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 00:56:37 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 00:56:37 	ppp 		[wan_link0] Link: reconnection attempt 2
Apr 22 00:56:33 	ppp 		[wan_link0] Link: reconnection attempt 2 in 4 seconds
Apr 22 00:56:33 	ppp 		[wan_link0] LCP: Down event
Apr 22 00:56:33 	ppp 		[wan_link0] Link: DOWN event
Apr 22 00:56:33 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 00:56:24 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 00:56:24 	ppp 		[wan_link0] Link: reconnection attempt 1
Apr 22 00:56:22 	ppp 		[wan_link0] Link: reconnection attempt 1 in 2 seconds
Apr 22 00:56:22 	ppp 		[wan_link0] LCP: Down event
Apr 22 00:56:22 	ppp 		[wan_link0] Link: DOWN event
Apr 22 00:56:22 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 00:56:13 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 00:56:13 	ppp 		[wan_link0] LCP: LayerStart
Apr 22 00:56:13 	ppp 		[wan_link0] LCP: state change Initial --> Starting
Apr 22 00:56:13 	ppp 		[wan_link0] LCP: Open event
Apr 22 00:56:13 	ppp 		[wan_link0] Link: OPEN event
Apr 22 00:56:13 	ppp 		[wan] Bundle: Interface ng0 created
Apr 22 00:56:13 	ppp 		web: web is not running
Apr 22 00:56:12 	ppp 		process 7617 terminated
Apr 22 00:56:12 	ppp 		[wan_link0] Link: Shutdown
Apr 22 00:56:12 	ppp 		[wan] Bundle: Shutdown
Apr 22 00:56:12 	ppp 		waiting for process 7617 to die...
Apr 22 00:56:11 	ppp 		waiting for process 7617 to die...
Apr 22 00:56:10 	ppp 		[wan] IPV6CP: Close event
Apr 22 00:56:10 	ppp 		[wan] IPCP: Close event
Apr 22 00:56:10 	ppp 		[wan] IFACE: Close event
Apr 22 00:56:10 	ppp 		caught fatal signal TERM
Apr 22 00:56:10 	ppp 		waiting for process 7617 to die...
Apr 22 00:56:10 	ppp 		process 77431 started, version 5.8 (root@pfSense_v2_3_2_amd64-pfSense_v2_3_2-job-04 16:03 19-Jul-2016)
Apr 22 00:56:10 	ppp 		Multi-link PPP daemon for FreeBSD
Apr 22 00:56:06 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 00:56:06 	ppp 		[wan_link0] Link: reconnection attempt 1
Apr 22 00:56:03 	ppp 		[wan_link0] Link: reconnection attempt 1 in 3 seconds
Apr 22 00:56:03 	ppp 		[wan_link0] LCP: LayerStart
Apr 22 00:56:03 	ppp 		[wan_link0] LCP: state change Stopped --> Starting
Apr 22 00:56:03 	ppp 		[wan_link0] LCP: Down event
Apr 22 00:56:03 	ppp 		[wan_link0] Link: DOWN event
Apr 22 00:56:03 	ppp 		[wan_link0] PPPoE: connection closed
Apr 22 00:56:03 	ppp 		[wan_link0] LCP: LayerFinish
Apr 22 00:56:03 	ppp 		[wan_link0] LCP: state change Stopping --> Stopped
Apr 22 00:56:01 	ppp 		[wan_link0] LCP: SendTerminateReq #4
Apr 22 00:55:58 	ppp 		[wan_link0] LCP: LayerDown
Apr 22 00:55:58 	ppp 		[wan_link0] LCP: SendTerminateReq #3
Apr 22 00:55:58 	ppp 		[wan] IPV6CP: state change Closing --> Initial
Apr 22 00:55:58 	ppp 		[wan] Bundle: No NCPs left. Closing links...
Apr 22 00:55:58 	ppp 		[wan] IPV6CP: LayerFinish
Apr 22 00:55:58 	ppp 		[wan] IPV6CP: Down event
Apr 22 00:55:58 	ppp 		[wan] IPCP: state change Closing --> Initial
Apr 22 00:55:58 	ppp 		[wan] IPCP: LayerFinish
Apr 22 00:55:58 	ppp 		[wan] IPCP: Down event
Apr 22 00:55:58 	ppp 		[wan] IFACE: Rename interface pppoe0 to pppoe0
Apr 22 00:55:58 	ppp 		[wan] IFACE: Down event
Apr 22 00:55:58 	ppp 		[wan] IPV6CP: LayerDown
Apr 22 00:55:58 	ppp 		[wan] IPV6CP: SendTerminateReq #2
Apr 22 00:55:58 	ppp 		[wan] IPV6CP: state change Opened --> Closing
Apr 22 00:55:58 	ppp 		[wan] IPV6CP: Close event
Apr 22 00:55:57 	ppp 		[wan] IPCP: LayerDown
Apr 22 00:55:57 	ppp 		[wan] IPCP: SendTerminateReq #4
Apr 22 00:55:57 	ppp 		[wan] IPCP: state change Opened --> Closing
Apr 22 00:55:57 	ppp 		[wan] IPCP: Close event
Apr 22 00:55:57 	ppp 		[wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Apr 22 00:55:57 	ppp 		[wan_link0] Link: Leave bundle "wan"
Apr 22 00:55:57 	ppp 		[wan_link0] LCP: state change Opened --> Stopping
Apr 22 00:55:57 	ppp 		[wan_link0] LCP: peer not responding to echo requests
Apr 22 00:55:57 	ppp 		[wan_link0] LCP: no reply to 5 echo request(s)
Apr 22 00:55:47 	ppp 		[wan_link0] LCP: no reply to 4 echo request(s)
Apr 22 00:55:37 	ppp 		[wan_link0] LCP: no reply to 3 echo request(s)
Apr 22 00:55:27 	ppp 		[wan_link0] LCP: no reply to 2 echo request(s)
Apr 22 00:55:17 	ppp 		[wan_link0] LCP: no reply to 1 echo request(s)

This one went through a few reconnection cycles before fixing itself:

Apr 22 23:39:23 	ppp 		[wan_link0] Link: Leave bundle "wan"
Apr 22 23:39:23 	ppp 		[wan_link0] LCP: state change Opened --> Starting
Apr 22 23:39:23 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:39:23 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:39:23 	ppp 		[wan_link0] PPPoE: connection closed
Apr 22 23:39:17 	ppp 		[wan_link0] LCP: no reply to 4 echo request(s)
Apr 22 23:39:07 	ppp 		[wan_link0] LCP: no reply to 3 echo request(s)
Apr 22 23:38:57 	ppp 		[wan_link0] LCP: no reply to 2 echo request(s)
Apr 22 23:38:47 	ppp 		[wan_link0] LCP: no reply to 1 echo request(s)
Apr 22 23:28:46 	ppp 		[wan]  ***HIDDEN*** -> 172.16.15.132
Apr 22 23:28:46 	ppp 		[wan] IPCP: LayerUp
Apr 22 23:28:46 	ppp 		[wan] IPCP: state change Ack-Sent --> Opened
Apr 22 23:28:46 	ppp 		[wan] SECDNS 81.139.57.100
Apr 22 23:28:46 	ppp 		[wan] PRIDNS 81.139.56.100
Apr 22 23:28:46 	ppp 		[wan] IPADDR ***HIDDEN***
Apr 22 23:28:46 	ppp 		[wan] IPCP: rec'd Configure Ack #249 (Ack-Sent)
Apr 22 23:28:46 	ppp 		[wan] SECDNS 81.139.57.100
Apr 22 23:28:46 	ppp 		[wan] PRIDNS 81.139.56.100
Apr 22 23:28:46 	ppp 		[wan] IPADDR  ***HIDDEN***
Apr 22 23:28:46 	ppp 		[wan] IPCP: SendConfigReq #249
Apr 22 23:28:46 	ppp 		[wan] SECDNS 81.139.57.100
Apr 22 23:28:46 	ppp 		[wan] PRIDNS 81.139.56.100
Apr 22 23:28:46 	ppp 		[wan]  ***HIDDEN*** is OK
Apr 22 23:28:46 	ppp 		[wan] IPADDR  ***HIDDEN***
Apr 22 23:28:46 	ppp 		[wan] IPCP: rec'd Configure Nak #248 (Ack-Sent)
Apr 22 23:28:46 	ppp 		[wan] IFACE: Rename interface ng0 to pppoe0
Apr 22 23:28:46 	ppp 		[wan] IFACE: Up event
Apr 22 23:28:45 	ppp 		[wan] 02e0:6fff:fe28:30cd -> a2f3:e4ff:fe7e:3230
Apr 22 23:28:45 	ppp 		[wan] IPV6CP: LayerUp
Apr 22 23:28:45 	ppp 		[wan] IPV6CP: state change Ack-Sent --> Opened
Apr 22 23:28:45 	ppp 		[wan] IPV6CP: rec'd Configure Ack #145 (Ack-Sent)
Apr 22 23:28:45 	ppp 		[wan] SECDNS 0.0.0.0
Apr 22 23:28:45 	ppp 		[wan] PRIDNS 0.0.0.0
Apr 22 23:28:45 	ppp 		[wan] IPADDR 0.0.0.0
Apr 22 23:28:45 	ppp 		[wan] IPCP: SendConfigReq #248
Apr 22 23:28:45 	ppp 		[wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 22 23:28:45 	ppp 		[wan] IPCP: rec'd Configure Reject #247 (Ack-Sent)
Apr 22 23:28:45 	ppp 		[wan] IPCP: state change Req-Sent --> Ack-Sent
Apr 22 23:28:45 	ppp 		[wan] IPADDR 172.16.15.132
Apr 22 23:28:45 	ppp 		[wan] IPCP: SendConfigAck #151
Apr 22 23:28:45 	ppp 		[wan] 172.16.15.132 is OK
Apr 22 23:28:45 	ppp 		[wan] IPADDR 172.16.15.132
Apr 22 23:28:45 	ppp 		[wan] IPCP: rec'd Configure Request #151 (Req-Sent)
Apr 22 23:28:45 	ppp 		[wan] IPV6CP: state change Req-Sent --> Ack-Sent
Apr 22 23:28:45 	ppp 		[wan] IPV6CP: SendConfigAck #136
Apr 22 23:28:45 	ppp 		[wan] IPV6CP: rec'd Configure Request #136 (Req-Sent)
Apr 22 23:28:45 	ppp 		[wan] IPV6CP: SendConfigReq #145
Apr 22 23:28:45 	ppp 		[wan] IPV6CP: state change Starting --> Req-Sent
Apr 22 23:28:45 	ppp 		[wan] IPV6CP: Up event
Apr 22 23:28:45 	ppp 		[wan] SECDNS 0.0.0.0
Apr 22 23:28:45 	ppp 		[wan] PRIDNS 0.0.0.0
Apr 22 23:28:45 	ppp 		[wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 22 23:28:45 	ppp 		[wan] IPADDR 0.0.0.0
Apr 22 23:28:45 	ppp 		[wan] IPCP: SendConfigReq #247
Apr 22 23:28:45 	ppp 		[wan] IPCP: state change Starting --> Req-Sent
Apr 22 23:28:45 	ppp 		[wan] IPCP: Up event
Apr 22 23:28:45 	ppp 		[wan] IPV6CP: LayerStart
Apr 22 23:28:45 	ppp 		[wan] IPV6CP: state change Initial --> Starting
Apr 22 23:28:45 	ppp 		[wan] IPV6CP: Open event
Apr 22 23:28:45 	ppp 		[wan] IPCP: LayerStart
Apr 22 23:28:45 	ppp 		[wan] IPCP: state change Initial --> Starting
Apr 22 23:28:45 	ppp 		[wan] IPCP: Open event
Apr 22 23:28:45 	ppp 		[wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Apr 22 23:28:45 	ppp 		[wan_link0] Link: Join bundle "wan"
Apr 22 23:28:45 	ppp 		[wan_link0] Link: Matched action 'bundle "wan" ""'
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: authorization successful
Apr 22 23:28:45 	ppp 		[wan_link0] MESG: CHAP authentication success
Apr 22 23:28:45 	ppp 		[wan_link0] CHAP: rec'd SUCCESS #1 len: 31
Apr 22 23:28:45 	ppp 		[wan_link0] CHAP: sending RESPONSE #1 len: 45
Apr 22 23:28:45 	ppp 		[wan_link0] CHAP: Using authname "Internet@btbroadband.com"
Apr 22 23:28:45 	ppp 		[wan_link0] Name: " ***HIDDEN***"
Apr 22 23:28:45 	ppp 		[wan_link0] CHAP: rec'd CHALLENGE #1 len: 69
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: LayerUp
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: auth: peer wants CHAP, I want nothing
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: state change Ack-Sent --> Opened
Apr 22 23:28:45 	ppp 		[wan_link0] MAGICNUM 0xbe0ec800
Apr 22 23:28:45 	ppp 		[wan_link0] MRU 1492
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: rec'd Configure Ack #164 (Ack-Sent)
Apr 22 23:28:45 	ppp 		[wan_link0] MAGICNUM 0xbe0ec800
Apr 22 23:28:45 	ppp 		[wan_link0] MRU 1492
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: SendConfigReq #164
Apr 22 23:28:45 	ppp 		[wan_link0] PROTOCOMP
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: rec'd Configure Reject #163 (Ack-Sent)
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: state change Req-Sent --> Ack-Sent
Apr 22 23:28:45 	ppp 		[wan_link0] MAGICNUM 0x41b7f9c5
Apr 22 23:28:45 	ppp 		[wan_link0] AUTHPROTO CHAP MD5
Apr 22 23:28:45 	ppp 		[wan_link0] MRU 1492
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: SendConfigAck #53
Apr 22 23:28:45 	ppp 		[wan_link0] MAGICNUM 0x41b7f9c5
Apr 22 23:28:45 	ppp 		[wan_link0] AUTHPROTO CHAP MD5
Apr 22 23:28:45 	ppp 		[wan_link0] MRU 1492
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: rec'd Configure Request #53 (Req-Sent)
Apr 22 23:28:45 	ppp 		[wan_link0] MAGICNUM 0xbe0ec800
Apr 22 23:28:45 	ppp 		[wan_link0] MRU 1492
Apr 22 23:28:45 	ppp 		[wan_link0] PROTOCOMP
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: SendConfigReq #163
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: state change Starting --> Req-Sent
Apr 22 23:28:45 	ppp 		[wan_link0] LCP: Up event
Apr 22 23:28:45 	ppp 		[wan_link0] Link: UP event
Apr 22 23:28:45 	ppp 		[wan_link0] PPPoE: connection successful
Apr 22 23:28:45 	ppp 		PPPoE: rec'd ACNAME "acc-aln12.so-ex"
Apr 22 23:28:43 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:28:43 	ppp 		[wan_link0] Link: reconnection attempt 13
Apr 22 23:28:41 	ppp 		[wan_link0] Link: reconnection attempt 13 in 2 seconds
Apr 22 23:28:41 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:28:41 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:28:41 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 23:28:32 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:28:32 	ppp 		[wan_link0] Link: reconnection attempt 12
Apr 22 23:28:30 	ppp 		[wan_link0] Link: reconnection attempt 12 in 2 seconds
Apr 22 23:28:30 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:28:30 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:28:30 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 23:28:21 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:28:21 	ppp 		[wan_link0] Link: reconnection attempt 11
Apr 22 23:28:20 	ppp 		[wan_link0] Link: reconnection attempt 11 in 1 seconds
Apr 22 23:28:20 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:28:20 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:28:20 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 23:28:11 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:28:11 	ppp 		[wan_link0] Link: reconnection attempt 10
Apr 22 23:28:09 	ppp 		[wan_link0] Link: reconnection attempt 10 in 2 seconds
Apr 22 23:28:09 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:28:09 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:28:09 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 23:28:00 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:28:00 	ppp 		[wan_link0] Link: reconnection attempt 9
Apr 22 23:27:58 	ppp 		[wan_link0] Link: reconnection attempt 9 in 2 seconds
Apr 22 23:27:58 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:27:58 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:27:58 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 23:27:49 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:27:49 	ppp 		[wan_link0] Link: reconnection attempt 8
Apr 22 23:27:46 	ppp 		[wan_link0] Link: reconnection attempt 8 in 3 seconds
Apr 22 23:27:46 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:27:46 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:27:46 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 23:27:37 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:27:37 	ppp 		[wan_link0] Link: reconnection attempt 7
Apr 22 23:27:33 	ppp 		[wan_link0] Link: reconnection attempt 7 in 4 seconds
Apr 22 23:27:33 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:27:33 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:27:33 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 23:27:24 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:27:24 	ppp 		[wan_link0] Link: reconnection attempt 6
Apr 22 23:27:21 	ppp 		[wan_link0] Link: reconnection attempt 6 in 3 seconds
Apr 22 23:27:21 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:27:21 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:27:21 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 23:27:12 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:27:12 	ppp 		[wan_link0] Link: reconnection attempt 5
Apr 22 23:27:11 	ppp 		[wan_link0] Link: reconnection attempt 5 in 1 seconds
Apr 22 23:27:11 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:27:11 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:27:11 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 23:27:02 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:27:02 	ppp 		[wan_link0] Link: reconnection attempt 4
Apr 22 23:26:59 	ppp 		[wan_link0] Link: reconnection attempt 4 in 3 seconds
Apr 22 23:26:59 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:26:59 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:26:59 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 23:26:50 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:26:50 	ppp 		[wan_link0] Link: reconnection attempt 3
Apr 22 23:26:48 	ppp 		[wan_link0] Link: reconnection attempt 3 in 2 seconds
Apr 22 23:26:48 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:26:48 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:26:48 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 23:26:39 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:26:39 	ppp 		[wan_link0] Link: reconnection attempt 2
Apr 22 23:26:35 	ppp 		[wan_link0] Link: reconnection attempt 2 in 4 seconds
Apr 22 23:26:35 	ppp 		[wan_link0] LCP: Down event
Apr 22 23:26:35 	ppp 		[wan_link0] Link: DOWN event
Apr 22 23:26:35 	ppp 		[wan_link0] PPPoE connection timeout after 9 seconds
Apr 22 23:26:26 	ppp 		[wan_link0] PPPoE: Connecting to ''
Apr 22 23:26:26 	ppp 		[wan_link0] Link: reconnection attempt 1
Apr 22 23:26:24 	ppp 		[wan_link0] Link: reconnection attempt 1 in 2 seconds
Apr 22 23:26:24 	ppp 		[wan_link0] LCP: LayerDown
Apr 22 23:26:24 	ppp 		[wan] IPV6CP: state change Closing --> Initial
Apr 22 23:26:24 	ppp 		[wan] Bundle: No NCPs left. Closing links...
Apr 22 23:26:24 	ppp 		[wan] IPV6CP: LayerFinish
Apr 22 23:26:24 	ppp 		[wan] IPV6CP: Down event
Apr 22 23:26:24 	ppp 		[wan] IPCP: state change Closing --> Initial
Apr 22 23:26:24 	ppp 		[wan] IPCP: LayerFinish
Apr 22 23:26:24 	ppp 		[wan] IPCP: Down event
Apr 22 23:26:24 	ppp 		[wan] IFACE: Rename interface pppoe0 to pppoe0
Apr 22 23:26:24 	ppp 		[wan] IFACE: Down event
Apr 22 23:26:23 	ppp 		[wan] IPV6CP: LayerDown
Apr 22 23:26:23 	ppp 		[wan] IPV6CP: SendTerminateReq #144
Apr 22 23:26:23 	ppp 		[wan] IPV6CP: state change Opened --> Closing
Apr 22 23:26:23 	ppp 		[wan] IPV6CP: Close event
Apr 22 23:26:23 	ppp 		[wan] IPCP: LayerDown
Apr 22 23:26:23 	ppp 		[wan] IPCP: SendTerminateReq #246

Thanks for your eyeball and brain time!

f.meunier

Hello
Could you post the PPPoE config ? (Interfaces / PPPs / Edit)
Is "Dial On Demand" enabled ?
Is "Idle Timeout" set ?

tstorm

I think I'm starting to have this issue as well.

achiskon

I have this very issue!
I don't know what to do anymore.
Started right after updating to 2.3.3, frequency is almost 1 disconnect daily by average. Requires reboot to work again, and logs are exactly the same.

Did anyone try to find the cause?

Hoji

Hi All,

I've now got more sites up and running, all with different configurations, modem hardware, pFsense hardware and ISPs - the experiment continues!

The common factor appears to be the stability of the PPPoE connection. For example my home VDSL2+ is exceptionally stable with PPPoE uptime currently 33 days, i.e. since upgrading to 2.3.4, and I've not had any problems. A different site's connection suffers from LCP timeouts on a regular basis, possibly caused by VDSL resyncs due to changing SNR, though that's just a guess from occasionally seeing the negotiated connection speed changing. This particular site appears to be the worst behaved, though it runs the same hardware and almost identical configuration as my home connection (i3-7100 Gigabyte Brix, Cisco 3560CX & Draytek Vigor 130). A third site has a very stable PPPoE connection which runs for weeks at a time apart from occasionally where it all goes haywire; many LCP timeouts / reconnections within minutes and this very quickly causes the issue.

My loose assumption has become that there is some sort of race condition which exists between the PPPoE client and some other part of pfSense responsible for managing the PPP connection, and this is triggered by an unstable connection causing PPPoE to renegotiate on a regular basis. I'm intending to hack these particular site into submission by using the ISP's hateful hardware and a DMZ to relieve pFsense's responsibility for keeping the PPPoE connection up, but it would be lovely to get to the bottom of this madness once and for all. Before I do this however I plan to run a wireshark capture on the WAN interface once the issue manifests itself to see if PPPoE reconnections are actually being sent by pFsense as I suspect they are not.

Are there any developers familiar with on the PPPoE functionality that would like to use me as a guinea pig for testing? Or anything? Just some pearls of wisdom?

Once again, thanks for your time.

P.S. f.meunier , I am not using dial-on-demand or idle timeout on the connection, all simple configurations - I've attached the relevant bits of the configuration below.

WAN interface

 <wan><enable></enable>
<if>pppoe0</if>

<ipaddr>pppoe</ipaddr>
<dhcphostname></dhcphostname>
<alias-address></alias-address>
<alias-subnet>32</alias-subnet>

<adv_dhcp_pt_timeout></adv_dhcp_pt_timeout>
<adv_dhcp_pt_retry></adv_dhcp_pt_retry>
<adv_dhcp_pt_select_timeout></adv_dhcp_pt_select_timeout>
<adv_dhcp_pt_reboot></adv_dhcp_pt_reboot>
<adv_dhcp_pt_backoff_cutoff></adv_dhcp_pt_backoff_cutoff>
<adv_dhcp_pt_initial_interval></adv_dhcp_pt_initial_interval>
<adv_dhcp_pt_values>SavedCfg</adv_dhcp_pt_values>
<adv_dhcp_send_options></adv_dhcp_send_options>
<adv_dhcp_request_options></adv_dhcp_request_options>
<adv_dhcp_required_options></adv_dhcp_required_options>
<adv_dhcp_option_modifiers></adv_dhcp_option_modifiers>
<adv_dhcp_config_advanced></adv_dhcp_config_advanced>
<adv_dhcp_config_file_override></adv_dhcp_config_file_override>
<adv_dhcp_config_file_override_path></adv_dhcp_config_file_override_path>
<spoofmac></spoofmac></wan>

PPP config

 <ppp><ptpid>0</ptpid>
<type>pppoe</type>
<if>pppoe0</if>
<ports>em0</ports>
<username>Internet@btbroadband.com</username>
<password>xxxxxxxxxxxx</password>

<bandwidth></bandwidth></ppp>

simi8

i have the same problem! I'm going crazy to workaround this issue.
In my case, when the pppoe connection crash, the modem/router (tplink 8970 in bridge mode) becomes unreachable. I mean that I'm unable to reach its web interface with a PC connected directly on its lan! It seems that pfsense cause the modem to crash in some way that it need to be rebooted. But the modem reboot is not enough, also pfsense need to be rebooted.
Currently I'm unable to have stable connection for more than 12hours.

Hoji

Still experiencing this problem time and time again on multiple sites. I'm surprised none of the devs have jumped in on this one! Just some further information…

When this situation rears its ugly head the PPP server on the other end is replying to the discovery packets sent by pfsense. However, in the PPP syslog, PPPoE: Connecting to ' ' still appears, despite the reply. This of course happens every 2 seconds, forever.

Furthermore, this appears to have nothing to do with rebooting - this capture was taken after commissioning a new pfsense router, and it just plain wouldn't connect.

I've since given up using PPPoE on pfsense - Pity really :(

![Wireshark PPP.jpg](/public/imported_attachments/1/Wireshark PPP.jpg)
![Wireshark PPP.jpg_thumb](/public/imported_attachments/1/Wireshark PPP.jpg_thumb)

Catwoolfii

I think the problem should be looked for in netgraph's work. Here is an example output:

/root: ngctl list
There are 14 total nodes:
  Name: re0             Type: ether           ID: 00000001   Num hooks: 1
  Name: ngctl44913      Type: socket          ID: 000015c2   Num hooks: 0
  Name: <unnamed>       Type: socket          ID: 00000005   Num hooks: 0
  Name: ath0_wlan1      Type: ether           ID: 00000008   Num hooks: 0
  Name: <unnamed>       Type: pppoe           ID: 00000013   Num hooks: 2
  Name: mpd16350-lso    Type: socket          ID: 00000d25   Num hooks: 1
  Name: mpd16350-cso    Type: socket          ID: 00000d26   Num hooks: 0
  Name: mpd16350-eso    Type: socket          ID: 00000d27   Num hooks: 0
  Name: ng0             Type: iface           ID: 00000d28   Num hooks: 1
  Name: mpd16350-wan    Type: ppp             ID: 00000d29   Num hooks: 3
  Name: mpd16350-wan_link0-lt Type: tee       ID: 00000d2a   Num hooks: 2
  Name: <unnamed>       Type: socket          ID: 00000d2b   Num hooks: 0
  Name: mpd16350-stats  Type: socket          ID: 00000d2c   Num hooks: 0
  Name: mpd16350-wan-mss Type: tcpmss         ID: 00000d2d   Num hooks: 2

On this protocol based the mechanism of the mpd5 daemon. More can be read here.

nahun

@Hoji did you ever end up figuring anything out with PPPoE and pfsense? I'm seeing the same issue with residential fiber.

23Cunningham

A different site's connection suffers from LCP timeouts on a regular basis, possibly caused by VDSL resyncs due to changing SNR, though that's just a guess from occasionally seeing the negotiated connection speed changing. This particular site appears to be the worst behaved, though it runs the same hardware and almost identical configuration as my home connection (i3-7100 Gigabyte Brix, Cisco 3560CX & Draytek Vigor 130). A third site has a very stable PPPoE connection which runs for weeks at a time apart from occasionally where it all goes haywire; many LCP timeouts / reconnections within minutes and this very quickly causes the issue.