PPPoE disconnects in the evening

Hi

My PPPoE connection shuts down in the evenings.

Network topology
ISP > TP-Link TD-8616 ADSL2+ Modem at 192.168.2.1> Router GL.iNet GL-B1300 at 192.168.1.1 >Wireless Devices

OpenWrt System Info

Model: GL.iNet GL-B1300
Architecture: ARMv7 Processor rev 5 (v7l)
Firmware Version: OpenWrt 19.07.0 r10860-a3ffeb413b / LuCI openwrt-19.07 branch git-20.167.61968-87da00a
Kernel Version: 4.14.162

Due to the lack of a wired device, I currently can't update to 19.07.3.

Output of uci export network (sensitive data masked)

:~# uci export network
package network

config interface 'loopback'
	option ifname 'lo'
	option proto 'static'
	option ipaddr '127.0.0.1'
	option netmask '255.0.0.0'

config globals 'globals'
	option ula_prefix <masked>

config interface 'lan'
	option type 'bridge'
	option ifname 'eth0'
	option proto 'static'
	option ipaddr '192.168.1.1'
	option netmask '255.255.255.0'
	option ip6assign '60'

config interface 'wan'
	option ifname 'eth1'
	option proto 'pppoe'
	option ipv6 'auto'
	option username <masked>
	option password <masked>
	option keepalive '6 10'
	option demand '0'

config switch
	option name 'switch0'
	option reset '1'
	option enable_vlan '1'

config switch_vlan
	option device 'switch0'
	option vlan '1'
	option ports '3 4 0'

config interface 'dsl_modem'
	option ifname 'eth1'
	option proto 'static'
	option ipaddr '192.168.2.2'
	option netmask '255.255.255.0'

config interface 'guest'
	option proto 'static'
	option ipaddr '192.168.3.1'
	option netmask '255.255.255.0'

Output of uci export network

br-lan    Link encap:Ethernet  HWaddr E4:95:6E:45:19:7E  
          inet addr:192.168.1.1  Bcast:192.168.1.255  Mask:255.255.255.0
          inet6 addr: 2a02:200:2e01:1810::1/60 Scope:Global
          inet6 addr: fe80::e695:6eff:fe45:197e/64 Scope:Link
          inet6 addr: fd31:cd52:b5ba::1/60 Scope:Global
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:306252 errors:0 dropped:0 overruns:0 frame:0
          TX packets:403474 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:23845844 (22.7 MiB)  TX bytes:515381627 (491.5 MiB)

eth0      Link encap:Ethernet  HWaddr E4:95:6E:45:19:7E  
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:6514 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:0 (0.0 B)  TX bytes:801120 (782.3 KiB)

eth1      Link encap:Ethernet  HWaddr E4:95:6E:45:19:7F  
          inet addr:192.168.2.2  Bcast:192.168.2.255  Mask:255.255.255.0
          inet6 addr: fe80::e695:6eff:fe45:197f/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:2274065 errors:0 dropped:0 overruns:0 frame:0
          TX packets:1590741 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:2851607194 (2.6 GiB)  TX bytes:242910305 (231.6 MiB)

lo        Link encap:Local Loopback  
          inet addr:127.0.0.1  Mask:255.0.0.0
          inet6 addr: ::1/128 Scope:Host
          UP LOOPBACK RUNNING  MTU:65536  Metric:1
          RX packets:4388 errors:0 dropped:0 overruns:0 frame:0
          TX packets:4388 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:316517 (309.0 KiB)  TX bytes:316517 (309.0 KiB)

pppoe-wan Link encap:Point-to-Point Protocol  
          inet addr:46.253.186.56  P-t-P:80.254.79.177  Mask:255.255.255.255
          inet6 addr: 2a02:200:2f00:1181:a877:e9d0:da7e:af34/64 Scope:Global
          inet6 addr: fe80::a877:e9d0:da7e:af34/10 Scope:Link
          UP POINTOPOINT RUNNING NOARP MULTICAST  MTU:1492  Metric:1
          RX packets:69247 errors:0 dropped:0 overruns:0 frame:0
          TX packets:53582 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:3 
          RX bytes:84656183 (80.7 MiB)  TX bytes:5206188 (4.9 MiB)

wlan0     Link encap:Ethernet  HWaddr E4:95:6E:45:19:7E  
          inet6 addr: fe80::e695:6eff:fe45:197e/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:306941 errors:0 dropped:0 overruns:0 frame:0
          TX packets:404183 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:28178614 (26.8 MiB)  TX bytes:523498886 (499.2 MiB)

wlan0-1   Link encap:Ethernet  HWaddr E6:95:6E:45:19:7E  
          inet addr:192.168.3.1  Bcast:192.168.3.255  Mask:255.255.255.0
          inet6 addr: fe80::e495:6eff:fe45:197e/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:1302851 errors:0 dropped:0 overruns:0 frame:0
          TX packets:1870760 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:203714799 (194.2 MiB)  TX bytes:2356769329 (2.1 GiB)
`
``

Here is a system log extract. I restarted the modem and got the connection back

Thu Jun 25 05:20:23 2020 daemon.warn pppd[25046]: Timeout waiting for PADO packets
Thu Jun 25 05:20:23 2020 daemon.err pppd[25046]: Unable to complete PPPoE Discovery
Thu Jun 25 05:20:23 2020 daemon.info pppd[25046]: Exit.
Thu Jun 25 05:20:24 2020 daemon.notice netifd: Interface 'wan' is now down
Thu Jun 25 05:20:24 2020 daemon.notice netifd: Interface 'wan' is setting up now
Thu Jun 25 05:20:24 2020 daemon.err insmod: module is already loaded - slhc
Thu Jun 25 05:20:24 2020 daemon.err insmod: module is already loaded - ppp_generic
Thu Jun 25 05:20:24 2020 daemon.err insmod: module is already loaded - pppox
Thu Jun 25 05:20:24 2020 daemon.err insmod: module is already loaded - pppoe
Thu Jun 25 05:20:24 2020 daemon.info pppd[25099]: Plugin rp-pppoe.so loaded.
Thu Jun 25 05:20:24 2020 daemon.info pppd[25099]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Thu Jun 25 05:20:24 2020 daemon.notice pppd[25099]: pppd 2.4.7 started by root, uid 0
Thu Jun 25 05:20:39 2020 daemon.warn pppd[25099]: Timeout waiting for PADO packets
Thu Jun 25 05:20:39 2020 daemon.err pppd[25099]: Unable to complete PPPoE Discovery
Thu Jun 25 05:20:39 2020 daemon.info pppd[25099]: Exit.
Thu Jun 25 05:20:39 2020 daemon.notice netifd: Interface 'wan' is now down
Thu Jun 25 05:20:39 2020 daemon.notice netifd: Interface 'wan' is setting up now
Thu Jun 25 05:20:39 2020 daemon.err insmod: module is already loaded - slhc
Thu Jun 25 05:20:39 2020 daemon.err insmod: module is already loaded - ppp_generic
Thu Jun 25 05:20:39 2020 daemon.err insmod: module is already loaded - pppox
Thu Jun 25 05:20:39 2020 daemon.err insmod: module is already loaded - pppoe
Thu Jun 25 05:20:39 2020 daemon.info pppd[25153]: Plugin rp-pppoe.so loaded.
Thu Jun 25 05:20:39 2020 daemon.info pppd[25153]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Thu Jun 25 05:20:39 2020 daemon.notice pppd[25153]: pppd 2.4.7 started by root, uid 0
Thu Jun 25 05:20:44 2020 daemon.info pppd[25153]: PPP session is 59390
Thu Jun 25 05:20:44 2020 daemon.warn pppd[25153]: Connected to 34:0a:98:23:7a:bb via interface eth1
Thu Jun 25 05:20:44 2020 kern.info kernel: [112054.134342] pppoe-wan: renamed from ppp0
Thu Jun 25 05:20:44 2020 daemon.info pppd[25153]: Renamed interface ppp0 to pppoe-wan
Thu Jun 25 05:20:44 2020 daemon.info pppd[25153]: Using interface pppoe-wan
Thu Jun 25 05:20:44 2020 daemon.notice pppd[25153]: Connect: pppoe-wan <--> eth1
Thu Jun 25 05:20:48 2020 daemon.info pppd[25153]: CHAP authentication succeeded
Thu Jun 25 05:20:48 2020 daemon.notice pppd[25153]: CHAP authentication succeeded
Thu Jun 25 05:20:48 2020 daemon.notice pppd[25153]: peer from calling number 34:0A:98:23:7A:BB authorized
Thu Jun 25 05:20:48 2020 daemon.notice pppd[25153]: local  LL address fe80::c9bb:361c:e726:371c
Thu Jun 25 05:20:48 2020 daemon.notice pppd[25153]: remote LL address fe80::02be:75ff:fe96:0c00
Thu Jun 25 05:20:48 2020 daemon.notice pppd[25153]: local  IP address 46.253.186.56
Thu Jun 25 05:20:48 2020 daemon.notice pppd[25153]: remote IP address 80.254.79.177
Thu Jun 25 05:20:48 2020 daemon.notice pppd[25153]: primary   DNS address 80.254.79.93
Thu Jun 25 05:20:48 2020 daemon.notice pppd[25153]: secondary DNS address 80.254.79.7
Thu Jun 25 05:20:48 2020 daemon.notice netifd: Network device 'pppoe-wan' link is up
Thu Jun 25 05:20:48 2020 daemon.notice netifd: Interface 'wan' is now up
Thu Jun 25 05:20:48 2020 daemon.info dnsmasq[1735]: reading /tmp/resolv.conf.auto
Thu Jun 25 05:20:48 2020 daemon.info dnsmasq[1735]: using local addresses only for domain test
Thu Jun 25 05:20:48 2020 daemon.info dnsmasq[1735]: using local addresses only for domain onion
Thu Jun 25 05:20:48 2020 daemon.info dnsmasq[1735]: using local addresses only for domain localhost
Thu Jun 25 05:20:48 2020 daemon.info dnsmasq[1735]: using local addresses only for domain local
Thu Jun 25 05:20:48 2020 daemon.info dnsmasq[1735]: using local addresses only for domain invalid
Thu Jun 25 05:20:48 2020 daemon.info dnsmasq[1735]: using local addresses only for domain bind
Thu Jun 25 05:20:48 2020 daemon.info dnsmasq[1735]: using local addresses only for domain lan
Thu Jun 25 05:20:48 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.93#53
Thu Jun 25 05:20:48 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.7#53
Thu Jun 25 05:20:48 2020 daemon.notice netifd: Network alias 'pppoe-wan' link is up
Thu Jun 25 05:20:48 2020 daemon.notice netifd: Interface 'wan_6' is enabled
Thu Jun 25 05:20:48 2020 daemon.notice netifd: Interface 'wan_6' has link connectivity
Thu Jun 25 05:20:48 2020 daemon.notice netifd: Interface 'wan_6' is setting up now
Thu Jun 25 05:20:48 2020 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Thu Jun 25 05:20:48 2020 user.notice firewall: Reloading firewall due to ifupdate of wan (pppoe-wan)
Thu Jun 25 05:20:53 2020 daemon.notice netifd: Interface 'wan_6' is now up
Thu Jun 25 05:20:53 2020 daemon.info dnsmasq[1735]: reading /tmp/resolv.conf.auto
Thu Jun 25 05:20:53 2020 daemon.info dnsmasq[1735]: using local addresses only for domain test
Thu Jun 25 05:20:53 2020 daemon.info dnsmasq[1735]: using local addresses only for domain onion
Thu Jun 25 05:20:53 2020 daemon.info dnsmasq[1735]: using local addresses only for domain localhost
Thu Jun 25 05:20:53 2020 daemon.info dnsmasq[1735]: using local addresses only for domain local
Thu Jun 25 05:20:53 2020 daemon.info dnsmasq[1735]: using local addresses only for domain invalid
Thu Jun 25 05:20:53 2020 daemon.info dnsmasq[1735]: using local addresses only for domain bind
Thu Jun 25 05:20:53 2020 daemon.info dnsmasq[1735]: using local addresses only for domain lan
Thu Jun 25 05:20:53 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.93#53
Thu Jun 25 05:20:53 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.7#53
Thu Jun 25 05:20:53 2020 daemon.info dnsmasq[1735]: using nameserver 2a02:200:1:11::100#53
Thu Jun 25 05:20:53 2020 daemon.info dnsmasq[1735]: using nameserver 2a02:200:1:12::100#53
Thu Jun 25 05:20:53 2020 user.notice firewall: Reloading firewall due to ifup of wan_6 (pppoe-wan)
Thu Jun 25 05:21:58 2020 daemon.info pppd[25153]: No response to 6 echo-requests
Thu Jun 25 05:21:58 2020 daemon.notice pppd[25153]: Serial link appears to be disconnected.
Thu Jun 25 05:21:58 2020 daemon.info pppd[25153]: Connect time 1.2 minutes.
Thu Jun 25 05:21:58 2020 daemon.info pppd[25153]: Sent 16234 bytes, received 9097 bytes.
Thu Jun 25 05:21:58 2020 daemon.notice netifd: Network device 'pppoe-wan' link is down
Thu Jun 25 05:21:58 2020 daemon.notice netifd: Network alias 'pppoe-wan' link is down
Thu Jun 25 05:21:58 2020 daemon.err odhcp6c[25329]: Failed to send DHCPV6 message to ff02::1:2 (Permission denied)
Thu Jun 25 05:21:58 2020 daemon.notice netifd: Interface 'wan_6' has link connectivity loss
Thu Jun 25 05:21:58 2020 daemon.notice netifd: Interface 'wan' has lost the connection
Thu Jun 25 05:21:58 2020 daemon.warn dnsmasq[1735]: no servers found in /tmp/resolv.conf.auto, will retry
Thu Jun 25 05:21:58 2020 daemon.notice netifd: wan_6 (25329): Command failed: Permission denied
Thu Jun 25 05:21:58 2020 daemon.err odhcp6c[25329]: Failed to send DHCPV6 message to ff02::1:2 (Permission denied)
Thu Jun 25 05:21:58 2020 daemon.notice netifd: Interface 'wan_6' is now down
Thu Jun 25 05:21:58 2020 daemon.notice netifd: Interface 'wan_6' is disabled
Thu Jun 25 05:22:04 2020 daemon.notice pppd[25153]: Connection terminated.
Thu Jun 25 05:22:04 2020 daemon.info pppd[25153]: Sent PADT
Thu Jun 25 05:22:04 2020 daemon.notice pppd[25153]: Modem hangup
Thu Jun 25 05:22:04 2020 daemon.info pppd[25153]: Exit.
Thu Jun 25 05:22:04 2020 daemon.notice netifd: Interface 'wan' is now down
Thu Jun 25 05:22:04 2020 daemon.notice netifd: Interface 'wan' is setting up now
Thu Jun 25 05:22:04 2020 daemon.err insmod: module is already loaded - slhc
Thu Jun 25 05:22:04 2020 daemon.err insmod: module is already loaded - ppp_generic
Thu Jun 25 05:22:04 2020 daemon.err insmod: module is already loaded - pppox
Thu Jun 25 05:22:04 2020 daemon.err insmod: module is already loaded - pppoe
Thu Jun 25 05:22:04 2020 daemon.info pppd[25572]: Plugin rp-pppoe.so loaded.
Thu Jun 25 05:22:04 2020 daemon.info pppd[25572]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Thu Jun 25 05:22:04 2020 daemon.notice pppd[25572]: pppd 2.4.7 started by root, uid 0
Thu Jun 25 05:22:14 2020 daemon.info pppd[25572]: PPP session is 59414
Thu Jun 25 05:22:14 2020 daemon.warn pppd[25572]: Connected to 34:0a:98:23:7a:bb via interface eth1
Thu Jun 25 05:22:14 2020 kern.info kernel: [112144.173919] pppoe-wan: renamed from ppp0
Thu Jun 25 05:22:14 2020 daemon.info pppd[25572]: Renamed interface ppp0 to pppoe-wan
Thu Jun 25 05:22:14 2020 daemon.info pppd[25572]: Using interface pppoe-wan
Thu Jun 25 05:22:14 2020 daemon.notice pppd[25572]: Connect: pppoe-wan <--> eth1
Thu Jun 25 05:22:18 2020 daemon.info pppd[25572]: CHAP authentication succeeded
Thu Jun 25 05:22:18 2020 daemon.notice pppd[25572]: CHAP authentication succeeded
Thu Jun 25 05:22:18 2020 daemon.notice pppd[25572]: peer from calling number 34:0A:98:23:7A:BB authorized
Thu Jun 25 05:22:18 2020 daemon.notice pppd[25572]: local  LL address fe80::a877:e9d0:da7e:af34
Thu Jun 25 05:22:18 2020 daemon.notice pppd[25572]: remote LL address fe80::02be:75ff:fe96:0c00
Thu Jun 25 05:22:18 2020 daemon.notice pppd[25572]: local  IP address 46.253.186.56
Thu Jun 25 05:22:18 2020 daemon.notice pppd[25572]: remote IP address 80.254.79.177
Thu Jun 25 05:22:18 2020 daemon.notice pppd[25572]: primary   DNS address 80.254.79.93
Thu Jun 25 05:22:18 2020 daemon.notice pppd[25572]: secondary DNS address 80.254.79.7
Thu Jun 25 05:22:18 2020 daemon.notice netifd: Network device 'pppoe-wan' link is up
Thu Jun 25 05:22:18 2020 daemon.notice netifd: Interface 'wan' is now up
Thu Jun 25 05:22:18 2020 daemon.info dnsmasq[1735]: reading /tmp/resolv.conf.auto
Thu Jun 25 05:22:18 2020 daemon.info dnsmasq[1735]: using local addresses only for domain test
Thu Jun 25 05:22:18 2020 daemon.info dnsmasq[1735]: using local addresses only for domain onion
Thu Jun 25 05:22:18 2020 daemon.info dnsmasq[1735]: using local addresses only for domain localhost
Thu Jun 25 05:22:18 2020 daemon.info dnsmasq[1735]: using local addresses only for domain local
Thu Jun 25 05:22:18 2020 daemon.info dnsmasq[1735]: using local addresses only for domain invalid
Thu Jun 25 05:22:18 2020 daemon.info dnsmasq[1735]: using local addresses only for domain bind
Thu Jun 25 05:22:18 2020 daemon.info dnsmasq[1735]: using local addresses only for domain lan
Thu Jun 25 05:22:18 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.93#53
Thu Jun 25 05:22:18 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.7#53
Thu Jun 25 05:22:18 2020 daemon.notice netifd: Network alias 'pppoe-wan' link is up
Thu Jun 25 05:22:18 2020 daemon.notice netifd: Interface 'wan_6' is enabled
Thu Jun 25 05:22:18 2020 daemon.notice netifd: Interface 'wan_6' has link connectivity
Thu Jun 25 05:22:18 2020 daemon.notice netifd: Interface 'wan_6' is setting up now
Thu Jun 25 05:22:18 2020 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Thu Jun 25 05:22:18 2020 user.notice firewall: Reloading firewall due to ifupdate of wan (pppoe-wan)
Thu Jun 25 05:22:22 2020 daemon.notice netifd: Interface 'wan_6' is now up
Thu Jun 25 05:22:22 2020 daemon.info dnsmasq[1735]: reading /tmp/resolv.conf.auto
Thu Jun 25 05:22:22 2020 daemon.info dnsmasq[1735]: using local addresses only for domain test
Thu Jun 25 05:22:22 2020 daemon.info dnsmasq[1735]: using local addresses only for domain onion
Thu Jun 25 05:22:22 2020 daemon.info dnsmasq[1735]: using local addresses only for domain localhost
Thu Jun 25 05:22:22 2020 daemon.info dnsmasq[1735]: using local addresses only for domain local
Thu Jun 25 05:22:22 2020 daemon.info dnsmasq[1735]: using local addresses only for domain invalid
Thu Jun 25 05:22:22 2020 daemon.info dnsmasq[1735]: using local addresses only for domain bind
Thu Jun 25 05:22:22 2020 daemon.info dnsmasq[1735]: using local addresses only for domain lan
Thu Jun 25 05:22:22 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.93#53
Thu Jun 25 05:22:22 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.7#53
Thu Jun 25 05:22:22 2020 daemon.info dnsmasq[1735]: using nameserver 2a02:200:1:11::100#53
Thu Jun 25 05:22:22 2020 daemon.info dnsmasq[1735]: using nameserver 2a02:200:1:12::100#53
Thu Jun 25 05:22:23 2020 user.notice firewall: Reloading firewall due to ifup of wan_6 (pppoe-wan)

Sadly Timeout waiting for PADO packets is the most common error message for PPPoE links, by itself it doesn't tell you a whole lot. But many (most) xDSL did (and some still do) enforce a 24h disconnect with changing IP addresses over here, to discourage server uses (by changing the IP address) and kicking inactive devices off the net, are you sure that this isn't an issue with your ISP?

To check this, I'd look if it always fails at (roughly) the same time each day - and then reboot (well, restart the WAN connection, but rebooting might be easier for you) once in the morning (or some other distinct time of day) and then check what happens the next day (does it reconnect exactly 24h after your reboot or is it still only failing in the evening).

1 Like

Here is a recent thread about PPPoE disconnects, but I do not know if it is the same issue though: PPPoE disconnects every few hours . Did you search the forum?

I update over wireless all the time; never an issue.

That issue would trigger often, but shouldn't always happen around the same time of day, therefore my first suspicion would be on 24h disconnects.

@fantom-x I did search the forum, but didn't find that post. From there, I learned the PPP debug option. The rest is to advanced for me to understand. Thanks.

By default, wireless is deactivated after a new install. How do you cope with that? Do you check "Keep settings" checkbox?

@slh The PPPoE seems to fail always around 22:00. It seems to reconnect but keeps dropping. Only when I wake up the next morning do I have the internet back.

The log with echo debug >> /etc/ppp/options

Thu Jun 25 21:50:00 2020 daemon.notice hostapd: wlan0-1: AP-STA-DISCONNECTED f0:0f:ec:53:66:7d
Thu Jun 25 21:50:00 2020 daemon.info hostapd: wlan0-1: STA f0:0f:ec:53:66:7d IEEE 802.11: disassociated
Thu Jun 25 21:50:01 2020 daemon.info hostapd: wlan0-1: STA f0:0f:ec:53:66:7d IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Thu Jun 25 21:50:26 2020 daemon.info pppd[25572]: No response to 6 echo-requests
Thu Jun 25 21:50:26 2020 daemon.notice pppd[25572]: Serial link appears to be disconnected.
Thu Jun 25 21:50:26 2020 daemon.info pppd[25572]: Connect time 988.2 minutes.
Thu Jun 25 21:50:26 2020 daemon.info pppd[25572]: Sent 371946308 bytes, received 1668403689 bytes.
Thu Jun 25 21:50:26 2020 daemon.err odhcp6c[25748]: Failed to send RS (Permission denied)
Thu Jun 25 21:50:26 2020 daemon.err odhcp6c[25748]: Failed to send DHCPV6 message to ff02::1:2 (Permission denied)
Thu Jun 25 21:50:26 2020 daemon.notice netifd: Network device 'pppoe-wan' link is down
Thu Jun 25 21:50:26 2020 daemon.notice netifd: Network alias 'pppoe-wan' link is down
Thu Jun 25 21:50:26 2020 daemon.notice netifd: Interface 'wan_6' has link connectivity loss
Thu Jun 25 21:50:26 2020 daemon.notice netifd: Interface 'wan' has lost the connection
Thu Jun 25 21:50:26 2020 daemon.warn dnsmasq[1735]: no servers found in /tmp/resolv.conf.auto, will retry
Thu Jun 25 21:50:26 2020 daemon.notice netifd: wan_6 (25748): Command failed: Permission denied
Thu Jun 25 21:50:26 2020 daemon.err odhcp6c[25748]: Failed to send DHCPV6 message to ff02::1:2 (Permission denied)
Thu Jun 25 21:50:26 2020 daemon.notice netifd: Interface 'wan_6' is now down
Thu Jun 25 21:50:26 2020 daemon.notice netifd: Interface 'wan_6' is disabled
Thu Jun 25 21:50:32 2020 daemon.notice pppd[25572]: Connection terminated.
Thu Jun 25 21:50:32 2020 daemon.info pppd[25572]: Sent PADT
Thu Jun 25 21:50:32 2020 daemon.notice pppd[25572]: Modem hangup
Thu Jun 25 21:50:32 2020 daemon.info pppd[25572]: Exit.
Thu Jun 25 21:50:32 2020 daemon.notice netifd: Interface 'wan' is now down
Thu Jun 25 21:50:32 2020 daemon.notice netifd: Interface 'wan' is setting up now
Thu Jun 25 21:50:32 2020 daemon.err insmod: module is already loaded - slhc
Thu Jun 25 21:50:32 2020 daemon.err insmod: module is already loaded - ppp_generic
Thu Jun 25 21:50:32 2020 daemon.err insmod: module is already loaded - pppox
Thu Jun 25 21:50:32 2020 daemon.err insmod: module is already loaded - pppoe
Thu Jun 25 21:50:32 2020 daemon.info pppd[32583]: Plugin rp-pppoe.so loaded.
Thu Jun 25 21:50:32 2020 daemon.info pppd[32583]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Thu Jun 25 21:50:32 2020 daemon.notice pppd[32583]: pppd 2.4.7 started by root, uid 0
Thu Jun 25 21:50:32 2020 daemon.debug pppd[32583]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Thu Jun 25 21:50:32 2020 daemon.debug pppd[32583]:  dst ff:ff:ff:ff:ff:ff  src e4:95:6e:45:19:7f
Thu Jun 25 21:50:32 2020 daemon.debug pppd[32583]:  [service-name] [host-uniq  47 7f 00 00]
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]:  dst ff:ff:ff:ff:ff:ff  src e4:95:6e:45:19:7f
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]:  [service-name] [host-uniq  47 7f 00 00]
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 34
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]:  dst e4:95:6e:45:19:7f  src 34:0a:98:23:7a:bb
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]:  [service-name] [host-uniq  47 7f 00 00] [AC-name ipi-lss690-r-bn-01]
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]: Send PPPOE Discovery V1T1 PADR session 0x0 length 12
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]:  dst 34:0a:98:23:7a:bb  src e4:95:6e:45:19:7f
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]:  [service-name] [host-uniq  47 7f 00 00]
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]: Recv PPPOE Discovery V1T1 PADS session 0x20ee length 12
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]:  dst e4:95:6e:45:19:7f  src 34:0a:98:23:7a:bb
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]:  [service-name] [host-uniq  47 7f 00 00]
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]: PADS: Service-Name: ''
Thu Jun 25 21:50:37 2020 daemon.info pppd[32583]: PPP session is 8430
Thu Jun 25 21:50:37 2020 daemon.warn pppd[32583]: Connected to 34:0a:98:23:7a:bb via interface eth1
Thu Jun 25 21:50:37 2020 daemon.debug pppd[32583]: using channel 15
Thu Jun 25 21:50:37 2020 kern.info kernel: [171446.567621] pppoe-wan: renamed from ppp0
Thu Jun 25 21:50:38 2020 daemon.info pppd[32583]: Renamed interface ppp0 to pppoe-wan
Thu Jun 25 21:50:38 2020 daemon.info pppd[32583]: Using interface pppoe-wan
Thu Jun 25 21:50:38 2020 daemon.notice pppd[32583]: Connect: pppoe-wan <--> eth1
Thu Jun 25 21:50:38 2020 daemon.debug pppd[32583]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0x731352b0>]
Thu Jun 25 21:50:38 2020 daemon.debug pppd[32583]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0x731352b0>]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: rcvd [LCP ConfReq id=0x2 <mru 1500> <auth chap MD5> <magic 0xba2ea7c3>]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: sent [LCP ConfAck id=0x2 <mru 1500> <auth chap MD5> <magic 0xba2ea7c3>]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: sent [LCP EchoReq id=0x0 magic=0x731352b0]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: rcvd [CHAP Challenge id=0x1 <42ceff856187bf1c0e98627de23007fd>, name = "Huawei"]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: sent [CHAP Response id=0x1 <035e3d9e760efdb2dd8791e9caa55224>, name = "0105298061@bb.monzoon.net"]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: rcvd [LCP EchoRep id=0x0 magic=0xba2ea7c3]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: rcvd [LCP ConfReq id=0x1 <auth chap MD5> <magic 0xa298d097>]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: sent [LCP ConfReq id=0x2 <mru 1492> <magic 0x7aa7c117>]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: sent [LCP ConfAck id=0x1 <auth chap MD5> <magic 0xa298d097>]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: rcvd [LCP ConfAck id=0x2 <mru 1492> <magic 0x7aa7c117>]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: sent [LCP EchoReq id=0x0 magic=0x7aa7c117]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: rcvd [CHAP Challenge id=0x2 <415eef31f04a23629e39bd114d683214>, name = "zrh1-lns01"]
Thu Jun 25 21:50:40 2020 daemon.debug pppd[32583]: sent [CHAP Response id=0x2 <3b10ee57638a4b6bf4b73d60b434126c>, name = "0105298061@bb.monzoon.net"]
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: rcvd [CHAP Success id=0x2 ""]
Thu Jun 25 21:50:41 2020 daemon.info pppd[32583]: CHAP authentication succeeded
Thu Jun 25 21:50:41 2020 daemon.notice pppd[32583]: CHAP authentication succeeded
Thu Jun 25 21:50:41 2020 daemon.notice pppd[32583]: peer from calling number 34:0A:98:23:7A:BB authorized
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: sent [IPV6CP ConfReq id=0x1 <addr fe80::21a5:5f20:395e:41ce>]
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: rcvd [IPCP ConfReq id=0x1 <addr 80.254.79.176>]
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: sent [IPCP ConfAck id=0x1 <addr 80.254.79.176>]
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: rcvd [IPV6CP ConfReq id=0x1 <addr fe80::ce46:d6ff:fe82:5900>]
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: sent [IPV6CP ConfAck id=0x1 <addr fe80::ce46:d6ff:fe82:5900>]
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: rcvd [IPCP ConfNak id=0x1 <addr 46.253.186.56> <ms-dns1 80.254.79.93> <ms-dns2 80.254.79.7>]
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: sent [IPCP ConfReq id=0x2 <addr 46.253.186.56> <ms-dns1 80.254.79.93> <ms-dns2 80.254.79.7>]
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: rcvd [IPV6CP ConfAck id=0x1 <addr fe80::21a5:5f20:395e:41ce>]
Thu Jun 25 21:50:41 2020 daemon.notice pppd[32583]: local  LL address fe80::21a5:5f20:395e:41ce
Thu Jun 25 21:50:41 2020 daemon.notice pppd[32583]: remote LL address fe80::ce46:d6ff:fe82:5900
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: Script /lib/netifd/ppp6-up started (pid 32725)
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: rcvd [IPCP ConfAck id=0x2 <addr 46.253.186.56> <ms-dns1 80.254.79.93> <ms-dns2 80.254.79.7>]
Thu Jun 25 21:50:41 2020 daemon.notice pppd[32583]: local  IP address 46.253.186.56
Thu Jun 25 21:50:41 2020 daemon.notice pppd[32583]: remote IP address 80.254.79.176
Thu Jun 25 21:50:41 2020 daemon.notice pppd[32583]: primary   DNS address 80.254.79.93
Thu Jun 25 21:50:41 2020 daemon.notice pppd[32583]: secondary DNS address 80.254.79.7
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: Script /lib/netifd/ppp-up started (pid 32726)
Thu Jun 25 21:50:41 2020 daemon.notice netifd: Network device 'pppoe-wan' link is up
Thu Jun 25 21:50:41 2020 daemon.notice netifd: Interface 'wan' is now up
Thu Jun 25 21:50:41 2020 daemon.info dnsmasq[1735]: reading /tmp/resolv.conf.auto
Thu Jun 25 21:50:41 2020 daemon.info dnsmasq[1735]: using local addresses only for domain test
Thu Jun 25 21:50:41 2020 daemon.info dnsmasq[1735]: using local addresses only for domain onion
Thu Jun 25 21:50:41 2020 daemon.info dnsmasq[1735]: using local addresses only for domain localhost
Thu Jun 25 21:50:41 2020 daemon.info dnsmasq[1735]: using local addresses only for domain local
Thu Jun 25 21:50:41 2020 daemon.info dnsmasq[1735]: using local addresses only for domain invalid
Thu Jun 25 21:50:41 2020 daemon.info dnsmasq[1735]: using local addresses only for domain bind
Thu Jun 25 21:50:41 2020 daemon.info dnsmasq[1735]: using local addresses only for domain lan
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: Script /lib/netifd/ppp-up finished (pid 32726), status = 0x1
Thu Jun 25 21:50:41 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.93#53
Thu Jun 25 21:50:41 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.7#53
Thu Jun 25 21:50:41 2020 daemon.notice netifd: Network alias 'pppoe-wan' link is up
Thu Jun 25 21:50:41 2020 daemon.notice netifd: Interface 'wan_6' is enabled
Thu Jun 25 21:50:41 2020 daemon.notice netifd: Interface 'wan_6' has link connectivity
Thu Jun 25 21:50:41 2020 daemon.notice netifd: Interface 'wan_6' is setting up now
Thu Jun 25 21:50:41 2020 daemon.debug pppd[32583]: Script /lib/netifd/ppp6-up finished (pid 32725), status = 0x0
Thu Jun 25 21:50:41 2020 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Thu Jun 25 21:50:41 2020 user.notice firewall: Reloading firewall due to ifupdate of wan (pppoe-wan)
Thu Jun 25 21:50:51 2020 daemon.notice netifd: Interface 'wan_6' is now up
Thu Jun 25 21:50:51 2020 user.notice firewall: Reloading firewall due to ifup of wan_6 (pppoe-wan)
Thu Jun 25 21:51:01 2020 daemon.err uhttpd[811]: luci: accepted login on / for root from 192.168.1.130
Thu Jun 25 21:51:51 2020 daemon.info pppd[32583]: No response to 6 echo-requests
Thu Jun 25 21:51:51 2020 daemon.notice pppd[32583]: Serial link appears to be disconnected.
Thu Jun 25 21:51:51 2020 daemon.info pppd[32583]: Connect time 1.2 minutes.
Thu Jun 25 21:51:51 2020 daemon.info pppd[32583]: Sent 37415 bytes, received 19194 bytes.
Thu Jun 25 21:51:51 2020 daemon.debug pppd[32583]: Script /lib/netifd/ppp-down started (pid 511)
Thu Jun 25 21:51:51 2020 daemon.notice netifd: Network device 'pppoe-wan' link is down
Thu Jun 25 21:51:51 2020 daemon.notice netifd: Network alias 'pppoe-wan' link is down
Thu Jun 25 21:51:51 2020 daemon.notice netifd: Interface 'wan_6' has link connectivity loss
Thu Jun 25 21:51:51 2020 daemon.debug pppd[32583]: Script /lib/netifd/ppp-down started (pid 513)
Thu Jun 25 21:51:51 2020 daemon.debug pppd[32583]: sent [LCP TermReq id=0x3 "Peer not responding"]
Thu Jun 25 21:51:51 2020 daemon.notice netifd: Interface 'wan' has lost the connection
Thu Jun 25 21:51:51 2020 daemon.warn dnsmasq[1735]: no servers found in /tmp/resolv.conf.auto, will retry
Thu Jun 25 21:51:51 2020 daemon.debug pppd[32583]: Script /lib/netifd/ppp-down finished (pid 511), status = 0x1
Thu Jun 25 21:51:51 2020 daemon.debug pppd[32583]: Script /lib/netifd/ppp-down finished (pid 513), status = 0x1
Thu Jun 25 21:51:51 2020 daemon.err odhcp6c[32759]: Failed to send DHCPV6 message to ff02::1:2 (Permission denied)
Thu Jun 25 21:51:51 2020 daemon.notice netifd: Interface 'wan_6' is now down
Thu Jun 25 21:51:51 2020 daemon.notice netifd: Interface 'wan_6' is disabled
Thu Jun 25 21:51:54 2020 daemon.debug pppd[32583]: sent [LCP TermReq id=0x4 "Peer not responding"]
Thu Jun 25 21:51:57 2020 daemon.notice pppd[32583]: Connection terminated.
Thu Jun 25 21:51:57 2020 daemon.debug pppd[32583]: Send PPPOE Discovery V1T1 PADT session 0x20ee length 8
Thu Jun 25 21:51:57 2020 daemon.debug pppd[32583]:  dst 34:0a:98:23:7a:bb  src e4:95:6e:45:19:7f
Thu Jun 25 21:51:57 2020 daemon.debug pppd[32583]:  [host-uniq  47 7f 00 00]
Thu Jun 25 21:51:57 2020 daemon.info pppd[32583]: Sent PADT
Thu Jun 25 21:51:57 2020 daemon.notice pppd[32583]: Modem hangup
Thu Jun 25 21:51:57 2020 daemon.info pppd[32583]: Exit.
Thu Jun 25 21:51:57 2020 daemon.notice netifd: Interface 'wan' is now down
Thu Jun 25 21:51:57 2020 daemon.notice netifd: Interface 'wan' is setting up now
Thu Jun 25 21:51:57 2020 daemon.err insmod: module is already loaded - slhc
Thu Jun 25 21:51:57 2020 daemon.err insmod: module is already loaded - ppp_generic
Thu Jun 25 21:51:57 2020 daemon.err insmod: module is already loaded - pppox
Thu Jun 25 21:51:57 2020 daemon.err insmod: module is already loaded - pppoe
Thu Jun 25 21:51:57 2020 daemon.info pppd[594]: Plugin rp-pppoe.so loaded.
Thu Jun 25 21:51:57 2020 daemon.info pppd[594]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Thu Jun 25 21:51:57 2020 daemon.notice pppd[594]: pppd 2.4.7 started by root, uid 0
Thu Jun 25 21:51:57 2020 daemon.debug pppd[594]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Thu Jun 25 21:51:57 2020 daemon.debug pppd[594]:  dst ff:ff:ff:ff:ff:ff  src e4:95:6e:45:19:7f
Thu Jun 25 21:51:57 2020 daemon.debug pppd[594]:  [service-name] [host-uniq  52 02 00 00]
Thu Jun 25 21:52:02 2020 daemon.debug pppd[594]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Thu Jun 25 21:52:02 2020 daemon.debug pppd[594]:  dst ff:ff:ff:ff:ff:ff  src e4:95:6e:45:19:7f
Thu Jun 25 21:52:02 2020 daemon.debug pppd[594]:  [service-name] [host-uniq  52 02 00 00]
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]:  dst ff:ff:ff:ff:ff:ff  src e4:95:6e:45:19:7f
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]:  [service-name] [host-uniq  52 02 00 00]
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 34
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]:  dst e4:95:6e:45:19:7f  src 34:0a:98:23:7a:bb
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]:  [service-name] [host-uniq  52 02 00 00] [AC-name ipi-lss690-r-bn-01]
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]: Send PPPOE Discovery V1T1 PADR session 0x0 length 12
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]:  dst 34:0a:98:23:7a:bb  src e4:95:6e:45:19:7f
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]:  [service-name] [host-uniq  52 02 00 00]
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]: Recv PPPOE Discovery V1T1 PADS session 0x2644 length 12
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]:  dst e4:95:6e:45:19:7f  src 34:0a:98:23:7a:bb
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]:  [service-name] [host-uniq  52 02 00 00]
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]: PADS: Service-Name: ''
Thu Jun 25 21:52:07 2020 daemon.info pppd[594]: PPP session is 9796
Thu Jun 25 21:52:07 2020 daemon.warn pppd[594]: Connected to 34:0a:98:23:7a:bb via interface eth1
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]: using channel 16
Thu Jun 25 21:52:07 2020 kern.info kernel: [171536.147859] pppoe-wan: renamed from ppp0
Thu Jun 25 21:52:07 2020 daemon.info pppd[594]: Renamed interface ppp0 to pppoe-wan
Thu Jun 25 21:52:07 2020 daemon.info pppd[594]: Using interface pppoe-wan
Thu Jun 25 21:52:07 2020 daemon.notice pppd[594]: Connect: pppoe-wan <--> eth1
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0x32f4f40b>]
Thu Jun 25 21:52:07 2020 daemon.debug pppd[594]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0x32f4f40b>]
Thu Jun 25 21:52:10 2020 daemon.debug pppd[594]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0x32f4f40b>]
Thu Jun 25 21:52:10 2020 daemon.debug pppd[594]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0x32f4f40b>]
Thu Jun 25 21:52:10 2020 daemon.debug pppd[594]: rcvd [LCP ConfReq id=0x2 <mru 1500> <auth chap MD5> <magic 0xefeda51b>]
Thu Jun 25 21:52:10 2020 daemon.debug pppd[594]: sent [LCP ConfAck id=0x2 <mru 1500> <auth chap MD5> <magic 0xefeda51b>]
Thu Jun 25 21:52:10 2020 daemon.debug pppd[594]: sent [LCP EchoReq id=0x0 magic=0x32f4f40b]
Thu Jun 25 21:52:10 2020 daemon.debug pppd[594]: rcvd [CHAP Challenge id=0x1 <c2325e44d4cd3e364393bac53e43230e>, name = "Huawei"]
Thu Jun 25 21:52:10 2020 daemon.debug pppd[594]: sent [CHAP Response id=0x1 <71ff151009ad9f94c11567f4e90e313a>, name = "0105298061@bb.monzoon.net"]
Thu Jun 25 21:52:10 2020 daemon.debug pppd[594]: rcvd [LCP EchoRep id=0x0 magic=0xefeda51b]
Thu Jun 25 21:52:10 2020 daemon.debug pppd[594]: rcvd [LCP ConfReq id=0x1 <auth chap MD5> <magic 0xa29a3091>]
Thu Jun 25 21:52:10 2020 daemon.debug pppd[594]: sent [LCP ConfReq id=0x2 <mru 1492> <magic 0x8e9536d6>]
Thu Jun 25 21:52:10 2020 daemon.debug pppd[594]: sent [LCP ConfAck id=0x1 <auth chap MD5> <magic 0xa29a3091>]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: rcvd [LCP ConfAck id=0x2 <mru 1492> <magic 0x8e9536d6>]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: sent [LCP EchoReq id=0x0 magic=0x8e9536d6]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: rcvd [CHAP Challenge id=0x2 <d69919f310d5f9ce9e39bd113a301e7a>, name = "zrh1-lns01"]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: sent [CHAP Response id=0x2 <cb7dba4ddf6596dac1fa4f24a3682ee1>, name = "0105298061@bb.monzoon.net"]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: rcvd [CHAP Success id=0x2 ""]
Thu Jun 25 21:52:11 2020 daemon.info pppd[594]: CHAP authentication succeeded
Thu Jun 25 21:52:11 2020 daemon.notice pppd[594]: CHAP authentication succeeded
Thu Jun 25 21:52:11 2020 daemon.notice pppd[594]: peer from calling number 34:0A:98:23:7A:BB authorized
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: sent [IPV6CP ConfReq id=0x1 <addr fe80::7461:5822:901f:e0b4>]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: rcvd [IPCP ConfReq id=0x1 <addr 80.254.79.176>]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: sent [IPCP ConfAck id=0x1 <addr 80.254.79.176>]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: rcvd [IPV6CP ConfReq id=0x1 <addr fe80::ce46:d6ff:fe82:5900>]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: sent [IPV6CP ConfAck id=0x1 <addr fe80::ce46:d6ff:fe82:5900>]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: rcvd [IPCP ConfNak id=0x1 <addr 46.253.186.56> <ms-dns1 80.254.79.93> <ms-dns2 80.254.79.7>]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: sent [IPCP ConfReq id=0x2 <addr 46.253.186.56> <ms-dns1 80.254.79.93> <ms-dns2 80.254.79.7>]
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: rcvd [IPV6CP ConfAck id=0x1 <addr fe80::7461:5822:901f:e0b4>]
Thu Jun 25 21:52:11 2020 daemon.notice pppd[594]: local  LL address fe80::7461:5822:901f:e0b4
Thu Jun 25 21:52:11 2020 daemon.notice pppd[594]: remote LL address fe80::ce46:d6ff:fe82:5900
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: Script /lib/netifd/ppp6-up started (pid 737)
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: rcvd [IPCP ConfAck id=0x2 <addr 46.253.186.56> <ms-dns1 80.254.79.93> <ms-dns2 80.254.79.7>]
Thu Jun 25 21:52:11 2020 daemon.notice pppd[594]: local  IP address 46.253.186.56
Thu Jun 25 21:52:11 2020 daemon.notice pppd[594]: remote IP address 80.254.79.176
Thu Jun 25 21:52:11 2020 daemon.notice pppd[594]: primary   DNS address 80.254.79.93
Thu Jun 25 21:52:11 2020 daemon.notice pppd[594]: secondary DNS address 80.254.79.7
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: Script /lib/netifd/ppp-up started (pid 738)
Thu Jun 25 21:52:11 2020 daemon.notice netifd: Network device 'pppoe-wan' link is up
Thu Jun 25 21:52:11 2020 daemon.notice netifd: Interface 'wan' is now up
Thu Jun 25 21:52:11 2020 daemon.info dnsmasq[1735]: reading /tmp/resolv.conf.auto
Thu Jun 25 21:52:11 2020 daemon.info dnsmasq[1735]: using local addresses only for domain test
Thu Jun 25 21:52:11 2020 daemon.info dnsmasq[1735]: using local addresses only for domain onion
Thu Jun 25 21:52:11 2020 daemon.info dnsmasq[1735]: using local addresses only for domain localhost
Thu Jun 25 21:52:11 2020 daemon.info dnsmasq[1735]: using local addresses only for domain local
Thu Jun 25 21:52:11 2020 daemon.info dnsmasq[1735]: using local addresses only for domain invalid
Thu Jun 25 21:52:11 2020 daemon.info dnsmasq[1735]: using local addresses only for domain bind
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: Script /lib/netifd/ppp-up finished (pid 738), status = 0x1
Thu Jun 25 21:52:11 2020 daemon.info dnsmasq[1735]: using local addresses only for domain lan
Thu Jun 25 21:52:11 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.93#53
Thu Jun 25 21:52:11 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.7#53
Thu Jun 25 21:52:11 2020 daemon.notice netifd: Network alias 'pppoe-wan' link is up
Thu Jun 25 21:52:11 2020 daemon.notice netifd: Interface 'wan_6' is enabled
Thu Jun 25 21:52:11 2020 daemon.notice netifd: Interface 'wan_6' has link connectivity
Thu Jun 25 21:52:11 2020 daemon.notice netifd: Interface 'wan_6' is setting up now
Thu Jun 25 21:52:11 2020 daemon.debug pppd[594]: Script /lib/netifd/ppp6-up finished (pid 737), status = 0x0
Thu Jun 25 21:52:11 2020 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Thu Jun 25 21:52:11 2020 user.notice firewall: Reloading firewall due to ifupdate of wan (pppoe-wan)
Thu Jun 25 21:52:15 2020 daemon.notice netifd: Interface 'wan_6' is now up
Thu Jun 25 21:52:15 2020 daemon.info dnsmasq[1735]: reading /tmp/resolv.conf.auto
Thu Jun 25 21:52:15 2020 daemon.info dnsmasq[1735]: using local addresses only for domain test
Thu Jun 25 21:52:15 2020 daemon.info dnsmasq[1735]: using local addresses only for domain onion
Thu Jun 25 21:52:15 2020 daemon.info dnsmasq[1735]: using local addresses only for domain localhost
Thu Jun 25 21:52:15 2020 daemon.info dnsmasq[1735]: using local addresses only for domain local
Thu Jun 25 21:52:15 2020 daemon.info dnsmasq[1735]: using local addresses only for domain invalid
Thu Jun 25 21:52:15 2020 daemon.info dnsmasq[1735]: using local addresses only for domain bind
Thu Jun 25 21:52:15 2020 daemon.info dnsmasq[1735]: using local addresses only for domain lan
Thu Jun 25 21:52:15 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.93#53
Thu Jun 25 21:52:15 2020 daemon.info dnsmasq[1735]: using nameserver 80.254.79.7#53
Thu Jun 25 21:52:15 2020 daemon.info dnsmasq[1735]: using nameserver 2a02:200:1:11::100#53
Thu Jun 25 21:52:15 2020 daemon.info dnsmasq[1735]: using nameserver 2a02:200:1:12::100#53
Thu Jun 25 21:52:15 2020 user.notice firewall: Reloading firewall due to ifup of wan_6 (pppoe-wan)
Thu Jun 25 21:53:41 2020 daemon.info pppd[594]: No response to 6 echo-requests
Thu Jun 25 21:53:41 2020 daemon.notice pppd[594]: Serial link appears to be disconnected.
Thu Jun 25 21:53:41 2020 daemon.info pppd[594]: Connect time 1.5 minutes.
Thu Jun 25 21:53:41 2020 daemon.info pppd[594]: Sent 455751 bytes, received 8279252 bytes.
Thu Jun 25 21:53:41 2020 daemon.debug pppd[594]: Script /lib/netifd/ppp-down started (pid 946)
Thu Jun 25 21:53:41 2020 daemon.err odhcp6c[772]: Failed to send DHCPV6 message to ff02::1:2 (Permission denied)
Thu Jun 25 21:53:41 2020 daemon.notice netifd: Network device 'pppoe-wan' link is down
Thu Jun 25 21:53:41 2020 daemon.notice netifd: Network alias 'pppoe-wan' link is down
Thu Jun 25 21:53:41 2020 daemon.notice netifd: Interface 'wan_6' has link connectivity loss
Thu Jun 25 21:53:41 2020 daemon.debug pppd[594]: Script /lib/netifd/ppp-down started (pid 949)
Thu Jun 25 21:53:41 2020 daemon.debug pppd[594]: sent [LCP TermReq id=0x3 "Peer not responding"]
Thu Jun 25 21:53:41 2020 daemon.notice netifd: Interface 'wan' has lost the connection
Thu Jun 25 21:53:41 2020 daemon.warn dnsmasq[1735]: no servers found in /tmp/resolv.conf.auto, will retry
Thu Jun 25 21:53:41 2020 daemon.debug pppd[594]: Script /lib/netifd/ppp-down finished (pid 946), status = 0x1
Thu Jun 25 21:53:41 2020 daemon.debug pppd[594]: Script /lib/netifd/ppp-down finished (pid 949), status = 0x1
Thu Jun 25 21:53:41 2020 daemon.notice netifd: wan_6 (772): Command failed: Permission denied
Thu Jun 25 21:53:41 2020 daemon.err odhcp6c[772]: Failed to send DHCPV6 message to ff02::1:2 (Permission denied)
Thu Jun 25 21:53:41 2020 daemon.notice netifd: Interface 'wan_6' is now down
Thu Jun 25 21:53:41 2020 daemon.notice netifd: Interface 'wan_6' is disabled
Thu Jun 25 21:53:44 2020 daemon.debug pppd[594]: sent [LCP TermReq id=0x4 "Peer not responding"]
Thu Jun 25 21:53:47 2020 daemon.notice pppd[594]: Connection terminated.

19.07.0 has a vulnerable ppp client. Definitely update ASAP. See: https://openwrt.org/advisory/2020-02-21-1

1 Like

Thank you for the info. I didn't see this one before. I just updated to 19.07.3. I will check the logs tonight.

I am on 19.07.3 and in the evenings before 10 o clock the PPPoE still disconnects and fails to reconnect. Here is a excerpt from the log:

Sun Jun 28 23:21:21 2020 daemon.info pppd[26370]: Exit.
Sun Jun 28 23:21:21 2020 daemon.notice netifd: Interface 'wan' is now down
Sun Jun 28 23:21:21 2020 daemon.notice netifd: Interface 'wan' is setting up now
Sun Jun 28 23:21:21 2020 daemon.err insmod: module is already loaded - slhc
Sun Jun 28 23:21:21 2020 daemon.err insmod: module is already loaded - ppp_generic
Sun Jun 28 23:21:21 2020 daemon.err insmod: module is already loaded - pppox
Sun Jun 28 23:21:21 2020 daemon.err insmod: module is already loaded - pppoe
Sun Jun 28 23:21:21 2020 daemon.info pppd[26423]: Plugin rp-pppoe.so loaded.
Sun Jun 28 23:21:21 2020 daemon.info pppd[26423]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Sun Jun 28 23:21:21 2020 daemon.notice pppd[26423]: pppd 2.4.7 started by root, uid 0
Sun Jun 28 23:21:21 2020 daemon.debug pppd[26423]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Sun Jun 28 23:21:21 2020 daemon.debug pppd[26423]:  dst ff:ff:ff:ff:ff:ff  src e4:95:6e:45:19:7f
Sun Jun 28 23:21:21 2020 daemon.debug pppd[26423]:  [service-name] [host-uniq  37 67 00 00]
Sun Jun 28 23:21:26 2020 daemon.debug pppd[26423]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Sun Jun 28 23:21:26 2020 daemon.debug pppd[26423]:  dst ff:ff:ff:ff:ff:ff  src e4:95:6e:45:19:7f
Sun Jun 28 23:21:26 2020 daemon.debug pppd[26423]:  [service-name] [host-uniq  37 67 00 00]
Sun Jun 28 23:21:31 2020 daemon.debug pppd[26423]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Sun Jun 28 23:21:31 2020 daemon.debug pppd[26423]:  dst ff:ff:ff:ff:ff:ff  src e4:95:6e:45:19:7f
Sun Jun 28 23:21:31 2020 daemon.debug pppd[26423]:  [service-name] [host-uniq  37 67 00 00]
Sun Jun 28 23:21:36 2020 daemon.warn pppd[26423]: Timeout waiting for PADO packets
Sun Jun 28 23:21:36 2020 daemon.err pppd[26423]: Unable to complete PPPoE Discovery
Sun Jun 28 23:21:36 2020 daemon.info pppd[26423]: Exit.

Any ideas what I could do? If not, then I will buy a configured Router from my Internet provider.

How do you fix this when it happens? Does it just recover some time later?
Does it work after rebooting the modem or the router?

It just works again the next morning.

In the evening, nothing got the connection back so far. I tried these steps:

  • Reconnect WAN Interface in Luci
  • Restart Router
  • Restart Modem.
1 Like

That seems to imply your ISP's end of the PPPoE link....

1 Like

Ok. I will check with them.

This error (Timeout waiting for PADO packets) occurs when ISP's side does not respond to your router's request to establish a connection. Often it happens when the previous connection was not properly terminated, and ISP's hardware does not expect (ignores) requests from the client's side.
You can either talk to your ISP and show them the logs, and/or set your router's crontab to automatically reboot when connection is lost.

Alternatively, you have regularly scheduled radio interference. In my own experience, it was a bad (but otherwise still working fine) LED bulb on a timed switch about five meters away from DSL modem/line that was overwhelming the signal with noise.

How can Set Crontab to router? please explain

Is Google banned in your country?
Did you try to search for "crontab OpenWrt"?

https://openwrt.org/docs/guide-user/base-system/cron

Whats the problem is someone like you send me a direct link?
You think my Google not working

Ahh forget , Thanks for the link

It is usually assumed people read though OpenWrt User Guide before posting questions here.

The problem is that I have to go to Google, post the question there, copy the first link, and paste it here... exactly the same that you could have done yourself.

1 Like