OpenVPN Support Forum

Community Support Forum
https://forums.openvpn.net/

Client connects only on second try

https://forums.openvpn.net/viewtopic.php?t=31343

Page 1 of 1

Client connects only on second try

Posted: Sun Nov 22, 2020 12:56 am
by bigAlNZ
Hello,

I have a OpenVPN server running behind a ADSL modem. I can not enter routes no the modem, so I have had to put the server into NAT mode with :

Code: Select all

iptables -t nat -I POSTROUTING -o eth0 -s 10.8.0.0/24 -j MASQUERADE
Clients are able to connect OK - but only it seems on the second attempt.

In order to try to debug this I did a tcpdump on the server on 1194 eth0 - I can see the incoming traffic when I first initiate the connection, but nothing is showing on the openvpn log to register the attempt to connect. After the timeout and retry it connects just fine.

I am running the openvpn server on Lubuntu on virtual Hyper-V machine. Windows 10 is the host.

server.conf
Server conf

mode server
tls-server
port 1194
proto udp
dev tun
script-security 2

server 10.8.0.0 255.255.255.0
push "route 192.168.1.0 255.255.255.0"
push "dhcp-option DNS 192.168.1.1"
client-to-client

ca ca.crt
cert server.crt
key server.key # This file should be kept secret
dh dh2048.pem
tls-auth ta.key 0

ifconfig-pool-persist ipp.txt
cipher BF-CBC
comp-lzo

max-clients 5

user nobody
keepalive 10 120
persist-key
persist-tun
status /var/log/openvpn/openvpn-status.log
--log-append openvpn.log
verb 3

#crl-verify crl.pem


client
Client config

client

dev tun

remote secret.freeddns.org 1194
nobind

resolv-retry infinite

persist-key
persist-tun

ca ca.crt
cert client1.crt
key client1.key

dhcp-option DNS 192.168.100.201

tls-auth ta.key 1

cipher BF-CBC
remote-cert-tls server
auth-nocache

comp-lzo

verb 3


Thanks.

Re: Client connects only on second try

Posted: Sun Nov 22, 2020 1:39 am
by TinCanTech
bigAlNZ wrote: ↑
Sun Nov 22, 2020 12:56 am
 Clients are able to connect OK - but only it seems on the second attempt
Try removing:
bigAlNZ wrote: ↑
Sun Nov 22, 2020 12:56 am

Code: Select all

max-clients 5

Re: Client connects only on second try

Posted: Sun Nov 22, 2020 2:24 am
by bigAlNZ
Good idea, but I am the only client.

Re: Client connects only on second try

Posted: Sun Nov 22, 2020 2:43 am
by TinCanTech
Maybe it is the fifth attempt and not the second ?

Re: Client connects only on second try

Posted: Sun Nov 22, 2020 4:31 am
by Pippin
I did a tcpdump on the server on 1194 eth0 - I can see the incoming traffic
What did it look like?
but nothing is showing on the openvpn log
Maybe try

Code: Select all

verb 6

Re: Client connects only on second try

Posted: Sun Nov 22, 2020 5:26 am
by TinCanTech
Pippin wrote: ↑
Sun Nov 22, 2020 4:31 am
I did a tcpdump on the server on 1194 eth0 - I can see the incoming traffic
What did it look like?
Encrypted ..

Re: Client connects only on second try

Posted: Sun Nov 22, 2020 7:33 am
by bigAlNZ
verb6 is a good idea.

Log still doesnt seem to show much relevant. I disconnect and reconnect - nothing immediately comes up indicating that OVPN is trying to accept the connection:

Code: Select all

Sun Nov 22 20:27:36 2020 us=947951 client1/121.74.193.xx:58074 UDPv4 WRITE [38] to [AF_INET]121.74.193.xx:58074: P_DATA_V1 kid=0 DATA len=37
Sun Nov 22 20:27:46 2020 us=139347 client1/121.74.193.xx:58074 UDPv4 WRITE [38] to [AF_INET]121.74.193.xx:58074: P_DATA_V1 kid=0 DATA len=37
Sun Nov 22 20:27:56 2020 us=209043 client1/121.74.193.xx:58074 UDPv4 WRITE [38] to [AF_INET]121.74.193.xx:58074: P_DATA_V1 kid=0 DATA len=37
Sun Nov 22 20:28:06 2020 us=275272 client1/121.74.193.xx:58074 UDPv4 WRITE [38] to [AF_INET]121.74.193.xx:58074: P_DATA_V1 kid=0 DATA len=37
Sun Nov 22 20:28:16 2020 us=338019 client1/121.74.193.xx:58074 UDPv4 WRITE [38] to [AF_INET]121.74.193.xx:58074: P_DATA_V1 kid=0 DATA len=37
Sun Nov 22 20:28:26 2020 us=516828 client1/121.74.193.xx:58074 UDPv4 WRITE [38] to [AF_INET]121.74.193.xx:58074: P_DATA_V1 kid=0 DATA len=37
Sun Nov 22 20:28:36 2020 us=587280 client1/121.74.193.xx:58074 UDPv4 WRITE [38] to [AF_INET]121.74.193.xx:58074: P_DATA_V1 kid=0 DATA len=37
I wonder if it is anything to do with Lubuntu (normally I use Ubuntu)

Re: Client connects only on second try

Posted: Tue Nov 24, 2020 6:30 am
by bigAlNZ
A bit more information. This is the connection log

Code: Select all

Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_private_mode = 00000000
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_cert_private = DISABLED
Tue Nov 24 19:28:12 2020   pkcs11_pin_cache_period = -1
Tue Nov 24 19:28:12 2020   pkcs11_id = '[UNDEF]'
Tue Nov 24 19:28:12 2020   pkcs11_id_management = DISABLED
Tue Nov 24 19:28:12 2020   server_network = 0.0.0.0
Tue Nov 24 19:28:12 2020   server_netmask = 0.0.0.0
Tue Nov 24 19:28:12 2020   server_network_ipv6 = ::
Tue Nov 24 19:28:12 2020   server_netbits_ipv6 = 0
Tue Nov 24 19:28:12 2020   server_bridge_ip = 0.0.0.0
Tue Nov 24 19:28:12 2020   server_bridge_netmask = 0.0.0.0
Tue Nov 24 19:28:12 2020   server_bridge_pool_start = 0.0.0.0
Tue Nov 24 19:28:12 2020   server_bridge_pool_end = 0.0.0.0
Tue Nov 24 19:28:12 2020   ifconfig_pool_defined = DISABLED
Tue Nov 24 19:28:12 2020   ifconfig_pool_start = 0.0.0.0
Tue Nov 24 19:28:12 2020   ifconfig_pool_end = 0.0.0.0
Tue Nov 24 19:28:12 2020   ifconfig_pool_netmask = 0.0.0.0
Tue Nov 24 19:28:12 2020   ifconfig_pool_persist_filename = '[UNDEF]'
Tue Nov 24 19:28:12 2020   ifconfig_pool_persist_refresh_freq = 600
Tue Nov 24 19:28:12 2020   ifconfig_ipv6_pool_defined = DISABLED
Tue Nov 24 19:28:12 2020   ifconfig_ipv6_pool_base = ::
Tue Nov 24 19:28:12 2020   ifconfig_ipv6_pool_netbits = 0
Tue Nov 24 19:28:12 2020   n_bcast_buf = 256
Tue Nov 24 19:28:12 2020   tcp_queue_limit = 64
Tue Nov 24 19:28:12 2020   real_hash_size = 256
Tue Nov 24 19:28:12 2020   virtual_hash_size = 256
Tue Nov 24 19:28:12 2020   client_connect_script = '[UNDEF]'
Tue Nov 24 19:28:12 2020   learn_address_script = '[UNDEF]'
Tue Nov 24 19:28:12 2020   client_disconnect_script = '[UNDEF]'
Tue Nov 24 19:28:12 2020   client_config_dir = '[UNDEF]'
Tue Nov 24 19:28:12 2020   ccd_exclusive = DISABLED
Tue Nov 24 19:28:12 2020   tmp_dir = 'C:\Users\ALGRAN~1\AppData\Local\Temp\'
Tue Nov 24 19:28:12 2020   push_ifconfig_defined = DISABLED
Tue Nov 24 19:28:12 2020   push_ifconfig_local = 0.0.0.0
Tue Nov 24 19:28:12 2020   push_ifconfig_remote_netmask = 0.0.0.0
Tue Nov 24 19:28:12 2020   push_ifconfig_ipv6_defined = DISABLED
Tue Nov 24 19:28:12 2020   push_ifconfig_ipv6_local = ::/0
Tue Nov 24 19:28:12 2020   push_ifconfig_ipv6_remote = ::
Tue Nov 24 19:28:12 2020   enable_c2c = DISABLED
Tue Nov 24 19:28:12 2020   duplicate_cn = DISABLED
Tue Nov 24 19:28:12 2020   cf_max = 0
Tue Nov 24 19:28:12 2020   cf_per = 0
Tue Nov 24 19:28:12 2020   max_clients = 1024
Tue Nov 24 19:28:12 2020   max_routes_per_client = 256
Tue Nov 24 19:28:12 2020   auth_user_pass_verify_script = '[UNDEF]'
Tue Nov 24 19:28:12 2020   auth_user_pass_verify_script_via_file = DISABLED
Tue Nov 24 19:28:12 2020   auth_token_generate = DISABLED
Tue Nov 24 19:28:12 2020   auth_token_lifetime = 0
Tue Nov 24 19:28:12 2020   client = ENABLED
Tue Nov 24 19:28:12 2020   pull = ENABLED
Tue Nov 24 19:28:12 2020   auth_user_pass_file = '[UNDEF]'
Tue Nov 24 19:28:12 2020   show_net_up = DISABLED
Tue Nov 24 19:28:12 2020   route_method = 3
Tue Nov 24 19:28:12 2020   block_outside_dns = DISABLED
Tue Nov 24 19:28:12 2020   ip_win32_defined = DISABLED
Tue Nov 24 19:28:12 2020   ip_win32_type = 3
Tue Nov 24 19:28:12 2020   dhcp_masq_offset = 0
Tue Nov 24 19:28:12 2020   dhcp_lease_time = 31536000
Tue Nov 24 19:28:12 2020   tap_sleep = 0
Tue Nov 24 19:28:12 2020   dhcp_options = ENABLED
Tue Nov 24 19:28:12 2020   dhcp_renew = DISABLED
Tue Nov 24 19:28:12 2020   dhcp_pre_release = DISABLED
Tue Nov 24 19:28:12 2020   domain = '[UNDEF]'
Tue Nov 24 19:28:12 2020   netbios_scope = '[UNDEF]'
Tue Nov 24 19:28:12 2020   netbios_node_type = 0
Tue Nov 24 19:28:12 2020   disable_nbt = DISABLED
Tue Nov 24 19:28:12 2020   DNS[0] = 192.168.1.1
Tue Nov 24 19:28:12 2020 OpenVPN 2.4.5 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Mar  1 2018
Tue Nov 24 19:28:12 2020 Windows version 6.2 (Windows 8 or greater) 64bit
Tue Nov 24 19:28:12 2020 library versions: OpenSSL 1.1.0f  25 May 2017, LZO 2.10
Tue Nov 24 19:28:12 2020 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25343
Tue Nov 24 19:28:12 2020 Need hold release from management interface, waiting...
Tue Nov 24 19:28:13 2020 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25343
Tue Nov 24 19:28:13 2020 MANAGEMENT: CMD 'state on'
Tue Nov 24 19:28:13 2020 MANAGEMENT: CMD 'log all on'
Tue Nov 24 19:28:13 2020 MANAGEMENT: CMD 'echo all on'
Tue Nov 24 19:28:13 2020 MANAGEMENT: CMD 'bytecount 5'
Tue Nov 24 19:28:13 2020 MANAGEMENT: CMD 'hold off'
Tue Nov 24 19:28:13 2020 MANAGEMENT: CMD 'hold release'
Tue Nov 24 19:28:13 2020 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Nov 24 19:28:13 2020 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Nov 24 19:28:13 2020 LZO compression initializing
Tue Nov 24 19:28:13 2020 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Tue Nov 24 19:28:13 2020 MANAGEMENT: >STATE:1606199293,RESOLVE,,,,,,
Tue Nov 24 19:28:14 2020 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Tue Nov 24 19:28:14 2020 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-client'
Tue Nov 24 19:28:14 2020 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-server'
Tue Nov 24 19:28:14 2020 TCP/UDP: Preserving recently used remote address: [AF_INET6]2407:7000:8cb8:6967:d8c8:6f0b:de14:6a49:1194
Tue Nov 24 19:28:14 2020 Socket Buffers: R=[65536->65536] S=[65536->65536]
Tue Nov 24 19:28:14 2020 UDP link local: (not bound)
Tue Nov 24 19:28:14 2020 UDP link remote: [AF_INET6]2407:7000:8cb8:6967:d8c8:6f0b:de14:6a49:1194
Tue Nov 24 19:28:14 2020 MANAGEMENT: >STATE:1606199294,WAIT,,,,,,
Tue Nov 24 19:28:14 2020 UDP WRITE [42] to [AF_INET6]2407:7000:8cb8:6967:d8c8:6f0b:de14:6a49:1194: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 pid=[ #1 ] [ ] pid=0 DATA len=0
Tue Nov 24 19:28:14 2020 UDP READ [0] from [AF_UNSPEC]: DATA UNDEF len=-1
Tue Nov 24 19:28:16 2020 UDP WRITE [42] to [AF_INET6]2407:7000:8cb8:6967:d8c8:6f0b:de14:6a49:1194: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 pid=[ #2 ] [ ] pid=0 DATA len=0
Tue Nov 24 19:28:20 2020 UDP WRITE [42] to [AF_INET6]2407:7000:8cb8:6967:d8c8:6f0b:de14:6a49:1194: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 pid=[ #3 ] [ ] pid=0 DATA len=0
The successful connection is actually nothing to do with the second attempt (I can force a retry right away) it seems that you need to wait 1 minute before a successful attempt.

After logging in I notice a lot of these entries on the client log:

Code: Select all

ue Nov 24 19:30:09 2020 UDP WRITE [101] to [AF_INET]27.252.83.xxx:1194: P_DATA_V2 kid=0 DATA len=100
Tue Nov 24 19:30:09 2020 TUN READ [70]
Tue Nov 24 19:30:09 2020 UDP WRITE [95] to [AF_INET]27.252.83.xxx:1194: P_DATA_V2 kid=0 DATA len=94
Tue Nov 24 19:30:09 2020 TUN READ [70]
Tue Nov 24 19:30:09 2020 UDP WRITE [95] to [AF_INET]27.252.83.xxx:1194: P_DATA_V2 kid=0 DATA len=94
Tue Nov 24 19:30:09 2020 TUN READ [76]
Tue Nov 24 19:30:09 2020 UDP WRITE [101] to [AF_INET]27.252.83.xxx:1194: P_DATA_V2 kid=0 DATA len=100
Tue Nov 24 19:30:09 2020 TUN READ [76]
Tue Nov 24 19:30:09 2020 UDP WRITE [101] to [AF_INET]27.252.83.xxx:1194: P_DATA_V2 kid=0 DATA len=100
Tue Nov 24 19:30:09 2020 TUN READ [70]
Tue Nov 24 19:30:09 2020 UDP WRITE [95] to [AF_INET]27.252.83.xxx:1194: P_DATA_V2 kid=0 DATA len=94
Tue Nov 24 19:30:09 2020 TUN READ [70]
Tue Nov 24 19:30:09 2020 UDP WRITE [95] to [AF_INET]27.252.83.xxx:1194: P_DATA_V2 kid=0 DATA len=94
Tue Nov 24 19:30:10 2020 TUN READ [76]
Tue Nov 24 19:30:10 2020 UDP WRITE [101] to [AF_INET]27.252.83.xxx:1194: P_DATA_V2 kid=0 DATA len=100
Tue Nov 24 19:30:10 2020 TUN READ [76]
Tue Nov 24 19:30:10 2020 UDP WRITE [101] to [AF_INET]27.252.83.xxx:1194: P_DATA_V2 kid=0 DATA len=100
Does this give any more clues?

Re: Client connects only on second try

Posted: Tue Nov 24, 2020 6:48 am
by bigAlNZ
I found the issue. secret.freeddns.org was registering a IPV6 address - but it would only connect on the second attempt when it used IPV4.

Turned IPV6 off in freeddns and life was good.
All times are UTC
Page 1 of 1
Powered by phpBB® Forum Software © phpBB Limited
https://www.phpbb.com/