I have a dual WAN configuration on my AC68P with the latest firmware. WAN(0) is Comcast with an SB6141 modem, and WAN(1) is a USB mobile hotspot. Dual WAN Mode is "fail over," and "allow failback" is also checked. I give 60 seconds to both Failover and Failback Execution Time.
Sometime last year I started getting "WAN(0) Connection: ISP's DHCP did not function properly" messages, but once it failed over to WAN(1) it usually could recover and restore WAN(0). This has changed with recent firmware updates. Now about once a week I get the same error, but when it tries to fail back to WAN(0) it can never recover and keeps failing over to WAN(1) again. There is no error in the cable modem's log and Comcast shows the modem is online. The only way to get out of this loop is to reboot the AC68P.
I wonder if anyone has the same problem. I have searched "ISP's DHCP did not function properly," but there doesn't seem to be a definite answer.
Here is the router log.
Apr 1 16:20:04 nat: apply redirect rules
Apr 1 16:20:10 WAN(0) Connection: ISP's DHCP did not function properly.
Apr 1 16:21:08 rc_service: wanduck 223:notify_rc restart_wan_if 0
Apr 1 16:21:08 wan: [deconfig] udhcpc done[286]
Apr 1 16:21:08 kernel: Attempt to kill tasklet from interrupt
Apr 1 16:21:08 kernel: et0: et_mvlan_netdev_event: event 9 for vlan1 mvlan_en 0
Apr 1 16:21:08 kernel: et0: et_mvlan_netdev_event: event 2 for vlan1 mvlan_en 0
Apr 1 16:21:08 kernel: et0: et_mvlan_netdev_event: event 13 for vlan1 mvlan_en 0
Apr 1 16:21:09 kernel: et0: et_mvlan_netdev_event: event 1 for vlan1 mvlan_en 0
Apr 1 16:21:09 kernel: et0: et_mvlan_netdev_event: event 13 for vlan2 mvlan_en 0
Apr 1 16:21:09 kernel: et0: et_mvlan_netdev_event: event 1 for vlan2 mvlan_en 0
Apr 1 16:21:09 kernel: et0: et_mvlan_netdev_event: event 4 for vlan1 mvlan_en 0
Apr 1 16:21:11 wan: [deconfig] udhcpc done[286]
Apr 1 16:21:12 rc_service: udhcpc 22709:notify_rc start_firewall
Apr 1 16:21:12 miniupnpd[873]: shutting down MiniUPnPd
Apr 1 16:21:12 wan: finish adding multi routes
Apr 1 16:21:12 dhcp client: bound 174.50.xxx.yy via 174.50.yyy.z during 275487 seconds.
Apr 1 16:21:12 nat: apply nat rules (/tmp/nat_rules_usb0_usb0)
Apr 1 16:21:13 miniupnpd[22741]: version 1.9 started
Apr 1 16:21:13 miniupnpd[22741]: HTTP listening on port 42411
Apr 1 16:21:13 miniupnpd[22741]: Listening for NAT-PMP/PCP traffic on port 5351
Apr 1 16:21:13 rc_service: wanduck 223:notify_rc restart_wan_if 1
Apr 1 16:21:17 WAN(1) Connection: ISP's DHCP did not function properly.
Apr 1 16:21:17 wan: [deconfig] udhcpc done[286]
Apr 1 16:21:20 rc_service: udhcpc 22822:notify_rc start_firewall
Apr 1 16:21:20 miniupnpd[22741]: shutting down MiniUPnPd
Apr 1 16:21:21 wan: finish adding multi routes
Apr 1 16:21:21 nat: apply nat rules (/tmp/nat_rules_usb0_usb0)
Apr 1 16:21:21 rc_service: udhcpc 22822:notify_rc stop_upnp
Apr 1 16:21:21 rc_service: waitting "start_firewall" via udhcpc ...
Apr 1 16:21:21 miniupnpd[22861]: version 1.9 started
Apr 1 16:21:21 miniupnpd[22861]: HTTP listening on port 40788
Apr 1 16:21:21 miniupnpd[22861]: Listening for NAT-PMP/PCP traffic on port 5351
Apr 1 16:21:22 rc_service: udhcpc 22822:notify_rc start_upnp
Apr 1 16:21:22 rc_service: waitting "stop_upnp" via udhcpc ...
Apr 1 16:21:22 miniupnpd[22861]: shutting down MiniUPnPd
Apr 1 16:21:23 start_ddns: update WWW.ASUS.COM dyndns, wan_unit 1
Apr 1 16:21:23 ddns update: ez-ipupdate: starting...
Apr 1 16:21:24 ddns update: connected to nwsrv-ns1.asus.com (103.10.4.108) on port 80.
Apr 1 16:21:24 miniupnpd[22885]: version 1.9 started
Apr 1 16:21:24 miniupnpd[22885]: HTTP listening on port 57686
Apr 1 16:21:24 miniupnpd[22885]: Listening for NAT-PMP/PCP traffic on port 5351
Apr 1 16:21:24 WAN(1) Connection: WAN was restored.
Apr 1 16:21:26 ddns update: Asus update entry:: return: HTTP/1.1 299 |Invalid IP format| 192.168.0.103^M Date: Sun, 01 Apr 2018 23:21:24 GMT^M Server: Apache^M X-Powered-By: PHP/5.6.30^M Content-Length: 0^M Content-Type: text/html; charset=UTF-8^M ^M
Apr 1 16:21:26 ddns update: retval= 1, ddns_return_code (,299)
Apr 1 16:21:26 ddns update: asusddns_update: 1
Apr 1 16:21:41 kernel: SHN Release Version: 2.0.1 3529123_patch
Apr 1 16:21:41 kernel: UDB Core Version: 0.2.14 r3529123
Apr 1 16:21:41 kernel: sizeof forward pkt param = 192
Apr 1 16:21:44 rc_service: udhcpc 22822:notify_rc start_firewall
Apr 1 16:21:44 watchdog: start ddns.
Apr 1 16:21:44 rc_service: watchdog 283:notify_rc restart_ddns
Apr 1 16:21:44 rc_service: waitting "start_firewall" via udhcpc ...
Apr 1 16:21:45 miniupnpd[22885]: shutting down MiniUPnPd
Apr 1 16:21:45 dhcp client: bound 192.168.0.103 via 192.168.0.1 during 7200 seconds.
Apr 1 16:21:45 nat: apply nat rules (/tmp/nat_rules_usb0_usb0)
Apr 1 16:21:46 miniupnpd[23123]: version 1.9 started
Apr 1 16:21:46 miniupnpd[23123]: HTTP listening on port 42392
Apr 1 16:21:46 miniupnpd[23123]: Listening for NAT-PMP/PCP traffic on port 5351
Apr 1 16:21:46 start_ddns: update WWW.ASUS.COM dyndns, wan_unit 1
Apr 1 16:21:46 ddns update: ez-ipupdate: starting...
Apr 1 16:21:47 ddns update: connected to nwsrv-ns1.asus.com (103.10.4.108) on port 80.
Apr 1 16:21:49 ddns update: Asus update entry:: return: HTTP/1.1 299 |Invalid IP format| 192.168.0.103^M Date: Sun, 01 Apr 2018 23:21:47 GMT^M Server: Apache^M X-Powered-By: PHP/5.6.30^M Content-Length: 0^M Content-Type: text/html; charset=UTF-8^M ^M
Apr 1 16:21:49 ddns update: retval= 1, ddns_return_code (,299)
Apr 1 16:21:49 ddns update: asusddns_update: 1
Apr 1 16:22:18 nat: apply redirect rules
Apr 1 16:22:24 rc_service: wanduck 223:notify_rc stop_wan_if 1
Apr 1 16:22:25 wan: [deconfig] udhcpc done[286]
Apr 1 16:22:28 rc_service: wanduck 223:notify_rc restart_wan_line 0
Apr 1 16:22:28 miniupnpd[23123]: shutting down MiniUPnPd
Apr 1 16:22:29 nat: apply nat rules (/tmp/nat_rules_eth0_eth0)
Apr 1 16:22:29 wan: finish adding multi routes
Apr 1 16:22:29 rc_service: wanduck 223:notify_rc restart_wan_if 0
Apr 1 16:22:29 rc_service: waitting "restart_wan_line 0" via wanduck ...
Apr 1 16:22:29 miniupnpd[23382]: version 1.9 started
Apr 1 16:22:29 miniupnpd[23382]: HTTP listening on port 41325
Apr 1 16:22:29 miniupnpd[23382]: Listening for NAT-PMP/PCP traffic on port 5351
Apr 1 16:22:29 wan: finish adding multi routes
Apr 1 16:22:30 wan: [deconfig] udhcpc done[286]
Apr 1 16:22:30 kernel: Attempt to kill tasklet from interrupt
Apr 1 16:22:30 kernel: et0: et_mvlan_netdev_event: event 9 for vlan1 mvlan_en 0
Apr 1 16:22:30 kernel: et0: et_mvlan_netdev_event: event 2 for vlan1 mvlan_en 0
Apr 1 16:22:30 kernel: et0: et_mvlan_netdev_event: event 9 for vlan2 mvlan_en 0
Apr 1 16:22:31 kernel: et0: et_mvlan_netdev_event: event 2 for vlan2 mvlan_en 0
Apr 1 16:22:31 kernel: et0: et_mvlan_netdev_event: event 13 for vlan1 mvlan_en 0
Apr 1 16:22:31 kernel: et0: et_mvlan_netdev_event: event 1 for vlan1 mvlan_en 0
Apr 1 16:22:31 kernel: et0: et_mvlan_netdev_event: event 13 for vlan2 mvlan_en 0
Apr 1 16:22:31 kernel: et0: et_mvlan_netdev_event: event 1 for vlan2 mvlan_en 0
Apr 1 16:22:33 wan: [deconfig] udhcpc done[286]
Apr 1 16:22:34 rc_service: udhcpc 23403:notify_rc start_firewall
Apr 1 16:22:34 rc_service: wanduck 223:notify_rc restart_wan_if 1
Apr 1 16:22:34 rc_service: waitting "start_firewall" via udhcpc ...
Apr 1 16:22:34 miniupnpd[23382]: shutting down MiniUPnPd
Apr 1 16:22:34 wan: finish adding multi routes
Apr 1 16:22:34 dhcp client: bound 174.50.xxx.yy via 174.50.yyy.z during 275406 seconds.
Apr 1 16:22:34 nat: apply nat rules (/tmp/nat_rules_usb0_usb0)
Apr 1 16:22:35 miniupnpd[23435]: version 1.9 started
Apr 1 16:22:35 miniupnpd[23435]: HTTP listening on port 40192
Apr 1 16:22:35 miniupnpd[23435]: Listening for NAT-PMP/PCP traffic on port 5351
Apr 1 16:22:39 WAN(1) Connection: ISP's DHCP did not function properly.
Apr 1 16:22:39 wan: [deconfig] udhcpc done[286]
Sometime last year I started getting "WAN(0) Connection: ISP's DHCP did not function properly" messages, but once it failed over to WAN(1) it usually could recover and restore WAN(0). This has changed with recent firmware updates. Now about once a week I get the same error, but when it tries to fail back to WAN(0) it can never recover and keeps failing over to WAN(1) again. There is no error in the cable modem's log and Comcast shows the modem is online. The only way to get out of this loop is to reboot the AC68P.
I wonder if anyone has the same problem. I have searched "ISP's DHCP did not function properly," but there doesn't seem to be a definite answer.
Here is the router log.
Apr 1 16:20:04 nat: apply redirect rules
Apr 1 16:20:10 WAN(0) Connection: ISP's DHCP did not function properly.
Apr 1 16:21:08 rc_service: wanduck 223:notify_rc restart_wan_if 0
Apr 1 16:21:08 wan: [deconfig] udhcpc done[286]
Apr 1 16:21:08 kernel: Attempt to kill tasklet from interrupt
Apr 1 16:21:08 kernel: et0: et_mvlan_netdev_event: event 9 for vlan1 mvlan_en 0
Apr 1 16:21:08 kernel: et0: et_mvlan_netdev_event: event 2 for vlan1 mvlan_en 0
Apr 1 16:21:08 kernel: et0: et_mvlan_netdev_event: event 13 for vlan1 mvlan_en 0
Apr 1 16:21:09 kernel: et0: et_mvlan_netdev_event: event 1 for vlan1 mvlan_en 0
Apr 1 16:21:09 kernel: et0: et_mvlan_netdev_event: event 13 for vlan2 mvlan_en 0
Apr 1 16:21:09 kernel: et0: et_mvlan_netdev_event: event 1 for vlan2 mvlan_en 0
Apr 1 16:21:09 kernel: et0: et_mvlan_netdev_event: event 4 for vlan1 mvlan_en 0
Apr 1 16:21:11 wan: [deconfig] udhcpc done[286]
Apr 1 16:21:12 rc_service: udhcpc 22709:notify_rc start_firewall
Apr 1 16:21:12 miniupnpd[873]: shutting down MiniUPnPd
Apr 1 16:21:12 wan: finish adding multi routes
Apr 1 16:21:12 dhcp client: bound 174.50.xxx.yy via 174.50.yyy.z during 275487 seconds.
Apr 1 16:21:12 nat: apply nat rules (/tmp/nat_rules_usb0_usb0)
Apr 1 16:21:13 miniupnpd[22741]: version 1.9 started
Apr 1 16:21:13 miniupnpd[22741]: HTTP listening on port 42411
Apr 1 16:21:13 miniupnpd[22741]: Listening for NAT-PMP/PCP traffic on port 5351
Apr 1 16:21:13 rc_service: wanduck 223:notify_rc restart_wan_if 1
Apr 1 16:21:17 WAN(1) Connection: ISP's DHCP did not function properly.
Apr 1 16:21:17 wan: [deconfig] udhcpc done[286]
Apr 1 16:21:20 rc_service: udhcpc 22822:notify_rc start_firewall
Apr 1 16:21:20 miniupnpd[22741]: shutting down MiniUPnPd
Apr 1 16:21:21 wan: finish adding multi routes
Apr 1 16:21:21 nat: apply nat rules (/tmp/nat_rules_usb0_usb0)
Apr 1 16:21:21 rc_service: udhcpc 22822:notify_rc stop_upnp
Apr 1 16:21:21 rc_service: waitting "start_firewall" via udhcpc ...
Apr 1 16:21:21 miniupnpd[22861]: version 1.9 started
Apr 1 16:21:21 miniupnpd[22861]: HTTP listening on port 40788
Apr 1 16:21:21 miniupnpd[22861]: Listening for NAT-PMP/PCP traffic on port 5351
Apr 1 16:21:22 rc_service: udhcpc 22822:notify_rc start_upnp
Apr 1 16:21:22 rc_service: waitting "stop_upnp" via udhcpc ...
Apr 1 16:21:22 miniupnpd[22861]: shutting down MiniUPnPd
Apr 1 16:21:23 start_ddns: update WWW.ASUS.COM dyndns, wan_unit 1
Apr 1 16:21:23 ddns update: ez-ipupdate: starting...
Apr 1 16:21:24 ddns update: connected to nwsrv-ns1.asus.com (103.10.4.108) on port 80.
Apr 1 16:21:24 miniupnpd[22885]: version 1.9 started
Apr 1 16:21:24 miniupnpd[22885]: HTTP listening on port 57686
Apr 1 16:21:24 miniupnpd[22885]: Listening for NAT-PMP/PCP traffic on port 5351
Apr 1 16:21:24 WAN(1) Connection: WAN was restored.
Apr 1 16:21:26 ddns update: Asus update entry:: return: HTTP/1.1 299 |Invalid IP format| 192.168.0.103^M Date: Sun, 01 Apr 2018 23:21:24 GMT^M Server: Apache^M X-Powered-By: PHP/5.6.30^M Content-Length: 0^M Content-Type: text/html; charset=UTF-8^M ^M
Apr 1 16:21:26 ddns update: retval= 1, ddns_return_code (,299)
Apr 1 16:21:26 ddns update: asusddns_update: 1
Apr 1 16:21:41 kernel: SHN Release Version: 2.0.1 3529123_patch
Apr 1 16:21:41 kernel: UDB Core Version: 0.2.14 r3529123
Apr 1 16:21:41 kernel: sizeof forward pkt param = 192
Apr 1 16:21:44 rc_service: udhcpc 22822:notify_rc start_firewall
Apr 1 16:21:44 watchdog: start ddns.
Apr 1 16:21:44 rc_service: watchdog 283:notify_rc restart_ddns
Apr 1 16:21:44 rc_service: waitting "start_firewall" via udhcpc ...
Apr 1 16:21:45 miniupnpd[22885]: shutting down MiniUPnPd
Apr 1 16:21:45 dhcp client: bound 192.168.0.103 via 192.168.0.1 during 7200 seconds.
Apr 1 16:21:45 nat: apply nat rules (/tmp/nat_rules_usb0_usb0)
Apr 1 16:21:46 miniupnpd[23123]: version 1.9 started
Apr 1 16:21:46 miniupnpd[23123]: HTTP listening on port 42392
Apr 1 16:21:46 miniupnpd[23123]: Listening for NAT-PMP/PCP traffic on port 5351
Apr 1 16:21:46 start_ddns: update WWW.ASUS.COM dyndns, wan_unit 1
Apr 1 16:21:46 ddns update: ez-ipupdate: starting...
Apr 1 16:21:47 ddns update: connected to nwsrv-ns1.asus.com (103.10.4.108) on port 80.
Apr 1 16:21:49 ddns update: Asus update entry:: return: HTTP/1.1 299 |Invalid IP format| 192.168.0.103^M Date: Sun, 01 Apr 2018 23:21:47 GMT^M Server: Apache^M X-Powered-By: PHP/5.6.30^M Content-Length: 0^M Content-Type: text/html; charset=UTF-8^M ^M
Apr 1 16:21:49 ddns update: retval= 1, ddns_return_code (,299)
Apr 1 16:21:49 ddns update: asusddns_update: 1
Apr 1 16:22:18 nat: apply redirect rules
Apr 1 16:22:24 rc_service: wanduck 223:notify_rc stop_wan_if 1
Apr 1 16:22:25 wan: [deconfig] udhcpc done[286]
Apr 1 16:22:28 rc_service: wanduck 223:notify_rc restart_wan_line 0
Apr 1 16:22:28 miniupnpd[23123]: shutting down MiniUPnPd
Apr 1 16:22:29 nat: apply nat rules (/tmp/nat_rules_eth0_eth0)
Apr 1 16:22:29 wan: finish adding multi routes
Apr 1 16:22:29 rc_service: wanduck 223:notify_rc restart_wan_if 0
Apr 1 16:22:29 rc_service: waitting "restart_wan_line 0" via wanduck ...
Apr 1 16:22:29 miniupnpd[23382]: version 1.9 started
Apr 1 16:22:29 miniupnpd[23382]: HTTP listening on port 41325
Apr 1 16:22:29 miniupnpd[23382]: Listening for NAT-PMP/PCP traffic on port 5351
Apr 1 16:22:29 wan: finish adding multi routes
Apr 1 16:22:30 wan: [deconfig] udhcpc done[286]
Apr 1 16:22:30 kernel: Attempt to kill tasklet from interrupt
Apr 1 16:22:30 kernel: et0: et_mvlan_netdev_event: event 9 for vlan1 mvlan_en 0
Apr 1 16:22:30 kernel: et0: et_mvlan_netdev_event: event 2 for vlan1 mvlan_en 0
Apr 1 16:22:30 kernel: et0: et_mvlan_netdev_event: event 9 for vlan2 mvlan_en 0
Apr 1 16:22:31 kernel: et0: et_mvlan_netdev_event: event 2 for vlan2 mvlan_en 0
Apr 1 16:22:31 kernel: et0: et_mvlan_netdev_event: event 13 for vlan1 mvlan_en 0
Apr 1 16:22:31 kernel: et0: et_mvlan_netdev_event: event 1 for vlan1 mvlan_en 0
Apr 1 16:22:31 kernel: et0: et_mvlan_netdev_event: event 13 for vlan2 mvlan_en 0
Apr 1 16:22:31 kernel: et0: et_mvlan_netdev_event: event 1 for vlan2 mvlan_en 0
Apr 1 16:22:33 wan: [deconfig] udhcpc done[286]
Apr 1 16:22:34 rc_service: udhcpc 23403:notify_rc start_firewall
Apr 1 16:22:34 rc_service: wanduck 223:notify_rc restart_wan_if 1
Apr 1 16:22:34 rc_service: waitting "start_firewall" via udhcpc ...
Apr 1 16:22:34 miniupnpd[23382]: shutting down MiniUPnPd
Apr 1 16:22:34 wan: finish adding multi routes
Apr 1 16:22:34 dhcp client: bound 174.50.xxx.yy via 174.50.yyy.z during 275406 seconds.
Apr 1 16:22:34 nat: apply nat rules (/tmp/nat_rules_usb0_usb0)
Apr 1 16:22:35 miniupnpd[23435]: version 1.9 started
Apr 1 16:22:35 miniupnpd[23435]: HTTP listening on port 40192
Apr 1 16:22:35 miniupnpd[23435]: Listening for NAT-PMP/PCP traffic on port 5351
Apr 1 16:22:39 WAN(1) Connection: ISP's DHCP did not function properly.
Apr 1 16:22:39 wan: [deconfig] udhcpc done[286]
