OpenVPN over UDP stopped working for some clients
Posted: Fri Apr 07, 2017 10:52 am
Hello,
I have a frustrating TLS error problem since a few days, where some clients can connect to my OpenVPN server and some cannot. It's running on Windows using UDP/1194 and all the clients have exact same settings. I am attaching a server log level 6 of a working client and one not working. I don't have access to the not working client log (it's remote).
In addition, this exact setup used to work for long time (more than a year) until it stopped on the 4th April 2017.
It seems like the client can reach the server but the server cannot reply back to the client. BUT this only happens for some of the clients, even ones that belong to the same public network (in remote areas). So I cannot imagine how it can be a firewall error.
NOT WORKING
WORKING
As you can see, the P_ACK_V1 that is sent back to the server by the second client, is never sent by the first client. So it tries to complete the handshake forever...
I searched through the forum and found some old similar topics. I tried the following idea on the server config, but didn't help (viewtopic.php?t=21519)
local xxx.xxx.xxx.xxx
Any ideas how to troubleshoot this? Could it be a networking/routing problem? Thanks so much for reading through!
I have a frustrating TLS error problem since a few days, where some clients can connect to my OpenVPN server and some cannot. It's running on Windows using UDP/1194 and all the clients have exact same settings. I am attaching a server log level 6 of a working client and one not working. I don't have access to the not working client log (it's remote).
In addition, this exact setup used to work for long time (more than a year) until it stopped on the 4th April 2017.
It seems like the client can reach the server but the server cannot reply back to the client. BUT this only happens for some of the clients, even ones that belong to the same public network (in remote areas). So I cannot imagine how it can be a firewall error.
NOT WORKING
Code: Select all
Fri Apr 07 09:51:38 2017 us=278366 bad_client:49003 Re-using SSL/TLS context
Fri Apr 07 09:51:38 2017 us=278366 bad_client:49003 LZO compression initialized
Fri Apr 07 09:51:38 2017 us=278366 bad_client:49003 Control Channel MTU parms [ L:1558 D:138 EF:38 EB:0 ET:0 EL:0 ]
Fri Apr 07 09:51:38 2017 us=278366 bad_client:49003 Data Channel MTU parms [ L:1558 D:1450 EF:58 EB:135 ET:0 EL:0 AF:3/1 ]
Fri Apr 07 09:51:38 2017 us=278366 bad_client:49003 Local Options String: 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,cipher AES-256-CBC,auth SHA1,keysize 256,key-method 2,tls-server'
Fri Apr 07 09:51:38 2017 us=278366 bad_client:49003 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,cipher AES-256-CBC,auth SHA1,keysize 256,key-method 2,tls-client'
Fri Apr 07 09:51:38 2017 us=278366 bad_client:49003 Local Options hash (VER=V4): 'a8f55717'
Fri Apr 07 09:51:38 2017 us=278366 bad_client:49003 Expected Remote Options hash (VER=V4): '22188c5b'
Fri Apr 07 09:51:38 2017 us=278366 bad_client:49003 UDPv4 READ [14] from [AF_INET]bad_client:49003: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Fri Apr 07 09:51:38 2017 us=278366 bad_client:49003 TLS: Initial packet from [AF_INET]bad_client:49003, sid=7ea5008f ee298f22
Fri Apr 07 09:51:38 2017 us=278366 bad_client:49003 UDPv4 WRITE [26] to [AF_INET]bad_client:49003: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Fri Apr 07 09:51:40 2017 us=310517 bad_client:49003 UDPv4 WRITE [14] to [AF_INET]bad_client:49003: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ ] pid=0 DATA len=0
Fri Apr 07 09:51:44 2017 us=374822 bad_client:49003 UDPv4 WRITE [14] to [AF_INET]bad_client:49003: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ ] pid=0 DATA len=0
Fri Apr 07 09:51:52 2017 us=503448 bad_client:49003 UDPv4 WRITE [14] to [AF_INET]bad_client:49003: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ ] pid=0 DATA len=0
Fri Apr 07 09:52:08 2017 us=791909 bad_client:49003 UDPv4 WRITE [14] to [AF_INET]bad_client:49003: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ ] pid=0 DATA len=0
Fri Apr 07 09:52:39 2017 us=87018 bad_client:49003 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Fri Apr 07 09:52:39 2017 us=87018 bad_client:49003 TLS Error: TLS handshake failed
Fri Apr 07 09:52:39 2017 us=87018 bad_client:49003 SIGUSR1[soft,tls-error] received, client-instance restarting
Fri Apr 07 09:52:39 2017 us=399300 MULTI: multi_create_instance called
Fri Apr 07 09:52:39 2017 us=399300 bad_client:49004 Re-using SSL/TLS context
Fri Apr 07 09:52:39 2017 us=399300 bad_client:49004 LZO compression initialized
Fri Apr 07 09:52:39 2017 us=399300 bad_client:49004 Control Channel MTU parms [ L:1558 D:138 EF:38 EB:0 ET:0 EL:0 ]
Fri Apr 07 09:52:39 2017 us=399300 bad_client:49004 Data Channel MTU parms [ L:1558 D:1450 EF:58 EB:135 ET:0 EL:0 AF:3/1 ]
Fri Apr 07 09:52:39 2017 us=399300 bad_client:49004 Local Options String: 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,cipher AES-256-CBC,auth SHA1,keysize 256,key-method 2,tls-server'
Fri Apr 07 09:52:39 2017 us=399300 bad_client:49004 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,cipher AES-256-CBC,auth SHA1,keysize 256,key-method 2,tls-client'
Fri Apr 07 09:52:39 2017 us=399300 bad_client:49004 Local Options hash (VER=V4): 'a8f55717'
Fri Apr 07 09:52:39 2017 us=399300 bad_client:49004 Expected Remote Options hash (VER=V4): '22188c5b'
Fri Apr 07 09:52:39 2017 us=399300 bad_client:49004 UDPv4 READ [14] from [AF_INET]bad_client:49004: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Fri Apr 07 09:52:39 2017 us=399300 bad_client:49004 TLS: Initial packet from [AF_INET]bad_client:49004, sid=3850de6b eadae20a
Fri Apr 07 09:52:39 2017 us=399300 bad_client:49004 UDPv4 WRITE [26] to [AF_INET]bad_client:49004: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Fri Apr 07 09:52:41 2017 us=775314 bad_client:49004 UDPv4 WRITE [14] to [AF_INET]bad_client:49004: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ ] pid=0 DATA len=0
Fri Apr 07 09:52:45 2017 us=292476 bad_client:49004 UDPv4 WRITE [14] to [AF_INET]bad_client:49004: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ ] pid=0 DATA len=0
WORKING
Code: Select all
Fri Apr 07 09:51:46 2017 us=109968 MULTI: multi_create_instance called
Fri Apr 07 09:51:46 2017 us=109968 good_client:62320 Re-using SSL/TLS context
Fri Apr 07 09:51:46 2017 us=109968 good_client:62320 LZO compression initialized
Fri Apr 07 09:51:46 2017 us=109968 good_client:62320 Control Channel MTU parms [ L:1558 D:138 EF:38 EB:0 ET:0 EL:0 ]
Fri Apr 07 09:51:46 2017 us=109968 good_client:62320 Data Channel MTU parms [ L:1558 D:1450 EF:58 EB:135 ET:0 EL:0 AF:3/1 ]
Fri Apr 07 09:51:46 2017 us=109968 good_client:62320 Local Options String: 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,cipher AES-256-CBC,auth SHA1,keysize 256,key-method 2,tls-server'
Fri Apr 07 09:51:46 2017 us=109968 good_client:62320 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,cipher AES-256-CBC,auth SHA1,keysize 256,key-method 2,tls-client'
Fri Apr 07 09:51:46 2017 us=109968 good_client:62320 Local Options hash (VER=V4): 'a8f55717'
Fri Apr 07 09:51:46 2017 us=109968 good_client:62320 Expected Remote Options hash (VER=V4): '22188c5b'
Fri Apr 07 09:51:46 2017 us=109968 good_client:62320 UDPv4 READ [14] from [AF_INET]good_client:62320: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Fri Apr 07 09:51:46 2017 us=109968 good_client:62320 TLS: Initial packet from [AF_INET]good_client:62320, sid=0a4a2388 525f8203
Fri Apr 07 09:51:46 2017 us=109968 good_client:62320 UDPv4 WRITE [26] to [AF_INET]good_client:62320: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Fri Apr 07 09:51:46 2017 us=156863 good_client:62320 UDPv4 READ [22] from [AF_INET]good_client:62320: P_ACK_V1 kid=0 [ 0 ]
Fri Apr 07 09:51:46 2017 us=156863 good_client:62320 UDPv4 READ [114] from [AF_INET]good_client:62320: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=100
Fri Apr 07 09:51:46 2017 us=156863 good_client:62320 UDPv4 WRITE [22] to [AF_INET]good_client:62320: P_ACK_V1 kid=0 [ 1 ]
Fri Apr 07 09:51:46 2017 us=156863 good_client:62320 UDPv4 READ [114] from [AF_INET]good_client:62320: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Fri Apr 07 09:51:46 2017 us=156863 good_client:62320 UDPv4 WRITE [22] to [AF_INET]good_client:62320: P_ACK_V1 kid=0 [ 2 ]
As you can see, the P_ACK_V1 that is sent back to the server by the second client, is never sent by the first client. So it tries to complete the handshake forever...
I searched through the forum and found some old similar topics. I tried the following idea on the server config, but didn't help (viewtopic.php?t=21519)
local xxx.xxx.xxx.xxx
Any ideas how to troubleshoot this? Could it be a networking/routing problem? Thanks so much for reading through!