Client connects only on second try

Need help configuring your VPN? Just post here and you'll get that help.

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
bigAlNZ
OpenVpn Newbie
Posts: 8
Joined: Sun Nov 22, 2020 12:44 am

Client connects only on second try

Post by bigAlNZ » Sun Nov 22, 2020 12:56 am

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.
Top
TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Client connects only on second try

Post by TinCanTech » Sun Nov 22, 2020 1:39 am

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
Top
bigAlNZ
OpenVpn Newbie
Posts: 8
Joined: Sun Nov 22, 2020 12:44 am

Re: Client connects only on second try

Post by bigAlNZ » Sun Nov 22, 2020 2:24 am

Good idea, but I am the only client.
Top
TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Client connects only on second try

Post by TinCanTech » Sun Nov 22, 2020 2:43 am

Maybe it is the fifth attempt and not the second ?
Top
User avatar
Pippin
Forum Team
Posts: 1201
Joined: Wed Jul 01, 2015 8:03 am
Location: irc://irc.libera.chat:6697/openvpn

Re: Client connects only on second try

Post by Pippin » 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?
but nothing is showing on the openvpn log
Maybe try

Code: Select all

verb 6
I gloomily came to the ironic conclusion that if you take a highly intelligent person and give them the best possible, elite education, then you will most likely wind up with an academic who is completely impervious to reality.
Halton Arp
Top
TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Client connects only on second try

Post by TinCanTech » Sun Nov 22, 2020 5:26 am

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 ..
Top
bigAlNZ
OpenVpn Newbie
Posts: 8
Joined: Sun Nov 22, 2020 12:44 am

Re: Client connects only on second try

Post by bigAlNZ » Sun Nov 22, 2020 7:33 am

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)
Top
bigAlNZ
OpenVpn Newbie
Posts: 8
Joined: Sun Nov 22, 2020 12:44 am

Re: Client connects only on second try

Post by bigAlNZ » Tue Nov 24, 2020 6:30 am

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?
Top
bigAlNZ
OpenVpn Newbie
Posts: 8
Joined: Sun Nov 22, 2020 12:44 am

Re: Client connects only on second try

Post by bigAlNZ » Tue Nov 24, 2020 6:48 am

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.
Top
Post Reply

Return to “Configuration”