OpenWrt/LEDE Project

  • Status Unconfirmed
  • Percent Complete
    0%
  • Task Type Bug Report
  • Category Base system
  • Assigned To No-one
  • Operating System All
  • Severity Low
  • Priority Very Low
  • Reported Version Trunk
  • Due in Version Undecided
  • Due Date Undecided
  • Private
Attached to Project: OpenWrt/LEDE Project
Opened by lukasz1992 - 18.08.2018

FS#1794 - W8970 - ADSL stops working after some time

Hi,

I have installed Openwrt 18.06.0 on my TD-W8970 device.
There is a problem that randomly, after average 2-5 days pppoe wan connection just stops working.

DSL is synchronized:
Annex: A
Line Mode: G.992.5 (ADSL2+)
Line State: UP [0×801: showtime_tc_sync]
(...)
Power Management Mode: L0 - Synchronized

No “leave showtime” message, kernel log is clean, system log is full of pppd restarting messages. Pppd keeps restarting and timeouts.

The only solution is to reboot machine, it always helps. How to debug and diagnose the problem?

gmiranda commented on 23.10.2018 17:28

I think I'm also affected by this: DSL is synchronized but pppoe is down and restarting the WAN interface does nothing, I have to reboot the device.

I'm running Openwrt 18.06.1 and with LEDE 17.01.4 I had zero issues like this one.

Here's a system log:

Tue Oct 23 17:17:20 2018 daemon.info pppd[2423]: No response to 5 echo-requests
Tue Oct 23 17:17:20 2018 daemon.notice pppd[2423]: Serial link appears to be disconnected.
Tue Oct 23 17:17:20 2018 daemon.info pppd[2423]: Connect time 4860.6 minutes.
Tue Oct 23 17:17:20 2018 daemon.info pppd[2423]: Sent 1993189604 bytes, received 2456907197 bytes.
Tue Oct 23 17:17:20 2018 daemon.notice netifd: Network device 'pppoe-wan' link is down
Tue Oct 23 17:17:20 2018 daemon.notice netifd: Interface 'wan6' has link connectivity loss
Tue Oct 23 17:17:20 2018 daemon.err odhcp6c[2505]: Failed to send RS (Permission denied)
Tue Oct 23 17:17:21 2018 daemon.notice netifd: Interface 'wan' has lost the connection
Tue Oct 23 17:17:21 2018 daemon.warn dnsmasq[1824]: no servers found in /tmp/resolv.conf.auto, will retry
Tue Oct 23 17:17:21 2018 daemon.err odhcp6c[2505]: Failed to send DHCPV6 message to ff02::1:2 (Permission denied)
Tue Oct 23 17:17:21 2018 daemon.info odhcpd[899]: Using a RA lifetime of 0 seconds on br-lan
Tue Oct 23 17:17:22 2018 user.notice ddns-scripts[2604]: myddns_ipv4: PID '2604' terminated by 'SIGTERM' at 2018-10-23 17:17
Tue Oct 23 17:17:26 2018 daemon.notice pppd[2423]: Connection terminated.
Tue Oct 23 17:17:26 2018 daemon.notice netifd: Interface 'wan6' is disabled
Tue Oct 23 17:17:26 2018 daemon.info pppd[2423]: Sent PADT
Tue Oct 23 17:17:26 2018 daemon.notice pppd[2423]: Modem hangup
Tue Oct 23 17:17:26 2018 daemon.info pppd[2423]: Exit.
Tue Oct 23 17:17:27 2018 daemon.notice netifd: Interface 'wan' is now down
Tue Oct 23 17:17:27 2018 daemon.notice netifd: Interface 'wan' is disabled
Tue Oct 23 17:17:27 2018 daemon.notice netifd: Interface 'wan' is enabled
Tue Oct 23 17:17:27 2018 daemon.notice netifd: Interface 'wan' is setting up now
Tue Oct 23 17:17:27 2018 daemon.err insmod: module is already loaded - slhc
Tue Oct 23 17:17:27 2018 daemon.err insmod: module is already loaded - ppp_generic
Tue Oct 23 17:17:27 2018 daemon.err insmod: module is already loaded - pppox
Tue Oct 23 17:17:27 2018 daemon.err insmod: module is already loaded - pppoe
Tue Oct 23 17:17:27 2018 daemon.info pppd[5113]: Plugin rp-pppoe.so loaded.
Tue Oct 23 17:17:27 2018 daemon.info pppd[5113]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Tue Oct 23 17:17:27 2018 daemon.notice pppd[5113]: pppd 2.4.7 started by root, uid 0
Tue Oct 23 17:17:42 2018 daemon.warn pppd[5113]: Timeout waiting for PADO packets
Tue Oct 23 17:17:42 2018 daemon.err pppd[5113]: Unable to complete PPPoE Discovery
Tue Oct 23 17:17:42 2018 daemon.info pppd[5113]: Exit.
Tue Oct 23 17:17:43 2018 daemon.notice netifd: Interface 'wan' is now down
Tue Oct 23 17:17:43 2018 daemon.notice netifd: Interface 'wan' is disabled
Tue Oct 23 17:17:43 2018 daemon.notice netifd: Interface 'wan' is enabled
Tue Oct 23 17:17:43 2018 daemon.notice netifd: Interface 'wan' is setting up now
Tue Oct 23 17:17:43 2018 daemon.err insmod: module is already loaded - slhc
Tue Oct 23 17:17:43 2018 daemon.err insmod: module is already loaded - ppp_generic
Tue Oct 23 17:17:43 2018 daemon.err insmod: module is already loaded - pppox
Tue Oct 23 17:17:43 2018 daemon.err insmod: module is already loaded - pppoe
Tue Oct 23 17:17:44 2018 daemon.info pppd[5944]: Plugin rp-pppoe.so loaded.
Tue Oct 23 17:17:44 2018 daemon.info pppd[5944]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Tue Oct 23 17:17:44 2018 daemon.notice pppd[5944]: pppd 2.4.7 started by root, uid 0
Tue Oct 23 17:17:59 2018 daemon.warn pppd[5944]: Timeout waiting for PADO packets
Tue Oct 23 17:17:59 2018 daemon.err pppd[5944]: Unable to complete PPPoE Discovery
Tue Oct 23 17:17:59 2018 daemon.info pppd[5944]: Exit.
Tue Oct 23 17:17:59 2018 daemon.notice netifd: Interface 'wan' is now down
Tue Oct 23 17:17:59 2018 daemon.notice netifd: Interface 'wan' is disabled
Tue Oct 23 17:17:59 2018 daemon.notice netifd: Interface 'wan' is enabled
Tue Oct 23 17:17:59 2018 daemon.notice netifd: Interface 'wan' is setting up now
Tue Oct 23 17:17:59 2018 daemon.err insmod: module is already loaded - slhc
Tue Oct 23 17:17:59 2018 daemon.err insmod: module is already loaded - ppp_generic
Tue Oct 23 17:17:59 2018 daemon.err insmod: module is already loaded - pppox
Tue Oct 23 17:17:59 2018 daemon.err insmod: module is already loaded - pppoe
Tue Oct 23 17:18:00 2018 daemon.info pppd[6977]: Plugin rp-pppoe.so loaded.
Tue Oct 23 17:18:00 2018 daemon.info pppd[6977]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Tue Oct 23 17:18:00 2018 daemon.notice pppd[6977]: pppd 2.4.7 started by root, uid 0
Tue Oct 23 17:18:15 2018 daemon.warn pppd[6977]: Timeout waiting for PADO packets
Tue Oct 23 17:18:15 2018 daemon.err pppd[6977]: Unable to complete PPPoE Discovery
Tue Oct 23 17:18:15 2018 daemon.info pppd[6977]: Exit.
Tue Oct 23 17:18:15 2018 daemon.notice netifd: Interface 'wan' is now down
Tue Oct 23 17:18:15 2018 daemon.notice netifd: Interface 'wan' is disabled
Tue Oct 23 17:18:15 2018 daemon.notice netifd: Interface 'wan' is enabled
Tue Oct 23 17:18:15 2018 daemon.notice netifd: Interface 'wan' is setting up now
Tue Oct 23 17:18:15 2018 daemon.err insmod: module is already loaded - slhc
Tue Oct 23 17:18:15 2018 daemon.err insmod: module is already loaded - ppp_generic
Tue Oct 23 17:18:15 2018 daemon.err insmod: module is already loaded - pppox
Tue Oct 23 17:18:15 2018 daemon.err insmod: module is already loaded - pppoe
Tue Oct 23 17:18:15 2018 daemon.info pppd[7612]: Plugin rp-pppoe.so loaded.
Tue Oct 23 17:18:15 2018 daemon.info pppd[7612]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Tue Oct 23 17:18:15 2018 daemon.notice pppd[7612]: pppd 2.4.7 started by root, uid 0
Tue Oct 23 17:18:30 2018 daemon.warn pppd[7612]: Timeout waiting for PADO packets
Tue Oct 23 17:18:30 2018 daemon.err pppd[7612]: Unable to complete PPPoE Discovery
Tue Oct 23 17:18:30 2018 daemon.info pppd[7612]: Exit.
Tue Oct 23 17:18:31 2018 daemon.notice netifd: Interface 'wan' is now down
Tue Oct 23 17:18:31 2018 daemon.notice netifd: Interface 'wan' is disabled
Tue Oct 23 17:18:31 2018 daemon.notice netifd: Interface 'wan' is enabled
Tue Oct 23 17:18:31 2018 daemon.notice netifd: Interface 'wan' is setting up now
Tue Oct 23 17:18:31 2018 daemon.err insmod: module is already loaded - slhc
Tue Oct 23 17:18:31 2018 daemon.err insmod: module is already loaded - ppp_generic
Tue Oct 23 17:18:31 2018 daemon.err insmod: module is already loaded - pppox
Tue Oct 23 17:18:31 2018 daemon.err insmod: module is already loaded - pppoe
Tue Oct 23 17:18:31 2018 daemon.info pppd[7731]: Plugin rp-pppoe.so loaded.
Tue Oct 23 17:18:31 2018 daemon.info pppd[7731]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Tue Oct 23 17:18:31 2018 daemon.notice pppd[7731]: pppd 2.4.7 started by root, uid 0
Tue Oct 23 17:18:46 2018 daemon.warn pppd[7731]: Timeout waiting for PADO packets
Tue Oct 23 17:18:46 2018 daemon.err pppd[7731]: Unable to complete PPPoE Discovery
Tue Oct 23 17:18:46 2018 daemon.info pppd[7731]: Exit.
Tue Oct 23 17:18:46 2018 daemon.notice netifd: Interface 'wan' is now down
Tue Oct 23 17:18:46 2018 daemon.notice netifd: Interface 'wan' is disabled
Tue Oct 23 17:18:46 2018 daemon.notice netifd: Interface 'wan' is enabled
Tue Oct 23 17:18:46 2018 daemon.notice netifd: Interface 'wan' is setting up now
Tue Oct 23 17:18:47 2018 daemon.err insmod: module is already loaded - slhc
Tue Oct 23 17:18:47 2018 daemon.err insmod: module is already loaded - ppp_generic
Tue Oct 23 17:18:47 2018 daemon.err insmod: module is already loaded - pppox
Tue Oct 23 17:18:47 2018 daemon.err insmod: module is already loaded - pppoe
Tue Oct 23 17:18:47 2018 daemon.info pppd[7866]: Plugin rp-pppoe.so loaded.
Tue Oct 23 17:18:47 2018 daemon.info pppd[7866]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Tue Oct 23 17:18:47 2018 daemon.notice pppd[7866]: pppd 2.4.7 started by root, uid 0
Tue Oct 23 17:18:57 2018 daemon.notice netifd: Interface 'wan' is now down
Tue Oct 23 17:18:57 2018 daemon.notice netifd: Interface 'wan' is disabled
Tue Oct 23 17:18:57 2018 daemon.notice netifd: Interface 'wan' has link connectivity loss
Tue Oct 23 17:18:57 2018 daemon.notice netifd: Network device 'dsl0' link is down
Tue Oct 23 17:19:15 2018 daemon.notice netifd: Interface 'wan' is enabled
Tue Oct 23 17:19:15 2018 daemon.notice netifd: Network device 'dsl0' link is up
Tue Oct 23 17:19:15 2018 daemon.notice netifd: VLAN 'dsl0.20' link is up
Tue Oct 23 17:19:15 2018 daemon.notice netifd: Interface 'wan' has link connectivity
Tue Oct 23 17:19:15 2018 daemon.notice netifd: Interface 'wan' is setting up now
Tue Oct 23 17:19:15 2018 daemon.err insmod: module is already loaded - slhc
Tue Oct 23 17:19:15 2018 daemon.err insmod: module is already loaded - ppp_generic
Tue Oct 23 17:19:15 2018 daemon.err insmod: module is already loaded - pppox
Tue Oct 23 17:19:15 2018 daemon.err insmod: module is already loaded - pppoe
Tue Oct 23 17:19:16 2018 daemon.info pppd[8247]: Plugin rp-pppoe.so loaded.
Tue Oct 23 17:19:16 2018 daemon.info pppd[8247]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Tue Oct 23 17:19:16 2018 daemon.notice pppd[8247]: pppd 2.4.7 started by root, uid 0
Santtu Rekilä commented on 24.03.2019 11:26

I recently (week ago) upgraded my TD-W8970 from lede-17.01.4 to openwrt-18.06.2 and I'm also seeing this behavior seemingly randomly and then have to reboot to regain internet connectivity. I've now experienced it 3 times, first one after 3 days, second one after 1.5 days and the third one after only 12 hours of uptime. I'm using DSL without PPP, just ATM & LLC.

Running /etc/init.d/network restart or /etc/init.d/dsl_control restart, does not fix the issue.

Once the internet connectivity is lost, SSH'ing to the box becomes slow and commands in the shell start to fail like this:

 -----------------------------------------------------
 OpenWrt 18.06.2, r7676-cddd7b4c77
 -----------------------------------------------------
root@adsl:~# free
             total       used       free     shared    buffers     cached
Mem:         59128      50724       8404       1172       1816       3816
-/+ buffers/cache:      45092      14036
Swap:            0          0          0
root@adsl:~# ps w
-ash: can't fork: Out of memory
root@adsl:~# free
-ash: can't fork: Out of memory
root@adsl:~# cat /proc/meminfo 
MemTotal:          59128 kB
MemFree:            8256 kB
MemAvailable:          0 kB
Buffers:            1348 kB
Cached:             3332 kB
SwapCached:            0 kB
Active:             4700 kB
Inactive:           1632 kB
Active(anon):       2784 kB
Inactive(anon):       40 kB
Active(file):       1916 kB
Inactive(file):     1592 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:             0 kB
SwapFree:              0 kB
Dirty:                 0 kB
Writeback:             0 kB
AnonPages:          1664 kB
Mapped:             1848 kB
Shmem:              1172 kB
Slab:               8560 kB
SReclaimable:       1400 kB
SUnreclaim:         7160 kB
KernelStack:         560 kB
PageTables:          504 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:       29564 kB
Committed_AS:       5864 kB
VmallocTotal:    1048372 kB
VmallocUsed:           0 kB
VmallocChunk:          0 kB
root@adsl:~# echo 1 > /proc/sys/vm/compact_memory
root@adsl:~# ps -w
-ash: can't fork: Out of memory
root@adsl:~# ps -w
-ash: can't fork: Out of memory
root@adsl:~# 

The severity of this bug should be raised?
This firmware is no good for DSL use.

Santtu Rekilä commented on 31.03.2019 17:52

I've now confirmed this issue is also present in head/openwrt-18.06 and head/master

In addition to losing internet connection, accepting SSH and HTTP connections becomes very slow during this condition. The issue usually takes 1-2 days to begin.

Neither openwrt-18.06 or master exhibited the "Out of memory" behavior that 18.06.2 showed:

 
 -----------------------------------------------------
 OpenWrt SNAPSHOT, r9732-63ed513779
 -----------------------------------------------------
root@adsl:~# cat /proc/buddyinfo 
Node 0, zone   Normal    136     69     32     41     11      6      2      2      3      2      1 
root@adsl:~# free
              total        used        free      shared  buff/cache   available
Mem:          57944       28568       17100        1312       12276       11744
Swap:             0           0           0
root@adsl:~# /etc/init.d/dsl_control status
ATU-C Vendor ID:                          Infineon 113.197
ATU-C System Vendor ID:                   00,00,30,30,30,30,00,00
Chipset:                                  Lantiq-VRX200
Firmware Version:                         5.8.0.11.1.1
API Version:                              4.17.18.6
XTSE Capabilities:                        0x0, 0x0, 0x0, 0x0, 0x0, 0x1, 0x0, 0x0
Annex:                                    A
Line Mode:                                G.992.5 (ADSL2+)
Profile:                                  
Line State:                               UP [0x801: showtime_tc_sync]
Forward Error Correction Seconds (FECS):  Near: 1670 / Far: 0
Errored seconds (ES):                     Near: 35 / Far: 0
Severely Errored Seconds (SES):           Near: 32 / Far: 0
Loss of Signal Seconds (LOSS):            Near: 0 / Far: 6
Unavailable Seconds (UAS):                Near: 50 / Far: 50
Header Error Code Errors (HEC):           Near: 50 / Far: 0
Non Pre-emtive CRC errors (CRC_P):        Near: 0 / Far: 0
Pre-emtive CRC errors (CRCP_P):           Near: 0 / Far: 0
Power Management Mode:                    L0 - Synchronized
Latency [Interleave Delay]:               4.0 ms [Interleave]   2.0 ms [Interleave]
Data Rate:                                Down: 15.096 Mb/s / Up: 909 Kb/s
Line Attenuation (LATN):                  Down: 21.7 dB / Up: 8.8 dB
Signal Attenuation (SATN):                Down: 19.4 dB / Up: 9.0 dB
Noise Margin (SNR):                       Down: 8.3 dB / Up: 8.1 dB
Aggregate Transmit Power (ACTATP):        Down: 19.9 dB / Up: 10.2 dB
Max. Attainable Data Rate (ATTNDR):       Down: 15.188 Mb/s / Up: 908 Kb/s
Line Uptime Seconds:                      94919
Karadut Ağacı commented on 01.05.2019 11:39

Same issue on my w8970. Line led lights constantly but wan (internet) led does nothing, dark.
–From Türkiye ADSL2+ Annex A

Michele "O-Zone" commented on 11.06.2019 20:27

The same for me. All works well but, after some times, PPPOE disconnect (ATM is UP) and only a reboot reconnect the line.

Model TP-LINK TD-W8970
Architecture xRX200 rev 1.2
Firmware Version OpenWrt 18.06.2 r7676-cddd7b4c77 / LuCI openwrt-18.06 branch (git-19.020.41695-6f6641d)
Kernel Version 4.9.152

Santtu Rekilä commented on 11.06.2019 21:01

One thing that was suggested to me but I haven't had time to try yet, was to replace the DSL firmware file with another version: https://xdarklight.github.io/lantiq-xdsl-firmware-info/

Loading...

Available keyboard shortcuts

Tasklist

Task Details

Task Editing