| 2017-05-10 16:04:34 |
AW |
description |
OpenVPN intermittently fails to bind to local address during boot on Ubuntu Server 16.04.2 LTS. Sometimes it succeeds, sometimes it does not.
/var/log/openvpn.log
Wed May 10 15:42:02 2017 OpenVPN 2.3.10 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Feb 2 2016
Wed May 10 15:42:02 2017 library versions: OpenSSL 1.0.2g 1 Mar 2016, LZO 2.08
Wed May 10 15:42:02 2017 Diffie-Hellman initialized with 2048 bit key
Wed May 10 15:42:02 2017 Control Channel Authentication: using './easy-rsa/keys/ta.key' as a OpenVPN static key file
Wed May 10 15:42:02 2017 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed May 10 15:42:02 2017 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed May 10 15:42:02 2017 Socket Buffers: R=[212992->212992] S=[212992->212992]
Wed May 10 15:42:02 2017 TCP/UDP: Socket bind failed on local address [AF_INET]192.168.4.254:1194: Cannot assign requested address
Wed May 10 15:42:02 2017 Exiting due to fatal error
In case it does not start, running 'sudo service openvpn start' fixes that problem.
/var/log/openvpn.log
Wed May 10 15:42:43 2017 OpenVPN 2.3.10 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Feb 2 2016
Wed May 10 15:42:43 2017 library versions: OpenSSL 1.0.2g 1 Mar 2016, LZO 2.08
Wed May 10 15:42:43 2017 Diffie-Hellman initialized with 2048 bit key
Wed May 10 15:42:43 2017 Control Channel Authentication: using './easy-rsa/keys/ta.key' as a OpenVPN static key file
Wed May 10 15:42:43 2017 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed May 10 15:42:43 2017 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed May 10 15:42:43 2017 Socket Buffers: R=[212992->212992] S=[212992->212992]
Wed May 10 15:42:43 2017 ROUTE_GATEWAY 192.168.4.1/255.255.255.0 IFACE=ens4 HWADDR=52:54:00:f0:26:0c
Wed May 10 15:42:43 2017 TUN/TAP device tun0 opened
Wed May 10 15:42:43 2017 TUN/TAP TX queue length set to 100
Wed May 10 15:42:43 2017 do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Wed May 10 15:42:43 2017 /sbin/ip link set dev tun0 up mtu 1500
Wed May 10 15:42:43 2017 /sbin/ip addr add dev tun0 local 172.16.1.1 peer 172.16.1.2
Wed May 10 15:42:43 2017 /sbin/ip route add 172.16.1.0/24 via 172.16.1.2
Wed May 10 15:42:43 2017 GID set to nogroup
Wed May 10 15:42:43 2017 UID set to nobody
Wed May 10 15:42:43 2017 UDPv4 link local (bound): [AF_INET]192.168.4.254:1194
Wed May 10 15:42:43 2017 UDPv4 link remote: [undef]
Wed May 10 15:42:43 2017 MULTI: multi_init called, r=256 v=256
Wed May 10 15:42:43 2017 IFCONFIG POOL: base=172.16.1.4 size=62, ipv6=0
Wed May 10 15:42:43 2017 IFCONFIG POOL LIST
Wed May 10 15:42:43 2017 Initialization Sequence Completed
My guess is that systemd starts OpenVPN too early before the network is brought up sufficiently. Running 'sudo systemctl edit --full openvpn' and adding 'Wants=network-online.target' does not change that behaviour.
user@server:~$ sudo systemd-analyze critical-chain
graphical.target @2.160s
└─multi-user.target @2.159s
└─ntp.service @2.054s +104ms
└─remote-fs.target @2.052s
└─remote-fs-pre.target @2.052s
└─open-iscsi.service @1.993s +57ms
└─iscsid.service @1.942s +47ms
└─network-online.target @1.941s
└─network.target @1.929s
└─networking.service @1.793s +134ms
└─apparmor.service @1.140s +395ms
└─local-fs.target @1.140s
└─local-fs-pre.target @1.139s
└─lvm2-monitor.service @602ms +536ms
└─lvm2-lvmetad.service @773ms
└─systemd-journald.socket @574ms
└─-.slice @500ms
The boot time is quite short as this is a Virtual Machine (KVM). However this happens on bare metal as well.
/etc/openvpn/server.conf
local 192.168.4.254
port 1194
proto udp
dev tun
ca ./easy-rsa/keys/ca.crt
cert ./easy-rsa/keys/crt.crt
key ./easy-rsa/keys/key.key
dh ./easy-rsa/keys/dh2048.pem
tls-auth ./easy-rsa/keys/ta.key 0
server 172.16.1.0 255.255.255.0
ifconfig-pool-persist ipp.txt
push "route 192.168.0.0 255.255.255.0"
push "route 192.168.4.0 255.255.255.0"
keepalive 10 120
comp-lzo
max-clients 5
user nobody
group nogroup
persist-key
persist-tun
status openvpn-status.log
log-append /var/log/openvpn.log
verb 3
/etc/network/interfaces
# The loopback network interface
auto lo
iface lo inet loopback
# The primary network interface
auto ens3
iface ens3 inet static
address 192.168.0.1
netmask 255.255.255.0
network 192.168.0.0
broadcast 192.168.0.255
# The secondary network interface
auto ens4
iface ens4 inet static
address 192.168.4.254
netmask 255.255.255.0
network 192.168.4.0
broadcast 192.168.4.255
gateway 192.168.4.1
user@server:~$ sudo apt-cache policy openvpn
openvpn:
Installed: 2.3.10-1ubuntu2
Candidate: 2.3.10-1ubuntu2
Version table:
*** 2.3.10-1ubuntu2 500
500 http://de.archive.ubuntu.com/ubuntu xenial/main amd64 Packages
100 /var/lib/dpkg/status
user@server:~$ sudo apt-cache policy systemd
systemd:
Installed: 229-4ubuntu17
Candidate: 229-4ubuntu17
Version table:
*** 229-4ubuntu17 500
500 http://de.archive.ubuntu.com/ubuntu xenial-updates/main amd64 Packages
100 /var/lib/dpkg/status
229-4ubuntu10 500
500 http://security.ubuntu.com/ubuntu xenial-security/main amd64 Packages
229-4ubuntu4 500
500 http://de.archive.ubuntu.com/ubuntu xenial/main amd64 Packages |
OpenVPN intermittently fails to bind to local address during boot on Ubuntu Server 16.04.2 LTS. Sometimes it succeeds, sometimes it does not.
/var/log/openvpn.log
Wed May 10 15:42:02 2017 OpenVPN 2.3.10 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Feb 2 2016
Wed May 10 15:42:02 2017 library versions: OpenSSL 1.0.2g 1 Mar 2016, LZO 2.08
Wed May 10 15:42:02 2017 Diffie-Hellman initialized with 2048 bit key
Wed May 10 15:42:02 2017 Control Channel Authentication: using './easy-rsa/keys/ta.key' as a OpenVPN static key file
Wed May 10 15:42:02 2017 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed May 10 15:42:02 2017 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed May 10 15:42:02 2017 Socket Buffers: R=[212992->212992] S=[212992->212992]
Wed May 10 15:42:02 2017 TCP/UDP: Socket bind failed on local address [AF_INET]192.168.4.254:1194: Cannot assign requested address
Wed May 10 15:42:02 2017 Exiting due to fatal error
In case it does not start, running 'sudo service openvpn start' fixes that problem.
/var/log/openvpn.log
Wed May 10 15:42:43 2017 OpenVPN 2.3.10 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Feb 2 2016
Wed May 10 15:42:43 2017 library versions: OpenSSL 1.0.2g 1 Mar 2016, LZO 2.08
Wed May 10 15:42:43 2017 Diffie-Hellman initialized with 2048 bit key
Wed May 10 15:42:43 2017 Control Channel Authentication: using './easy-rsa/keys/ta.key' as a OpenVPN static key file
Wed May 10 15:42:43 2017 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed May 10 15:42:43 2017 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed May 10 15:42:43 2017 Socket Buffers: R=[212992->212992] S=[212992->212992]
Wed May 10 15:42:43 2017 ROUTE_GATEWAY 192.168.4.1/255.255.255.0 IFACE=ens4 HWADDR=52:54:00:f0:26:0c
Wed May 10 15:42:43 2017 TUN/TAP device tun0 opened
Wed May 10 15:42:43 2017 TUN/TAP TX queue length set to 100
Wed May 10 15:42:43 2017 do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Wed May 10 15:42:43 2017 /sbin/ip link set dev tun0 up mtu 1500
Wed May 10 15:42:43 2017 /sbin/ip addr add dev tun0 local 172.16.1.1 peer 172.16.1.2
Wed May 10 15:42:43 2017 /sbin/ip route add 172.16.1.0/24 via 172.16.1.2
Wed May 10 15:42:43 2017 GID set to nogroup
Wed May 10 15:42:43 2017 UID set to nobody
Wed May 10 15:42:43 2017 UDPv4 link local (bound): [AF_INET]192.168.4.254:1194
Wed May 10 15:42:43 2017 UDPv4 link remote: [undef]
Wed May 10 15:42:43 2017 MULTI: multi_init called, r=256 v=256
Wed May 10 15:42:43 2017 IFCONFIG POOL: base=172.16.1.4 size=62, ipv6=0
Wed May 10 15:42:43 2017 IFCONFIG POOL LIST
Wed May 10 15:42:43 2017 Initialization Sequence Completed
My guess is that systemd starts OpenVPN too early before the network is brought up sufficiently. Running 'sudo systemctl edit --full openvpn' and adding 'Wants=network-online.target' does not change that behaviour.
user@server:~$ sudo systemd-analyze critical-chain
graphical.target @2.160s
└─multi-user.target @2.159s
└─ntp.service @2.054s +104ms
└─remote-fs.target @2.052s
└─remote-fs-pre.target @2.052s
└─open-iscsi.service @1.993s +57ms
└─iscsid.service @1.942s +47ms
└─network-online.target @1.941s
└─network.target @1.929s
└─networking.service @1.793s +134ms
└─apparmor.service @1.140s +395ms
└─local-fs.target @1.140s
└─local-fs-pre.target @1.139s
└─lvm2-monitor.service @602ms +536ms
└─lvm2-lvmetad.service @773ms
└─systemd-journald.socket @574ms
└─-.slice @500ms
The boot time is quite short. Clean install with the additional packages ntp and openssh-server. This happens both on bare metal and as a Virtual Machine (KVM) as well.
/etc/openvpn/server.conf
local 192.168.4.254
port 1194
proto udp
dev tun
ca ./easy-rsa/keys/ca.crt
cert ./easy-rsa/keys/crt.crt
key ./easy-rsa/keys/key.key
dh ./easy-rsa/keys/dh2048.pem
tls-auth ./easy-rsa/keys/ta.key 0
server 172.16.1.0 255.255.255.0
ifconfig-pool-persist ipp.txt
push "route 192.168.0.0 255.255.255.0"
push "route 192.168.4.0 255.255.255.0"
keepalive 10 120
comp-lzo
max-clients 5
user nobody
group nogroup
persist-key
persist-tun
status openvpn-status.log
log-append /var/log/openvpn.log
verb 3
/etc/network/interfaces
# The loopback network interface
auto lo
iface lo inet loopback
# The primary network interface
auto ens3
iface ens3 inet static
address 192.168.0.1
netmask 255.255.255.0
network 192.168.0.0
broadcast 192.168.0.255
# The secondary network interface
auto ens4
iface ens4 inet static
address 192.168.4.254
netmask 255.255.255.0
network 192.168.4.0
broadcast 192.168.4.255
gateway 192.168.4.1
user@server:~$ sudo apt-cache policy openvpn
openvpn:
Installed: 2.3.10-1ubuntu2
Candidate: 2.3.10-1ubuntu2
Version table:
*** 2.3.10-1ubuntu2 500
500 http://de.archive.ubuntu.com/ubuntu xenial/main amd64 Packages
100 /var/lib/dpkg/status
user@server:~$ sudo apt-cache policy systemd
systemd:
Installed: 229-4ubuntu17
Candidate: 229-4ubuntu17
Version table:
*** 229-4ubuntu17 500
500 http://de.archive.ubuntu.com/ubuntu xenial-updates/main amd64 Packages
100 /var/lib/dpkg/status
229-4ubuntu10 500
500 http://security.ubuntu.com/ubuntu xenial-security/main amd64 Packages
229-4ubuntu4 500
500 http://de.archive.ubuntu.com/ubuntu xenial/main amd64 Packages |
|
