I’ve had this issue occur with some minor variations on both the MT300N-V2 and GL-MiFi, and am hoping the wise forum can help me diagnose and fix what’s causing it. The logs used in this post are from a GL-MiFi.
Essentially, I have both devices on 4G connections, and they work great until at some point they lose internet connectivity. Rebooting the devices then brings the connection back up, but this seems to happen on a regular schedule (nightly?).
The routers are connected to an OpenVPN access server, and set to keepalive. This VPN configuration is working fine, and gives evidence that the 4G connection is down in the logs as it continues to attempt to establish a tunnel after the WAN connection is severed.
I’m also specifying custom DNS (google) via the GL-iNet administration UI. I’ve tried both using the /tmp/resolv.conf.auto file and ignoring it, but this connection drop issue seems to occur regardless. However, I have noticed variations where I can get back to the router through the VPN, and this may be when I elect to ignore the resolv file This would suggest that the router itself is still able to get out to the internet to sustain the tunnel in these instances, but the clients on that router are not being server proper DNS/DHCP? In any event, the account below is not one of those instances where I can get back to the router through the VPN tunnel.
The pattern is generally the same each time…
Wireless carrier issues hour-long leases…
Mon Oct 22 01:06:39 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 01:06:39 2018 daemon.notice netifd: modem_4 (1949): udhcpc: lease of 25.121.209.255 obtained, lease time 7200
...
Mon Oct 22 02:06:39 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 02:06:39 2018 daemon.notice netifd: modem_4 (1949): udhcpc: lease of 25.121.209.255 obtained, lease time 7200
Then at one of these reissues, seemingly for no reason, my router renews its lease on the same IP address, and then promptly loses its internet connection…
Mon Oct 22 03:06:39 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 03:06:39 2018 daemon.notice netifd: modem_4 (1949): udhcpc: lease of 25.121.209.255 obtained, lease time 7200
Mon Oct 22 03:06:47 2018 daemon.info hostapd: wlan0: STA bc:83:85:ee:05:48 WPA: group key handshake completed (RSN)
Mon Oct 22 03:06:47 2018 daemon.info hostapd: wlan0: STA c8:d9:d2:44:d0:17 WPA: group key handshake completed (RSN)
Mon Oct 22 03:06:55 2018 daemon.info gl-health>>: AP Ok=1
Mon Oct 22 03:06:55 2018 daemon.info gl-health>>: network(caIfnames) = DROIDTETHER modem tethering wan wan6
Mon Oct 22 03:06:55 2018 daemon.info gl-health>>: STA Ok=1
Mon Oct 22 03:06:55 2018 daemon.info gl-health>>: Everthing is OK!!!
Mon Oct 22 03:06:55 2018 daemon.info gl-health>>: check wpa runing =
Mon Oct 22 03:07:25 2018 daemon.info gl-health>>: AP Ok=1
Mon Oct 22 03:07:25 2018 daemon.info gl-health>>: network(caIfnames) = DROIDTETHER modem tethering wan wan6
Mon Oct 22 03:07:25 2018 daemon.info gl-health>>: STA Ok=1
Mon Oct 22 03:07:25 2018 daemon.info gl-health>>: Everthing is OK!!!
Mon Oct 22 03:07:25 2018 daemon.info gl-health>>: check wpa runing =
Mon Oct 22 03:07:55 2018 daemon.info gl-health>>: AP Ok=1
Mon Oct 22 03:07:56 2018 daemon.info gl-health>>: network(caIfnames) = DROIDTETHER modem tethering wan wan6
Mon Oct 22 03:07:56 2018 daemon.info gl-health>>: STA Ok=1
Mon Oct 22 03:07:56 2018 daemon.info gl-health>>: Everthing is OK!!!
Mon Oct 22 03:07:56 2018 daemon.info gl-health>>: check wpa runing =
Mon Oct 22 03:08:26 2018 daemon.info gl-health>>: AP Ok=1
Mon Oct 22 03:08:26 2018 daemon.info gl-health>>: network(caIfnames) = DROIDTETHER modem tethering wan wan6
Mon Oct 22 03:08:26 2018 daemon.info gl-health>>: STA Ok=1
Mon Oct 22 03:08:26 2018 daemon.info gl-health>>: Everthing is OK!!!
Mon Oct 22 03:08:26 2018 daemon.info gl-health>>: check wpa runing =
Mon Oct 22 03:08:56 2018 daemon.info gl-health>>: AP Ok=1
Mon Oct 22 03:08:56 2018 daemon.info gl-health>>: network(caIfnames) = DROIDTETHER modem tethering wan wan6
Mon Oct 22 03:08:56 2018 daemon.info gl-health>>: STA Ok=1
Mon Oct 22 03:08:56 2018 daemon.info gl-health>>: Everthing is OK!!!
Mon Oct 22 03:08:56 2018 daemon.info gl-health>>: check wpa runing =
Mon Oct 22 03:09:21 2018 daemon.notice openvpn[3239]: [OpenVPN Server] Inactivity timeout (--ping-restart), restarting
Mon Oct 22 03:09:21 2018 daemon.notice openvpn[3239]: SIGUSR1[soft,ping-restart] received, process restarting
Mon Oct 22 03:09:21 2018 daemon.notice openvpn[3239]: Restart pause, 60 second(s)
Somehow, it will keep renewing its leases every hour, on the hour…
Mon Oct 22 04:06:39 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 04:06:39 2018 daemon.notice netifd: modem_4 (1949): udhcpc: lease of 25.121.209.255 obtained, lease time 7200
…sometimes it doesn’t appear to get a response…
Mon Oct 22 05:06:39 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 05:06:47 2018 daemon.info hostapd: wlan0: STA bc:83:85:ee:05:48 WPA: group key handshake completed (RSN)
Mon Oct 22 05:06:47 2018 daemon.info hostapd: wlan0: STA c8:d9:d2:44:d0:17 WPA: group key handshake completed (RSN)
Mon Oct 22 05:06:58 2018 daemon.info gl-health>>: AP Ok=1
Mon Oct 22 05:06:58 2018 daemon.info gl-health>>: network(caIfnames) = DROIDTETHER modem tethering wan wan6
Mon Oct 22 05:06:58 2018 daemon.info gl-health>>: STA Ok=1
Mon Oct 22 05:06:58 2018 daemon.info gl-health>>: Everthing is OK!!!
…all the while, OpenVPN client dutifully tries to reconnect, but does not…
Mon Oct 22 05:08:13 2018 daemon.warn openvpn[3239]: WARNING: --ns-cert-type is DEPRECATED. Use --remote-cert-tls instead.
Mon Oct 22 05:08:18 2018 daemon.err openvpn[3239]: RESOLVE: Cannot resolve host address: openvpn.hostname.com:443 (Try again)
Mon Oct 22 05:08:23 2018 daemon.err openvpn[3239]: RESOLVE: Cannot resolve host address: openvpn.hostname.com:443 (Try again)
Mon Oct 22 05:08:23 2018 daemon.warn openvpn[3239]: Could not determine IPv4/IPv6 protocol
Mon Oct 22 05:08:23 2018 daemon.notice openvpn[3239]: SIGUSR1[soft,init_instance] received, process restarting
Mon Oct 22 05:08:23 2018 daemon.notice openvpn[3239]: Restart pause, 300 second(s)
…now attempting to re-lease an IP from the carrier just 30 min after unsuccessful attempt…
Mon Oct 22 05:36:39 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…now 15 minutes after that…
Mon Oct 22 05:51:40 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…then 7.5 minutes…
Mon Oct 22 05:59:10 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…3.75 minutes…
Mon Oct 22 06:02:55 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…then half of that…
Mon Oct 22 06:04:47 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…until finally, it gets a new lease on the same IP address…
Mon Oct 22 06:05:43 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 06:05:43 2018 daemon.notice netifd: modem_4 (1949): udhcpc: lease of 25.121.209.255 obtained, lease time 7200
…but still no internet connection, as OpenVPN client is still unable to connect…
Mon Oct 22 06:10:18 2018 daemon.err openvpn[3239]: RESOLVE: Cannot resolve host address: openvpn.hostname.com:443 (Try again)
Mon Oct 22 06:10:23 2018 daemon.err openvpn[3239]: RESOLVE: Cannot resolve host address: openvpn.hostname.com:443 (Try again)
Mon Oct 22 06:10:23 2018 daemon.warn openvpn[3239]: Could not determine IPv4/IPv6 protocol
Mon Oct 22 06:10:23 2018 daemon.notice openvpn[3239]: SIGUSR1[soft,init_instance] received, process restarting
Mon Oct 22 06:10:23 2018 daemon.notice openvpn[3239]: Restart pause, 300 second(s)
…
Mon Oct 22 07:05:43 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 07:05:43 2018 daemon.notice netifd: modem_4 (1949): udhcpc: lease of 25.121.209.255 obtained, lease time 7200
…
Mon Oct 22 08:05:43 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…
Mon Oct 22 08:35:44 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…
Mon Oct 22 08:50:44 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…
Mon Oct 22 08:58:14 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…
Mon Oct 22 09:01:59 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…
Mon Oct 22 09:03:51 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…
Mon Oct 22 09:04:47 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…keeps attempting at half the delay until…
Mon Oct 22 09:05:15 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 09:05:29 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 09:05:36 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 09:05:39 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 09:05:40 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…this happens…
Mon Oct 22 09:05:40 2018 daemon.notice netifd: modem_4 (1949): udhcpc: lease lost, entering init state
Mon Oct 22 09:05:40 2018 daemon.notice netifd: Interface 'modem_4' has lost the connection
…and now it apparently stops attempting to renew its old address and asks for a new one…
Mon Oct 22 09:05:40 2018 daemon.info dnsmasq[3766]: reading /tmp/resolv.conf.auto
Mon Oct 22 09:05:40 2018 daemon.info dnsmasq[3766]: using nameserver 8.8.4.4#53
Mon Oct 22 09:05:40 2018 daemon.info dnsmasq[3766]: using nameserver 8.8.8.8#53
Mon Oct 22 09:05:40 2018 daemon.info dnsmasq[3766]: using local addresses only for domain localdomain.lan
Mon Oct 22 09:05:40 2018 daemon.info dnsmasq[3766]: using nameserver 8.8.8.8#53
Mon Oct 22 09:05:40 2018 daemon.info dnsmasq[3766]: using nameserver 8.8.4.4#53
…request for new IP is apparently granted…
Mon Oct 22 09:05:40 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending discover
Mon Oct 22 09:05:40 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending select for 29.16.113.153
Mon Oct 22 09:05:40 2018 daemon.notice netifd: modem_4 (1949): udhcpc: lease of 29.16.113.153 obtained, lease time 7200
Mon Oct 22 09:05:41 2018 daemon.notice netifd: Interface 'modem_4' is now up
Mon Oct 22 09:05:41 2018 daemon.info dnsmasq[3766]: reading /tmp/resolv.conf.auto
Mon Oct 22 09:05:41 2018 daemon.info dnsmasq[3766]: using nameserver 8.8.4.4#53
Mon Oct 22 09:05:41 2018 daemon.info dnsmasq[3766]: using nameserver 8.8.8.8#53
Mon Oct 22 09:05:41 2018 daemon.info dnsmasq[3766]: using local addresses only for domain localdomain.lan
Mon Oct 22 09:05:41 2018 daemon.info dnsmasq[3766]: using nameserver 8.8.8.8#53
Mon Oct 22 09:05:41 2018 daemon.info dnsmasq[3766]: using nameserver 8.8.4.4#53
…but still, OpenVPN unable to resolve server hostname…
Mon Oct 22 09:06:04 2018 daemon.err openvpn[3239]: RESOLVE: Cannot resolve host address: openvpn.hostname.com:443 (Try again)
Mon Oct 22 09:06:04 2018 daemon.warn openvpn[3239]: Could not determine IPv4/IPv6 protocol
Mon Oct 22 09:06:04 2018 daemon.notice openvpn[3239]: SIGUSR1[soft,init_instance] received, process restarting
Mon Oct 22 09:06:04 2018 daemon.notice openvpn[3239]: Restart pause, 300 second(s)
…then this routine some more…
Mon Oct 22 10:05:40 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
...
Mon Oct 22 10:35:40 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
...
Mon Oct 22 10:50:40 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
...
Mon Oct 22 10:58:10 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
…
Mon Oct 22 11:01:55 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
...
Mon Oct 22 11:03:47 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
...
Mon Oct 22 11:04:43 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
...
Mon Oct 22 11:05:11 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 11:05:25 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 11:05:32 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 11:05:35 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 11:05:36 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending renew
Mon Oct 22 11:05:36 2018 daemon.notice netifd: modem_4 (1949): udhcpc: lease lost, entering init state
Mon Oct 22 11:05:36 2018 daemon.notice netifd: Interface 'modem_4' has lost the connection
…then the PREVIOUS IP GETS RE-ISSUED!
Mon Oct 22 11:05:36 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending discover
Mon Oct 22 11:05:36 2018 daemon.notice netifd: modem_4 (1949): udhcpc: sending select for 25.121.209.255
Mon Oct 22 11:05:36 2018 daemon.notice netifd: modem_4 (1949): udhcpc: lease of 25.121.209.255 obtained, lease time 7200
…and still no connection available for OpenVPN…
Mon Oct 22 11:10:00 2018 daemon.err openvpn[3239]: RESOLVE: Cannot resolve host address: openvpn.hostname.com:443 (Try again)
Mon Oct 22 11:10:05 2018 daemon.err openvpn[3239]: RESOLVE: Cannot resolve host address: openvpn.hostname.com:443 (Try again)
Mon Oct 22 11:10:05 2018 daemon.warn openvpn[3239]: Could not determine IPv4/IPv6 protocol
Mon Oct 22 11:10:05 2018 daemon.notice openvpn[3239]: SIGUSR1[soft,init_instance] received, process restarting
Mon Oct 22 11:10:05 2018 daemon.notice openvpn[3239]: Restart pause, 300 second(s)
A simple etc/init.d/network restart brings everything back up. So what’s going on? My theory is there’s something in my local DHCP config, which issues leases every 12 h, that is conflicting when the carrier DHCP reissue. Is that possible? Or perhaps the various DNS settings I’ve tried are conflicting with the carrier IP lease? See etc/config/dhcp contents below:
config dnsmasq
option localise_queries '1'
option expandhosts '1'
option readethers '1'
option leasefile '/tmp/dhcp.leases'
option rebind_protection '0'
option local '/local.lan/'
option domain local.lan'
option localservice '0'
option nonwildcard '0'
list server '8.8.8.8'
list server '8.8.4.4'
option noresolv '1'
config dhcp 'lan'
option interface 'lan'
option leasetime '12h'
option limit '50'
option start '1'
config dhcp 'wan'
option interface 'wan'
option ignore '1'
config odhcpd 'odhcpd'
option maindhcp '0'
option leasefile '/tmp/hosts/odhcpd'
option leasetrigger '/usr/sbin/odhcpd-update'
config domain 'localhost'
option name 'console.gl-inet.com'
option ip '10.28.0.1'
config dhcp 'lan2'
option leasetime '12h'
option interface 'lan2'
option limit '50'
option start '1'