PPPoE will not re-connect after physical link down

bkraptor · Sep 29, 2012, 9:24 PM

I was testing the WAN redundancy when I noticed that the PPPoE connection I have is not coming back up once I disconnect and re-connect the cable.

Re-saving the interface config does not fix the problem. Manually killing mpd5 and re-saving the interface config does not fix the issue. The only way that the PPPoE is re-established is if I reboot the box.

The PPP logs contain this:

Sep 29 23:46:47 	ppp: [wan_link0] LCP: no reply to 1 echo request(s)
Sep 29 23:46:57 	ppp: [wan_link0] LCP: no reply to 2 echo request(s)
Sep 29 23:47:07 	ppp: [wan_link0] LCP: no reply to 3 echo request(s)
Sep 29 23:47:17 	ppp: [wan_link0] LCP: no reply to 4 echo request(s)
Sep 29 23:47:27 	ppp: [wan_link0] LCP: no reply to 5 echo request(s)
Sep 29 23:47:27 	ppp: [wan_link0] LCP: peer not responding to echo requests
Sep 29 23:47:27 	ppp: [wan_link0] LCP: state change Opened --> Stopping
Sep 29 23:47:27 	ppp: [wan_link0] Link: Leave bundle "wan"
Sep 29 23:47:27 	ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Sep 29 23:47:27 	ppp: [wan] IPCP: Close event
Sep 29 23:47:27 	ppp: [wan] IPCP: state change Opened --> Closing
Sep 29 23:47:27 	ppp: [wan] IPCP: SendTerminateReq #4
Sep 29 23:47:27 	ppp: [wan] IPCP: LayerDown
Sep 29 23:47:27 	ppp: [wan] IPV6CP: Close event
Sep 29 23:47:27 	ppp: [wan] IPV6CP: state change Opened --> Closing
Sep 29 23:47:27 	ppp: [wan] IPV6CP: SendTerminateReq #3
Sep 29 23:47:27 	ppp: [wan] IPV6CP: LayerDown
Sep 29 23:47:27 	ppp: [wan] IFACE: Down event
Sep 29 23:47:27 	ppp: [wan] IFACE: Rename interface pppoe1 to pppoe1
Sep 29 23:47:27 	ppp: [wan] IPCP: Down event
Sep 29 23:47:27 	ppp: [wan] IPCP: LayerFinish
Sep 29 23:47:27 	ppp: [wan] IPCP: state change Closing --> Initial
Sep 29 23:47:27 	ppp: [wan] IPV6CP: Down event
Sep 29 23:47:27 	ppp: [wan] IPV6CP: LayerFinish
Sep 29 23:47:27 	ppp: [wan] Bundle: No NCPs left. Closing links...
Sep 29 23:47:27 	ppp: [wan] IPV6CP: state change Closing --> Initial
Sep 29 23:47:27 	ppp: [wan_link0] LCP: SendTerminateReq #4
Sep 29 23:47:27 	ppp: [wan_link0] LCP: LayerDown
Sep 29 23:47:29 	ppp: [wan_link0] LCP: SendTerminateReq #5
Sep 29 23:47:31 	ppp: [wan_link0] LCP: state change Stopping --> Stopped
Sep 29 23:47:31 	ppp: [wan_link0] LCP: LayerFinish
Sep 29 23:47:31 	ppp: [wan_link0] PPPoE: connection closed
Sep 29 23:47:31 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:47:31 	ppp: [wan_link0] LCP: Down event
Sep 29 23:47:31 	ppp: [wan_link0] LCP: state change Stopped --> Starting
Sep 29 23:47:31 	ppp: [wan_link0] LCP: LayerStart
Sep 29 23:47:31 	ppp: [wan_link0] Link: reconnection attempt 1 in 2 seconds
Sep 29 23:47:33 	ppp: [wan_link0] Link: reconnection attempt 1
Sep 29 23:47:33 	ppp: [wan_link0] PPPoE: Connecting to ''
Sep 29 23:47:42 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Sep 29 23:47:42 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:47:42 	ppp: [wan_link0] LCP: Down event
Sep 29 23:47:42 	ppp: [wan_link0] Link: reconnection attempt 2 in 4 seconds
Sep 29 23:47:46 	ppp: [wan_link0] Link: reconnection attempt 2
Sep 29 23:47:46 	ppp: [wan_link0] PPPoE: Connecting to ''
Sep 29 23:47:55 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Sep 29 23:47:55 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:47:55 	ppp: [wan_link0] LCP: Down event
Sep 29 23:47:55 	ppp: [wan_link0] Link: reconnection attempt 3 in 2 seconds
Sep 29 23:47:57 	ppp: [wan_link0] Link: reconnection attempt 3
Sep 29 23:47:57 	ppp: [wan_link0] PPPoE: Connecting to ''
Sep 29 23:48:06 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Sep 29 23:48:06 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:48:06 	ppp: [wan_link0] LCP: Down event
Sep 29 23:48:06 	ppp: [wan_link0] Link: reconnection attempt 4 in 4 seconds
Sep 29 23:48:10 	ppp: [wan_link0] Link: reconnection attempt 4
Sep 29 23:48:10 	ppp: [wan_link0] PPPoE: Connecting to ''
Sep 29 23:48:19 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Sep 29 23:48:19 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:48:19 	ppp: [wan_link0] LCP: Down event
Sep 29 23:48:19 	ppp: [wan_link0] Link: reconnection attempt 5 in 2 seconds
Sep 29 23:48:21 	ppp: [wan_link0] Link: reconnection attempt 5
Sep 29 23:48:21 	ppp: [wan_link0] PPPoE: Connecting to ''
Sep 29 23:48:30 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Sep 29 23:48:30 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:48:30 	ppp: [wan_link0] LCP: Down event
Sep 29 23:48:30 	ppp: [wan_link0] Link: reconnection attempt 6 in 3 seconds
Sep 29 23:48:33 	ppp: [wan_link0] Link: reconnection attempt 6
Sep 29 23:48:33 	ppp: [wan_link0] PPPoE: Connecting to ''
Sep 29 23:48:42 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Sep 29 23:48:42 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:48:42 	ppp: [wan_link0] LCP: Down event
Sep 29 23:48:42 	ppp: [wan_link0] Link: reconnection attempt 7 in 1 seconds
Sep 29 23:48:43 	ppp: [wan_link0] Link: reconnection attempt 7
Sep 29 23:48:43 	ppp: [wan_link0] PPPoE: Connecting to ''
Sep 29 23:48:53 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Sep 29 23:48:53 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:48:53 	ppp: [wan_link0] LCP: Down event
Sep 29 23:48:53 	ppp: [wan_link0] Link: reconnection attempt 8 in 1 seconds
Sep 29 23:48:54 	ppp: [wan_link0] Link: reconnection attempt 8
Sep 29 23:48:54 	ppp: [wan_link0] PPPoE: Connecting to ''
Sep 29 23:49:03 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Sep 29 23:49:03 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:49:03 	ppp: [wan_link0] LCP: Down event
Sep 29 23:49:03 	ppp: [wan_link0] Link: reconnection attempt 9 in 2 seconds
Sep 29 23:49:05 	ppp: [wan_link0] Link: reconnection attempt 9
Sep 29 23:49:05 	ppp: [wan_link0] PPPoE: Connecting to ''
Sep 29 23:49:14 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Sep 29 23:49:14 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:49:14 	ppp: [wan_link0] LCP: Down event
Sep 29 23:49:14 	ppp: [wan_link0] Link: reconnection attempt 10 in 2 seconds
Sep 29 23:49:16 	ppp: [wan_link0] Link: reconnection attempt 10
Sep 29 23:49:16 	ppp: [wan_link0] PPPoE: Connecting to ''
Sep 29 23:49:25 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Sep 29 23:49:25 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:49:25 	ppp: [wan_link0] LCP: Down event
Sep 29 23:49:25 	ppp: [wan_link0] Link: reconnection attempt 11 in 3 seconds
Sep 29 23:49:28 	ppp: [wan_link0] Link: reconnection attempt 11
Sep 29 23:49:28 	ppp: [wan_link0] PPPoE: Connecting to ''
Sep 29 23:49:37 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Sep 29 23:49:37 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:49:37 	ppp: [wan_link0] LCP: Down event
Sep 29 23:49:37 	ppp: [wan_link0] Link: reconnection attempt 12 in 3 seconds
Sep 29 23:49:40 	ppp: [wan_link0] Link: reconnection attempt 12
Sep 29 23:49:40 	ppp: [wan_link0] PPPoE: Connecting to ''
Sep 29 23:49:49 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Sep 29 23:49:49 	ppp: [wan_link0] Link: DOWN event
Sep 29 23:49:49 	ppp: [wan_link0] LCP: Down event
Sep 29 23:49:49 	ppp: [wan_link0] Link: reconnection attempt 13 in 3 seconds
Sep 29 23:49:52 	ppp: [wan_link0] Link: reconnection attempt 13
Sep 29 23:49:52 	ppp: [wan_link0] PPPoE: Connecting to ''

/var/etc/mpd_wan.conf

startup:
        # configure the console
        set console close
        # configure the web server
        set web close

default:
pppoeclient:
        create bundle static wan
        set bundle enable ipv6cp
        set iface name pppoe1
        set iface route default
        set iface disable on-demand
        set iface idle 0
        set iface enable tcpmssfix
        set iface up-script /usr/local/sbin/ppp-linkup
        set iface down-script /usr/local/sbin/ppp-linkdown
        set ipcp ranges 0.0.0.0/0 0.0.0.0/0
        #log -bund -ccp -chat -iface -ipcp -lcp -link

        create link static wan_link0 pppoe
        set link action bundle wan
        set link disable multilink
        set link keep-alive 10 60
        set link max-redial 0
        set link disable chap pap
        set link accept chap pap eap
        set link disable incoming
        set link mtu 1492
        set auth authname "xxx"
        set auth password yyy
        set pppoe service ""
        set pppoe iface em2
        open

I'm running:
2.1-BETA0 (amd64)
built on Thu Sep 27 09:20:24 EDT 2012
FreeBSD 8.3-RELEASE-p4

<edit>I have found this same issue mentioned in this bug report:
http://redmine.pfsense.org/issues/1943

It mentions a work-around. Could this work-around be implemented in all future releases?

<edit #2="">The work-around seems to fix this issue. What other potential problems might arise from implementing this work-around?</edit></edit>

xbipin · Sep 30, 2012, 6:28 AM

there is a long thread for this issue
http://forum.pfsense.org/index.php/topic,41061.0.html

bkraptor · Sep 30, 2012, 6:43 AM

That thread seems to be about a different issue, because for me it was enough to implement jimp's solution from this thread:
http://forum.pfsense.org/index.php/topic,40671.msg219480.html#msg219480

xbipin · Sep 30, 2012, 6:50 AM

that workaround works partially, meaning if there is link loss only which is when u pull the plug, if the link is up and pppoe disconnects then its a reconnect loop and this happens if the isp modem is reset or if that reboots which is more likely to happen and others have a switch between pfsense and the isp modem in which case link loss is less likely to occur at all

bkraptor · Sep 30, 2012, 8:52 AM

As long as it works for one use case I see no reason for not implementing this fix. It may not fix all possible situations, but it fixes some.

For me this fix works because I have no provider modem in my home - I just get a Cat5E cable that I plug in my pfSense box. There is a provider box in the building and they have some kind of Huawei CPE there that does internet + voice + cable TV over a single fiber pair. My Cat5E cable plugs into that device.

xbipin · Sep 30, 2012, 9:06 AM

yes its true it fixes partially in link loss situations and should be implemented.

i guess u have FTTB and i have FTTH so ur modem is in the building and mine is at my home

bkraptor · Oct 5, 2012, 10:16 PM

Could this fix be implemented? It's only the matter of removing one line.

w0w · Oct 6, 2012, 9:40 AM

I have no problem with reconnection, since 2.1 beta0 builds, even if this line presents.
May be there are some problems in other configurations if this line is removed, but I am not sure.

On 2.0.x builds I must to down/up physical interface (if config down em0…) to reconnect after link loss and removing that line does not work for me also.

yon · Oct 6, 2012, 8:06 PM

I find Dynamic DNS clients can't re-connect link after for auto update. please check and fix it.

:P

bkraptor · Nov 8, 2012, 12:35 PM

Bumping this thread.

Could this simple fix be implemented?

@jimp:

Failing that, give this a try: Edit usr/local/sbin/ppp-linkdown and comment out or remove this line (keep an unaltered copy around though so you can restore the copy if it doesn't help)
/usr/sbin/ngctl shutdown $1:

bkraptor · Nov 20, 2012, 10:06 PM

Patch to be used with the System Patches package:
Path Strip Count = 1
Base Directory = /
Ignore Whitespace checked

--- a/usr/local/sbin/ppp-linkdown       2012-11-20 23:51:28.000000000 +0200
+++ b/usr/local/sbin/ppp-linkdown       2012-11-20 23:55:26.000000000 +0200
@@ -20,7 +20,9 @@
        fi
 fi
 # delete the node just in case mpd cannot do that
-/usr/sbin/ngctl shutdown $1:
+### disabled because of the following bug:
+### http://redmine.pfsense.org/issues/1943
+#/usr/sbin/ngctl shutdown $1:
 if [ -f "/var/etc/nameserver_$1" ]; then
        # Remove old entries
        for nameserver in `cat /var/etc/nameserver_$1`; do