problem after server restart - client doesn't accept new ip

This forum is for admins who are looking to build or expand their OpenVPN setup.
Forum rules
Please use the [oconf] BB tag for openvpn Configurations. See viewtopic.php?f=30&t=21589 for an example.
leshik
OpenVpn Newbie
Posts: 11
Joined: Tue Mar 03, 2015 3:21 pm

problem after server restart - client doesn't accept new ip

Post by leshik » Tue Mar 03, 2015 3:56 pm

Hi,

I'm seeing strange behavior with some clients when openvpn server is restarted. Client doesn't change it's IP to new one assigned by server, but still routinely exchange keepalives and thinks everything is ok (however, data packets aren't transmitted or received).

Here is my server log cleaned up to that particular client:

This is initial connection by 1st client (note it's IP address 10.9.2.2)

Feb 27 13:02:08 www ovpn-server1[23154]: 95.78.118.23:48612 TLS: Initial packet from [AF_INET]95.78.118.23:48612, sid=3131a981 13ecb0c8
Feb 27 13:02:13 www ovpn-server1[23154]: 95.78.118.23:48612 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
Feb 27 13:02:13 www ovpn-server1[23154]: 95.78.118.23:48612 VERIFY OK: depth=1, C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
Feb 27 13:02:13 www ovpn-server1[23154]: 95.78.118.23:48612 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=164410db-b350-4a2b-bf89-8bcdaa5ead29
Feb 27 13:02:13 www ovpn-server1[23154]: 95.78.118.23:48612 VERIFY OK: depth=0, C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=164410db-b350-4a2b-bf89-8bcdaa5ead29
Feb 27 13:02:14 www ovpn-server1[23154]: 95.78.118.23:48612 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Feb 27 13:02:14 www ovpn-server1[23154]: 95.78.118.23:48612 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Feb 27 13:02:14 www ovpn-server1[23154]: 95.78.118.23:48612 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Feb 27 13:02:14 www ovpn-server1[23154]: 95.78.118.23:48612 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Feb 27 13:02:14 www ovpn-server1[23154]: 95.78.118.23:48612 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
Feb 27 13:02:14 www ovpn-server1[23154]: 95.78.118.23:48612 [164410db-b350-4a2b-bf89-8bcdaa5ead29] Peer Connection Initiated with [AF_INET]95.78.118.23:48612
Feb 27 13:02:14 www ovpn-server1[23154]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 MULTI_sva: pool returned IPv4=10.9.2.2, IPv6=(Not enabled)
Feb 27 13:02:14 www ovpn-server1[23154]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 MULTI: Learn: 10.9.2.2 -> 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612
Feb 27 13:02:14 www ovpn-server1[23154]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 MULTI: primary virtual IP for 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612: 10.9.2.2
Feb 27 13:02:16 www ovpn-server1[23154]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 PUSH: Received control message: 'PUSH_REQUEST'
Feb 27 13:02:16 www ovpn-server1[23154]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 send_push_reply(): safe_cap=940
Feb 27 13:02:16 www ovpn-server1[23154]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 SENT CONTROL [164410db-b350-4a2b-bf89-8bcdaa5ead29]: 'PUSH_REPLY,route 10.8.0.0 255.255.0.0,route 10.9.0.1,topology net30,ping 10,ping-restart 120,ifconfig 10.9.2.2 10.9.2.1' (status=1)


Here is server restart occurs (notice PID change)

Mar 1 10:04:41 www ovpn-server1[7334]: 95.78.118.23:48612 TLS: Initial packet from [AF_INET]95.78.118.23:48612, sid=eb5f5a98 9fd247dc
Mar 1 10:04:42 www ovpn-server1[7334]: 95.78.118.23:48612 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
Mar 1 10:04:42 www ovpn-server1[7334]: 95.78.118.23:48612 VERIFY OK: depth=1, C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
Mar 1 10:04:42 www ovpn-server1[7334]: 95.78.118.23:48612 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=164410db-b350-4a2b-bf89-8bcdaa5ead29
Mar 1 10:04:42 www ovpn-server1[7334]: 95.78.118.23:48612 VERIFY OK: depth=0, C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=164410db-b350-4a2b-bf89-8bcdaa5ead29
Mar 1 10:04:42 www ovpn-server1[7334]: 95.78.118.23:48612 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mar 1 10:04:42 www ovpn-server1[7334]: 95.78.118.23:48612 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar 1 10:04:42 www ovpn-server1[7334]: 95.78.118.23:48612 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mar 1 10:04:42 www ovpn-server1[7334]: 95.78.118.23:48612 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar 1 10:04:42 www ovpn-server1[7334]: 95.78.118.23:48612 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
Mar 1 10:04:42 www ovpn-server1[7334]: 95.78.118.23:48612 [164410db-b350-4a2b-bf89-8bcdaa5ead29] Peer Connection Initiated with [AF_INET]95.78.118.23:48612
Mar 1 10:04:42 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 MULTI_sva: pool returned IPv4=10.9.0.70, IPv6=(Not enabled)
Mar 1 10:04:42 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 MULTI: Learn: 10.9.0.70 -> 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612


New address assigned

Mar 1 10:04:42 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 MULTI: primary virtual IP for 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612: 10.9.0.70
Mar 1 10:04:43 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 TLS Error: local/remote TLS keys are out of sync: [AF_INET]95.78.118.23:48612 [2]
Mar 1 10:04:53 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 TLS Error: local/remote TLS keys are out of sync: [AF_INET]95.78.118.23:48612 [2]
Mar 1 10:05:03 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 TLS Error: local/remote TLS keys are out of sync: [AF_INET]95.78.118.23:48612 [2]
Mar 1 10:05:07 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 TLS Error: local/remote TLS keys are out of sync: [AF_INET]95.78.118.23:48612 [2]


Another client connecting

Mar 1 10:05:16 www ovpn-server1[7334]: 78.138.130.196:45610 TLS: Initial packet from [AF_INET]78.138.130.196:45610, sid=e4100959 332f4832
Mar 1 10:05:17 www ovpn-server1[7334]: 78.138.130.196:45610 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
Mar 1 10:05:17 www ovpn-server1[7334]: 78.138.130.196:45610 VERIFY OK: depth=1, C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
Mar 1 10:05:17 www ovpn-server1[7334]: 78.138.130.196:45610 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=5569482b-9569-4356-8699-dbc210fbafe9
Mar 1 10:05:17 www ovpn-server1[7334]: 78.138.130.196:45610 VERIFY OK: depth=0, C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=5569482b-9569-4356-8699-dbc210fbafe9

Mar 1 10:05:17 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 TLS Error: local/remote TLS keys are out of sync: [AF_INET]95.78.118.23:48612 [2]
Mar 1 10:05:17 www ovpn-server1[7334]: 78.138.130.196:45610 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mar 1 10:05:17 www ovpn-server1[7334]: 78.138.130.196:45610 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar 1 10:05:17 www ovpn-server1[7334]: 78.138.130.196:45610 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mar 1 10:05:17 www ovpn-server1[7334]: 78.138.130.196:45610 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar 1 10:05:17 www ovpn-server1[7334]: 78.138.130.196:45610 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
Mar 1 10:05:17 www ovpn-server1[7334]: 78.138.130.196:45610 [5569482b-9569-4356-8699-dbc210fbafe9] Peer Connection Initiated with [AF_INET]78.138.130.196:45610
Mar 1 10:05:17 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 MULTI_sva: pool returned IPv4=10.9.2.2, IPv6=(Not enabled)
Mar 1 10:05:17 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 MULTI: Learn: 10.9.2.2 -> 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610


The original IP of first client assigned to another client

Mar 1 10:05:17 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 MULTI: primary virtual IP for 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610: 10.9.2.2
Mar 1 10:05:20 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 PUSH: Received control message: 'PUSH_REQUEST'
Mar 1 10:05:20 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 send_push_reply(): safe_cap=940
Mar 1 10:05:20 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 SENT CONTROL [5569482b-9569-4356-8699-dbc210fbafe9]: 'PUSH_REPLY,route 10.8.0.0 255.255.0.0,route 10.9.0.1,topology net30,ping 10,ping-restart 120,ifconfig 10.9.2.2 10.9.2.1' (status=1)

Mar 1 10:05:27 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 TLS Error: local/remote TLS keys are out of sync: [AF_INET]95.78.118.23:48612 [2]
Mar 1 10:05:37 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 TLS Error: local/remote TLS keys are out of sync: [AF_INET]95.78.118.23:48612 [2]
Mar 1 11:04:42 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 TLS: soft reset sec=0 bytes=179912/0 pkts=1939/0
Mar 1 11:04:43 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
Mar 1 11:04:43 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 VERIFY OK: depth=1, C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
Mar 1 11:04:43 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=164410db-b350-4a2b-bf89-8bcdaa5ead29
Mar 1 11:04:43 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 VERIFY OK: depth=0, C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=164410db-b350-4a2b-bf89-8bcdaa5ead29
Mar 1 11:04:43 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mar 1 11:04:43 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar 1 11:04:43 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mar 1 11:04:43 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar 1 11:04:43 www ovpn-server1[7334]: 164410db-b350-4a2b-bf89-8bcdaa5ead29/95.78.118.23:48612 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA

Mar 1 11:05:17 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 TLS: soft reset sec=0 bytes=47257/0 pkts=740/0
Mar 1 11:05:18 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
Mar 1 11:05:18 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 VERIFY OK: depth=1, C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
Mar 1 11:05:18 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=5569482b-9569-4356-8699-dbc210fbafe9
Mar 1 11:05:18 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 VERIFY OK: depth=0, C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=5569482b-9569-4356-8699-dbc210fbafe9
Mar 1 11:05:19 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mar 1 11:05:19 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar 1 11:05:19 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mar 1 11:05:19 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar 1 11:05:19 www ovpn-server1[7334]: 5569482b-9569-4356-8699-dbc210fbafe9/78.138.130.196:45610 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA


Here is what's going on at the client side:

Mar 1 10:03:25 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: TLS: tls_process: killed expiring key
Mar 1 10:03:26 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: TLS: soft reset sec=0 bytes=2052286/0 pkts=5351/0
Mar 1 10:04:26 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Mar 1 10:04:26 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: TLS Error: TLS handshake failed
Mar 1 10:04:26 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Mar 1 10:04:41 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: TLS: Initial packet from [AF_INET]1.2.3.4:1201, sid=84d60c59 061713e6
Mar 1 10:04:41 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: VERIFY OK: depth=1, C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
Mar 1 10:04:41 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: VERIFY OK: nsCertType=SERVER
Mar 1 10:04:41 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: VERIFY OK: depth=0, C=[hidden], L=[hidden], O=[hidden], CN=server, emailAddress=[hidden]
Mar 1 10:04:42 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mar 1 10:04:42 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar 1 10:04:42 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mar 1 10:04:42 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar 1 10:04:42 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
Mar 1 11:03:26 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: TLS: tls_multi_process: killed expiring key
Mar 1 11:04:42 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: VERIFY OK: depth=1, C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
Mar 1 11:04:42 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: VERIFY OK: nsCertType=SERVER
Mar 1 11:04:42 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: VERIFY OK: depth=0, C=[hidden], L=[hidden], O=[hidden], CN=server, emailAddress=[hidden]
Mar 1 11:04:43 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mar 1 11:04:43 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar 1 11:04:43 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mar 1 11:04:43 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar 1 11:04:43 164410db-b350-4a2b-bf89-8bcdaa5ead29 ovpn-client[3453]: Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA

The IP address at the client is not changed and data packets stop transmitting & receiving. IP remains 10.9.2.2 until I manually restart openvpn at the client.

Here is my server config:

proto udp
port 1201
dev tun1
server 10.9.0.0 255.255.0.0
push "route 10.8.0.0 255.255.0.0"
ca ca.crt
cert server.crt
key server.key
dh dh2048.pem
keepalive 10 120
comp-lzo
fragment 1200
mssfix 1200
txqueuelen 1000
user nobody
group nogroup
persist-key
persist-tun
verb 3
client-config-dir ccd
crl-verify crl.pem
max-clients 2048

And here is the client config:

client
dev tun0
proto udp
remote 1.2.3.4 1201
remote-random
resolv-retry infinite
nobind
persist-key
persist-tun
ca ca.crt
cert client.crt
key client.key
ns-cert-type server
comp-lzo
verb 3
mssfix 1200
fragment 1200

What can I try to resolve the issue?

User avatar
maikcat
Forum Team
Posts: 4200
Joined: Wed Jan 12, 2011 9:23 am
Location: Athens,Greece
Contact:

Re: problem after server restart - client doesn't accept new

Post by maikcat » Tue Mar 03, 2015 5:39 pm

post your ccd files contents,
are both clients use the same cert?if not post the contents of their ccd file.

Michael.

leshik
OpenVpn Newbie
Posts: 11
Joined: Tue Mar 03, 2015 3:21 pm

Re: problem after server restart - client doesn't accept new

Post by leshik » Tue Mar 03, 2015 5:47 pm

The ccd dir is empty.
Certs are different (please, notice that CNs are different).
There is no ccd at client side also.

User avatar
maikcat
Forum Team
Posts: 4200
Joined: Wed Jan 12, 2011 9:23 am
Location: Athens,Greece
Contact:

Re: problem after server restart - client doesn't accept new

Post by maikcat » Wed Mar 04, 2015 7:05 am

what version are you using on client/server?

Michael.

leshik
OpenVpn Newbie
Posts: 11
Joined: Tue Mar 03, 2015 3:21 pm

Re: problem after server restart - client doesn't accept new

Post by leshik » Wed Mar 04, 2015 10:25 am

Ah, I'm sorry that I forgot to include system & version information.
This is openvpn 2.3.2 on ubuntu 14.04 server side and on ubuntu 13.10 client side. Both are 64-bit versions.

User avatar
maikcat
Forum Team
Posts: 4200
Joined: Wed Jan 12, 2011 9:23 am
Location: Athens,Greece
Contact:

Re: problem after server restart - client doesn't accept new

Post by maikcat » Wed Mar 04, 2015 11:56 am

can you post the same logs using verb 4?

you can also try to use ifconfig-pool-persist but avoid it for now.

Michael.

leshik
OpenVpn Newbie
Posts: 11
Joined: Tue Mar 03, 2015 3:21 pm

Re: problem after server restart - client doesn't accept new

Post by leshik » Wed Mar 04, 2015 12:20 pm

I set verb 4 and will post here as soon as there will be enough statistics.
As for ifconfig-pool-persist, I don't use it intentionally as it's "unreliable" (in the sense that stated in man page - "entries in this file are treated by OpenVPN as suggestions only").

User avatar
maikcat
Forum Team
Posts: 4200
Joined: Wed Jan 12, 2011 9:23 am
Location: Athens,Greece
Contact:

Re: problem after server restart - client doesn't accept new

Post by maikcat » Wed Mar 04, 2015 1:36 pm

thats why i said "avoid it for now" ;)

Michael.

leshik
OpenVpn Newbie
Posts: 11
Joined: Tue Mar 03, 2015 3:21 pm

Re: problem after server restart - client doesn't accept new

Post by leshik » Sat May 30, 2015 1:01 pm

Hi,

Encountered this bug again, now with verb 4. The case is very similar.

This is the initial connection by 1-st client (note it's IP address 10.9.3.70)

May 29 09:59:53 www ovpn-server1[21681]: 89.151.172.78:10002 Re-using SSL/TLS context
May 29 09:59:53 www ovpn-server1[21681]: 89.151.172.78:10002 LZO compression initialized
May 29 09:59:53 www ovpn-server1[21681]: 89.151.172.78:10002 Control Channel MTU parms [ L:1546 D:138 EF:38 EB:0 ET:0 EL:0 ]
May 29 09:59:53 www ovpn-server1[21681]: 89.151.172.78:10002 Data Channel MTU parms [ L:1546 D:1200 EF:46 EB:135 ET:0 EL:0 AF:3/1 ]
May 29 09:59:53 www ovpn-server1[21681]: 89.151.172.78:10002 Fragmentation MTU parms [ L:1546 D:1200 EF:45 EB:135 ET:1 EL:0 AF:3/1 ]
May 29 09:59:53 www ovpn-server1[21681]: 89.151.172.78:10002 Local Options String: 'V4,dev-type tun,link-mtu 1546,tun-mtu 1500,proto UDPv4,comp-lzo,mtu-dynamic,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
May 29 09:59:53 www ovpn-server1[21681]: 89.151.172.78:10002 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1546,tun-mtu 1500,proto UDPv4,comp-lzo,mtu-dynamic,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
May 29 09:59:53 www ovpn-server1[21681]: 89.151.172.78:10002 Local Options hash (VER=V4): '8e7959c7'
May 29 09:59:53 www ovpn-server1[21681]: 89.151.172.78:10002 Expected Remote Options hash (VER=V4): 'c086e1aa'
May 29 09:59:53 www ovpn-server1[21681]: 89.151.172.78:10002 TLS: Initial packet from [AF_INET]89.151.172.78:10002, sid=48c7d4e6 d6477d7d
May 29 09:59:55 www ovpn-server1[21681]: 89.151.172.78:10002 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
May 29 09:59:55 www ovpn-server1[21681]: 89.151.172.78:10002 VERIFY OK: depth=1, C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
May 29 09:59:55 www ovpn-server1[21681]: 89.151.172.78:10002 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=69bd6a89-aeaf-4d10-bf74-0e53facb9d69
May 29 09:59:55 www ovpn-server1[21681]: 89.151.172.78:10002 VERIFY OK: depth=0, C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=69bd6a89-aeaf-4d10-bf74-0e53facb9d69
May 29 09:59:56 www ovpn-server1[21681]: 89.151.172.78:10002 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
May 29 09:59:56 www ovpn-server1[21681]: 89.151.172.78:10002 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
May 29 09:59:56 www ovpn-server1[21681]: 89.151.172.78:10002 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
May 29 09:59:56 www ovpn-server1[21681]: 89.151.172.78:10002 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
May 29 09:59:56 www ovpn-server1[21681]: 89.151.172.78:10002 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
May 29 09:59:56 www ovpn-server1[21681]: 89.151.172.78:10002 [69bd6a89-aeaf-4d10-bf74-0e53facb9d69] Peer Connection Initiated with [AF_INET]89.151.172.78:10002
May 29 09:59:56 www ovpn-server1[21681]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:10002 MULTI_sva: pool returned IPv4=10.9.3.70, IPv6=(Not enabled)
May 29 09:59:56 www ovpn-server1[21681]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:10002 MULTI: Learn: 10.9.3.70 -> 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:10002
May 29 09:59:56 www ovpn-server1[21681]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:10002 MULTI: primary virtual IP for 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:10002: 10.9.3.70
May 29 09:59:58 www ovpn-server1[21681]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:10002 PUSH: Received control message: 'PUSH_REQUEST'
May 29 09:59:58 www ovpn-server1[21681]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:10002 send_push_reply(): safe_cap=940
May 29 09:59:58 www ovpn-server1[21681]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:10002 SENT CONTROL [69bd6a89-aeaf-4d10-bf74-0e53facb9d69]: 'PUSH_REPLY,route 10.8.0.0 255.255.0.0,route 91.189.94.4 255.255.255.255,route 91.189.89.199 255.255.255.255,route 194.186.207.162 255.255.255.255,route 10.9.0.1,topology net30,ping 10,ping-restart 120,ifconfig 10.9.3.70 10.9.3.69' (status=1)


Here is server restart occurs (notice PID change)

May 30 04:01:59 www ovpn-server1[6896]: 89.151.172.78:21430 Re-using SSL/TLS context
May 30 04:01:59 www ovpn-server1[6896]: 89.151.172.78:21430 LZO compression initialized
May 30 04:01:59 www ovpn-server1[6896]: 89.151.172.78:21430 Control Channel MTU parms [ L:1546 D:138 EF:38 EB:0 ET:0 EL:0 ]
May 30 04:01:59 www ovpn-server1[6896]: 89.151.172.78:21430 Data Channel MTU parms [ L:1546 D:1200 EF:46 EB:135 ET:0 EL:0 AF:3/1 ]
May 30 04:01:59 www ovpn-server1[6896]: 89.151.172.78:21430 Fragmentation MTU parms [ L:1546 D:1200 EF:45 EB:135 ET:1 EL:0 AF:3/1 ]
May 30 04:01:59 www ovpn-server1[6896]: 89.151.172.78:21430 Local Options String: 'V4,dev-type tun,link-mtu 1546,tun-mtu 1500,proto UDPv4,comp-lzo,mtu-dynamic,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
May 30 04:01:59 www ovpn-server1[6896]: 89.151.172.78:21430 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1546,tun-mtu 1500,proto UDPv4,comp-lzo,mtu-dynamic,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
May 30 04:01:59 www ovpn-server1[6896]: 89.151.172.78:21430 Local Options hash (VER=V4): '8e7959c7'
May 30 04:01:59 www ovpn-server1[6896]: 89.151.172.78:21430 Expected Remote Options hash (VER=V4): 'c086e1aa'
May 30 04:01:59 www ovpn-server1[6896]: 89.151.172.78:21430 TLS: Initial packet from [AF_INET]89.151.172.78:21430, sid=2e03d667 4ec4a92f
May 30 04:02:01 www ovpn-server1[6896]: 89.151.172.78:21430 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
May 30 04:02:01 www ovpn-server1[6896]: 89.151.172.78:21430 VERIFY OK: depth=1, C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
May 30 04:02:01 www ovpn-server1[6896]: 89.151.172.78:21430 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=69bd6a89-aeaf-4d10-bf74-0e53facb9d69
May 30 04:02:01 www ovpn-server1[6896]: 89.151.172.78:21430 VERIFY OK: depth=0, C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=69bd6a89-aeaf-4d10-bf74-0e53facb9d69
May 30 04:02:01 www ovpn-server1[6896]: 89.151.172.78:21430 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
May 30 04:02:01 www ovpn-server1[6896]: 89.151.172.78:21430 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
May 30 04:02:01 www ovpn-server1[6896]: 89.151.172.78:21430 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
May 30 04:02:01 www ovpn-server1[6896]: 89.151.172.78:21430 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
May 30 04:02:01 www ovpn-server1[6896]: 89.151.172.78:21430 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
May 30 04:02:01 www ovpn-server1[6896]: 89.151.172.78:21430 [69bd6a89-aeaf-4d10-bf74-0e53facb9d69] Peer Connection Initiated with [AF_INET]89.151.172.78:21430
May 30 04:02:01 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 MULTI_sva: pool returned IPv4=10.9.0.242, IPv6=(Not enabled)
May 30 04:02:01 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 MULTI: Learn: 10.9.0.242 -> 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430


New address assigned

May 30 04:02:01 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 MULTI: primary virtual IP for 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430: 10.9.0.242

Another client connecting

May 30 04:02:04 www ovpn-server1[6896]: 188.133.184.6:50152 Re-using SSL/TLS context
May 30 04:02:04 www ovpn-server1[6896]: 188.133.184.6:50152 LZO compression initialized
May 30 04:02:04 www ovpn-server1[6896]: 188.133.184.6:50152 Control Channel MTU parms [ L:1546 D:138 EF:38 EB:0 ET:0 EL:0 ]
May 30 04:02:04 www ovpn-server1[6896]: 188.133.184.6:50152 Data Channel MTU parms [ L:1546 D:1200 EF:46 EB:135 ET:0 EL:0 AF:3/1 ]
May 30 04:02:04 www ovpn-server1[6896]: 188.133.184.6:50152 Fragmentation MTU parms [ L:1546 D:1200 EF:45 EB:135 ET:1 EL:0 AF:3/1 ]
May 30 04:02:04 www ovpn-server1[6896]: 188.133.184.6:50152 Local Options String: 'V4,dev-type tun,link-mtu 1546,tun-mtu 1500,proto UDPv4,comp-lzo,mtu-dynamic,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
May 30 04:02:04 www ovpn-server1[6896]: 188.133.184.6:50152 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1546,tun-mtu 1500,proto UDPv4,comp-lzo,mtu-dynamic,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
May 30 04:02:04 www ovpn-server1[6896]: 188.133.184.6:50152 Local Options hash (VER=V4): '8e7959c7'
May 30 04:02:04 www ovpn-server1[6896]: 188.133.184.6:50152 Expected Remote Options hash (VER=V4): 'c086e1aa'
May 30 04:02:04 www ovpn-server1[6896]: 188.133.184.6:50152 TLS: Initial packet from [AF_INET]188.133.184.6:50152, sid=444dad21 593d95fa
May 30 04:02:11 www ovpn-server1[6896]: 188.133.184.6:50152 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
May 30 04:02:11 www ovpn-server1[6896]: 188.133.184.6:50152 VERIFY OK: depth=1, C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
May 30 04:02:11 www ovpn-server1[6896]: 188.133.184.6:50152 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=8cde99a0-be9d-422b-8c6a-753095c5df87
May 30 04:02:11 www ovpn-server1[6896]: 188.133.184.6:50152 VERIFY OK: depth=0, C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=8cde99a0-be9d-422b-8c6a-753095c5df87

May 30 04:02:11 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 TLS Error: local/remote TLS keys are out of sync: [AF_INET]89.151.172.78:21430 [3]
May 30 04:02:12 www ovpn-server1[6896]: 188.133.184.6:50152 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
May 30 04:02:12 www ovpn-server1[6896]: 188.133.184.6:50152 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
May 30 04:02:12 www ovpn-server1[6896]: 188.133.184.6:50152 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
May 30 04:02:12 www ovpn-server1[6896]: 188.133.184.6:50152 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
May 30 04:02:12 www ovpn-server1[6896]: 188.133.184.6:50152 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
May 30 04:02:12 www ovpn-server1[6896]: 188.133.184.6:50152 [8cde99a0-be9d-422b-8c6a-753095c5df87] Peer Connection Initiated with [AF_INET]188.133.184.6:50152
May 30 04:02:12 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 MULTI_sva: pool returned IPv4=10.9.3.70, IPv6=(Not enabled)
May 30 04:02:12 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 MULTI: Learn: 10.9.3.70 -> 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152


The original IP of first client assigned to another client

May 30 04:02:12 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 MULTI: primary virtual IP for 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152: 10.9.3.70
May 30 04:02:14 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 PUSH: Received control message: 'PUSH_REQUEST'
May 30 04:02:14 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 send_push_reply(): safe_cap=940
May 30 04:02:14 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 SENT CONTROL [8cde99a0-be9d-422b-8c6a-753095c5df87]: 'PUSH_REPLY,route 10.8.0.0 255.255.0.0,route 91.189.94.4 255.255.255.255,route 91.189.89.199 255.255.255.255,route 194.186.207.162 255.255.255.255,route 10.9.0.1,topology net30,ping 10,ping-restart 120,ifconfig 10.9.3.70 10.9.3.69' (status=1)

May 30 04:02:14 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 TLS Error: local/remote TLS keys are out of sync: [AF_INET]89.151.172.78:21430 [3]
May 30 04:02:15 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 TLS Error: local/remote TLS keys are out of sync: [AF_INET]89.151.172.78:21430 [3]
May 30 04:02:17 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 TLS Error: local/remote TLS keys are out of sync: [AF_INET]89.151.172.78:21430 [3]
May 30 04:02:21 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 TLS Error: local/remote TLS keys are out of sync: [AF_INET]89.151.172.78:21430 [3]
May 30 04:02:29 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 TLS Error: local/remote TLS keys are out of sync: [AF_INET]89.151.172.78:21430 [3]
May 30 04:02:39 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 TLS Error: local/remote TLS keys are out of sync: [AF_INET]89.151.172.78:21430 [3]
May 30 04:02:45 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 TLS Error: local/remote TLS keys are out of sync: [AF_INET]89.151.172.78:21430 [3]
May 30 04:02:55 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 TLS Error: local/remote TLS keys are out of sync: [AF_INET]89.151.172.78:21430 [3]
May 30 04:03:17 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 MULTI: bad source address from client [10.9.3.70], packet dropped
May 30 04:03:17 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 MULTI: bad source address from client [10.9.3.70], packet dropped
May 30 04:04:21 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 MULTI: bad source address from client [10.9.3.70], packet dropped
May 30 04:04:22 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 MULTI: bad source address from client [10.9.3.70], packet dropped
May 30 04:04:24 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 MULTI: bad source address from client [10.9.3.70], packet dropped


... etc. (this message lasts forever until the client gets killed)

May 30 05:02:12 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 TLS: soft reset sec=0 bytes=2799031/0 pkts=6706/0
May 30 05:02:14 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
May 30 05:02:14 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 VERIFY OK: depth=1, C=[hidden], L=[hidden], O=[hidden], CN=[hidden], emailAddress=[hidden]
May 30 05:02:14 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 CRL CHECK OK: C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=8cde99a0-be9d-422b-8c6a-753095c5df87
May 30 05:02:14 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 VERIFY OK: depth=0, C=[hidden], L=[hidden], O=[hidden], OU=[hidden], CN=8cde99a0-be9d-422b-8c6a-753095c5df87
May 30 05:02:14 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
May 30 05:02:14 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
May 30 05:02:14 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
May 30 05:02:14 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
May 30 05:02:14 www ovpn-server1[6896]: 8cde99a0-be9d-422b-8c6a-753095c5df87/188.133.184.6:50152 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA


As usual, there is nothing special in logs at the client side.

User avatar
Traffic
OpenVPN Protagonist
Posts: 4066
Joined: Sat Aug 09, 2014 11:24 am

Re: problem after server restart - client doesn't accept new

Post by Traffic » Sat May 30, 2015 5:31 pm

leshik wrote:... etc. (this message lasts forever until the client gets killed)
This one:
leshik wrote:May 30 04:02:39 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 TLS Error: local/remote TLS keys are out of sync: [AF_INET]89.151.172.78:21430 [3]
or this one:
leshik wrote:May 30 04:03:17 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 MULTI: bad source address from client [10.9.3.70], packet dropped
:?:

leshik
OpenVpn Newbie
Posts: 11
Joined: Tue Mar 03, 2015 3:21 pm

Re: problem after server restart - client doesn't accept new

Post by leshik » Sat May 30, 2015 6:07 pm

leshik wrote:May 30 04:03:17 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 MULTI: bad source address from client [10.9.3.70], packet dropped
This one.

User avatar
Traffic
OpenVPN Protagonist
Posts: 4066
Joined: Sat Aug 09, 2014 11:24 am

Re: problem after server restart - client doesn't accept new

Post by Traffic » Sat May 30, 2015 7:17 pm

maikcat wrote:post the contents of their ccd file
leshik wrote:The ccd dir is empty
leshik wrote:MULTI: bad source address from client [10.9.3.70], packet dropped
leshik wrote:This one
You need to utilize your CCD files correctly.

https://community.openvpn.net/openvpn/w ... rt-failedq

https://openvpn.net/index.php/open-sour ... html#scope

leshik
OpenVpn Newbie
Posts: 11
Joined: Tue Mar 03, 2015 3:21 pm

Re: problem after server restart - client doesn't accept new

Post by leshik » Mon Jun 01, 2015 8:12 am

Traffic wrote:You need to utilize your CCD files correctly.
What do you mean by "utilizing correctly"? I don't use them at all. Everything works until server restarted by monit because of memory leak. After that *some* clients (no different than others) fail to obtain new address while server give their addresses to others.

User avatar
Traffic
OpenVPN Protagonist
Posts: 4066
Joined: Sat Aug 09, 2014 11:24 am

Re: problem after server restart - client doesn't accept new

Post by Traffic » Mon Jun 01, 2015 9:45 am

leshik wrote:fail to obtain new address while server give their addresses to others
if you want fixed VPN IP addresses for your clients you need to use --ifconfig-push in your CCD files.

leshik
OpenVpn Newbie
Posts: 11
Joined: Tue Mar 03, 2015 3:21 pm

Re: problem after server restart - client doesn't accept new

Post by leshik » Mon Jun 01, 2015 9:50 am

Traffic wrote:
leshik wrote:fail to obtain new address while server give their addresses to others
if you want fixed VPN IP addresses for your clients you need to use --ifconfig-push in your CCD files.
I don't want fixed VPN adresses. I want server to not assign already used addresses. Or (as should be done in this situation, since new server instance has no knowledge of already assigned IPs), at least, that client could figure out that situation and renegotiate new address (or reconnect) instead of silently presuming that nothing has changed.

User avatar
Traffic
OpenVPN Protagonist
Posts: 4066
Joined: Sat Aug 09, 2014 11:24 am

Re: problem after server restart - client doesn't accept new

Post by Traffic » Mon Jun 01, 2015 10:19 am

See --ifconfig-pool-persist in The Manual v23x

Note:
  • The Manual wrote:entries in this file are treated by OpenVPN as suggestions only, based on past associations between a common name and IP address. They do not guarantee that the given common name will always receive the given IP address. If you want guaranteed assignment, use --ifconfig-push
Bear in mind .. OpenVPN is Free Open Source Software and as such is a work in progress and makes no claims of suitability:
  • License.txt wrote:NO WARRANTY

    11. BECAUSE THE PROGRAM IS LICENSED FREE OF CHARGE, THERE IS NO WARRANTY
    FOR THE PROGRAM, TO THE EXTENT PERMITTED BY APPLICABLE LAW. EXCEPT WHEN
    OTHERWISE STATED IN WRITING THE COPYRIGHT HOLDERS AND/OR OTHER PARTIES
    PROVIDE THE PROGRAM "AS IS" WITHOUT WARRANTY OF ANY KIND, EITHER EXPRESSED
    OR IMPLIED, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES OF
    MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE. THE ENTIRE RISK AS
    TO THE QUALITY AND PERFORMANCE OF THE PROGRAM IS WITH YOU. SHOULD THE
    PROGRAM PROVE DEFECTIVE, YOU ASSUME THE COST OF ALL NECESSARY SERVICING,
    REPAIR OR CORRECTION.
The point being .. some things don't work very well as they are still in development.

Also, in order to resolve this issue:
leshik wrote:leshik wrote:
May 30 04:03:17 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 MULTI: bad source address from client [10.9.3.70], packet dropped

This one.
you must use --iroute in CCD files ..

leshik
OpenVpn Newbie
Posts: 11
Joined: Tue Mar 03, 2015 3:21 pm

Re: problem after server restart - client doesn't accept new

Post by leshik » Mon Jun 01, 2015 10:35 am

Traffic wrote:See --ifconfig-pool-persist in The Manual v23x
I don't use this option entirely due to the statement in manual you quoted :)
Traffic wrote:Bear in mind .. OpenVPN is Free Open Source Software and as such is a work in progress and makes no claims of suitability
...
The point being .. some things don't work very well as they are still in development.
I fully understand that and I don't request any support. I'm just reporting the bug and hope that developers will fix it in the future. If this forum is wrong place to report bugs, please direct me to the right place.
Traffic wrote:Also, in order to resolve this issue:
leshik wrote:leshik wrote:
May 30 04:03:17 www ovpn-server1[6896]: 69bd6a89-aeaf-4d10-bf74-0e53facb9d69/89.151.172.78:21430 MULTI: bad source address from client [10.9.3.70], packet dropped

This one.
you must use --iroute in CCD files ..
It's surely unfeasible to use and maintain the database of CCD files for my setup of ~3000 nodes. I'd rather write a server-side script that would ping clients once in 5 min then kill stalled ones via management interface.
However, I hope the bug will be fixed someday.

User avatar
Traffic
OpenVPN Protagonist
Posts: 4066
Joined: Sat Aug 09, 2014 11:24 am

Re: problem after server restart - client doesn't accept new

Post by Traffic » Mon Jun 01, 2015 11:00 am

leshik wrote:It's surely unfeasible to use and maintain the database of CCD files for my setup of ~3000 nodes
in that case [presumably] you are not interested in the client LANs and so having the server drop these packets is suitable. There is no way for you to manage ~3000 remote firewalls.
leshik wrote:I'm just reporting the bug and hope that developers will fix it in the future. If this forum is wrong place to report bugs, please direct me to the right place.
The right place to report a bug is:
https://community.openvpn.net/openvpn/newticket
(*Login required*)

To view a list of reported bugs:
https://community.openvpn.net/openvpn/report
(*Anonymous browse available*)

leshik
OpenVpn Newbie
Posts: 11
Joined: Tue Mar 03, 2015 3:21 pm

Re: problem after server restart - client doesn't accept new

Post by leshik » Mon Jun 01, 2015 11:07 am

Traffic wrote:
leshik wrote:It's surely unfeasible to use and maintain the database of CCD files for my setup of ~3000 nodes
in that case [presumably] you are not interested in the client LANs and so having the server drop these packets is suitable. There is no way for you to manage ~3000 remote firewalls.
Absolutely. I only need connectivity to nodes themselves, for them to exchange information with the server and for remote management purpose. The problem here is that it's not LAN IP is dropped, but client tun0 interface IP address!
Traffic wrote:
leshik wrote:I'm just reporting the bug and hope that developers will fix it in the future. If this forum is wrong place to report bugs, please direct me to the right place.
The right place to report a bug is:
https://community.openvpn.net/openvpn/newticket
(*Login required*)

To view a list of reported bugs:
https://community.openvpn.net/openvpn/report
(*Anonymous browse available*)
Ok, thank you. I'll report there.

User avatar
Traffic
OpenVPN Protagonist
Posts: 4066
Joined: Sat Aug 09, 2014 11:24 am

Re: problem after server restart - client doesn't accept new

Post by Traffic » Mon Jun 01, 2015 11:29 am

Not sure you actually have a bug though ..

You have ~3000 clients but you also use certs and keys .. so have you issued ~3000 certs and keys ? If so managing ~3000 CCD files is not that difficult. If your clients share certs/keys then you probably need to use --duplicate-cn in your server config.

Also, add --push "explicit-exit-notify 3" to your server config .. this may help the server keep track of clients.

Post Reply