PPPoE disconnects requiring reboot



  • 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!



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



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



  • 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?



  • 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> 
    


  • 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.



  • 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)


Log in to reply