Lantiq-VRX200 - VDSL - random disconnects

I'm using an o2 Box 6431 with Release 19.07.1. Overall performance and stability has dramatically improved since 18.06.x. There is just one thing that keeps me scratching my head. I have random DSL disconnects now and then. Could be after 24h, 30 minutes or any other random time. Any idea on how to further debug this? Here are the logs:

dsl_control status

ATU-C Vendor ID:                          Broadcom 178.18
ATU-C System Vendor ID:                   Broadcom
Chipset:                                  Lantiq-VRX200
Firmware Version:                         5.9.1.4.0.7
API Version:                              4.17.18.6
XTSE Capabilities:                        0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x2
Annex:                                    B
Line Mode:                                G.993.5 (VDSL2 with down- and upstream vectoring)
Profile:                                  17a
Line State:                               UP [0x801: showtime_tc_sync]
Forward Error Correction Seconds (FECS):  Near: 0 / Far: 129
Errored seconds (ES):                     Near: 2 / Far: 57
Severely Errored Seconds (SES):           Near: 1 / Far: 16
Loss of Signal Seconds (LOSS):            Near: 3 / Far: 0
Unavailable Seconds (UAS):                Near: 577 / Far: 577
Header Error Code Errors (HEC):           Near: 0 / 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]:               0.13 ms [Fast]   0.0 ms [Fast]
Data Rate:                                Down: 111.868 Mb/s / Up: 41.770 Mb/s
Line Attenuation (LATN):                  Down: 5.7 dB / Up: 4.3 dB
Signal Attenuation (SATN):                Down: 5.7 dB / Up: 4.2 dB
Noise Margin (SNR):                       Down: 11.1 dB / Up: 9.3 dB
Aggregate Transmit Power (ACTATP):        Down: -3.9 dB / Up: 13.5 dB
Max. Attainable Data Rate (ATTNDR):       Down: 130.301 Mb/s / Up: 41.775 Mb/s
Line Uptime Seconds:                      27177
Line Uptime:                              7h 32m 57s

kernel.log

[113655.544274] leave showtime
[113660.669453] IPv6: ADDRCONF(NETDEV_UP): dsl0: link is not ready
[113660.684368] IPv6: ADDRCONF(NETDEV_UP): dsl0.7: link is not ready
[113760.471532] enter showtime
[113760.473223] IPv6: ADDRCONF(NETDEV_CHANGE): dsl0: link becomes ready
[113760.484579] IPv6: ADDRCONF(NETDEV_CHANGE): dsl0.7: link becomes ready
[113760.498052] enter showtime
[113762.184334] pppoe-wan: renamed from ppp0

system.log

Sat Feb  1 04:58:32 2020 kern.warn kernel: [113655.544274] leave showtime
Sat Feb  1 04:58:32 2020 daemon.notice netifd: Network device 'dsl0' link is down
Sat Feb  1 04:58:33 2020 daemon.notice netifd: VLAN 'dsl0.7' link is down
Sat Feb  1 04:58:33 2020 daemon.notice netifd: Interface 'wan' has link connectivity loss
Sat Feb  1 04:58:33 2020 daemon.info pppd[22326]: Terminating on signal 15
Sat Feb  1 04:58:33 2020 daemon.info pppd[22326]: Connect time 164.3 minutes.
Sat Feb  1 04:58:33 2020 daemon.info pppd[22326]: Sent 55323264 bytes, received 776810218 bytes.
Sat Feb  1 04:58:33 2020 daemon.notice netifd: Network device 'pppoe-wan' link is down
Sat Feb  1 04:58:33 2020 daemon.notice netifd: Network alias 'pppoe-wan' link is down
Sat Feb  1 04:58:33 2020 daemon.notice netifd: Interface 'wan_6' has link connectivity loss
Sat Feb  1 04:58:33 2020 daemon.err odhcp6c[22451]: Failed to send RS (Permission denied)
Sat Feb  1 04:58:33 2020 daemon.err odhcp6c[22451]: Failed to send DHCPV6 message to ff02::1:2 (Permission denied)
Sat Feb  1 04:58:33 2020 daemon.notice netifd: wan_6 (22451): Command failed: Permission denied
Sat Feb  1 04:58:33 2020 daemon.err odhcp6c[22451]: Failed to send DHCPV6 message to ff02::1:2 (Permission denied)
Sat Feb  1 04:58:33 2020 daemon.notice netifd: Interface 'wan_6' is now down
Sat Feb  1 04:58:33 2020 daemon.notice netifd: Interface 'wan_6' is disabled

Sat Feb  1 04:58:38 2020 daemon.notice netifd: Interface 'wan' is now down
Sat Feb  1 04:58:38 2020 daemon.notice netifd: Interface 'wan' is disabled
Sat Feb  1 04:58:38 2020 kern.info kernel: [113660.669453] IPv6: ADDRCONF(NETDEV_UP): dsl0: link is not ready
Sat Feb  1 04:58:38 2020 daemon.notice netifd: Interface 'wan' is enabled
Sat Feb  1 04:58:38 2020 kern.info kernel: [113660.684368] IPv6: ADDRCONF(NETDEV_UP): dsl0.7: link is not ready

Sat Feb  1 04:59:39 2020 daemon.info watchcat[2250]: no internet connectivity for 90 seconds. Reseting when reaching 900
Sat Feb  1 05:00:17 2020 kern.warn kernel: [113760.471532] enter showtime
Sat Feb  1 05:00:17 2020 kern.info kernel: [113760.473223] IPv6: ADDRCONF(NETDEV_CHANGE): dsl0: link becomes ready
Sat Feb  1 05:00:17 2020 daemon.notice netifd: Network device 'dsl0' link is up
Sat Feb  1 05:00:17 2020 kern.info kernel: [113760.484579] IPv6: ADDRCONF(NETDEV_CHANGE): dsl0.7: link becomes ready
Sat Feb  1 05:00:17 2020 daemon.notice netifd: VLAN 'dsl0.7' link is up
Sat Feb  1 05:00:17 2020 daemon.notice netifd: Interface 'wan' has link connectivity
Sat Feb  1 05:00:17 2020 daemon.notice netifd: Interface 'wan' is setting up now
Sat Feb  1 05:00:17 2020 kern.warn kernel: [113760.498052] enter showtime
Sat Feb  1 05:00:18 2020 daemon.err insmod: module is already loaded - slhc
Sat Feb  1 05:00:18 2020 daemon.err insmod: module is already loaded - ppp_generic
Sat Feb  1 05:00:18 2020 daemon.err insmod: module is already loaded - pppox
Sat Feb  1 05:00:18 2020 daemon.err insmod: module is already loaded - pppoe
Sat Feb  1 05:00:19 2020 daemon.info pppd[24525]: Plugin rp-pppoe.so loaded.
Sat Feb  1 05:00:19 2020 daemon.info pppd[24525]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Sat Feb  1 05:00:19 2020 daemon.notice pppd[24525]: pppd 2.4.7 started by root, uid 0
Sat Feb  1 05:00:19 2020 daemon.info pppd[24525]: PPP session is 420
Sat Feb  1 05:00:19 2020 daemon.warn pppd[24525]: Connected to 88:a2:5e:bb:d5:c7 via interface dsl0.7
Sat Feb  1 05:00:19 2020 kern.info kernel: [113762.184334] pppoe-wan: renamed from ppp0
Sat Feb  1 05:00:19 2020 daemon.info pppd[24525]: Renamed interface ppp0 to pppoe-wan
Sat Feb  1 05:00:19 2020 daemon.info pppd[24525]: Using interface pppoe-wan
Sat Feb  1 05:00:19 2020 daemon.notice pppd[24525]: Connect: pppoe-wan <--> dsl0.7
Sat Feb  1 05:00:19 2020 daemon.info pppd[24525]: Remote message: SRU=39336#SRD=96783#
Sat Feb  1 05:00:19 2020 daemon.notice pppd[24525]: PAP authentication succeeded
Sat Feb  1 05:00:19 2020 daemon.notice pppd[24525]: peer from calling number 88:A2:5E:BB:D5:C7 authorized
Sat Feb  1 05:00:21 2020 daemon.notice pppd[24525]: local  IP address 93.237.66.58
Sat Feb  1 05:00:21 2020 daemon.notice pppd[24525]: remote IP address 62.155.245.83
Sat Feb  1 05:00:21 2020 daemon.notice pppd[24525]: primary   DNS address 217.0.43.145
Sat Feb  1 05:00:21 2020 daemon.notice pppd[24525]: secondary DNS address 217.0.43.129
Sat Feb  1 05:00:21 2020 daemon.notice pppd[24525]: local  LL address fe80::e17b:808e:b441:14ce
Sat Feb  1 05:00:21 2020 daemon.notice pppd[24525]: remote LL address fe80::8aa2:5eff:febb:d5c7
Sat Feb  1 05:00:21 2020 daemon.notice netifd: Network device 'pppoe-wan' link is up
Sat Feb  1 05:00:21 2020 daemon.notice netifd: Interface 'wan' is now up

Sat Feb  1 05:00:22 2020 daemon.notice netifd: Network alias 'pppoe-wan' link is up
Sat Feb  1 05:00:22 2020 daemon.notice netifd: Interface 'wan_6' is enabled
Sat Feb  1 05:00:22 2020 daemon.notice netifd: Interface 'wan_6' has link connectivity
Sat Feb  1 05:00:22 2020 daemon.notice netifd: Interface 'wan_6' is setting up now

Sat Feb  1 05:00:28 2020 daemon.notice netifd: Interface 'wan_6' is now up

Unfortunately, that's a common issue with xDSL and OpenWrt.
You can try if a different firmware helps. Apart from that I don't know anything that can help, sadly.

1 Like

Same here, except for a long period I had a rather stable combination of line-card, line-card software revision and modem blob version, and I have seen reports of instabilities/resyncs with FritzBox hard- and software depending on line-card and software revision as well. If AVM fixed/squelches these not only by changes in the blob, but also by changes in the driver their blobs would work only so so for OpenWrt.
My hunch however is that the modems simply do not report all errors that occur up to the users and hence we believe our link is okay, when in reality all hell broke loose. My link uses ITU G998.4 G.INP retransmissions and my current hypothesis is that heavy retransmit activity precedes the resyncs, but with current OpenWrt ltq drivers and dsl_cmd we simply do not see them... (I see massive scary changes my links SNR over sub-carrier plots over the course of the day and quite line noise plots over sub-carriers also indicate massive RF ingress over the course of a day, both indicators of issues that can easily throw a link of balance, but at least with my link seems not correlated strongly with increases in the typical error counters).

Going to try a different firmware and report back in the other thread.

This topic was automatically closed 10 days after the last reply. New replies are no longer allowed.