Short wan dhcp lease issue...

[SnakeByte]

For whatever reason, my ATT router is dishing out the wan ip address with a 600 second lease time (every 10 minutes). Normally this shouldn't be a problem, especially since the ip address doesn't change. However, with these asus routers, they seem to be restarting a shirt ton of stuff each time the ip is renewed. This is breaking existing network connections, among other transient issues. Is there a way to stop this from happening? Like, if the ip address doesn't change, don't do any of that restart stuff?

I've tried setting the wan interface to the ip address statically, and that works for a while, but eventually the att router stops sending and receiving traffic and I have to revert back to dhcp to get things going again.

 

[mstombs]

Short lease times are typical of 'half-bridge' modems, can be as low as 30 or 60 seconds it enables your router to pick up a change in the real wan ip relatively quickly. Your router should 'renew' with 50% of lease remaining, i.e. every 5 minutes. If the lease is allowed to timeout, then yes a soft reboot seems to happen, with a corresponding break in your internet connections.

Do you get anything in the log from 'wanduck' - this is an internet connection monitoring process.

Have you tried both 'normal' and 'aggressive' in setting for wan dhcp query frequency?

I have had my own wan dhcp issues for years, but much less frequent since my isp lease is 7 days, I also run my own wan monitoring ping script, which can reset the wan for me when dhcp gets completely stuck.

 

[sfx2000]

IF this helps - some providers will drop lease times down to 5/10 minutes before implementing network changes to minimize impact - once work is complete, it gets bumped back to 12/24 hours...

 

[RMerlin]

Sometimes, unplugging the modem for an extended period of time (10-30 mins) can help "flush" any cached MAC address their DHCP server might have stored.

 

[SnakeByte]

From what I'm seeing, the problem I'm experiencing is due to how ASUS is dealing with the network interface itself. For instance, if I start ping and have it ping away and then the dhcp update happens, ping will exit because the network interface disappears. This shouldn't normally happen during a dhcp update, so I'm thinking one of the other things that asus does when dhcp does a renewal is what is causing my problem. For instance, it looks like QOS settings are re-done, and maybe some vpn stuff. Perhaps the bridge interface is being re-created? I'm hoping to stop all of this extra after-dhcp stuff from happening when the ip address doesn't actually change.

 

[sfx2000]

Is there a chance that the ATT DSL modem is restarting on it's own?

Line Conditions, bum config, bad ac adapter perhaps?

 

[john9527]

There has to be something else at play here.....my ISP renews every 24 hours, and nothing gets restarted as a result. I also don't recall other complaints of this type. Can you post your system log when you believe the DHCP renew is happening? Maybe it's your modem that's dropping the link when it shouldn't?

PS...I just rebooted yesterday and mine is due to be renewed in another 1 1/2 hours.....I'll see what happens.

 

[SnakeByte]

I know it's not the ISP's modem because if I manually set the ip address on the ASUS Router to what the DHCP lease gave, everything works fine for days. The log is nice and quiet.

Here's what happens when DHCP is enabled on the wan interface:

Jan  6 19:10:06 miniupnpd[14502]: ioctl(s, SIOCGIFADDR, ...): Cannot assign requested address
Jan  6 19:10:06 miniupnpd[14502]: Failed to get IP for interface eth0
Jan  6 19:10:06 miniupnpd[14502]: SendNATPMPPublicAddressChangeNotification: cannot get public IP address, stopping
Jan  6 19:10:06 miniupnpd[14502]: ioctl(s, SIOCGIFADDR, ...): Cannot assign requested address
Jan  6 19:10:06 miniupnpd[14502]: ioctl(s, SIOCGIFADDR, ...): Cannot assign requested address
Jan  6 19:10:06 dnsmasq[14672]: read /etc/hosts - 5 addresses
Jan  6 19:10:06 dnsmasq[14672]: read /etc/hosts.dnsmasq - 2 addresses
Jan  6 19:10:06 dnsmasq-dhcp[14672]: read /etc/ethers - 2 addresses
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 68.94.157.8#53 for domain local
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 68.94.156.8#53 for domain local
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 192.168.1.254#53 for domain local
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 192.168.1.254#53 for domain attlocal.net
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 192.168.1.254#53
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 68.94.156.8#53
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 68.94.157.8#53
Jan  6 19:10:06 kernel: br0: received packet on vlan1 with own address as source address
Jan  6 19:10:06 kernel: br0: received packet on vlan1 with own address as source address
Jan  6 19:10:06 rc_service: udhcpc 15363:notify_rc start_firewall
Jan  6 19:10:06 dnsmasq[14672]: read /etc/hosts - 5 addresses
Jan  6 19:10:06 dnsmasq[14672]: read /etc/hosts.dnsmasq - 2 addresses
Jan  6 19:10:06 dnsmasq-dhcp[14672]: read /etc/ethers - 2 addresses
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 68.94.157.8#53 for domain local
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 68.94.156.8#53 for domain local
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 192.168.1.254#53 for domain local
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 192.168.1.254#53 for domain attlocal.net
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 192.168.1.254#53
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 68.94.156.8#53
Jan  6 19:10:06 dnsmasq[14672]: using nameserver 68.94.157.8#53
Jan  6 19:10:06 kernel: br0: received packet on vlan1 with own address as source address
Jan  6 19:10:06 kernel: br0: received packet on vlan1 with own address as source address
Jan  6 19:10:06 kernel: br0: received packet on vlan1 with own address as source address
Jan  6 19:10:06 kernel: br0: received packet on vlan1 with own address as source address
Jan  6 19:10:06 start_nat_rules: apply the nat_rules(/tmp/nat_rules_eth0_eth0)!
Jan  6 19:10:06 wan: finish adding multi routes
Jan  6 19:10:06 rc_service: udhcpc 15363:notify_rc stop_upnp
Jan  6 19:10:06 rc_service: waitting "start_firewall" via udhcpc ...
Jan  6 19:10:06 custom script: Running /jffs/scripts/firewall-start (args: eth0)
Jan  6 19:10:07 miniupnpd[14502]: shutting down MiniUPnPd
Jan  6 19:10:08 rc_service: udhcpc 15363:notify_rc start_upnp
Jan  6 19:10:08 miniupnpd[15410]: HTTP listening on port 52154
Jan  6 19:10:08 miniupnpd[15410]: Listening for NAT-PMP/PCP traffic on port 5351
Jan  6 19:10:09 rc_service: udhcpc 15363:notify_rc stop_vpnserver1
Jan  6 19:10:09 rc_service: udhcpc 15363:notify_rc start_vpnserver1
Jan  6 19:10:09 rc_service: waitting "stop_vpnserver1" via udhcpc ...
Jan  6 19:10:09 openvpn[14596]: event_wait : Interrupted system call (code=4)
Jan  6 19:10:09 openvpn[14596]: Closing TUN/TAP interface
Jan  6 19:10:09 openvpn[14596]: /usr/sbin/ip addr del dev tun21 10.8.0.1/24
Jan  6 19:10:09 openvpn[14596]: SIGTERM[hard,] received, process exiting
Jan  6 19:10:10 openvpn-routing: Refreshing policy rules for client 1
Jan  6 19:10:10 openvpn-routing: Allow WAN access to all VPN clients
Jan  6 19:10:10 kernel: ADDRCONF(NETDEV_UP): tun21: link is not ready
Jan  6 19:10:10 kernel: device tun21 entered promiscuous mode
Jan  6 19:10:11 openvpn-routing: Refreshing policy rules for client 2
Jan  6 19:10:11 openvpn-routing: Allow WAN access to all VPN clients
Jan  6 19:10:11 rc_service: udhcpc 15363:notify_rc stop_vpnclient1
Jan  6 19:10:11 rc_service: waitting "start_vpnserver1" via udhcpc ...
Jan  6 19:10:11 openvpn[15501]: OpenVPN 2.3.7 arm-unknown-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [MH] [IPv6] built on Jul 16 2015
Jan  6 19:10:11 openvpn[15501]: library versions: OpenSSL 1.0.2d 9 Jul 2015, LZO 2.08
Jan  6 19:10:11 openvpn[15502]: Diffie-Hellman initialized with 2048 bit key
Jan  6 19:10:11 openvpn[15502]: Socket Buffers: R=[122880->122880] S=[122880->122880]
Jan  6 19:10:11 openvpn[15502]: TUN/TAP device tun21 opened
Jan  6 19:10:11 openvpn[15502]: TUN/TAP TX queue length set to 100
Jan  6 19:10:11 openvpn[15502]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Jan  6 19:10:11 openvpn[15502]: /usr/sbin/ip link set dev tun21 up mtu 1500
Jan  6 19:10:11 openvpn[15502]: /usr/sbin/ip addr add dev tun21 10.8.0.1/24 broadcast 10.8.0.255
Jan  6 19:10:11 kernel: ADDRCONF(NETDEV_CHANGE): tun21: link becomes ready
Jan  6 19:10:11 openvpn[15502]: UDPv4 link local (bound): [undef]
Jan  6 19:10:11 openvpn[15502]: UDPv4 link remote: [undef]
Jan  6 19:10:11 openvpn[15502]: MULTI: multi_init called, r=256 v=256
Jan  6 19:10:11 openvpn[15502]: IFCONFIG POOL: base=10.8.0.2 size=252, ipv6=0
Jan  6 19:10:11 openvpn[15502]: Initialization Sequence Completed
Jan  6 19:10:12 rc_service: udhcpc 15363:notify_rc start_vpnclient1
Jan  6 19:10:12 rc_service: waitting "stop_vpnclient1" via udhcpc ...
Jan  6 19:10:12 openvpn-routing: Configuring policy rules for client 1
Jan  6 19:10:12 openvpn-routing: Flushing client routing table
Jan  6 19:10:12 openvpn-routing: Completed routing policy configuration
Jan  6 19:10:12 dnsmasq[14672]: read /etc/hosts - 5 addresses
Jan  6 19:10:12 dnsmasq[14672]: read /etc/hosts.dnsmasq - 2 addresses
Jan  6 19:10:12 dnsmasq-dhcp[14672]: read /etc/ethers - 2 addresses
Jan  6 19:10:12 dnsmasq[14672]: using nameserver 68.94.157.8#53 for domain local
Jan  6 19:10:12 dnsmasq[14672]: using nameserver 68.94.156.8#53 for domain local
Jan  6 19:10:12 dnsmasq[14672]: using nameserver 192.168.1.254#53 for domain local
Jan  6 19:10:12 dnsmasq[14672]: using nameserver 192.168.1.254#53 for domain attlocal.net
Jan  6 19:10:12 dnsmasq[14672]: using nameserver 192.168.1.254#53
Jan  6 19:10:12 dnsmasq[14672]: using nameserver 68.94.156.8#53
Jan  6 19:10:12 dnsmasq[14672]: using nameserver 68.94.157.8#53
Jan  6 19:10:12 dnsmasq[14672]: exiting on receipt of SIGTERM
Jan  6 19:10:12 dnsmasq[15578]: started, version 2.73rc9 cachesize 1500
Jan  6 19:10:12 dnsmasq[15578]: warning: interface ppp1* does not currently exist
Jan  6 19:10:12 dnsmasq[15578]: asynchronous logging enabled, queue limit is 5 messages
Jan  6 19:10:12 dnsmasq-dhcp[15578]: DHCP, IP range 192.168.100.2 -- 192.168.100.254, lease time 1d
Jan  6 19:10:12 dnsmasq[15578]: read /etc/hosts - 5 addresses
Jan  6 19:10:12 dnsmasq[15578]: read /etc/hosts.dnsmasq - 2 addresses
Jan  6 19:10:12 dnsmasq-dhcp[15578]: read /etc/ethers - 2 addresses
Jan  6 19:10:12 dnsmasq[15578]: using nameserver 68.94.157.8#53 for domain local
Jan  6 19:10:12 dnsmasq[15578]: using nameserver 68.94.156.8#53 for domain local
Jan  6 19:10:12 dnsmasq[15578]: using nameserver 192.168.1.254#53 for domain local
Jan  6 19:10:12 dnsmasq[15578]: using nameserver 192.168.1.254#53 for domain attlocal.net
Jan  6 19:10:12 dnsmasq[15578]: using nameserver 192.168.1.254#53
Jan  6 19:10:12 dnsmasq[15578]: using nameserver 68.94.156.8#53
Jan  6 19:10:12 dnsmasq[15578]: using nameserver 68.94.157.8#53
Jan  6 19:10:15 rc_service: udhcpc 15363:notify_rc start_firewall
Jan  6 19:10:15 dhcp client: bound 108.214.102.126 via 108.214.100.1 during 600 seconds.
Jan  6 19:10:15 start_nat_rules: apply the nat_rules(/tmp/nat_rules_eth0_eth0)!
Jan  6 19:10:16 custom script: Running /jffs/scripts/firewall-start (args: eth0)
Jan  6 19:10:21 openvpn-routing: Skipping, client 1 not in routing policy mode
Jan  6 19:10:37 kernel: htb: htb qdisc 17: is non-work-conserving?

 

[john9527]

Is the miniupnpd log the first entry indicating a change? Are you running native IPv6?

Call this a SWAG, but if you are running native IPv6, try turning that off and see if it changes the behavior.

I checked my log at my renew time, and I see that it reacted to the IPv6 renew, but on my fork, it just caused a restart of radvd which is no longer used on the later Merlin builds.

 

[SnakeByte]

Advanced Settings -> IPV6 -> Basic Config shows:
Connection Type: Disabled

I did attempt to get IPV6 working months ago though, but couldn't due to the ATT half-bridge thing not playing nicely with this. Perhaps something didn't clear in the ASUS that should have?

Yes, the miniupnpd is the first to complain. I only figured out it was related to dhcp when I saw the log entry of 600 seconds for the lease in the middle of all that and the fact that this was happening every 10 minutes.

Is there a way I can trigger this myself using a CLI command?

 

[mstombs]

If the lease and issues are every 10 minutes, then it is the renew at half time (and its repeats) that fail

You can trigger a full renew from the command line using

 killall -USR1 udhcpc

It will do pretty much the same as your log I recall.

I am currently experimenting with adding "-B" to the udhcpc command line - lookup the command the firmware uses using "ps", then re-enter it with the addition

/sbin/udhcpc -B -i eth0 -p /var/run/udhcpc0.pid -s /tmp/udhcpc -t2 -T5 -A160 -O33 -O249

I suspect my isp doesn't correctly reply to the unicast renew messages, I hope this will make them all broadcast?

 

[SnakeByte]

Killing udhcpc doesn't trigger anything, but starting the process back up again, causes everything in my log above to happen. Same thing happens if I switch from dhcp to static in the web gui (or vice versa).

 

[mstombs]

The killall with USR1 does not 'kill' udhcpc, it just signals udhcpc to renew the lease. If nothing happens then that might be the problem!