Automatic PPPoE WAN connection

My OpenWrt router is linked to my DSL modem, and uses PPPoE to connect to the WAN. Sometimes something goes wrong with my ISP's DSLAM, and it either sends my modem an LCP termination packet, or (like in the following example) it does no longer respond to LCP echo requests from my side. In either case the connection is terminated, and after that my router tries and renegotiates the link. Usually everything goes well and CHAP authentication succeeds, however sometimes the DSLAM does not provides my router a WAN IP address. The strange thing is that at this point my router stops trying to reconnect. Here's is what I log when this happens:

Thu Jul  5 20:01:43 2018 daemon.info pppd[11691]: No response to 6 echo-requests
Thu Jul  5 20:01:43 2018 daemon.notice pppd[11691]: Serial link appears to be disconnected.
Thu Jul  5 20:01:43 2018 daemon.info pppd[11691]: Connect time 10.9 minutes.
Thu Jul  5 20:01:43 2018 daemon.info pppd[11691]: Sent 147563 bytes, received 130674 bytes.
Thu Jul  5 20:01:43 2018 daemon.notice netifd: Network device 'pppoe-WAN' link is down
Thu Jul  5 20:01:43 2018 daemon.notice netifd: Interface 'WAN' has lost the connection
Thu Jul  5 20:01:43 2018 daemon.warn dnsmasq[940]: no servers found in /tmp/resolv.conf.auto, will retry
Thu Jul  5 20:01:44 2018 daemon.info odhcpd[647]: Using a RA lifetime of 0 seconds on br-lan
Thu Jul  5 20:01:49 2018 daemon.notice pppd[11691]: Connection terminated.
Thu Jul  5 20:01:49 2018 daemon.info pppd[11691]: Sent PADT
Thu Jul  5 20:01:49 2018 daemon.notice pppd[11691]: Modem hangup
Thu Jul  5 20:01:49 2018 daemon.info pppd[11691]: Exit.
Thu Jul  5 20:01:49 2018 daemon.notice netifd: Interface 'WAN' is now down
Thu Jul  5 20:01:49 2018 daemon.notice netifd: Interface 'WAN' is disabled
Thu Jul  5 20:01:49 2018 daemon.notice netifd: Interface 'WAN' is enabled
Thu Jul  5 20:01:49 2018 daemon.notice netifd: Interface 'WAN' is setting up now
Thu Jul  5 20:01:49 2018 daemon.info pppd[11904]: Plugin rp-pppoe.so loaded.
Thu Jul  5 20:01:49 2018 daemon.info pppd[11904]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Thu Jul  5 20:01:49 2018 daemon.notice pppd[11904]: pppd 2.4.7 started by root, uid 0
Thu Jul  5 20:01:49 2018 kern.warn kernel: [386509.312974] br-lan: received packet on eth0.1 with own address as source address
Thu Jul  5 20:01:49 2018 daemon.info pppd[11904]: PPP session is 51633
Thu Jul  5 20:01:49 2018 daemon.warn pppd[11904]: Connected to f4:ac:c1:19:64:19 via interface eth0.2
Thu Jul  5 20:01:49 2018 kern.info kernel: [386509.380458] pppoe-WAN: renamed from ppp0
Thu Jul  5 20:01:49 2018 daemon.info pppd[11904]: Using interface pppoe-WAN
Thu Jul  5 20:01:49 2018 daemon.notice pppd[11904]: Connect: pppoe-WAN <--> eth0.2
Thu Jul  5 20:01:53 2018 daemon.info pppd[11904]: CHAP authentication succeeded: Successful login
Thu Jul  5 20:01:53 2018 daemon.notice pppd[11904]: CHAP authentication succeeded
Thu Jul  5 20:01:53 2018 daemon.notice pppd[11904]: peer from calling number F4:AC:C1:19:64:19 authorized
Thu Jul  5 20:01:53 2018 daemon.err pppd[11904]: Could not determine local IP address
Thu Jul  5 20:01:53 2018 daemon.info pppd[11904]: Connect time 0.1 minutes.
Thu Jul  5 20:01:53 2018 daemon.info pppd[11904]: Sent 104 bytes, received 66 bytes.

I need to manually reconnect the WAN interface under Network -> Interfaces in LuCi. I have to repeat this step until finally my ISP kindly provide me a public IP address.

Is there a way to automate this action? Ideally, OpenWrt should try and try again, until the connection is up and running.

Cheers!

2 Likes

take a look at watchcat :wink:

but I think - that openwrt trys also in specific cycles to reconnect - or not?

1 Like

try to set:

config interface 'wan'
	option pppd_options 'persist maxfail 0'

https://wiki.openwrt.org/doc/uci/network#protocol_pppoe_ppp_over_ethernet
https://ppp.samba.org/pppd.html

But im not sure about the right syntax of pppd_options, maybe we need to add a list or seperate in any way.

EDIT: the syntax should be okay... I checked my pppd task options... there I can find "maxfail 1" - thats why OpenWRT terminate after a fail..

Maybe it is expected/needed behavior... maybe you can't override it. just test it and look at ps aux|grep pppd

1 Like

or take a look at this hotplug-script:

but both versions looks faulty to me.... but the idea is good

1 Like

Yes, but not always, and I haven't figured out why. Sometimes it happens that it stops trying, and the only way to reconnect is manually.

I'll look at your suggestions. Thanks!

I'm testing this script, adapted from those that you linked above. Till now everything seems fine.

~# cat /etc/hotplug.d/iface/99-keepwanalive 
#!/bin/sh                                                                                                                            
# Place me in /etc/hotplug.d/iface/99-keepwanalive                                                                                   
                                                                                                                                     
COUNTER="0"                                                                                                                          
FLAG="0"                                                                                                                             
                                                                                                                                     
if [ "$ACTION" = "ifdown" -a "$INTERFACE" = "WAN" ]; then                                                                            
                                                                                                                                     
while [ "$FLAG" = 0 ]                                                                                                                
do                                                                                                                                   
        sleep 1                                                                                                                      
        grep "unknown" /sys/class/net/pppoe-WAN/operstate                                                                            
        RESULT="$?"                                                                                                                  
        if [ "$RESULT" != 0 ]; then                                                                                                  
                let COUNTER++                                                                                                        
                                # priority=7 -> debug                                                                                
                logger -t PPPoE -p 7 "Log from /etc/hotplug.d/iface/99-keepwanalive"                                                 
                                # priority=5 -> notice (default)                                                                     
                logger -t PPPoE -p 5 "Attempt #${COUNTER} to reconnect pppoe-WAN"                                                    
                                                                                                                                     
                ifup WAN
                sleep 10 #sec
        else
                FLAG=1
        fi
done

fi

OpenWrt handles different pppd exit codes differently in order to avoid spamming the ISP with too many requests. For example if the exit codes indicates a login failure due to wrong credentials, OpenWrt will not try to reconnect, in other cases it will.

The code responsible for that is here:
https://git.openwrt.org/?p=openwrt/openwrt.git;a=blob;f=package/network/services/ppp/files/ppp.sh;h=73bc3161cdcb9f67bfd7875895a6230167792231;hb=98a6bee09a87262da7c5c61874c565f53ee42d35#l160

Maybe, in your non-reconnect-state, the pppd daemon exits with a status code that is deemed not restart-worthy. Do you see any error indication in ifstatus WAN when your router is in the stuck state?

Login succeeds, but no IP address is provided from the peer DSLAM. Sometimes OpenWrt tries to reconnect, other times it doesn't, although the issue is always the same (no IP address from peer). I don't get any further hint in my logs. What is ifstatus WAN? I don't find any ifstatus command.

Anyhow, the script I'm using seems to work pretty well:

[..]
Mon Jul  9 19:05:03 2018 daemon.notice pppd[2307]: Connect: pppoe-WAN <--> eth0.2
Mon Jul  9 19:05:06 2018 daemon.info pppd[2307]: CHAP authentication succeeded: Successful login
Mon Jul  9 19:05:06 2018 daemon.notice pppd[2307]: CHAP authentication succeeded
Mon Jul  9 19:05:06 2018 daemon.notice pppd[2307]: peer from calling number F4:AC:C1:19:64:19 authorized
Mon Jul  9 19:05:06 2018 daemon.err pppd[2307]: Could not determine local IP address
Mon Jul  9 19:05:06 2018 daemon.info pppd[2307]: Connect time 0.1 minutes.
Mon Jul  9 19:05:06 2018 daemon.info pppd[2307]: Sent 104 bytes, received 66 bytes.
Mon Jul  9 19:05:13 2018 user.debug PPPoE: Log from /etc/hotplug.d/iface/99-keepwanalive
Mon Jul  9 19:05:13 2018 user.notice PPPoE: Attempt #2 to reconnect pppoe-WAN
Mon Jul  9 19:05:13 2018 daemon.info pppd[2307]: Terminating on signal 15
Mon Jul  9 19:05:13 2018 daemon.notice pppd[2307]: Connection terminated.
Mon Jul  9 19:05:13 2018 daemon.info pppd[2307]: Sent PADT
Mon Jul  9 19:05:13 2018 daemon.info pppd[2307]: Exit.
Mon Jul  9 19:05:13 2018 daemon.notice netifd: Interface 'WAN' is now down
Mon Jul  9 19:05:13 2018 daemon.notice netifd: Interface 'WAN' is disabled
Mon Jul  9 19:05:13 2018 daemon.notice netifd: Interface 'WAN' is enabled
Mon Jul  9 19:05:13 2018 daemon.notice netifd: Interface 'WAN' is setting up now
Mon Jul  9 19:05:14 2018 daemon.info pppd[2418]: Plugin rp-pppoe.so loaded.
Mon Jul  9 19:05:14 2018 daemon.info pppd[2418]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Mon Jul  9 19:05:14 2018 daemon.notice pppd[2418]: pppd 2.4.7 started by root, uid 0
Mon Jul  9 19:05:14 2018 kern.warn kernel: [728719.668104] br-lan: received packet on eth0.1 with own address as source address
Mon Jul  9 19:05:14 2018 daemon.info pppd[2418]: PPP session is 38668
Mon Jul  9 19:05:14 2018 daemon.warn pppd[2418]: Connected to f4:ac:c1:19:64:19 via interface eth0.2
Mon Jul  9 19:05:14 2018 kern.info kernel: [728719.736916] pppoe-WAN: renamed from ppp0
Mon Jul  9 19:05:14 2018 daemon.info pppd[2418]: Using interface pppoe-WAN
Mon Jul  9 19:05:14 2018 daemon.notice pppd[2418]: Connect: pppoe-WAN <--> eth0.2
Mon Jul  9 19:05:17 2018 daemon.info pppd[2418]: CHAP authentication succeeded: Successful login
Mon Jul  9 19:05:17 2018 daemon.notice pppd[2418]: CHAP authentication succeeded
Mon Jul  9 19:05:17 2018 daemon.notice pppd[2418]: peer from calling number F4:AC:C1:19:64:19 authorized
Mon Jul  9 19:05:17 2018 daemon.err pppd[2418]: Could not determine local IP address
Mon Jul  9 19:05:17 2018 daemon.info pppd[2418]: Connect time 0.1 minutes.
Mon Jul  9 19:05:17 2018 daemon.info pppd[2418]: Sent 104 bytes, received 66 bytes.
Mon Jul  9 19:05:24 2018 user.debug PPPoE: Log from /etc/hotplug.d/iface/99-keepwanalive
Mon Jul  9 19:05:24 2018 user.notice PPPoE: Attempt #3 to reconnect pppoe-WAN
Mon Jul  9 19:05:25 2018 daemon.info pppd[2418]: Terminating on signal 15
Mon Jul  9 19:05:25 2018 daemon.notice pppd[2418]: Connection terminated.
Mon Jul  9 19:05:25 2018 daemon.info pppd[2418]: Sent PADT
Mon Jul  9 19:05:25 2018 daemon.info pppd[2418]: Exit.
Mon Jul  9 19:05:25 2018 daemon.notice netifd: Interface 'WAN' is now down
Mon Jul  9 19:05:25 2018 daemon.notice netifd: Interface 'WAN' is disabled
Mon Jul  9 19:05:25 2018 daemon.notice netifd: Interface 'WAN' is enabled
Mon Jul  9 19:05:25 2018 daemon.notice netifd: Interface 'WAN' is setting up now
Mon Jul  9 19:05:25 2018 daemon.info pppd[2489]: Plugin rp-pppoe.so loaded.
Mon Jul  9 19:05:25 2018 daemon.info pppd[2489]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Mon Jul  9 19:05:25 2018 daemon.notice pppd[2489]: pppd 2.4.7 started by root, uid 0
Mon Jul  9 19:05:25 2018 kern.warn kernel: [728730.967488] br-lan: received packet on eth0.1 with own address as source address
Mon Jul  9 19:05:25 2018 daemon.info pppd[2489]: PPP session is 48166
Mon Jul  9 19:05:25 2018 daemon.warn pppd[2489]: Connected to 00:1e:bd:32:fb:19 via interface eth0.2
Mon Jul  9 19:05:25 2018 kern.info kernel: [728731.036150] pppoe-WAN: renamed from ppp0
Mon Jul  9 19:05:25 2018 daemon.info pppd[2489]: Using interface pppoe-WAN
Mon Jul  9 19:05:25 2018 daemon.notice pppd[2489]: Connect: pppoe-WAN <--> eth0.2
Mon Jul  9 19:05:28 2018 daemon.info pppd[2489]: CHAP authentication succeeded: Successful login
Mon Jul  9 19:05:28 2018 daemon.notice pppd[2489]: CHAP authentication succeeded
Mon Jul  9 19:05:28 2018 daemon.notice pppd[2489]: peer from calling number 00:1E:BD:32:FB:19 authorized
Mon Jul  9 19:05:28 2018 daemon.notice pppd[2489]: local  IP address WWW.XXX.YYY.ZZZ
Mon Jul  9 19:05:28 2018 daemon.notice pppd[2489]: remote IP address 213.205.24.56
Mon Jul  9 19:05:28 2018 daemon.notice pppd[2489]: primary   DNS address 213.205.32.70
Mon Jul  9 19:05:28 2018 daemon.notice pppd[2489]: secondary DNS address 8.8.8.8
Mon Jul  9 19:05:28 2018 daemon.notice netifd: Network device 'pppoe-WAN' link is up
Mon Jul  9 19:05:28 2018 daemon.notice netifd: Interface 'WAN' is now up

ifstatus should be available on any standard OpenWrt, it essentially is a wrapper around ubus. Instead of ifstatus WAN you can try ubus call network.interface.WAN status

1 Like