OpenVPN goes spontaneously into deadlock

[alexAubin]

Issue discussed with a VPN user today ... The setup is working pretty well, but for some reason sometimes the VPN spontaneously goes down, hence the server being seemingly "down" because it's unreachable

Studying the log, I'm seeing this, with the issue precisely starting at 10:38

2023-12-11 08:43:57 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
2023-12-11 08:43:57 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
2023-12-11 08:43:57 NOTE: --mute triggered...
2023-12-11 08:51:16 1 variation(s) on previous 5 message(s) suppressed by --mute
2023-12-11 08:51:16 TCP/UDP: Incoming packet rejected from [AF_INET]xx.xx.xx.xx:45884[2], expected peer address: [AF_INET]xx.xx.xx.xx:1194 (allow this incoming source address/port
by removing --remote or adding --float)

2023-12-11 09:14:43 TCP/UDP: Incoming packet rejected from [AF_INET]xx.xx.xx.xx:50951[2], expected peer address: [AF_INET]xx.xx.xx.xx:1194 (allow this incoming source address/port b
y removing --remote or adding --float)

2023-12-11 09:43:57 TLS: soft reset sec=3600/3600 bytes=10035432/-1 pkts=16672/0
2023-12-11 09:43:57 VERIFY OK: depth=1, C=FR, ST=Some, L=Place O=SomeISP, OU=SomeISP, CN=Easy-RSA CA, emailAddress=president@SomeISP.net
2023-12-11 09:43:57 VERIFY OK: depth=0, C=FR, ST=Some, L=Place O=SomeISP, OU=SomeISP, CN=vpn.SomeISP.net, emailAddress=president@SomeISP.net
2023-12-11 09:43:57 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
2023-12-11 09:43:57 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
2023-12-11 09:43:57 NOTE: --mute triggered...

2023-12-11 10:00:59 1 variation(s) on previous 5 message(s) suppressed by --mute
2023-12-11 10:00:59 TCP/UDP: Incoming packet rejected from [AF_INET]xx.xx.xx.xx:58829[2], expected peer address: [AF_INET]xx.xx.xx.xx:1194 (allow this incoming source address/port b
y removing --remote or adding --float)

2023-12-11 10:38:46 [vpn.SomeISP.net] Inactivity timeout (--ping-restart), restarting
2023-12-11 10:38:46 SIGUSR1[soft,ping-restart] received, process restarting
2023-12-11 10:38:46 Restart pause, 5 second(s)
2023-12-11 10:38:51 WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.
2023-12-11 10:38:51 TCP/UDP: Preserving recently used remote address: [AF_INET]xx.xx.xx.xx:1194
2023-12-11 10:38:51 Socket Buffers: R=[212992->212992] S=[212992->212992]
2023-12-11 10:38:51 UDP link local (bound): [AF_INET][undef]:1194
2023-12-11 10:38:51 UDP link remote: [AF_INET]xx.xx.xx.xx:1194

2023-12-11 10:39:21 [UNDEF] Inactivity timeout (--ping-restart), restarting
2023-12-11 10:39:21 SIGUSR1[soft,ping-restart] received, process restarting
2023-12-11 10:39:21 Restart pause, 5 second(s)
2023-12-11 10:39:26 WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.
2023-12-11 10:39:46 RESOLVE: Cannot resolve host address: vpn.SomeISP.net:1194 (Temporary failure in name resolution)
2023-12-11 10:40:06 RESOLVE: Cannot resolve host address: vpn.SomeISP.net:1194 (Temporary failure in name resolution)
2023-12-11 10:40:06 Could not determine IPv4/IPv6 protocol
2023-12-11 10:40:06 SIGUSR1[soft,init_instance] received, process restarting
2023-12-11 10:40:06 Restart pause, 5 second(s)
2023-12-11 10:40:11 WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.

2023-12-11 10:40:31 RESOLVE: Cannot resolve host address: vpn.SomeISP.net:1194 (Temporary failure in name resolution)
2023-12-11 10:40:51 RESOLVE: Cannot resolve host address: vpn.SomeISP.net:1194 (Temporary failure in name resolution)
2023-12-11 10:40:51 Could not determine IPv4/IPv6 protocol
2023-12-11 10:40:51 SIGUSR1[soft,init_instance] received, process restarting
2023-12-11 10:40:51 Restart pause, 5 second(s)
2023-12-11 10:40:56 WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.

2023-12-11 10:41:16 RESOLVE: Cannot resolve host address: vpn.SomeISP.net:1194 (Temporary failure in name resolution)
2023-12-11 10:41:36 RESOLVE: Cannot resolve host address: vpn.SomeISP.net:1194 (Temporary failure in name resolution)
2023-12-11 10:41:36 Could not determine IPv4/IPv6 protocol
2023-12-11 10:41:36 SIGUSR1[soft,init_instance] received, process restarting
[...]

In particular:

WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.

and

RESOLVE: Cannot resolve host address: vpn.SomeISP.net

Which is reminiscent of the good old issue where the resolv conf points to some DNS server, but somehow the ip table rules forbid talking to it maybe ? I'm not sure exactly what's responsible for this, but it feels like we should add another failsafe, maybe in ynh-vpnclient-checker, that does check that dns resolution is working and attempt to fix it if it's not ... maybe using 8.8.8.8 as a desperate measure idk x_x

[hidrarga]

Does the issue occur with my last PR (#118) ? Because there were quite a lot of changes, so maybe this is already solved ?

[hidrarga]

I'm closing as I think it was solved with the last PRs. We can open the issue again if the issue is still there.