VPN connection drops after variable time, unable to reconnect by itself

This forum is for admins who are looking to build or expand their OpenVPN setup.

Moderators: TinCanTech, TinCanTech, TinCanTech, TinCanTech, TinCanTech, TinCanTech

Forum rules
Please use the [oconf] BB tag for openvpn Configurations. See viewtopic.php?f=30&t=21589 for an example.
Post Reply
masscream
OpenVpn Newbie
Posts: 6
Joined: Tue Aug 16, 2022 1:59 pm

VPN connection drops after variable time, unable to reconnect by itself

Post by masscream » Tue Aug 16, 2022 7:56 pm

Hello everyone. I'm a little bit out of ideas, so I hope, maybe someone may have experience with this issue. I'm running a small server with services for a small non-profitable org. Because there is a complicated access and conditions onsite, I'm running there just a little "white horse" server A, with OpenVPN server on it, which is forwarding all the requests to another site. There is a client (server B), automatically connecting to the VPN server (A), hosting all the services. For months, the connection has been stable without any issues, however, a few weeks ago, it started to drop randomly with a strange phenomenon. I can't say what was / is the trigger point, generally for the fault, as well as for the particular drops. I made no significant change or so... The issue itself occurs the way that the VPN connection goes down from the client side (B) (Inactivity timeout) and when it's trying to recover the connection, it returns with the error "TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)" and so on and on... It's nice it says to check the network connectivity, however, that is not the issue. What is proven by the fact that restarting the client daemon causes immediately the client to connect successfully. Sometimes, it drops the connection within hours since the restart, sometimes it takes days... What I did to start the troubleshooting, except restarting the related devices on the infrastructure was, that I increased the log levels of the server side (although it does not receive the bad attempts, so the problem is client (B)) as well as of the client side. One of the first error details I caught after that, was that a msg "Recursive routing detected, drop tun packet to [AF_INET]84.42.x.x:1194" appeared. I tried googling a little and then added the "allow-recursive-routing" to the client config, what caused that these messages disappeared. However the connection is still going down, last time I increased log verbosity to 7 and catching more and more details... Please, if you may have suspicion what could be the cause, put me on the track. It's annoying. Thanks a lot.

Client Config-B

client
dev tun
proto udp
remote 84.42.x.x 1194
resolv-retry infinite
nobind
persist-key
persist-tun
remote-cert-tls server
auth SHA512
cipher AES-256-CBC
ignore-unknown-option block-outside-dns
log /var/log/openvpn/client.log
verb 7
allow-recursive-routing
<ca>
certs here...


Server Config-A

local 0.0.0.0
port 1194
proto udp
dev tun
ca ca.crt
cert server.crt
key server.key
dh dh.pem
auth SHA512
tls-crypt tc.key
topology subnet
server 10.7.0.0 255.255.255.0
server-ipv6 fddd:1194:1194:1194::/64
client-config-dir /etc/openvpn/server/ccd
push "redirect-gateway def1 ipv6 bypass-dhcp"
push "dhcp-option DOMAIN my-domain.com"
push "dhcp-option DNS 10.7.0.1"
keepalive 10 120
cipher AES-256-CBC
data-ciphers AES-256-CBC
user nobody
group nogroup
persist-key
persist-tun
crl-verify crl.pem
explicit-exit-notify
status openvpn-status.log
log /var/log/openvpn/server.log
verb 5


Drop 1

Code: Select all

Aug 01 16:30:09 client openvpn[1696]: VERIFY EKU OK
Aug 01 16:30:09 client openvpn[1696]: VERIFY OK: depth=0, CN=server
Aug 01 16:30:09 client openvpn[1696]: Outgoing Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key
Aug 01 16:30:09 client openvpn[1696]: Outgoing Data Channel: Using 512 bit message hash 'SHA512' for HMAC authentication
Aug 01 16:30:09 client openvpn[1696]: Incoming Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key
Aug 01 16:30:09 client openvpn[1696]: Incoming Data Channel: Using 512 bit message hash 'SHA512' for HMAC authentication
Aug 01 16:30:09 client openvpn[1696]: Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
Aug 01 16:50:03 client openvpn[1696]: [server] Inactivity timeout (--ping-restart), restarting
Aug 01 16:50:03 client openvpn[1696]: SIGUSR1[soft,ping-restart] received, process restarting
Aug 01 16:50:03 client openvpn[1696]: Restart pause, 5 second(s)
Aug 01 16:50:08 client openvpn[1696]: TCP/UDP: Preserving recently used remote address: [AF_INET]84.42.x.x:1194
Aug 01 16:50:08 client openvpn[1696]: Socket Buffers: R=[212992->212992] S=[212992->212992]
Aug 01 16:50:08 client openvpn[1696]: UDP link local: (not bound)
Aug 01 16:50:08 client openvpn[1696]: UDP link remote: [AF_INET]84.42.x.x:1194
Aug 01 16:51:08 client openvpn[1696]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Aug 01 16:51:08 client openvpn[1696]: TLS Error: TLS handshake failed
Aug 01 16:51:08 client openvpn[1696]: SIGUSR1[soft,tls-error] received, process restarting
Aug 01 16:51:08 client openvpn[1696]: Restart pause, 5 second(s)

Aug 01 16:30:09 server openvpn[39472]: client/46.39.x.x:59683 Outgoing Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key
Aug 01 16:30:09 server openvpn[39472]: client/46.39.x.x:59683 Outgoing Data Channel: Using 512 bit message hash 'SHA512' for HMAC authentication
Aug 01 16:30:09 server openvpn[39472]: client/46.39.x.x:59683 Incoming Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key
Aug 01 16:30:09 server openvpn[39472]: client/46.39.x.x:59683 Incoming Data Channel: Using 512 bit message hash 'SHA512' for HMAC authentication
Aug 01 16:30:09 server openvpn[39472]: client/46.39.x.x:59683 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
Aug 01 16:52:03 server openvpn[39472]: client/46.39.x.x:59683 [client] Inactivity timeout (--ping-restart), restarting
Aug 01 16:52:03 server openvpn[39472]: client/46.39.x.x:59683 SIGUSR1[soft,ping-restart] received, client-instance restarting
Drop 2 (client only)

Code: Select all

Sun Aug 14 01:13:24 2022 us=89113 Recursive routing detected, drop tun packet to [AF_INET]84.42.x.x:1194
Sun Aug 14 01:13:25 2022 us=149235 [server] Inactivity timeout (--ping-restart), restarting
Sun Aug 14 01:13:25 2022 us=149418 TCP/UDP: Closing socket
Sun Aug 14 01:13:25 2022 us=149451 SIGUSR1[soft,ping-restart] received, process restarting
Sun Aug 14 01:13:25 2022 us=149478 Restart pause, 5 second(s)
Sun Aug 14 01:13:30 2022 us=149564 Re-using SSL/TLS context
Sun Aug 14 01:13:30 2022 us=149682 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
Sun Aug 14 01:13:30 2022 us=149708 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Sun Aug 14 01:13:30 2022 us=149733 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-client'
Sun Aug 14 01:13:30 2022 us=149739 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-server'
Sun Aug 14 01:13:30 2022 us=149750 TCP/UDP: Preserving recently used remote address: [AF_INET]84.42.x.x:1194
Sun Aug 14 01:13:30 2022 us=149774 Socket Buffers: R=[212992->212992] S=[212992->212992]
Sun Aug 14 01:13:30 2022 us=149784 UDP link local: (not bound)
Sun Aug 14 01:13:30 2022 us=149790 UDP link remote: [AF_INET]84.42.x.x:1194
WrrrSun Aug 14 01:13:30 2022 us=149994 Recursive routing detected, drop tun packet to [AF_INET]84.42.x.x:1194
rWrSun Aug 14 01:13:32 2022 us=276099 Recursive routing detected, drop tun packet to [AF_INET]84.42.x.x:1194
rWrSun Aug 14 01:13:36 2022 us=319499 Recursive routing detected, drop tun packet to [AF_INET]84.42.x.x:1194
rrrrrrrWrSun Aug 14 01:13:44 2022 us=667422 Recursive routing detected, drop tun packet to [AF_INET]84.42.x.x:1194
rrrrrrrrrWrSun Aug 14 01:14:00 2022 us=174136 Recursive routing detected, drop tun packet to [AF_INET]84.42.x.x:1194
rrrrrrrrrrrrrrrrrrrrrSun Aug 14 01:14:30 2022 us=74325 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Sun Aug 14 01:14:30 2022 us=74356 TLS Error: TLS handshake failed
Sun Aug 14 01:14:30 2022 us=74424 TCP/UDP: Closing socket
Sun Aug 14 01:14:30 2022 us=74449 SIGUSR1[soft,tls-error] received, process restarting
Sun Aug 14 01:14:30 2022 us=74464 Restart pause, 5 second(s)
Sun Aug 14 01:14:35 2022 us=74547 Re-using SSL/TLS context
Sun Aug 14 01:14:35 2022 us=74636 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
Sun Aug 14 01:14:35 2022 us=74653 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Sun Aug 14 01:14:35 2022 us=74675 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-client'
Sun Aug 14 01:14:35 2022 us=74681 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-server'
Sun Aug 14 01:14:35 2022 us=74690 TCP/UDP: Preserving recently used remote address: [AF_INET]84.42.x.x:1194
Sun Aug 14 01:14:35 2022 us=74714 Socket Buffers: R=[212992->212992] S=[212992->212992]
Sun Aug 14 01:14:35 2022 us=74724 UDP link local: (not bound)
Sun Aug 14 01:14:35 2022 us=74730 UDP link remote: [AF_INET]84.42.x.x:1194
Drop 3 (client only)

Code: Select all

Tue Aug 16 14:46:32 2022 us=132676 VERIFY KU OK
Tue Aug 16 14:46:32 2022 us=132686 Validating certificate extended key usage
Tue Aug 16 14:46:32 2022 us=132693 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Tue Aug 16 14:46:32 2022 us=132707 VERIFY EKU OK
Tue Aug 16 14:46:32 2022 us=132713 VERIFY OK: depth=0, CN=server
WRWWWRwrWRRWRTue Aug 16 14:46:32 2022 us=154714 Outgoing Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key
Tue Aug 16 14:46:32 2022 us=154768 Outgoing Data Channel: Using 512 bit message hash 'SHA512' for HMAC authentication
Tue Aug 16 14:46:32 2022 us=154777 Incoming Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key
Tue Aug 16 14:46:32 2022 us=154786 Incoming Data Channel: Using 512 bit message hash 'SHA512' for HMAC authentication
WTue Aug 16 14:46:32 2022 us=154815 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
RwRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwRwrWRwrWRwRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwRwrWRwRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwrWRwr$
Tue Aug 16 14:54:47 2022 us=1079 TCP/UDP: Closing socket
Tue Aug 16 14:54:47 2022 us=1105 SIGUSR1[soft,ping-restart] received, process restarting
Tue Aug 16 14:54:47 2022 us=1123 Restart pause, 5 second(s)
Tue Aug 16 14:54:52 2022 us=1237 Re-using SSL/TLS context
Tue Aug 16 14:54:52 2022 us=1334 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
Tue Aug 16 14:54:52 2022 us=1349 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Tue Aug 16 14:54:52 2022 us=1371 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-client'
Tue Aug 16 14:54:52 2022 us=1377 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-server'
Tue Aug 16 14:54:52 2022 us=1387 TCP/UDP: Preserving recently used remote address: [AF_INET]84.42.x.x:1194
Tue Aug 16 14:54:52 2022 us=1408 Socket Buffers: R=[212992->212992] S=[212992->212992]
Tue Aug 16 14:54:52 2022 us=1417 UDP link local: (not bound)
Tue Aug 16 14:54:52 2022 us=1423 UDP link remote: [AF_INET]84.42.x.x:1194
WrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrrWrrrWrrrrrrrWrrrrrrrrrrrWrrrrrrrrrrrrrrrrrrrrTue Aug 16 14:55:52 2022 us=654834 TLS Error: TLS key negotiation failed to occur within 60 seconds (che$
Tue Aug 16 14:55:52 2022 us=654886 TLS Error: TLS handshake failed
Tue Aug 16 14:55:52 2022 us=654954 TCP/UDP: Closing socket
Tue Aug 16 14:55:52 2022 us=654977 SIGUSR1[soft,tls-error] received, process restarting
Tue Aug 16 14:55:52 2022 us=654991 Restart pause, 5 second(s)
Tue Aug 16 14:55:57 2022 us=655109 Re-using SSL/TLS context
Tue Aug 16 14:55:57 2022 us=655204 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
Tue Aug 16 14:55:57 2022 us=655221 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Tue Aug 16 14:55:57 2022 us=655242 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-client'
Tue Aug 16 14:55:57 2022 us=655248 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-server'
Tue Aug 16 14:55:57 2022 us=655257 TCP/UDP: Preserving recently used remote address: [AF_INET]84.42.x.x:1194
Tue Aug 16 14:55:57 2022 us=655276 Socket Buffers: R=[212992->212992] S=[212992->212992]
Tue Aug 16 14:55:57 2022 us=655285 UDP link local: (not bound)
Tue Aug 16 14:55:57 2022 us=655291 UDP link remote: [AF_INET]84.42.x.x:1194

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: VPN connection drops after variable time, unable to reconnect by itself

Post by TinCanTech » Tue Aug 16, 2022 8:11 pm

masscream wrote:
Tue Aug 16, 2022 7:56 pm
allow-recursive-routing
Bad idea.
masscream wrote:
Tue Aug 16, 2022 7:56 pm
local 0.0.0.0
Bad idea.
masscream wrote:
Tue Aug 16, 2022 7:56 pm
server-ipv6 fddd1194:/64
Really ....


Also, openvpn --version

masscream
OpenVpn Newbie
Posts: 6
Joined: Tue Aug 16, 2022 1:59 pm

Re: VPN connection drops after variable time, unable to reconnect by itself

Post by masscream » Wed Aug 17, 2022 10:42 am

I allowed recursive routing, cause it looked this was the cause of the issue (why it was working flawlessly before, no idea). It's true that I let some of the options the way they were, cause they were harmless in the setup I use (I don't have IPv6 support in the LAN, as well as there is almost no access for the users from the LAN... Using external firewall, segmented setup). But if something from the above really causes the issue, I will reconfigure it.

Code: Select all

Server A (Debian)
OpenVPN 2.5.1 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on May 14 2021
library versions: OpenSSL 1.1.1n  15 Mar 2022, LZO 2.10

Client B (RHEL)
OpenVPN 2.4.12 x86_64-redhat-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Mar 17 2022
library versions: OpenSSL 1.1.1k  FIPS 25 Mar 2021, LZO 2.08

masscream
OpenVpn Newbie
Posts: 6
Joined: Tue Aug 16, 2022 1:59 pm

Re: VPN connection drops after variable time, unable to reconnect by itself

Post by masscream » Wed Aug 17, 2022 11:09 am

Drop 4, verbosity 7

Code: Select all

Wed Aug 17 11:55:05 2022 us=884 UDP WRITE [244] to [AF_INET]84.42.x.x:1194: P_DATA_V2 kid=6 DATA len=243
Wed Aug 17 11:55:05 2022 us=896 TUN READ [272]
Wed Aug 17 11:55:05 2022 us=902 TLS: tls_pre_encrypt: key_id=6
Wed Aug 17 11:55:05 2022 us=913 UDP WRITE [372] to [AF_INET]84.42.x.x:1194: P_DATA_V2 kid=6 DATA len=371
Wed Aug 17 11:55:05 2022 us=927 TUN READ [400]
Wed Aug 17 11:55:05 2022 us=933 TLS: tls_pre_encrypt: key_id=6
Wed Aug 17 11:55:05 2022 us=948 UDP WRITE [500] to [AF_INET]84.42.x.x:1194: P_DATA_V2 kid=6 DATA len=499
Wed Aug 17 11:55:05 2022 us=962 [server] Inactivity timeout (--ping-restart), restarting
Wed Aug 17 11:55:05 2022 us=973 PID packet_id_free
Wed Aug 17 11:55:05 2022 us=1035 PID packet_id_free
Wed Aug 17 11:55:05 2022 us=1072 PID packet_id_free
Wed Aug 17 11:55:05 2022 us=1079 PID packet_id_free
Wed Aug 17 11:55:05 2022 us=1099 PID packet_id_free
Wed Aug 17 11:55:05 2022 us=1106 PID packet_id_free
Wed Aug 17 11:55:05 2022 us=1111 PID packet_id_free
Wed Aug 17 11:55:05 2022 us=1116 PID packet_id_free
Wed Aug 17 11:55:05 2022 us=1122 TCP/UDP: Closing socket
Wed Aug 17 11:55:05 2022 us=1136 PID packet_id_free
Wed Aug 17 11:55:05 2022 us=1147 SIGUSR1[soft,ping-restart] received, process restarting
Wed Aug 17 11:55:05 2022 us=1163 Restart pause, 5 second(s)
Wed Aug 17 11:55:10 2022 us=1275 Re-using SSL/TLS context
Wed Aug 17 11:55:10 2022 us=1333 tls_crypt_adjust_frame_parameters: Adjusting frame parameters for tls-crypt by 56 bytes
Wed Aug 17 11:55:10 2022 us=1349 PID packet_id_init seq_backtrack=64 time_backtrack=15
Wed Aug 17 11:55:10 2022 us=1377 PID packet_id_init seq_backtrack=64 time_backtrack=15
Wed Aug 17 11:55:10 2022 us=1386 PID packet_id_init seq_backtrack=64 time_backtrack=15
Wed Aug 17 11:55:10 2022 us=1401 PID packet_id_init seq_backtrack=64 time_backtrack=15
Wed Aug 17 11:55:10 2022 us=1408 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
Wed Aug 17 11:55:10 2022 us=1416 MTU DYNAMIC mtu=1450, flags=2, 1621 -> 1450
Wed Aug 17 11:55:10 2022 us=1422 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Wed Aug 17 11:55:10 2022 us=1437 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 100 bytes
Wed Aug 17 11:55:10 2022 us=1443 calc_options_string_link_mtu: link-mtu 1621 -> 1601
Wed Aug 17 11:55:10 2022 us=1453 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 100 bytes
Wed Aug 17 11:55:10 2022 us=1458 calc_options_string_link_mtu: link-mtu 1621 -> 1601
Wed Aug 17 11:55:10 2022 us=1466 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-client'
Wed Aug 17 11:55:10 2022 us=1471 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-server'
Wed Aug 17 11:55:10 2022 us=1480 TCP/UDP: Preserving recently used remote address: [AF_INET]84.42.x.x:1194
Wed Aug 17 11:55:10 2022 us=1499 Socket Buffers: R=[212992->212992] S=[212992->212992]
Wed Aug 17 11:55:10 2022 us=1508 UDP link local: (not bound)
Wed Aug 17 11:55:10 2022 us=1514 UDP link remote: [AF_INET]84.42.x.x:1194
Wed Aug 17 11:55:10 2022 us=1531 TLS Warning: no data channel send key available:  [key#0 state=S_INITIAL id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Wed Aug 17 11:55:10 2022 us=1537 SENT PING
Wed Aug 17 11:55:10 2022 us=1561 UDP WRITE [54] to [AF_INET]84.42.x.x:1194: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=354 DATA len=40
Wed Aug 17 11:55:10 2022 us=1698 TUN READ [528]
Wed Aug 17 11:55:10 2022 us=1712 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Wed Aug 17 11:55:10 2022 us=1722 TUN READ [1040]
Wed Aug 17 11:55:10 2022 us=1732 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Wed Aug 17 11:55:10 2022 us=1741 TUN READ [1500]
Wed Aug 17 11:55:10 2022 us=1751 TLS Warning: no data channel send key available:  [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
Do you want me to increase the log verbosity...? I may try to lower the MTU as some of the sources on the internet say.

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: VPN connection drops after variable time, unable to reconnect by itself

Post by TinCanTech » Wed Aug 17, 2022 11:40 am

masscream wrote:
Wed Aug 17, 2022 11:09 am
Do you want me to increase the log verbosity
No. --verb 4 is preferred.
masscream wrote:
Wed Aug 17, 2022 11:09 am
I may try to lower the MTU as some of the sources on the internet say
Or you could try plugging in an onion ..

MTU has nothing to do with your problem and any website telling you to change it is garbage.

Please start with the official howto. https://community.openvpn.net/openvpn/wiki/HOWTO

FYI:
  • If you don't know what recursive routing is then you absolutely should not allow it.
  • Do not use --local 0.0.0.0
  • Your IPv6 server setting is totally bogus.

masscream
OpenVpn Newbie
Posts: 6
Joined: Tue Aug 16, 2022 1:59 pm

Re: VPN connection drops after variable time, unable to reconnect by itself

Post by masscream » Wed Aug 17, 2022 6:29 pm

TinCanTech wrote:
Wed Aug 17, 2022 11:40 am
No. --verb 4 is preferred.
Drop no. 3 is actually verb 5, and did not give me any helpful detail about the issue. That's why I'm asking.
TinCanTech wrote:
Wed Aug 17, 2022 11:40 am
MTU has nothing to do with your problem and any website telling you to change it is garbage.
If you say so, what is the real cause of the issue then?
TinCanTech wrote:
Wed Aug 17, 2022 11:40 am
If you don't know what recursive routing is then you absolutely should not allow it.
I checked the manpage already before applying the option. The problem is, that sometimes even the official answer is not enough, and asking what could this and this possibly do in the operation.... would be more annoying and also time demanding in the situation you're not getting any useful info about the issue. Therefore you can try to risk it and see. Depending on the environment. In experience, the option did not affect the performance of the server or made things worse, it just did not solve the problem in the result.
TinCanTech wrote:
Wed Aug 17, 2022 11:40 am
Do not use --local 0.0.0.0
If I don't specify the option, the server will apply function of "--local 0.0.0.0" anyway, so what is your point? Useless line of config, or that the VPN should not listen on all of the interfaces...?
TinCanTech wrote:
Wed Aug 17, 2022 11:40 am
Your IPv6 server setting is totally bogus.
My IPv6 is a total default bogus, what came with the default config from the repo already. I just did not bother removing it, since I don't use IPv6...

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: VPN connection drops after variable time, unable to reconnect by itself

Post by TinCanTech » Wed Aug 17, 2022 7:04 pm

Your problem is your network not openvpn.

We don't trouble shoot company networks here.

If you require professional assistance then I am available for hire.

masscream
OpenVpn Newbie
Posts: 6
Joined: Tue Aug 16, 2022 1:59 pm

Re: VPN connection drops after variable time, unable to reconnect by itself

Post by masscream » Thu Aug 18, 2022 8:51 am

Oh, I get your point now. Firstly, you got me wrong. I deploy servers not for a living, I'm doing so in my free time to mostly play and learn something new. Yes, I do administer and provide some of these services to 1 non-profitable organization, but the reason is that I voluntarily serve there and there is no one more qualified for this part of service. I took this kind of activity there also as an opportunity to extend my playground, which consists mainly of home-sites. I was not hired as a professional and I'm not making any money there, so don't primarily they. That is also (and not only this) why I chose the way of linux and open-source stuff. Sadly, as the time is going, more and more real money making comps. are migrating to MS bullcrap and 365 Teams litter. And I'm not looking for a professional assistance too.

rjt
OpenVpn Newbie
Posts: 1
Joined: Mon Oct 17, 2022 10:43 pm

Re: VPN connection drops after variable time, unable to reconnect by itself

Post by rjt » Mon Oct 17, 2022 10:46 pm

I started getting the same error after updating my openvpn client to 2.5 while the server remained at 2.4. Noticed that you are using different versions 2.4 and 2.5 as well:

Code: Select all

Server A (Debian) 
    OpenVPN 2.5.1 x86_64-pc-linux-gnu

  Client B (RHEL)
    OpenVPN 2.4.12 x86_64-redhat-linux-gnu  
  

masscream
OpenVpn Newbie
Posts: 6
Joined: Tue Aug 16, 2022 1:59 pm

Re: VPN connection drops after variable time, unable to reconnect by itself

Post by masscream » Tue Oct 18, 2022 9:10 am

Actually, with the time, I was able to figure out what the problem was and get rid of that. I wanted to also write a resolution and finally this forced me to. When going through system logs, I discovered, that actually under this problem, the NetworkManager was having issues with the connection itself as well. According to one similar problem forum page, I found out, that the result/part of the cause was that the main ip route and the IP address of the OpenVPN server has just disappeared from the system IP routes. After re-adding it there manually, the connection temporarily started working. Next info I found out digging around NM and hardware itself was, that actually properties of my primary eth connection changed when the dropout occured - from 1 gig to 100mb, what actually put me on the real track. I had there a poor ethernet cable, which, after the physical check and reseat, started to make the job thoroughly. No issues since then!

What just suprised me quite not in the positive way was a feedback I got on this forum. I posted my question here in the principle of getting help with the open-source product, however I got only smart bunch of egomanical crap and begging for money instead of the real one. Microsoft and other big making money corps would clap their hands. Luckily, I found the cause/help myself, but next time, when looking for help, I would not be definitely looking for one here! Good luck though.

Wrong state

Code: Select all

[masscream@server log]$ route -n
Kernel IP routing table
Destination     Gateway         Genmask         Flags Metric Ref    Use Iface
0.0.0.0         10.7.0.1        128.0.0.0       UG    0      0        0 tun0
0.0.0.0         192.168.30.1    0.0.0.0         UG    100    0        0 eno1
10.7.0.0        0.0.0.0         255.255.255.0   U     0      0        0 tun0
128.0.0.0       10.7.0.1        128.0.0.0       UG    0      0        0 tun0
192.168.30.0    0.0.0.0         255.255.255.0   U     100    0        0 eno1

[masscream@server log]$ sudo inxi -nz
Network:
  Device-1: Intel 82579LM Gigabit Network driver: e1000e
  IF: eno1 state: up speed: 100 Mbps duplex: full mac: <filter>
  IF-ID-1: tun0 state: unknown speed: 10 Mbps duplex: full mac: N/A
Right state

Code: Select all

[masscream@server log]$ route -n
Kernel IP routing table
Destination     Gateway         Genmask         Flags Metric Ref    Use Iface
0.0.0.0         10.7.0.1        128.0.0.0       UG    0      0        0 tun0
0.0.0.0         192.168.30.1    0.0.0.0         UG    100    0        0 eno1
10.7.0.0        0.0.0.0         255.255.255.0   U     0      0        0 tun0
84.42.x.x       192.168.30.1    255.255.255.255 UGH   0      0        0 eno1
128.0.0.0       10.7.0.1        128.0.0.0       UG    0      0        0 tun0
192.168.30.0    0.0.0.0         255.255.255.0   U     100    0        0 eno1

[masscream@server log]$ sudo inxi -nz
Network:
  Device-1: Intel 82579LM Gigabit Network driver: e1000e
  IF: eno1 state: up speed: 1000 Mbps duplex: full mac: <filter>
  IF-ID-1: tun0 state: unknown speed: 10 Mbps duplex: full mac: N/A

That was my case, but yours can be (a little) different, or have another cause.

Post Reply