1. This site uses cookies. By continuing to use this site, you are agreeing to our use of cookies. Learn More.

WRT54GL unable to reconnect on a random basis

Discussion in 'Tomato Firmware' started by lanmtl, Feb 14, 2010.

  1. lanmtl

    lanmtl Addicted to LI Member

    Hi!
    I have had this problem affecting me for a few weeks now. It occurs in the middle of the night most of the time so I don't notice it but it does happen.
    For some reason, the WAN connection drops. The router takes a little while to notice and then tries to redial. But this is to no avail, it only reconnect after 10-15 minutes of trying.
    Not sure what is going on here, it might be a tomato bug...

    I tried to reboot the router but the same thing happens.

    Here are the logs when it happened (it keeps looping after that):
    Code:
    Feb 14 02:59:06 ? daemon.info dnsmasq-dhcp[6746]: DHCPACK(br0) 192.168.1.102 00:23:xx:xx:xx:xx iphone-wireless
    Feb 14 02:59:50 ? daemon.warn miniupnpd[6798]: HTTP Connection closed inexpectedly
    Feb 14 03:00:01 ? syslog.info root: -- MARK --
    Feb 14 03:17:21 ? daemon.info dnsmasq-dhcp[6746]: DHCPREQUEST(br0) 192.168.1.102 00:23:6c:33:94:6c 
    Feb 14 03:17:21 ? daemon.info dnsmasq-dhcp[6746]: DHCPACK(br0) 192.168.1.102 00:23:6c:33:94:6c pierre-iphone-wireless
    Feb 14 03:26:21 ? auth.info login[7429]: root login on 'pts/0'
    Feb 14 03:27:24 ? daemon.info dnsmasq-dhcp[6746]: DHCPREQUEST(br0) 192.168.1.101 00:26:bb:05:43:89 
    Feb 14 03:27:24 ? daemon.info dnsmasq-dhcp[6746]: DHCPACK(br0) 192.168.1.101 00:26:bb:05:43:89 pierre-laptop
    Feb 14 03:28:09 ? daemon.warn pppoe[6739]: LCP appears to be disconnected (pending: 5).
    Feb 14 03:28:09 ? daemon.info pppoe[6739]: Sending LCP Termination-Request
    Feb 14 03:28:12 ? daemon.info pppoe[6739]: Sending LCP Termination-Request
    Feb 14 03:28:15 ? daemon.info pppoe[6739]: Connection terminated.
    Feb 14 03:28:15 ? daemon.notice pppoe[6739]: Disconnected.
    Feb 14 03:28:15 ? daemon.notice pppoe[6739]: Connect time 1437.0 minutes.
    Feb 14 03:28:15 ? daemon.notice pppoe[6739]: Sent 244465685 bytes, received 2375854996 bytes.
    Feb 14 03:28:15 ? daemon.info pppoe[6739]: Sending PADT.
    Feb 14 03:28:18 ? user.info redial[6738]: WAN down. Reconnecting...
    Feb 14 03:28:18 ? daemon.info dnsmasq[6746]: exiting on receipt of SIGTERM
    Feb 14 03:28:18 ? daemon.info pppoe[6739]: Exiting
    Feb 14 03:28:20 ? daemon.info dnsmasq[7522]: started, version 2.51 cachesize 150
    Feb 14 03:28:20 ? daemon.info dnsmasq[7522]: compile time options: no-IPv6 GNU-getopt no-RTC no-DBus no-I18N DHCP no-scripts no-TFTP
    Feb 14 03:28:20 ? daemon.info dnsmasq-dhcp[7522]: DHCP, IP range 192.168.1.100 -- 192.168.1.149, lease time 1d
    Feb 14 03:28:20 ? daemon.warn dnsmasq[7522]: no servers found in /etc/resolv.dnsmasq, will retry
    Feb 14 03:28:20 ? daemon.info pppoe[7525]: Starting
    Feb 14 03:28:20 ? daemon.info pppoe[7525]: Sending PADI.
    Feb 14 03:28:20 ? daemon.info dnsmasq[7522]: read /etc/hosts - 0 addresses
    Feb 14 03:28:20 ? user.info redial[7524]: Started. Time: 30
    Feb 14 03:28:20 ? daemon.info dnsmasq[7522]: read /etc/hosts.dnsmasq - 9 addresses
    Feb 14 03:28:30 ? daemon.info pppoe[7525]: Resending...
    Feb 14 03:28:40 ? daemon.info pppoe[7525]: Resending...
    Feb 14 03:28:47 ? daemon.info pppoe[7525]: Resending...
    Feb 14 03:28:50 ? daemon.info pppoe[7525]: Resending...
    Feb 14 03:28:57 ? daemon.info pppoe[7525]: Sending PADI.
    Feb 14 03:29:00 ? user.info redial[7524]: WAN down. Reconnecting...
    Feb 14 03:29:00 ? daemon.info dnsmasq[7522]: exiting on receipt of SIGTERM
    Feb 14 03:29:00 ? daemon.info dnsmasq[7544]: started, version 2.51 cachesize 150
    Feb 14 03:29:00 ? daemon.info dnsmasq[7544]: compile time options: no-IPv6 GNU-getopt no-RTC no-DBus no-I18N DHCP no-scripts no-TFTP
    Feb 14 03:29:00 ? daemon.info dnsmasq-dhcp[7544]: DHCP, IP range 192.168.1.100 -- 192.168.1.149, lease time 1d
    Feb 14 03:29:00 ? daemon.warn dnsmasq[7544]: no servers found in /etc/resolv.dnsmasq, will retry
    Feb 14 03:29:00 ? daemon.info dnsmasq[7544]: read /etc/hosts - 0 addresses
    Feb 14 03:29:00 ? daemon.info dnsmasq[7544]: read /etc/hosts.dnsmasq - 9 addresses
    Feb 14 03:29:08 ? daemon.info pppoe[7550]: Starting
    Feb 14 03:29:08 ? daemon.info pppoe[7550]: Sending PADI.
    Feb 14 03:29:08 ? user.info redial[7549]: Started. Time: 30
    Feb 14 03:29:12 ? daemon.info dnsmasq-dhcp[7544]: DHCPREQUEST(br0) 192.168.1.102 00:23:6c:33:94:6c 
    Feb 14 03:29:12 ? daemon.info dnsmasq-dhcp[7544]: DHCPACK(br0) 192.168.1.102 00:23:6c:33:94:6c pierre-iphone-wireless
    Feb 14 03:29:18 ? daemon.info pppoe[7550]: Resending...
    Feb 14 03:29:28 ? daemon.info pppoe[7550]: Resending...
    Feb 14 03:29:34 ? daemon.info pppoe[7550]: Resending...
    Feb 14 03:29:37 ? daemon.info pppoe[7550]: Resending...
    Feb 14 03:29:41 ? daemon.info pppoe[7550]: Sending PADI.
    Feb 14 03:29:45 ? daemon.info pppoe[7550]: Resending...
    Feb 14 03:29:48 ? user.info redial[7549]: WAN down. Reconnecting...
    
     
  2. Toastman

    Toastman Super Moderator Staff Member Member

    That's interesting, because I am fighting a similar problem, my logs are the same as yours. I have no idea why the modem loses sync, but in my case it never reconnects at all. When I notice or customers complain, I have to manually restart the modem. Which is a really big headache for me. Switching off the modem and restoring power immediately restores sync - which seems to eliminate the DSLAM.

    If it is possible for you to power cycle yours immediately after such a disconnection it might be interesting to see if it will also immediately reconnect.

    The disconnection problem began after moving from 5Mbps/512kbps ADSL to new ADSL2+ connections at 16Mbps/1Mbps. I have established that it is a modem problem, many modems I have tried do not reconnect after the loss of sync, but some do. Unfortunately I have not found a modem so far that both reconnects OK and can actually handle 16Mbps sustained throughput. (Rumor has it that Broadcom chipsets are the best, but I haven't found a modem with a Broadcom chipset yet).

    Switching to ADSL only, always syncs at 8Mbps and that is stable on any modem.

    I have now collected quite a few modems from different manufacturers, and I am that finding many of them have problems with ADSL2+ connections. I had suspected it to be heat related, and modded all these modems with fans, keeping them very cool - but the issue still happens.

    A second issue - is that on occasions when a modem is back up and running, Tomato itself (all versions seem the same) often doesn't try to reconnect. From your description I don't think this applies in your case.

    Still hunting for some clues :confused:


    EDIT: Just noticed that your "Connect time = 1437.0 minutes." This is almost exactly 24 hours, and many ISP's force a reconnect after 24 hours. But if so, something is going wrong.
     
  3. lanmtl

    lanmtl Addicted to LI Member

    My ISP doesn't cycle the connection every 24 hours. I do it myself with a cron job everyday at 3:30am (it triggered a bit after, it's not included in the log) to get a fresh IP. Even if the ISP was forcing 24 hours cycles, the modem shouldn't have trouble reconnecting on first attempt.
    I thought about it being a modem issue but I couldn't investigate and powercycle the modem as it was 3:30am and the modem is physically located in my neighbours flat (we have an ethernet cable running through the wall to get to the modem)
    What is very strange is that it never occurs at predictable moments and I can't think of anything specific to reproduce the situation. For the last few weeks it's been fine, now it's fine again (it took it 20 minutes to eventually reconnect) but the issue seems to come and go randomly.
    I have ADSL1 here, almost no noise on the line and far from the max speeds ADSL1 can deliver.
    I have yet to find this iptables rule to allow me to login the modem over the network even though it is plugged in the WAN port. I saw it somewhere but I can't find it.
     
  4. lanmtl

    lanmtl Addicted to LI Member

  5. neoufo51

    neoufo51 Network Guru Member

    I had this problem until I switched to the Teddy_Bear mod of Tomato.
     
  6. Toastman

    Toastman Super Moderator Staff Member Member

    Maybe we'll find out what is going on eventually, maybe not :biggrin:

    BTW your other post has the correct iptables scripts to access the modem. Sometimes this works perfectly here, sometimes it doesn't and the modem does not reply, though it does so if PC plugged in direct to the modem. It seems to depend on the manufacturer/type number of the modem.
     
  7. lanmtl

    lanmtl Addicted to LI Member

    More weirdness:
    Code:
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    Feb 15 21:55:08 ? daemon.info pppoe[7500]: Sending PADI.
    **** Last message repeated a zillion times
    
    When I PPoE with my Mac directly over ethernet, no problem connecting.
     
  8. Toastman

    Toastman Super Moderator Staff Member Member

    It's trying to reconnect, but your ISP is not responding. Two scenarios:

    !) Is the modem SYNC light ON? If it is, I suspect that the modem is just not passing anything to the ISP. Try just rebooting the modem and not the router, see if it reconnects. If it reconnects, points to the modem, if not, points to Tomato.


    2) Modem SYNC light is OFF - if so, that points to the modem.
     
  9. lanmtl

    lanmtl Addicted to LI Member

    Ok, all points to the routing rule I added in IP tables.
    The PADI sent and not being acknowledged by the modem happened only when I played around with the vlan1/0 eth1/0 routing. So I may have cut the ability from the router to contact the modem. When I removed the rule, no more PPPoE errors to the extent of my last log quote.
    It still doesn't explain the losing sync and not reconnecting on a random basis but it explains the 'Sending PADI' issue.
     
  10. Jeff65

    Jeff65 Addicted to LI Member

    Have you gotten to the bottom of this issue?

    I'm having exactly the same issue except mine is sporadic. Sometimes it reconnects PPPoE after resyncing, sometimes it doesn't. Must power cycle the modem to have it reconnect. Same messages in the log and everything.

    Using Tomato 1.27 on WRT54GL and Speedtouch 536 as modem. This doesn't happen with my old Netgear modem.
     
  11. Jeff65

    Jeff65 Addicted to LI Member

    Take this with a grain of salt as it comes from only three data points, but it appears related to the speed at which the modem resyncs.

    If the DSL modem resyncs at a slower speed than the previous connection, PPPoE comes up without issue.

    If it resyncs at a faster speed than the previous connection, PPPoE fails with the same messages as OP's log.
     

Share This Page