OpenVPN not passing traffic

I have an AR750 running 2.272 and I’m having trouble getting OpenVPN to pass traffic. I had it working fine before a few days ago but then unplugged the router and now it doesn’t seem to want to work. The problem is that this is after many other unrelated problems and I’m wondering if something got changed along the way.

But what’s really strange is I had it working when I was connected to the hotspot on my phone and that’s not working anymore either. I am able to connect but no traffic passes and the connection eventually times out due to inactivity. I am using stunnel with OpenVPN and that also says its connected.

Also I know my OpenVPN server is working fine because I can actually connect to it thru my laptop running an stunnel and OpenVPN client, thru the AR750 with the OpenVPN client disabled. My other devices work as well.

I tried taking a look at the routes which all look right. I tried taking a look at the firewall but I am very unfamiliar with this particular interface. It… looks OK? But I am unsure if this might be the area of problem. The fact that I can’t get it to work on two different WWAN networks, and the fact that OpenVPN/stunnel is working from the client on my laptop setup with the exact same configuration, makes me wonder if it’s a simple routing/firewall problem on the AR750.

Anyone have any tips on what I can look for to find out why the traffic isn’t passing?

Thanks.

Had you changed any configuration file? Would it caused by stunnel?

I hadn’t touched anything with OpenVPN after I got it working. I had been messing around a lot with trying to get connected to an 802.1X wifi but that was it.

I am thinking now it has to do with stunnel though since I have it working on my laptop I think my basic configuration and server are working fine. However in trying to connect direct to OpenVPN without stunnel the traffic is passing. So I’d say stunnel is the culprit. Interesting I had it working a few days ago–or at least I thought I did. In looking at the logs the main difference I see is an error relating to adding a new route for 127.0.0.1 which appears to come from a process by OpenVPN to add a /32 route specifically for the OpenVPN server. I’m not sure if that’s the connection or not.

Maybe it’s still a firewall issue? Doesn’t know how to handle traffic going to 127.0.0.1? I don’t know, seems like a stretch. In any event connections get made, stunnel reports the connection to 127.0.0.1 from openvpn, connects to the remote server, the openvpn process starts, key exchanges etc, and then gets an IP and connects. It’s just the traffic isn’t passing thru it. Not sure how to troubleshoot that. I was thinking about some kind of packet capture like tcpdump but I don’t know how to get that installed. I tried opkg install tcpdump but nothing available.

So this is interesting! And I think what happened to me the other day. During the same AR750 session (by that I mean without rebooting or powering it off) if I connect directly to OpenVPN first, disconnect, then connect using my profile that uses stunnel (OpenVPN config the same except it connects to the stunnel on 127.0.0.1), then it works! I’ve simulated it a few times now. If I unplug or reboot the AR750 and try connecting to stunnel first, traffic won’t pass. But if I connect to OpenVPN directly, then disconnect and reconnect using stunnel, it works.

I have no idea to begin understanding why that is happening. I am not changing anything other than the order in which I connect. The problem I’m going to have with that process is the other location I’m going to blocks OpenVPN hence the use of stunnel. Not sure if I’m going to be able to connect first on my cell phone hotspot, get connected to stunnel, disconnect from hotspot, reconnect to enterprise wifi and… work? shrug I will try it and report back.

OK, so here’s what’s happening:

Step 1: plug in AR750, connect to enterprise network
Step 2: the UI is a little finicky at this point, so enable/disable network in LUCI until network connectivity established and solid
Step 3: attempt to connect to OpenVPN server directly. This connection fails, as expected, due to enterprise network policy
Step 4: attempt to connect to OpenVPN via stunnel. Connection is successful. Log shows stunnel successful connection to remote server and OpenVPN shows key exchange, server settings (i.e. route push), and remote VPN IP address. However, no traffic is passed thru and Internet on local side does not work. The OpenVPN connection eventually dies due to activity timeout.
Step 5: disconnect from enterprise wifi and connect to mobile phone hotspot via LUCI
Step 6: verify Internet connectivity again after a quick enable/disable process in LUCI
Step 7: attempt to connect to OpenVPN via stunnel. Connection is successful but still no traffic is passed.
Step 8: attempt to connect to OpenVPN server directly via UDP. Connection is successful and traffic passes. Internet connectivity works successfully.
Step 9: disconnect from OpenVPN server directly and reconnect using stunnel. Connection is successful again AND traffic passes. Internet connectivity continues to work. I can verify via the logs that stunnel makes the connection to the remote server on TCP 443 and OpenVPN is connected to 127.0.0.1.
Step 10: disconnect from mobile phone hotspot and reconnect to enterprise wifi via LUCI
At this point the OpenVPN/stunnel connection times out and I get errors in the log such as Permission denied on /dev/net/tun until I can get the wifi connection up and running. It never really seems to connect the first time I have to disable/enable the connection before the WAN is reestablished.
Step 11: OpenVPN connection errored out and stopped trying. I disabled and enabled the connection again. And once again it connects, but no traffic is passed.
Step 12: At this point I disable OpenVPN so traffic (filtered on the enterprise network) is working again. I then connect from the OpenVPN client on my PC (via stunnel also installed on the PC) and connect successfully to the remote server.

That is how I am connected at the moment. OpenVPN (PC) → stunnel (PC) → AR750 → enterprise wifi → stunnel (remote) → OpenVPN (remote)

My previous theory about an issue with the error of adding a route for 127.0.0.1 doesn’t seem to have panned out because sometimes it’s an error and sometimes not and the resulting Internet connectivity doesn’t correspond.

So, while I never rule anything out completely, I am not looking at my stunnel or OpenVPN server too closely since I am connected to them right now using my PC. The client configuration for both stunnel and OpenVPN on both the PC and AR750 are near identical with the exception of changing the IP address/port combination given the appropriate circumstance.

I am very curious about why the OpenVPN via stunnel connection on the AR750 works only after I connect one time to OpenVPN directly. If I unplug/reboot the AR750 and try to connect directly to OpenVPN via stunnel it will connect but traffic will not pass. This is occurring on two other WPA2-PSK wifi networks with no/limited firewall, one in particular is my mobile phone hotspot. Once I connect directly, then the stunnel works fine, doing nothing more than connecting first to OVPN direct.

The one thing I unfortunately can’t try is while connected to the enterprise network, without reconnecting network connections, to connect to OpenVPN directly first, since it’s blocked. I tried that process but since it never connects it’s not the same as on my mobile phone.

I am curious about this event…
Tue Feb 26 16:55:51 2019 user.notice firewall: Reloading firewall due to ifup of wwan (wlan-sta)
That is one of the reasons I was wondering if it was the firewall causing an issue. Everytime I get that event and then try to connect via stunnel, it doesn’t work. Connecting successfully directly to the OVPN server and then connecting via stunnel works, as long as this event didn’t fire off for whatever reason. One of those reasons is disconnecting from my hotspot and reconnecting to enterprise wifi. I don’t know, it’s strange but it seems like a dead end.

Not sure what else to look into…

Here is the log from when I connected to OpenVPN at 17:29:32, manually disconnected at 17:30:00 after no traffic was passing, until 17:30:28 when normal Internet connectivity was re-established.

Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21983]: OpenVPN 2.4.3 mips-openwrt-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD]
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21983]: library versions: OpenSSL 1.0.2k  26 Jan 2017, LZO 2.09
Tue Feb 26 17:29:32 2019 daemon.warn openvpn[21988]: WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: Outgoing Control Channel Authentication: Using 256 bit message hash 'SHA256' for HMAC authentication
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: Incoming Control Channel Authentication: Using 256 bit message hash 'SHA256' for HMAC authentication
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: TCP/UDP: Preserving recently used remote address: [AF_INET]127.0.0.1:3443
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: Socket Buffers: R=[87380->87380] S=[16384->16384]
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: Attempting to establish TCP connection with [AF_INET]127.0.0.1:3443 [nonblock]
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: TCP connection established with [AF_INET]127.0.0.1:3443
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: TCP_CLIENT link local: (not bound)
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: TCP_CLIENT link remote: [AF_INET]127.0.0.1:3443
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
Tue Feb 26 17:29:32 2019 daemon.notice stunnel: LOG5[17]: Service [openvpn-stunnel] accepted connection from 127.0.0.1:40402
Tue Feb 26 17:29:32 2019 daemon.notice stunnel: LOG5[17]: s_connect: connected <REMOTESERVER>:443
Tue Feb 26 17:29:32 2019 daemon.notice stunnel: LOG5[17]: Service [openvpn-stunnel] connected remote server from 10.1.17.89:35910
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: TLS: Initial packet from [AF_INET]127.0.0.1:3443, sid=96b4d31e 0936202e
Tue Feb 26 17:29:32 2019 kern.info kernel: [ 5073.834827] eth1: link down
Tue Feb 26 17:29:32 2019 kern.info kernel: [ 5073.838063] br-lan: port 1(eth1) entered disabled state
Tue Feb 26 17:29:32 2019 daemon.notice netifd: Network device 'eth1' link is down
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: VERIFY OK: depth=1, CN=xxxx root CA
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: VERIFY OK: nsCertType=SERVER
Tue Feb 26 17:29:32 2019 daemon.notice openvpn[21988]: VERIFY OK: depth=0, C=US, O=xxxx, CN=xxxx.com
Tue Feb 26 17:29:33 2019 daemon.notice openvpn[21988]: Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 4096 bit RSA
Tue Feb 26 17:29:33 2019 daemon.notice openvpn[21988]: [xxxx.com] Peer Connection Initiated with [AF_INET]127.0.0.1:3443
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: SENT CONTROL [xxxx.com]: 'PUSH_REQUEST' (status=1)
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: PUSH: Received control message: 'PUSH_REPLY,redirect-gateway def1,route 10.100.101.1,dhcp-option DNS 1.1.1.1,dhcp-option DNS 1.0.0.1,route-gateway 10.100.101.1,topology subnet,ping 10,ping-restart 120,ifconfig 10.100.101.4 255.255.255.0,peer-id 0,cipher AES-256-GCM'
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: OPTIONS IMPORT: timers and/or timeouts modified
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: OPTIONS IMPORT: --ifconfig/up options modified
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: OPTIONS IMPORT: route options modified
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: OPTIONS IMPORT: route-related options modified
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: OPTIONS IMPORT: peer-id set
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: OPTIONS IMPORT: adjusting link_mtu to 1626
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: OPTIONS IMPORT: data channel crypto options modified
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: Data Channel: using negotiated cipher 'AES-256-GCM'
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: Data Channel Encrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: Data Channel Decrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Feb 26 17:29:34 2019 daemon.notice netifd: Interface 'VPN_client' is enabled
Tue Feb 26 17:29:34 2019 daemon.notice netifd: Network device 'tun0' link is up
Tue Feb 26 17:29:34 2019 daemon.notice netifd: Interface 'VPN_client' has link connectivity 
Tue Feb 26 17:29:34 2019 daemon.notice netifd: Interface 'VPN_client' is setting up now
Tue Feb 26 17:29:34 2019 daemon.notice netifd: Interface 'VPN_client' is now up
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: TUN/TAP device tun0 opened
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: TUN/TAP TX queue length set to 100
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: do_ifconfig, tt->did_ifconfig_ipv6_setup=0
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: /sbin/ip link set dev tun0 up mtu 1500
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: /sbin/ip addr add dev tun0 10.100.101.4/24 broadcast 10.100.101.255
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: /sbin/ip route add 127.0.0.1/32 via 10.1.16.1
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: /sbin/ip route add 0.0.0.0/1 via 10.100.101.1
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: /sbin/ip route add 128.0.0.0/1 via 10.100.101.1
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: /sbin/ip route add 10.100.101.1/32 via 10.100.101.1
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: GID set to nogroup
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: UID set to nobody
Tue Feb 26 17:29:34 2019 daemon.warn openvpn[21988]: WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Tue Feb 26 17:29:34 2019 daemon.notice openvpn[21988]: Initialization Sequence Completed
Tue Feb 26 17:29:35 2019 kern.info kernel: [ 5076.335297] eth1: link up (1000Mbps/Full duplex)
Tue Feb 26 17:29:35 2019 kern.info kernel: [ 5076.340124] br-lan: port 1(eth1) entered forwarding state
Tue Feb 26 17:29:35 2019 kern.info kernel: [ 5076.345804] br-lan: port 1(eth1) entered forwarding state
Tue Feb 26 17:29:35 2019 daemon.notice netifd: Network device 'eth1' link is up
Tue Feb 26 17:29:35 2019 daemon.info odhcpd[1590]: Using a RA lifetime of 0 seconds on br-lan
Tue Feb 26 17:29:35 2019 user.notice firewall: Reloading firewall due to ifup of VPN_client (tun0)
Tue Feb 26 17:29:37 2019 kern.info kernel: [ 5078.343418] br-lan: port 1(eth1) entered forwarding state
Tue Feb 26 17:29:38 2019 daemon.info dnsmasq-dhcp[2630]: DHCPREQUEST(br-lan) 192.168.8.232 f4:8e:38:f1:6a:d3 
Tue Feb 26 17:29:38 2019 daemon.info dnsmasq-dhcp[2630]: DHCPACK(br-lan) 192.168.8.232 f4:8e:38:f1:6a:d3 XXXX
Tue Feb 26 17:30:00 2019 daemon.notice netifd: Network device 'tun0' link is down
Tue Feb 26 17:30:00 2019 daemon.notice netifd: Interface 'VPN_client' has link connectivity loss
Tue Feb 26 17:30:00 2019 daemon.notice netifd: Interface 'VPN_client' is now down
Tue Feb 26 17:30:00 2019 daemon.notice netifd: Interface 'VPN_client' is disabled
Tue Feb 26 17:30:01 2019 daemon.info odhcpd[1590]: Using a RA lifetime of 0 seconds on br-lan
Tue Feb 26 17:30:03 2019 kern.info kernel: [ 5104.334408] eth1: link down
Tue Feb 26 17:30:03 2019 kern.info kernel: [ 5104.337659] br-lan: port 1(eth1) entered disabled state
Tue Feb 26 17:30:03 2019 daemon.notice netifd: Network device 'eth1' link is down
Tue Feb 26 17:30:05 2019 kern.info kernel: [ 5106.334687] eth1: link up (1000Mbps/Full duplex)
Tue Feb 26 17:30:05 2019 kern.info kernel: [ 5106.339510] br-lan: port 1(eth1) entered forwarding state
Tue Feb 26 17:30:05 2019 kern.info kernel: [ 5106.345180] br-lan: port 1(eth1) entered forwarding state
Tue Feb 26 17:30:05 2019 daemon.notice netifd: Network device 'eth1' link is up
Tue Feb 26 17:30:05 2019 daemon.err stunnel: LOG3[17]: socket fd: Broken pipe (32)
Tue Feb 26 17:30:05 2019 daemon.notice stunnel: LOG5[17]: Connection closed: 28375 byte(s) sent to TLS, 4686 byte(s) sent to socket
Tue Feb 26 17:30:07 2019 kern.info kernel: [ 5108.342915] br-lan: port 1(eth1) entered forwarding state
Tue Feb 26 17:30:08 2019 daemon.info dnsmasq-dhcp[2630]: DHCPREQUEST(br-lan) 192.168.8.232 f4:8e:38:f1:6a:d3 
Tue Feb 26 17:30:08 2019 daemon.info dnsmasq-dhcp[2630]: DHCPACK(br-lan) 192.168.8.232 f4:8e:38:f1:6a:d3 XXXX
Tue Feb 26 17:30:25 2019 daemon.notice netifd: Network device 'wlan-sta' link is down
Tue Feb 26 17:30:25 2019 daemon.notice netifd: Interface 'wwan' has link connectivity loss
Tue Feb 26 17:30:26 2019 daemon.notice netifd: wwan (29895): udhcpc: received SIGTERM
Tue Feb 26 17:30:26 2019 user.notice mwan3: ifdown interface wwan (unknown)
Tue Feb 26 17:30:26 2019 daemon.info odhcpd[1590]: Using a RA lifetime of 0 seconds on br-lan
Tue Feb 26 17:30:28 2019 kern.info kernel: [ 5129.484389] wlan-sta: authenticate with d0:72:dc:1e:4a:c3
Tue Feb 26 17:30:28 2019 kern.info kernel: [ 5129.503239] wlan-sta: send auth to d0:72:dc:1e:4a:c3 (try 1/3)
Tue Feb 26 17:30:28 2019 kern.info kernel: [ 5129.510736] wlan-sta: authenticated
Tue Feb 26 17:30:28 2019 kern.info kernel: [ 5129.542661] wlan-sta: associate with d0:72:dc:1e:4a:c3 (try 1/3)
Tue Feb 26 17:30:28 2019 kern.info kernel: [ 5129.552815] wlan-sta: RX AssocResp from d0:72:dc:1e:4a:c3 (capab=0x431 status=0 aid=3)
Tue Feb 26 17:30:28 2019 kern.info kernel: [ 5129.561368] wlan-sta: associated
Tue Feb 26 17:30:28 2019 daemon.notice netifd: Network device 'wlan-sta' link is up
Tue Feb 26 17:30:28 2019 daemon.notice netifd: Interface 'wwan' has link connectivity 
Tue Feb 26 17:30:28 2019 daemon.notice netifd: Interface 'wwan' is setting up now

Excuse my ignorance but why do you need a VPN and Stunnel? Doesn’t the VPN handle the encryption?

Fair question, because it does seem odd. While yes, it is encrypted twice (and obviously then creates a performance hit), it is not for that. It is for obscuring the traffic so it doesn’t look like OpenVPN traffic. To a firewall/content blocker it looks like regular old SSL traffic. There’s also a project called obfsproxy that I could have used but it’s a much less maintained project and I’m not sure I saw a package for that on the AR750 although admittedly I hadn’t looked. Also stunnel gives me the ability to obscure/tunnel other traffic other than just OpenVPN as well as encrypt unencrypted traffic (on my end at least, it’s still obviously unencrypted to the end point).

Thanks for asking.

And thank you for taking the time to reply and explain.

So after a lot of trial and error I figured out what the problem is, especially because of the situation where connecting via the stunnel immediately after a reboot would fail, then by connecting directly to the OpenVPN server it would work, and finally by connecting via stunnel again after successfully connecting direct, it would work. I poured through the logs of both before and after and found a difference in the routing table. When connecting the second time, direct to the OVPN server, an additional entry was made to the routing table which was the IP of the VPN server /32 via the gateway of my WAN connection. The first connection didn’t have that route and subsequent connections did. So I went ahead and rebooted the AR750, connected to the VPN, added that route manually, and… didn’t work. Not to give up I left the route, disconnected and reconnected to the VPN and lo and behold, it worked… via the stunnel like I wanted. But that doesn’t mean I’m out of the woods yet. Something happened to the WAN link a few minutes later, such as maybe re-associating with another AP (on the enterprise wifi) or something because the connection was reset, the firewall and routes were re-loaded, and OpenVPN errored out and never re-tried to connect. At this point I had to re-add the manual route and then manually connect to OpenVPN again. That worked.

So that begs a few questions / things I have to look into…

  • I need the OpenVPN via stunnel profile to add the IP address of the VPN server as a route via the gateway of the WAN. For now I manually put the IP in there but on other networks that IP will be different. I’ll have to somehow reference the currently connected WAN gateway. And then I’ll have to add that either in the ovpn profile or call it from a script maybe? Not sure why that’s happening anyway.

  • Something is happening to DNS on the AR750 that it’s not functioning. The clients that reference the IP of the AR750 don’t get DNS responses and sure enough from ssh on the AR750 DNS doesn’t work. I changed the DNS server in /etc/resolv.conf to my gateway on the remote VPN server which is a DNS forwarder and then nslookup from the AR750 started working but the clients still weren’t getting responses from the AR750. So then I manually changed the DNS servers on both clients and everything started working perfect.

  • Stability of the wifi WAN link seems to be in question although, particularly in an enterprise wifi environment where there are multiple WAP’s. Possibly when roaming to a different AP the connection drops hard, kills my manually added route, and OpenVPN never tries to reconnect automatically. I’m wondering what I can setup to mitigate this scenario.

Any help would be very much appreciated. I know now what I’m trying to do is possible and I’m just about there.

Ok, here’s what happened today at the enterprise network. I plugged in the AR750, it connected right up to the enterprise wifi, the OpenVPN client even connected (via stunnel) but of course there was no traffic. I had to ssh in, issue the route add for the VPN IP, disconnect and reconnect to OpenVPN. Then everything worked.

So the biggest question of the few that I have is: is there a way to run the route add automatically when the WWAN interface comes up? I’m looking for an /etc/network/ifup.d/ directory to drop a script but there is no /etc/network on the AR750. Where could I add a script that would run when WWAN is connected? I think specifically I would do it for “wlan-sta” which is the interface that connects to the enterprise network.

I’d like to do it this way, as opposed to having something get added at OS startup, in the event the gateway is different, like when the configuration on the network changes or when I connect to a different network. I figured in the script I could find out what the current gw is, and then add the route. Better yet if there’s an ifdown script I could remove that route too, though I’m less worried about that because a simple reboot of the AR750 would be sufficient.