[SOLVED] Openvpn clients random disconnect and cannot connect again.

kokoko3k · 2017-01-10 16:53:46

I run openvpn on my raspberry pi (arch arm) and on another archlinux system, both as a client .
AND
openvpn on my archlinux server installation.

Since i updated openvpn on the server to 2.4.0, clients random disconnects and never came up again, a restart of the service is needed.
What came up in the log (both arch arm and archlinux install) is the following:

# systemctl status openvpn@gozer-server
● openvpn@gozer-server.service - OpenVPN connection to gozer-server
   Loaded: loaded (/usr/lib/systemd/system/openvpn@.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since lun 2017-01-09 21:34:32 CET; 20h ago
  Process: 31714 ExecStart=/usr/bin/openvpn --cd /etc/openvpn --config /etc/openvpn/%i.conf --daemon openvpn@%i --writepid /run/openvpn@%i.pid --status-
 Main PID: 31717 (code=exited, status=1/FAILURE)

gen 09 21:34:31 pi openvpn@gozer-server[31717]: OPTIONS IMPORT: peer-id set
gen 09 21:34:31 pi openvpn@gozer-server[31717]: OPTIONS IMPORT: adjusting link_mtu to 1545
gen 09 21:34:31 pi openvpn@gozer-server[31717]: Preserving previous TUN/TAP instance: tun0
gen 09 21:34:31 pi openvpn@gozer-server[31717]: NOTE: Pulled options changed on restart, will need to close and reopen TUN/TAP device.
gen 09 21:34:31 pi openvpn@gozer-server[31717]: Closing TUN/TAP interface
gen 09 21:34:31 pi openvpn@gozer-server[31717]: /usr/bin/ip addr del dev tun0 192.168.8.2/24
gen 09 21:34:31 pi openvpn@gozer-server[31717]: Linux ip addr del failed: external program exited with error status: 2
gen 09 21:34:32 pi systemd[1]: openvpn@gozer-server.service: Main process exited, code=exited, status=1/FAILURE
gen 09 21:34:32 pi systemd[1]: openvpn@gozer-server.service: Unit entered failed state.
gen 09 21:34:32 pi systemd[1]: openvpn@gozer-server.service: Failed with result 'exit-code'.

Journalctl on the client says:

gen 09 21:30:49 pi openvpn@gozer-server[31717]: [Gozer] Inactivity timeout (--ping-restart), restarting
gen 09 21:30:49 pi openvpn@gozer-server[31717]: SIGUSR1[soft,ping-restart] received, process restarting
gen 09 21:30:49 pi openvpn@gozer-server[31717]: Restart pause, 2 second(s)
gen 09 21:30:51 pi openvpn@gozer-server[31717]: Socket Buffers: R=[163840->163840] S=[163840->163840]
gen 09 21:30:51 pi openvpn@gozer-server[31717]: UDPv4 link local: [undef]
gen 09 21:30:51 pi openvpn@gozer-server[31717]: UDPv4 link remote: [AF_INET]HIDDEN:HIDDEN
gen 09 21:31:51 pi openvpn@gozer-server[31717]: [UNDEF] Inactivity timeout (--ping-restart), restarting
gen 09 21:31:51 pi openvpn@gozer-server[31717]: SIGUSR1[soft,ping-restart] received, process restarting
gen 09 21:31:51 pi openvpn@gozer-server[31717]: Restart pause, 2 second(s)
gen 09 21:31:53 pi openvpn@gozer-server[31717]: Socket Buffers: R=[163840->163840] S=[163840->163840]
gen 09 21:31:53 pi openvpn@gozer-server[31717]: UDPv4 link local: [undef]
gen 09 21:31:53 pi openvpn@gozer-server[31717]: UDPv4 link remote: [AF_INET]HIDDEN:HIDDEN
gen 09 21:32:53 pi openvpn@gozer-server[31717]: [UNDEF] Inactivity timeout (--ping-restart), restarting
gen 09 21:32:53 pi openvpn@gozer-server[31717]: SIGUSR1[soft,ping-restart] received, process restarting
gen 09 21:32:53 pi openvpn@gozer-server[31717]: Restart pause, 2 second(s)
gen 09 21:32:55 pi openvpn@gozer-server[31717]: Socket Buffers: R=[163840->163840] S=[163840->163840]
gen 09 21:32:55 pi openvpn@gozer-server[31717]: UDPv4 link local: [undef]
gen 09 21:32:55 pi openvpn@gozer-server[31717]: UDPv4 link remote: [AF_INET]HIDDEN:HIDDEN
gen 09 21:33:55 pi openvpn@gozer-server[31717]: [UNDEF] Inactivity timeout (--ping-restart), restarting
gen 09 21:33:55 pi openvpn@gozer-server[31717]: SIGUSR1[soft,ping-restart] received, process restarting
gen 09 21:33:55 pi openvpn@gozer-server[31717]: Restart pause, 2 second(s)
gen 09 21:33:57 pi openvpn@gozer-server[31717]: Socket Buffers: R=[163840->163840] S=[163840->163840]
gen 09 21:33:57 pi openvpn@gozer-server[31717]: UDPv4 link local: [undef]
gen 09 21:33:57 pi openvpn@gozer-server[31717]: UDPv4 link remote: [AF_INET]HIDDEN:HIDDEN
gen 09 21:34:29 pi openvpn@gozer-server[31717]: TLS: Initial packet from [AF_INET]HIDDEN:HIDDEN, sid=5cc9dbd4 dccc1627
gen 09 21:34:29 pi openvpn@gozer-server[31717]: VERIFY OK: depth=1, C=it, ST=NA, L=Naples, O=None, CN=None CA, name=EasyRSA, emailAddress=whoknow@gmail.com
gen 09 21:34:29 pi openvpn@gozer-server[31717]: VERIFY OK: nsCertType=SERVER
gen 09 21:34:29 pi openvpn@gozer-server[31717]: VERIFY OK: depth=0, C=it, ST=NA, L=Naples, O=None, CN=Gozer, name=EasyRSA, emailAddress=whoknow@gmail.com
gen 09 21:34:29 pi openvpn@gozer-server[31717]: Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
gen 09 21:34:29 pi openvpn@gozer-server[31717]: Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
gen 09 21:34:29 pi openvpn@gozer-server[31717]: Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
gen 09 21:34:29 pi openvpn@gozer-server[31717]: Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
gen 09 21:34:29 pi openvpn@gozer-server[31717]: Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
gen 09 21:34:29 pi openvpn@gozer-server[31717]: [Gozer] Peer Connection Initiated with [AF_INET]HIDDEN:HIDDEN
gen 09 21:34:31 pi openvpn@gozer-server[31717]: SENT CONTROL [Gozer]: 'PUSH_REQUEST' (status=1)
gen 09 21:34:31 pi openvpn@gozer-server[31717]: PUSH: Received control message: 'PUSH_REPLY,ping 50,ping-restart 60,route-gateway 192.168.8.1,topology subnet,ifconfig 192.168.8.2 255.255.255.0,peer-id 5'
gen 09 21:34:31 pi openvpn@gozer-server[31717]: OPTIONS IMPORT: timers and/or timeouts modified
gen 09 21:34:31 pi openvpn@gozer-server[31717]: OPTIONS IMPORT: --ifconfig/up options modified
gen 09 21:34:31 pi openvpn@gozer-server[31717]: OPTIONS IMPORT: route-related options modified
gen 09 21:34:31 pi openvpn@gozer-server[31717]: OPTIONS IMPORT: peer-id set
gen 09 21:34:31 pi openvpn@gozer-server[31717]: OPTIONS IMPORT: adjusting link_mtu to 1545
gen 09 21:34:31 pi openvpn@gozer-server[31717]: Preserving previous TUN/TAP instance: tun0
gen 09 21:34:31 pi openvpn@gozer-server[31717]: NOTE: Pulled options changed on restart, will need to close and reopen TUN/TAP device.
gen 09 21:34:31 pi openvpn@gozer-server[31717]: Closing TUN/TAP interface
gen 09 21:34:31 pi openvpn@gozer-server[31717]: /usr/bin/ip addr del dev tun0 192.168.8.2/24
gen 09 21:34:31 pi openvpn@gozer-server[31717]: Linux ip addr del failed: external program exited with error status: 2
gen 09 21:34:32 pi openvpn@gozer-server[31717]: ERROR: Cannot ioctl TUNSETIFF tun: Operation not permitted (errno=1)
gen 09 21:34:32 pi systemd[1]: openvpn@gozer-server.service: Main process exited, code=exited, status=1/FAILURE
gen 09 21:34:32 pi openvpn@gozer-server[31717]: Exiting due to fatal error
gen 09 21:34:32 pi systemd[1]: openvpn@gozer-server.service: Unit entered failed state.
gen 09 21:34:32 pi systemd[1]: openvpn@gozer-server.service: Failed with result 'exit-code'.

Client configuration:

client
dev tun
proto udp
remote HIDDEN HIDDEN
remote HIDDEN HIDDEN
resolv-retry infinite
nobind
user nobody
group nobody
persist-key
persist-tun
ca /etc/openvpn/ca.crt
cert /etc/openvpn/CertificatoDiRiserva1.crt
key /etc/openvpn/CertificatoDiRiserva1.key
ns-cert-type server
tls-auth /etc/openvpn/ta.key 1
comp-lzo
verb 3
syslog openvpn@gozer-server
float
reneg-sec 0

Server configuration:

	port HIDDEN
	proto udp
dev tun
ca /etc/openvpn/keys/ca.crt
cert /etc/openvpn/keys/Gozer.crt
key /etc/openvpn/keys/Gozer.key  # This file should be kept secret
dh /etc/openvpn/keys/dh2048.pem
	topology subnet
	server 192.168.8.0 255.255.255.0
	ifconfig-pool-persist ipp.txt
client-to-client
tls-auth /etc/openvpn/keys/ta.key 0 # This file is secret
comp-lzo
user nobody
group nobody
persist-key
persist-tun
status openvpn-status.log
log         /var/log/openvpn-server.log
verb 3
		ping 50
		ping-restart 345600
		push "ping 50"
		push "ping-restart 60"

float
reneg-sec 0

Two questions arise:
1* WHY pulled option changed on restart? log says that timers(or timeouts), ifconfig and route options are modified, but they are not!
2* why ip addr del dev tun0 is failing?

Thanks...

Last edited by kokoko3k (2017-01-11 08:46:09)

R00KIE · 2017-01-10 18:25:23

Why openvpn@gozer-server? The current scheme is openvpn-{server,client}@xyz, are you using up-to-date versions everywhere? Did you make any changes to the service files?

kokoko3k · 2017-01-11 08:09:27

Clients are not updated to 2.40, yet, but i've never had compatibility problems between versions in the past.
Service files are vanilla.

I noticed that if i restart the server and then watch the logs on the client, the only thing changing in control message is the peer-id:

PUSH: Received control message: 'PUSH_REPLY,ping 50,ping-restart 60,route-gateway 192.168.8.1,topology subnet,ifconfig 192.168.8.2 255.255.255.0,peer-id 0'
#Server restarts, ping timeout, client try to restart:
PUSH: Received control message: 'PUSH_REPLY,ping 50,ping-restart 60,route-gateway 192.168.8.1,topology subnet,ifconfig 192.168.8.2 255.255.255.0,peer-id 1'
[..]

...then it tries to readjust the tun interface and fails, probably because of missing permissions to user "nobody"

-EDIT-
Just found this bug report, seems it will do the job:
https://community.openvpn.net/openvpn/ticket/649
I'll update clients.

-EDIT-
Quick and unsupported partial update solved the problem, full update will follow, thanks

Last edited by kokoko3k (2017-01-11 08:45:46)

Arch Linux

#1 2017-01-10 16:53:46

[SOLVED] Openvpn clients random disconnect and cannot connect again.

#2 2017-01-10 18:25:23

Re: [SOLVED] Openvpn clients random disconnect and cannot connect again.

#3 2017-01-11 08:09:27

Re: [SOLVED] Openvpn clients random disconnect and cannot connect again.

Board footer