More interesting syslog errors…
On boot, OVPN connects normally…
Sat Aug 18 15:11:32 2018 daemon.warn openvpn[1502]: WARNING: --ns-cert-type is DEPRECATED. Use --remote-cert-tls instead.
Sat Aug 18 15:11:32 2018 daemon.warn openvpn[1502]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Sat Aug 18 15:11:32 2018 daemon.notice openvpn[1502]: TCP/UDP: Preserving recently used remote address: [AF_INET]35.170.208.208:1194
Sat Aug 18 15:11:32 2018 daemon.notice openvpn[1502]: Socket Buffers: R=[163840->200000] S=[163840->200000]
Sat Aug 18 15:11:32 2018 daemon.notice openvpn[1502]: UDP link local: (not bound)
Sat Aug 18 15:11:32 2018 daemon.notice openvpn[1502]: UDP link remote: [AF_INET] {VPN Server IP removed}
Sat Aug 18 15:11:32 2018 daemon.notice openvpn[1502]: TLS: Initial packet from [AF_INET]{VPN Server IP removed}, sid=**{sid removed}
Sat Aug 18 15:11:32 2018 daemon.notice openvpn[1502]: VERIFY OK: depth=1, CN=OpenVPN CA
Sat Aug 18 15:11:32 2018 daemon.notice openvpn[1502]: VERIFY OK: nsCertType=SERVER
Sat Aug 18 15:11:32 2018 daemon.notice openvpn[1502]: VERIFY OK: depth=0, CN=OpenVPN Server
…until…
Sat Aug 18 15:11:34 2018 daemon.err openvpn[2814]: Halt command was pushed by server (‘disconnected due to new connection by same user’)
Not sure why a second session is being initiated…but the next one seems to complete normally.
Sat Aug 18 15:11:34 2018 daemon.notice openvpn[2814]: SIGTERM received, sending exit notification to peer
Sat Aug 18 15:11:34 2018 daemon.notice openvpn[1502]: Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Sat Aug 18 15:11:34 2018 daemon.notice openvpn[1502]: [OpenVPN Server] Peer Connection Initiated with [AF_INET]{VPN Server IP removed}
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: SENT CONTROL [OpenVPN Server]: ‘PUSH_REQUEST’ (status=1)
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[2814]: /sbin/ip route del {VPN Server IP removed}
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[2814]: /sbin/ip route del 0.0.0.0/1
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: PUSH: Received control message: ‘PUSH_REPLY,explicit-exit-notify,topology subnet,route-delay 5 30,dhcp-pre-release,dhcp-renew,dhcp-release,route-metric 101,ping 15,ping-restart 75,comp-lzo yes,redirect-gateway def1,redirect-gateway bypass-dhcp,redirect-gateway autolocal,route-gateway 10.27.0.145,dhcp-option DNS 172.31.0.2,register-dns,block-ipv6,ifconfig 10.27.0.154 255.255.255.240’
Sat Aug 18 15:11:35 2018 daemon.warn openvpn[1502]: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:4: dhcp-pre-release (2.4.3)
Sat Aug 18 15:11:35 2018 daemon.warn openvpn[1502]: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:5: dhcp-renew (2.4.3)
Sat Aug 18 15:11:35 2018 daemon.warn openvpn[1502]: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:6: dhcp-release (2.4.3)
Sat Aug 18 15:11:35 2018 daemon.warn openvpn[1502]: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:16: register-dns (2.4.3)
Sat Aug 18 15:11:35 2018 daemon.warn openvpn[1502]: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:17: block-ipv6 (2.4.3)
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: OPTIONS IMPORT: timers and/or timeouts modified
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: OPTIONS IMPORT: explicit notify parm(s) modified
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: OPTIONS IMPORT: compression parms modified
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: OPTIONS IMPORT: --ifconfig/up options modified
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: OPTIONS IMPORT: route options modified
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: OPTIONS IMPORT: route-related options modified
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: Data Channel Encrypt: Cipher ‘AES-128-CBC’ initialized with 128 bit key
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: Data Channel Encrypt: Using 160 bit message hash ‘SHA1’ for HMAC authentication
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: Data Channel Decrypt: Cipher ‘AES-128-CBC’ initialized with 128 bit key
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: Data Channel Decrypt: Using 160 bit message hash ‘SHA1’ for HMAC authentication
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: TUN/TAP device tun1 opened
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: TUN/TAP TX queue length set to 100
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: do_ifconfig, tt->did_ifconfig_ipv6_setup=0
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: /sbin/ip link set dev tun1 up mtu 1500
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[2814]: /sbin/ip route del 128.0.0.0/1
And then, seemingly out of nowhere…
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[2814]: Closing TUN/TAP interface
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[2814]: /sbin/ip addr del dev tun0 10.27.0.155/28
Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: /sbin/ip addr add dev tun1 10.27.0.154/28 broadcast 10.27.0.159
> Sat Aug 18 15:11:35 2018 daemon.notice netifd: Network device ‘tun0’ link is down
> Sat Aug 18 15:11:35 2018 daemon.notice netifd: Interface ‘VPN_client’ has link connectivity loss
> Sat Aug 18 15:11:35 2018 daemon.notice netifd: Interface ‘VPN_client’ is now down
> Sat Aug 18 15:11:35 2018 daemon.notice openvpn[2814]: /etc/openvpn/downdns tun0 1500 1558 10.27.0.155 255.255.255.240 init
> Sat Aug 18 15:11:35 2018 daemon.notice openvpn[1502]: /etc/openvpn/updns tun1 1500 1558 10.27.0.154 255.255.255.240 init
> Sat Aug 18 15:11:35 2018 daemon.notice netifd: Interface ‘VPN_client’ is disabled
> Sat Aug 18 15:11:35 2018 daemon.err openvpn[2814]: WARNING: Failed running command (–up/–down): external program exited with error status: 2
> Sat Aug 18 15:11:35 2018 daemon.notice openvpn[2814]: Exiting due to fatal error
> Sat Aug 18 15:11:36 2018 daemon.info dnsmasq[3630]: exiting on receipt of SIGTERM
Sat Aug 18 15:11:36 2018 daemon.info odhcpd[1348]: Using a RA lifetime of 0 seconds on br-lan
Sat Aug 18 15:11:40 2018 daemon.info dnsmasq[4105]: started, version 2.78 cachesize 150
Sat Aug 18 15:11:40 2018 daemon.info dnsmasq[4105]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-auth no-DNSSEC no-ID loop-detect inotify
> Sat Aug 18 15:11:40 2018 daemon.warn dnsmasq[4105]: warning: ignoring resolv-file flag because no-resolv is set
Sat Aug 18 15:11:40 2018 daemon.info dnsmasq-dhcp[4105]: DHCP, IP range 10.29.14.100 – 10.29.14.249, lease time 12h
Here’s where it gets interesting… now that the VPN is disconnected, router is resorting back to manually entered explicit DNS IPs from the UI (Google)
Sat Aug 18 15:11:40 2018 daemon.info dnsmasq[4105]: using nameserver 8.8.4.4#53
Sat Aug 18 15:11:40 2018 daemon.info dnsmasq[4105]: using nameserver 8.8.8.8#53
Sat Aug 18 15:11:40 2018 daemon.info dnsmasq[4105]: using local addresses only for domain RVITclient.lan
Sat Aug 18 15:11:40 2018 daemon.info dnsmasq[4105]: read /etc/hosts - 4 addresses
Sat Aug 18 15:11:40 2018 daemon.info dnsmasq[4105]: read /tmp/hosts/dhcp.cfg02411c - 3 addresses
Sat Aug 18 15:11:40 2018 daemon.info dnsmasq[4105]: read /tmp/hosts/odhcpd - 1 addresses
Sat Aug 18 15:11:40 2018 daemon.info dnsmasq-dhcp[4105]: read /etc/ethers - 0 addresses
Sat Aug 18 15:11:40 2018 daemon.notice openvpn[1502]: /sbin/ip route add {VPN Server IP removed} via 22.80.170.1
Sat Aug 18 15:11:40 2018 daemon.notice openvpn[1502]: /sbin/ip route add 0.0.0.0/1 via 10.27.0.145
Sat Aug 18 15:11:40 2018 daemon.notice openvpn[1502]: /sbin/ip route add 128.0.0.0/1 via 10.27.0.145
Sat Aug 18 15:11:40 2018 daemon.warn openvpn[1502]: WARNING: this configuration may cache passwords in memory – use the auth-nocache option to prevent this
Sat Aug 18 15:11:40 2018 daemon.notice openvpn[1502]: Initialization Sequence Completed
Sat Aug 18 15:12:27 2018 daemon.info dnsmasq[4105]: read /etc/hosts - 4 addresses
Sat Aug 18 15:12:27 2018 daemon.info dnsmasq[4105]: read /tmp/hosts/dhcp.cfg02411c - 3 addresses
Sat Aug 18 15:12:27 2018 daemon.info dnsmasq[4105]: read /tmp/hosts/odhcpd - 1 addresses
Sat Aug 18 15:12:27 2018 daemon.info dnsmasq-dhcp[4105]: read /etc/ethers - 0 addresses
Once this is all said and done, the weirdest part is I can ping IP addresses and domain names from the router, but when I attempt to do either from a client, I get 100% packet loss. I’ll add that I checked the contents of all 3 resolvfiles and they are all holding the correct DNS addresses, but no traffic is getting through from clients, even without DNS.
When I run /etc/init.d/dnsmasq restart, I get:
udhcpc: started, v1.25.1
udhcpc: sending discover
udhcpc: no lease, failing