Page 1 of 1

After first line drop - ADSL line will never sync

Posted: Fri Sep 20, 2013 12:45 am
by brazillians
Hi, I am having problems at the moment with my 7800N - where the ADSL line will not sync.

I used to be on BE internet, but switched over to Sky a week ago. I have the new sky box (SR101, fetched the username / password with wireshark) - and read up that I needed the new firmware (to 1.06h) to connect with MER authentication. However - my connection with sky is still using PPPoA so after I plugged in my details that worked fine.

However - the next morning I noticed the internet was dead. I checked the router status and the line was down. Even after re-plugging the phoneline, restarting, power cycling the router it would not come back. The only thing that would work is restarting the router from the web-interface (from selecting the button at the bottom of the screen), and selecting 'Restart Device with: Factory Default Settings'. After restarting the ADSL line would sync, and then I could enter my username /password again (via quick start) and gain access.

The other problem is any change I make which requires the line to re-sync also causes this problem to occur - so I cannot change the ADSL mode settings (e.g. turn on Phyr or adjust the SNR), it causes the router to go into this dead state where the line will never sync.

I have not tried rolling back to an older firmware version - I think I was previously on 1.06e - but I have tried 1.06h dt2 and I have the same problem. When I did the firmware upgrade the first time, I selected 'restart device with factory default settings' on [configuration] -- [system] -- [firmware upgrade] - but I did not do another 'restart with factory settings' after upgrading. I tried upgrading the firmware again to 1.06h then 1.06h dt2, each time after updating the firmware I would do an additional 'restart with factory default settings' but it would not fix the problem. I have noticed that the SNR does not seem to reset back to -1 when I visit 'http://192.168.1.254/snr.cgi' - it has always been set at 30.

Am I missing something when upgrading the firmware? Or is my router potentially broken? Any ideas, things to try?

Thanks

Here are the system logs:

Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_NOTIFY
Jan 01 00:00:26 user kernel: Open file: /etc/Wireless/RT2880/iNIC_ap.bin
Jan 01 00:00:26 user kernel: Open file: /var/iNIC_ap.dat
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_INITCFG(0)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_INITCFG(1)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_INITCFG(2)
Jan 01 00:00:27 user kernel: Send Init Cfg Data Done(3 packets)
Jan 01 00:00:27 user kernel: RACFG_CMD_BOOT_UPLOAD(0)
Jan 01 00:00:27 user kernel: RACFG_CMD_BOOT_UPLOAD(1)
Jan 01 00:00:27 user kernel: RACFG_CMD_BOOT_UPLOAD(2)
Jan 01 00:00:27 user kernel:
Jan 01 00:00:27 user kernel: CRC:01 08 14 18 f3 ba d7 75 22 32 2e 35 2e 30 2e 31 22 00 00 00 32 30 31 32 30 33 30 38 00 00 00 00 00 00 00 00 f0 45 06 00
Jan 01 00:00:27 user kernel: Send RT2880iNIC Firmware Done
Jan 01 00:00:27 user kernel: ===================================
Jan 01 00:00:27 user kernel: version: "2.5.0.1"
Jan 01 00:00:27 user kernel: size: 411120 bytes
Jan 01 00:00:27 user kernel: date: 20120308
Jan 01 00:00:27 user kernel: ===================================
Jan 01 00:00:27 user kernel:
Jan 01 00:00:27 user kernel: Send STARTUP to RT2880iNIC
Jan 01 00:00:27 user kernel: Close Firmware file
Jan 01 00:00:27 user kernel: RACFG_CMD_BOOT_STARTUP
Jan 01 00:00:28 user kernel: Line 0: ADSL G.992 channel analysis
Jan 01 00:00:29 user kernel: Update MAC(0)=00:04:ed:e0:37:93
Jan 01 00:00:29 user syslog: ifconfig ra0 up 2>/dev/null
Jan 01 00:00:29 user syslog: brctl addif br0 ra0 2>/dev/null
Jan 01 00:00:29 user kernel: device ra0 entered promiscuous mode
Jan 01 00:00:29 user kernel: br0: port 3(ra0) entering learning state
Jan 01 00:00:29 user kernel: br0: topology change detected, propagating
Jan 01 00:00:29 user kernel: br0: port 3(ra0) entering forwarding state
Jan 01 00:00:30 user syslog: ethctl eth0 vport query 2>/var/vcfgerr
Jan 01 00:00:30 user syslog: rm /var/vcfgerr
Jan 01 00:00:30 user syslog: ethctl eth1 vport query 2>/var/vcfgerr
Jan 01 00:00:30 user syslog: rm /var/vcfgerr
Jan 01 00:00:30 user syslog: rmmod vnet 2>/dev/null
Jan 01 00:00:30 user kernel: br0: port 3(ra0) entering disabled state
Jan 01 00:00:30 user kernel: br0: port 2(eth1) entering disabled state
Jan 01 00:00:30 user kernel: br0: port 3(ra0) entering learning state
Jan 01 00:00:30 user kernel: br0: port 2(eth1) entering learning state
Jan 01 00:00:30 user kernel: br0: topology change detected, propagating
Jan 01 00:00:30 user kernel: br0: port 3(ra0) entering forwarding state
Jan 01 00:00:30 user kernel: br0: topology change detected, propagating
Jan 01 00:00:30 user kernel: br0: port 2(eth1) entering forwarding state
Jan 01 00:00:30 user kernel: br0: port 1(eth0) entering learning state
Jan 01 00:00:30 user kernel: br0: topology change detected, propagating
Jan 01 00:00:30 user kernel: br0: port 1(eth0) entering forwarding state
Jan 01 00:00:31 daemon DHCP SERVER: DHCPDISCOVER from b8:27:eb:6a:ee:d7 via br0
Jan 01 00:00:31 user syslog: bind service port
Jan 01 00:00:31 daemon FDNSLOGIN: init
Jan 01 00:00:31 daemon FDNSLOGIN: begin service loop for FakedDnsProxy
Jan 01 00:00:31 daemon dnsmasq[91]: using nameserver 8.8.4.4#53
Jan 01 00:00:31 daemon dnsmasq[91]: using nameserver 8.8.8.8#53
Jan 01 00:00:32 daemon DHCP SERVER: DHCP offer to b8:27:eb:6a:ee:d7
Jan 01 00:00:32 daemon DHCP SERVER: DHCP request from b8:27:eb:6a:ee:d7
Jan 01 00:00:32 daemon DHCP SERVER: DHCP ack to b8:27:eb:6a:ee:d7
Jan 01 00:00:32 daemon UPNPD[528]: HTTP listening on port 2800
Jan 01 00:00:32 daemon DHCP SERVER: DHCPDISCOVER from 00:19:fb:ea:cb:85 via br0
Jan 01 00:00:32 daemon dnsmasq[91]: using nameserver 8.8.4.4#53
Jan 01 00:00:32 daemon dnsmasq[91]: using nameserver 8.8.8.8#53
Jan 01 00:00:33 daemon pppd[543]: PPPoATM setdevname_pppoatm
Jan 01 00:00:33 daemon pppd[543]: PPPoATM setdevname_pppoatm - SUCCESS
Jan 01 00:00:33 user kernel: br0: port 1(eth0) entering disabled state
Jan 01 00:00:33 daemon DHCP SERVER: DHCP offer to 00:19:fb:ea:cb:85
Jan 01 00:00:33 daemon DHCP SERVER: DHCP request from 00:19:fb:ea:cb:85
Jan 01 00:00:33 daemon DHCP SERVER: DHCP ack to 00:19:fb:ea:cb:85
Jan 01 00:00:33 daemon pppd[543]: pppd 2.4.1 started by admin, uid 0
Jan 01 00:00:35 user kernel: Line 0: ADSL G.992 message exchange
Jan 01 00:00:36 user kernel: Line 0: ADSL link down
Jan 01 00:00:37 user kernel: Line 0: xDSL G.994 training
Jan 01 00:00:45 daemon DHCP SERVER: DHCP request from 40:b0:fa:6c:c4:2d
Jan 01 00:00:45 daemon DHCP SERVER: DHCP ack to 40:b0:fa:6c:c4:2d
Jan 01 00:00:47 user kernel: Line 0: ADSL G.992 started
Jan 01 00:00:48 daemon DHCP SERVER: DHCP request from 30:85:a9:4d:a6:51
Jan 01 00:00:48 daemon DHCP SERVER: DHCP ack to 30:85:a9:4d:a6:51
Jan 01 00:00:51 user kernel: Line 0: ADSL G.992 channel analysis
Jan 01 00:00:55 user syslog: web: ::ffff:192.168.1.102 login
Jan 01 00:00:58 user kernel: Line 0: ADSL G.992 message exchange
Jan 01 00:00:58 user kernel: Line 0: ADSL link up, Path 0, us=755, ds=3573
Jan 01 00:01:00 daemon pppd[543]: PPPoE: Terminating on signal 15.
Jan 01 00:01:00 daemon pppd[543]: Exit.
Jan 01 00:01:02 daemon pppd[938]: PPPoATM setdevname_pppoatm
Jan 01 00:01:02 daemon pppd[938]: PPPoATM setdevname_pppoatm - SUCCESS
Jan 01 00:01:02 daemon pppd[938]: pppd 2.4.1 started by admin, uid 0
Jan 01 00:01:02 daemon pppd[938]: PPP: Start to connect ...
Jan 01 00:01:02 daemon pppd[938]: Using interface ppp0_0_38_1
Jan 01 00:01:02 daemon pppd[938]: Connect: ppp_0_0_38_1 <-->
Jan 01 00:01:02 daemon pppd[938]: Couldn't increase MTU to 1500.
Jan 01 00:01:06 user kernel: KLOB extended to 4 pools
Jan 01 00:01:08 daemon pppd[938]: PPP LCP UP.
Jan 01 00:01:08 daemon pppd[938]: Remote message: CHAP authentication success
Jan 01 00:01:08 daemon pppd[938]: local IP address 90.212.152.71
Jan 01 00:01:08 daemon pppd[938]: remote IP address 2.127.238.102
Jan 01 00:01:08 daemon pppd[938]: primary DNS address 90.207.238.97
Jan 01 00:01:08 daemon pppd[938]: secondary DNS address 90.207.238.99
Jan 01 00:01:09 daemon dnsmasq[91]: using nameserver 90.207.238.99#53
Jan 01 00:01:09 daemon dnsmasq[91]: using nameserver 90.207.238.97#53
Jan 01 00:01:09 daemon pppd[938]: Received valid IP address from server. Connection UP.
Jan 01 00:01:09 user syslog: begin: interface: ppp_0_0_38_1 go to up
Jan 01 00:01:09 daemon dnsmasq[91]: using nameserver 90.207.238.99#53
Jan 01 00:01:09 daemon dnsmasq[91]: using nameserver 90.207.238.97#53
Jan 01 00:01:09 daemon UPNPD[528]: received signal 15, good-bye
Jan 01 00:01:11 daemon UPNPD[1093]: HTTP listening on port 2800
Jan 01 00:01:12 user syslog: kill -9 471
Jan 01 00:01:12 user syslog: kill -9 469
Jan 01 00:01:13 user syslog: end: interface: ppp_0_0_38_1 go to up
Sep 19 23:25:32 user syslog: wps_btn&
Sep 19 23:25:32 user syslog: WSCScan&
Sep 19 23:25:33 user kernel: Net device ra0 going down....
Sep 19 23:25:33 user kernel: rlk_inic_mbss_close --->
Sep 19 23:25:33 user kernel: setup MBSS[0] success
Sep 19 23:25:33 user kernel: all interfaces closed.
Sep 19 23:25:33 user kernel: rlk_inic_mbss_close <---
Sep 19 23:25:33 user kernel: iNIC Closing
Sep 19 23:25:33 user kernel: Delete HeartBeatTimer ....
Sep 19 23:25:33 user kernel: iNIC Closed
Sep 19 23:25:33 user kernel: br0: port 3(ra0) entering disabled state
Sep 19 23:25:33 user kernel: iNIC Open ra0
Sep 19 23:25:33 user kernel: ADDR0 = 10000008, ADDR1 = 10100008
Sep 19 23:25:33 user kernel: CMD = 0016, STATUS = 04a0
Sep 19 23:25:33 user kernel: LATENCY = 20, CACHE LINE SIZE = 08
Sep 19 23:25:33 user kernel: INT LINE = 39
Sep 19 23:25:33 user kernel: Reset PCI Card
Sep 19 23:25:33 user kernel: ADDR0 = 10000008, ADDR1 = 10100008
Sep 19 23:25:33 user kernel: CMD = 0016, STATUS = 04a0
Sep 19 23:25:33 user kernel: INT LINE = 39
Sep 19 23:25:33 user kernel: ### LATENCY = 20, CACHE LINE SIZE = 08
Sep 19 23:25:33 user kernel: PDMA_RST_IDX = 0
Sep 19 23:25:33 user kernel: PDMA_GLO_CFG = 00000020
Sep 19 23:25:33 user kernel: TX_MAX_CNT0 = 00000080
Sep 19 23:25:33 user kernel: 2. reg = 00000020
Sep 19 23:25:33 user kernel: 2. PDMA_GLO_CFG = 00000065, reg = 00000065
Sep 19 23:25:33 user kernel: Op mode = 1
Sep 19 23:25:33 user kernel: BssidNum=1
Sep 19 23:25:33 user kernel: Wait for boot done...
Sep 19 23:25:33 user kernel: RACFG_CMD_BOOT_NOTIFY
Sep 19 23:25:33 user kernel: Open file: /etc/Wireless/RT2880/iNIC_ap.bin
Sep 19 23:25:33 user kernel: Open file: /var/iNIC_ap.dat
Sep 19 23:25:33 user kernel: RACFG_CMD_BOOT_INITCFG(0)
Sep 19 23:25:33 user kernel: RACFG_CMD_BOOT_INITCFG(1)
Sep 19 23:25:33 user kernel: RACFG_CMD_BOOT_INITCFG(2)
Sep 19 23:25:33 user kernel: Send Init Cfg Data Done(3 packets)
Sep 19 23:25:33 user kernel: RACFG_CMD_BOOT_UPLOAD(0)
Sep 19 23:25:33 user kernel: RACFG_CMD_BOOT_UPLOAD(1)
Sep 19 23:25:34 user kernel: RACFG_CMD_BOOT_UPLOAD(2)
Sep 19 23:25:34 user kernel:
Sep 19 23:25:34 user kernel: CRC:01 08 14 18 f3 ba d7 75 22 32 2e 35 2e 30 2e 31 22 00 00 00 32 30 31 32 30 33 30 38 00 00 00 00 00 00 00 00 f0 45 06 00
Sep 19 23:25:34 user kernel: Send RT2880iNIC Firmware Done
Sep 19 23:25:34 user kernel: ===================================
Sep 19 23:25:34 user kernel: version: "2.5.0.1"
Sep 19 23:25:34 user kernel: size: 411120 bytes
Sep 19 23:25:34 user kernel: date: 20120308
Sep 19 23:25:34 user kernel: ===================================
Sep 19 23:25:34 user kernel:
Sep 19 23:25:34 user kernel: Send STARTUP to RT2880iNIC
Sep 19 23:25:34 user kernel: Close Firmware file
Sep 19 23:25:34 user kernel: RACFG_CMD_BOOT_STARTUP
Sep 19 23:25:36 user kernel: Update MAC(0)=00:04:ed:e0:37:93
Sep 19 23:25:36 user kernel: br0: port 3(ra0) entering learning state
Sep 19 23:25:36 user kernel: br0: topology change detected, propagating
Sep 19 23:25:36 user kernel: br0: port 3(ra0) entering forwarding state
Sep 19 23:25:41 daemon DHCP SERVER: DHCP request from 30:85:a9:4d:a6:51
Sep 19 23:25:41 daemon DHCP SERVER: DHCP ack to 30:85:a9:4d:a6:51
Sep 19 23:25:43 daemon DHCP SERVER: DHCP request from 40:b0:fa:6c:c4:2d
Sep 19 23:25:43 daemon DHCP SERVER: DHCP ack to 40:b0:fa:6c:c4:2d
Sep 19 23:28:52 user syslog: ethctl eth0 vport query 2>/var/vcfgerr
Sep 19 23:28:52 user syslog: rm /var/vcfgerr
Sep 19 23:28:52 user syslog: ethctl eth1 vport query 2>/var/vcfgerr
Sep 19 23:28:52 user syslog: rm /var/vcfgerr
Sep 19 23:28:58 daemon DHCP SERVER: DHCP request from 5c:59:48:19:9d:62
Sep 19 23:28:58 daemon DHCP SERVER: DHCP ack to 5c:59:48:19:9d:62
Sep 19 23:35:37 user kernel: Line 0: ADSL link down
Sep 19 23:35:37 user syslog: tc qdisc del dev ppp_0_0_38_1 root 2>/dev/null
Sep 19 23:35:38 daemon pppd[938]: Terminating connection due to link down.
Sep 19 23:35:48 user kernel: Line 0: xDSL G.994 training
Sep 19 23:35:50 user kernel: Line 0: ADSL link down
Sep 19 23:35:56 user kernel: Line 0: xDSL G.994 training
Sep 19 23:36:06 user kernel: Line 0: ADSL G.992 started
Sep 19 23:36:10 user kernel: Line 0: ADSL G.992 channel analysis
Sep 19 23:36:17 user kernel: Line 0: ADSL link down
Sep 19 23:36:18 user kernel: Line 0: xDSL G.994 training
Sep 19 23:36:29 user kernel: Line 0: ADSL G.992 started
Sep 19 23:36:33 user kernel: Line 0: ADSL G.992 channel analysis
Sep 19 23:36:39 user kernel: Line 0: ADSL link down
Sep 19 23:36:41 user kernel: Line 0: xDSL G.994 training
Sep 19 23:36:51 user kernel: Line 0: ADSL G.992 started
Sep 19 23:36:55 user kernel: Line 0: ADSL G.992 channel analysis
Sep 19 23:37:02 user kernel: Line 0: ADSL link down
Sep 19 23:37:03 user kernel: Line 0: xDSL G.994 training
Sep 19 23:37:10 user kernel: Line 0: ADSL G.992 started
Sep 19 23:37:13 user kernel: Line 0: ADSL G.992 channel analysis
Sep 19 23:37:17 user kernel: Line 0: ADSL link down
Sep 19 23:37:18 user kernel: Line 0: xDSL G.994 training
Sep 19 23:37:25 user kernel: Line 0: ADSL G.992 started
Sep 19 23:37:28 user kernel: Line 0: ADSL G.992 channel analysis
Sep 19 23:37:32 user kernel: Line 0: ADSL link down
Sep 19 23:37:35 user kernel: Line 0: xDSL G.994 training
Sep 19 23:37:42 user kernel: Line 0: ADSL G.992 started
Sep 19 23:37:44 user kernel: Line 0: ADSL G.992 channel analysis
Sep 19 23:37:49 user kernel: Line 0: ADSL link down
Sep 19 23:37:50 user kernel: Line 0: xDSL G.994 training
Sep 19 23:38:00 user kernel: Line 0: ADSL G.992 started
Sep 19 23:38:04 user kernel: Line 0: ADSL G.992 channel analysis
Sep 19 23:38:10 user kernel: Line 0: ADSL link down
Sep 19 23:38:12 user kernel: Line 0: xDSL G.994 training
Sep 19 23:38:22 user kernel: Line 0: ADSL G.992 started
Sep 19 23:38:27 user kernel: Line 0: ADSL G.992 channel analysis
Sep 19 23:38:33 user kernel: Line 0: ADSL link down
Sep 19 23:38:34 user kernel: Line 0: xDSL G.994 training
Sep 19 23:38:45 user kernel: Line 0: ADSL G.992 started
Sep 19 23:38:49 user kernel: Line 0: ADSL G.992 channel analysis

Re: After first line drop - ADSL line will never sync

Posted: Tue Sep 24, 2013 10:21 am
by billion_fan
This is a strange one, I have seen some unit that cannot resync, but once they are resetted back to factory default settings, and setup from scratch they seems to work without any further issues

When tweaking the SNR, please use the following page http://192.168.1.254/snr/html, not http://192.168.1.254/snr/cgi. (the html link should show your -1 as the SNR)

Try resetting again, setup the device again manually without using a backup config, use the SNR link I posted (html) and make sure the SNR is -1, then make a change to the ADSL mode section and see if the issue occurs again.