Help with OpenVPN connection suddenly stopped working

viragomann · Mar 21, 2022, 3:23 PM

@prez_mgmt
Simply check the firewall log for packets on UDP 1194 after enabling logging in the rule.

However, as there is nothing in capture the packets from the client might not arrive on pfSense WAN and you have to find out why.

Does your pfSense have a public WAN or are you behind a router or in a CGN from your ISP?
Consider that the ISP could have changed this without letting you know.

Can you try to access from another public source like a mobile phone?

Prez_Mgmt · Mar 21, 2022, 4:09 PM

@viragomann thanks,
no hit from the port 1194 at all on the firewall logs. ISP is working fine, I have other resources on the pfsense box (2 websites and a bunch of RDP rules) that are working just fine.
pFsense box is exposed to WAN for the resources that use them in those case.

I think something broke in OpenVPN from last week. That's what I'm not sure what is because of the fact that it was working fine until then.

Any other ideas?
thanks again.

viragomann · Mar 21, 2022, 4:21 PM

@prez_mgmt
If your WAN is exposed to the internet and there are no OpenVPN packets arriving, you have to look for the issue outside of your network.

Can you reach the remote websites from the concerned client to rule out routing issues?

Could also be that the ISP is blocking the OpenVPN packets on one site.

Prez_Mgmt · Mar 21, 2022, 6:04 PM

@viragomann
Yes, the client can hit the pfsense network and can RDP to servers on there all made possible by the rules that are currently functional.
Reached out to ISP and they said line has been pretty static and not aware of any changes.
I had deleted all OpenVPN server settings and profile and made a new one using the wizard and that made no difference either yesterday.

EDIT:
When i Telnet, here's whats in the packet capture

13:48:08.722253 IP xx.xx.xx.9.51648 > xx.xx.xx.13.1194: tcp 0
13:48:09.723473 IP xx.xx.xx.9.51648 > xx.xx.xx.13.1194: tcp 0
13:48:11.733529 IP xx.xx.xx.9.51648 > xx.xx.xx.13.1194: tcp 0
13:48:15.739127 IP xx.xx.xx.9.51648 > xx.xx.xx.13.1194: tcp 0
13:48:20.840136 IP xx.xx.xx.167.47141 > xx.xx.xx.12.1194: UDP, length 18
13:48:23.749023 IP xx.xx.xx.9.51648 > xx.xx.xx.13.1194: tcp 0

but when i try the OpenVPN, nothing shows up

Prez_Mgmt · Mar 21, 2022, 7:17 PM

@viragomann
recreated the OpenVPN server profile again with the wizard and captured packets when I used the client installed on my android tablet.
It still times out with a different error this time.

Error from Android Client
Server
14:58:18.452 -- ----- OpenVPN Start -----
14:58:18.456 -- EVENT: CORE_THREAD_ACTIVE
14:58:18.471 -- OpenVPN core 3.git::662eae9a:Release android i386 32-bit PT_PROXY
14:58:18.473 -- Frame=512/2048/512 mssfix-ctrl=1250
14:58:18.475 -- UNUSED OPTIONS0 [persist-tun] 1 [persist-key] 2 [data-ciphers] [AES-256-GCM:AES-256-CBC] 3 [data-ciphers-fallback] [AES-256-CBC] 5 [tls-client] 8 [nobind] 9 [verify-x509-name] [Test_Cert1] [name] 12 [explicit-exit-notify]
14:58:18.483 -- EVENT: RESOLVE
14:58:18.500 -- Contacting xx.xx.173.22:1194 via UDP
14:58:18.503 -- EVENT: WAIT
14:58:18.513 -- Connecting to [xx.xx.173.22]:1194 (xx.xx.173.22) via UDPv4
14:58:28.480 -- Server poll timeout, trying next remote entry...
14:58:28.482 -- EVENT: RECONNECTING
14:58:28.511 -- EVENT: RESOLVE
14:58:28.531 -- Contacting xx.xx.173.22:1194 via UDP
14:58:28.533 -- EVENT: WAIT
14:58:28.541 -- Connecting to [xx.xx.173.22]:1194 (xx.xx.173.22) via UDPv4
14:58:38.483 -- Server poll timeout, trying next remote entry...
14:58:38.485 -- EVENT: RECONNECTING
14:58:38.506 -- EVENT: RESOLVE
14:58:38.512 -- Contacting xx.xx.173.22:1194 via UDP
14:58:38.515 -- EVENT: WAIT
14:58:38.531 -- Connecting to [xx.xx.173.22]:1194 (xx.xx.173.22) via UDPv4
14:58:48.486 -- Server poll timeout, trying next remote entry...
14:58:48.488 -- EVENT: RECONNECTING
14:58:48.515 -- EVENT: RESOLVE
14:58:48.542 -- Contacting xx.xx.173.22:1194 via UDP
14:58:48.545 -- EVENT: WAIT
14:58:48.555 -- Connecting to [xx.xx.173.22]:1194 (xx.xx.173.22) via UDPv4
14:58:58.489 -- Server poll timeout, trying next remote entry...
14:58:58.491 -- EVENT: RECONNECTING
14:58:58.520 -- EVENT: RESOLVE
14:58:58.539 -- Contacting xx.xx.173.22:1194 via UDP
14:58:58.543 -- EVENT: WAIT
14:58:58.563 -- Connecting to [xx.xx.173.22]:1194 (xx.xx.173.22) via UDPv4
14:59:08.493 -- Server poll timeout, trying next remote entry...
14:59:08.496 -- EVENT: RECONNECTING
14:59:08.521 -- EVENT: RESOLVE
14:59:08.558 -- Contacting xx.xx.173.22:1194 via UDP
14:59:08.560 -- EVENT: WAIT
14:59:08.581 -- Connecting to [xx.xx.173.22]:1194 (xx.xx.173.22) via UDPv4
14:59:18.481 -- EVENT: CONNECTION_TIMEOUT
14:59:18.505 -- EVENT: DISCONNECTED
14:59:18.506 -- Tunnel bytes per CPU second: 0
14:59:18.507 -- ----- OpenVPN Stop -----

Here's what I got from capture.
15:00:46.170620 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:47.149743 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:48.158568 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:49.204296 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:50.160043 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:51.159098 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:52.161317 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:53.160426 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:54.159824 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:55.152769 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:56.168151 IP xx.xx.126.2.45267 > xx.xx.173.22.1194: UDP, length 54
15:00:57.163370 IP xx.xx.126.2.45267 > xx.xx.173.22.1194: UDP, length 54
15:00:58.159141 IP xx.xx.126.2.45267 > xx.xx.173.22.1194: UDP, length 54
15:00:59.162368 IP xx.xx.126.2.45267 > xx.xx.173.22.1194: UDP, length 54
15:01:00.160371 IP xx.xx.126.2.45267 > xx.xx.173.22.1194: UDP, length 54
15:01:01.164876 IP xx.xx.126.2.45267 > xx.xx.173.22.1194: UDP, length 54
15:01:02.162614 IP xx.xx.126.2.45267 > xx.xx.173.22.1194: UDP, length 54
15:01:03.161270 IP xx.xx.126.2.45267 > xx.xx.173.22.1194: UDP, length 54
15:01:04.164278 IP xx.xx.126.2.45267 > xx.xx.173.22.1194: UDP, length 54
15:01:05.163686 IP xx.xx.126.2.45267 > xx.xx.173.22.1194: UDP, length 54
15:01:06.162714 IP xx.xx.126.2.45267 > xx.xx.173.22.1194: UDP, length 54
15:01:06.167794 IP xx.xx.126.2.44386 > xx.xx.173.22.1194: UDP, length 54
15:01:07.165597 IP xx.xx.126.2.44386 > xx.xx.173.22.1194: UDP, length 54
15:01:08.171957 IP xx.xx.126.2.44386 > xx.xx.173.22.1194: UDP, length 54
15:01:09.167605 IP xx.xx.126.2.44386 > xx.xx.173.22.1194: UDP, length 54
15:01:10.156457 IP xx.xx.126.2.44386 > xx.xx.173.22.1194: UDP, length 54
15:01:11.166766 IP xx.xx.126.2.44386 > xx.xx.173.22.1194: UDP, length 54
15:01:12.165905 IP xx.xx.126.2.44386 > xx.xx.173.22.1194: UDP, length 54
15:01:13.164581 IP xx.xx.126.2.44386 > xx.xx.173.22.1194: UDP, length 54
15:01:14.156318 IP xx.xx.126.2.44386 > xx.xx.173.22.1194: UDP, length 54
15:01:15.155731 IP xx.xx.126.2.44386 > xx.xx.173.22.1194: UDP, length 54
15:01:16.184092 IP xx.xx.126.2.55370 > xx.xx.173.22.1194: UDP, length 54
15:01:17.168983 IP xx.xx.126.2.55370 > xx.xx.173.22.1194: UDP, length 54
15:01:18.160979 IP xx.xx.126.2.55370 > xx.xx.173.22.1194: UDP, length 54
15:01:19.160368 IP xx.xx.126.2.55370 > xx.xx.173.22.1194: UDP, length 54
15:01:20.168043 IP xx.xx.126.2.55370 > xx.xx.173.22.1194: UDP, length 54
15:01:21.160047 IP xx.xx.126.2.55370 > xx.xx.173.22.1194: UDP, length 54
15:01:22.159106 IP xx.xx.126.2.55370 > xx.xx.173.22.1194: UDP, length 54
15:01:23.168094 IP xx.xx.126.2.55370 > xx.xx.173.22.1194: UDP, length 54
15:01:24.167895 IP xx.xx.126.2.55370 > xx.xx.173.22.1194: UDP, length 54
15:01:25.168081 IP xx.xx.126.2.55370 > xx.xx.173.22.1194: UDP, length 54
15:01:26.162359 IP xx.xx.126.2.55370 > xx.xx.173.22.1194: UDP, length 54
15:01:26.168263 IP xx.xx.126.2.35904 > xx.xx.173.22.1194: UDP, length 54
15:01:27.176060 IP xx.xx.126.2.35904 > xx.xx.173.22.1194: UDP, length 54
15:01:28.175253 IP xx.xx.126.2.35904 > xx.xx.173.22.1194: UDP, length 54
15:01:29.184120 IP xx.xx.126.2.35904 > xx.xx.173.22.1194: UDP, length 54
15:01:30.194009 IP xx.xx.126.2.35904 > xx.xx.173.22.1194: UDP, length 54
15:01:31.269986 IP xx.xx.126.2.35904 > xx.xx.173.22.1194: UDP, length 54
15:01:32.198976 IP xx.xx.126.2.35904 > xx.xx.173.22.1194: UDP, length 54
15:01:33.255560 IP xx.xx.126.2.35904 > xx.xx.173.22.1194: UDP, length 54
15:01:34.172270 IP xx.xx.126.2.35904 > xx.xx.173.22.1194: UDP, length 54
15:01:35.171567 IP xx.xx.126.2.35904 > xx.xx.173.22.1194: UDP, length 54
15:01:36.188088 IP xx.xx.126.2.35344 > xx.xx.173.22.1194: UDP, length 54
15:01:37.168073 IP xx.xx.126.2.35344 > xx.xx.173.22.1194: UDP, length 54
15:01:38.167160 IP xx.xx.126.2.35344 > xx.xx.173.22.1194: UDP, length 54
15:01:39.175835 IP xx.xx.126.2.35344 > xx.xx.173.22.1194: UDP, length 54
15:01:40.180018 IP xx.xx.126.2.35344 > xx.xx.173.22.1194: UDP, length 54
15:01:41.180207 IP xx.xx.126.2.35344 > xx.xx.173.22.1194: UDP, length 54
15:01:42.184402 IP xx.xx.126.2.35344 > xx.xx.173.22.1194: UDP, length 54
15:01:43.180102 IP xx.xx.126.2.35344 > xx.xx.173.22.1194: UDP, length 54
15:01:44.177093 IP xx.xx.126.2.35344 > xx.xx.173.22.1194: UDP, length 54
15:01:45.180071 IP xx.xx.126.2.35344 > xx.xx.173.22.1194: UDP, length 54

Prez_Mgmt · Mar 21, 2022, 7:35 PM

@viragomann
packet capture when using the windows client is the same as the android client but error message is still the TLS issue initially reported.

I am so out of ideas right now!

viragomann · Mar 21, 2022, 7:39 PM

@prez_mgmt said in Help with OpenVPN connection suddenly stopped working:

EDIT:
When i Telnet, here's whats in the packet capture
13:48:08.722253 IP xx.xx.xx.9.51648 > xx.xx.xx.13.1194: tcp 0

The point is that telnet uses TCP, but not UDP.

Here's what I got from capture.
15:00:46.170620 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:47.149743 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:48.158568 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54
15:00:49.204296 IP xx.xx.126.2.53622 > xx.xx.173.22.1194: UDP, length 54

So now you're seeing the packets in the capture?
So you also should see hits in the firewall log if logging is on. And if packets are passed there should also be something in the OpenVPN log.

Prez_Mgmt · Mar 21, 2022, 9:12 PM

@viragomann
yes, firewall lets it through and i see it once i preserve log for the rule.
OpenVPN logs on the otherhand looks like this :

Mar 21 15:23:14 openvpn 64796 event_wait : Interrupted system call (code=4)
Mar 21 15:23:16 openvpn 64796 /usr/local/sbin/ovpn-linkdown ovpns1 1500 1621 10.0.30.1 255.255.255.0 init
Mar 21 15:23:16 openvpn 64796 SIGTERM[hard,] received, process exiting
Mar 21 15:23:16 openvpn 27887 WARNING: POTENTIALLY DANGEROUS OPTION --verify-client-cert none|optional may accept clients which do not present a certificate
Mar 21 15:23:16 openvpn 27887 OpenVPN 2.5.4 amd64-portbld-freebsd12.3 [SSL (OpenSSL)] [LZO] [LZ4] [MH/RECVDA] [AEAD] built on Jan 13 2022
Mar 21 15:23:16 openvpn 27887 library versions: OpenSSL 1.1.1l-freebsd 24 Aug 2021, LZO 2.10
Mar 21 15:23:16 openvpn 28181 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 21 15:23:16 openvpn 28181 WARNING: experimental option --capath /var/etc/openvpn/server1/ca
Mar 21 15:23:16 openvpn 28181 TUN/TAP device ovpns1 exists previously, keep at program end
Mar 21 15:23:16 openvpn 28181 TUN/TAP device /dev/tun1 opened
Mar 21 15:23:16 openvpn 28181 /sbin/ifconfig ovpns1 10.0.30.1 10.0.30.2 mtu 1500 netmask 255.255.255.0 up
Mar 21 15:23:16 openvpn 28181 /usr/local/sbin/ovpn-linkup ovpns1 1500 1621 10.0.30.1 255.255.255.0 init
Mar 21 15:23:16 openvpn 28181 UDPv4 link local (bound): [AF_INET]xx.xx.173.23:1194
Mar 21 15:23:16 openvpn 28181 UDPv4 link remote: [AF_UNSPEC]
Mar 21 15:23:16 openvpn 28181 Initialization Sequence Completed

the ip its bound to here(UDPv4 link local (bound): [AF_INET]xx.xx.173.23:1194) is another on the network for the server i rdp into and managing the pFsense GUI on there. Not sure why its using that instead of the xx.xx.173.22:1194( which is the ip of the pfsense box itself

viragomann · Mar 22, 2022, 2:03 PM

@prez_mgmt
So the local IP the OpenVPN server is bound to doesn't match to that one your client tries to connect to.

So you either have change the servers IP or the clients remote line. Seems the server is using the wrong one.
In the OpenVPN server settings you can select the proper IP from the interface drop-down.

Prez_Mgmt · Mar 22, 2022, 2:03 PM

@viragomann
I don't see any section in the OpenVPN Server settings(VPN/OpenVPN/Servers/Edit) to select an IP from a dropdown, are you referring to the Firewall? Point me in right direction, thanks.

viragomann · Mar 22, 2022, 2:11 PM

@prez_mgmt
No the OpenVPN server. VPN > OpenVPN > Servers > Edit

You can select here any IP which is assigned to any pfSense interface.
Since your client is accessing xx.xx.126.2, but the server is listening on xx.xx.173.23, I assume, you've multiple IPs assigned to the WAN interface. So you should be able to select the proper one here.

Prez_Mgmt · Mar 22, 2022, 5:21 PM

@viragomann
Oh that Thanks again for your help.
When setting up a new OpenVPN server, its also says "The interface where OpenVPN will listen for incoming connections (typically WAN.)" and we have had that on WAN and its always worked that way. We don't have a VIP for the router/pfsense and can't assign one to it now anymore.

Also, i edited the client ip to match what OpenVPN logs says its bound to and its still this TL error.. it's driving me nuts at this point.