OpenVPN fails to start on boot

General questions.
Post Reply
jnko
Posts: 6
Joined: January 23rd, 2014, 3:09 pm

OpenVPN fails to start on boot

Post by jnko » January 22nd, 2019, 1:47 pm

I've set up a new IPFire installation and configured OpenVPN as Roadwarrior exactly as shown in https://wiki.ipfire.org/configuration/s ... vpn/config.

Now when I reboot IPFire every time OpenVPN fails to start properly with this error:

Code: Select all

Jan 22 11:50:15 vpn kernel: tun: Universal TUN/TAP device driver, 1.6
Jan 22 11:50:16 vpn openvpnserver[2657]: OpenVPN 2.4.6 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Dec 11 2018
Jan 22 11:50:16 vpn openvpnserver[2657]: library versions: OpenSSL 1.1.0j  20 Nov 2018, LZO 2.09
Jan 22 11:50:16 vpn openvpnserver[2659]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jan 22 11:50:16 vpn sshd[2672]: Server listening on 0.0.0.0 port 22.
Jan 22 11:50:16 vpn openvpnserver[2659]: Diffie-Hellman initialized with 4096 bit key
Jan 22 11:50:16 vpn openvpnserver[2659]: ROUTE_GATEWAY 139.ABC.DEF.254/255.255.0.0 IFACE=red0 HWADDR=18:03:73:20:97:50
Jan 22 11:50:16 vpn openvpnserver[2659]: TUN/TAP device tun0 opened
Jan 22 11:50:16 vpn openvpnserver[2659]: TUN/TAP TX queue length set to 100
Jan 22 11:50:16 vpn openvpnserver[2659]: do_ifconfig, tt->did_ifconfig_ipv6_setup=0
Jan 22 11:50:16 vpn openvpnserver[2659]: /sbin/ip link set dev tun0 up mtu 1500
Jan 22 11:50:16 vpn openvpnserver[2659]: /sbin/ip addr add dev tun0 local 10.52.192.1 peer 10.52.192.2
Jan 22 11:50:16 vpn openvpnserver[2659]: /sbin/ip route add 10.52.192.0/24 via 10.52.192.2
Jan 22 11:50:16 vpn openvpnserver[2659]: Could not determine IPv4/IPv6 protocol. Using AF_INET
Jan 22 11:50:16 vpn openvpnserver[2659]: Socket Buffers: R=[212992->212992] S=[212992->212992]
Jan 22 11:50:16 vpn openvpnserver[2659]: UDPv4 link local (bound): [AF_INET][undef]:1194
Jan 22 11:50:16 vpn openvpnserver[2659]: UDPv4 link remote: [AF_UNSPEC]
Jan 22 11:50:16 vpn openvpnserver[2659]: GID set to nobody
Jan 22 11:50:16 vpn openvpnserver[2659]: UID set to nobody
Jan 22 11:50:16 vpn openvpnserver[2659]: MULTI: multi_init called, r=256 v=256
Jan 22 11:50:16 vpn openvpnserver[2659]: IFCONFIG POOL: base=10.52.192.4 size=62, ipv6=0
Jan 22 11:50:16 vpn openvpnserver[2659]: ifconfig_pool_read(), in='client.fqdn,10.52.192.4', TODO: IPv6
Jan 22 11:50:16 vpn openvpnserver[2659]: succeeded -> ifconfig_pool_set()
Jan 22 11:50:16 vpn openvpnserver[2659]: IFCONFIG POOL LIST
Jan 22 11:50:16 vpn openvpnserver[2659]: client.fqdn,10.52.192.4
Jan 22 11:50:16 vpn openvpnserver[2659]: Initialization Sequence Completed
Jan 22 11:50:16 vpn codel: Codel AQM has been enabled on 'tun0'.
Jan 22 11:50:16 vpn guardian[2784]: <info> Guardian 2.0.2 successfully started...
Jan 22 11:50:17 vpn ntpd[2501]: Listen normally on 6 tun0 10.52.192.1:123
Jan 22 11:50:17 vpn ntpd[2501]: new interface(s) found: waking up resolver
Jan 22 11:50:17 vpn dhcpcd[2023]: red0: deleting route to 169.254.0.0/16
Jan 22 11:50:17 vpn dhcpcd.exe[2820]: red0 has been brought down
Jan 22 11:50:18 vpn openvpnserver[2659]: event_wait : Interrupted system call (code=4)
Jan 22 11:50:18 vpn openvpnserver[2659]: /sbin/ip route del 10.52.192.0/24
Jan 22 11:50:18 vpn openvpnserver[2659]: ERROR: Linux route delete command failed: external program exited with error status: 2
Jan 22 11:50:18 vpn openvpnserver[2659]: Closing TUN/TAP interface
Jan 22 11:50:18 vpn openvpnserver[2659]: /sbin/ip addr del dev tun0 local 10.52.192.1 peer 10.52.192.2
Jan 22 11:50:18 vpn openvpnserver[2659]: Linux ip addr del failed: external program exited with error status: 2
Jan 22 11:50:18 vpn openvpnserver[2659]: SIGTERM[hard,] received, process exiting
When I start OpenVPN service manually everything works as expected. It just fails after fresh boot.
IPFire is

Code: Select all

IPFire version: 	IPFire 2.21 (x86_64) - core126
Pakfire version: 	2.21-x86_64
Kernel version: 	Linux vpn.lan 4.14.86-ipfire #1 SMP Tue Dec 11 08:36:08 GMT 2018 x86_64 Intel(R) Core(TM) i3-2120 CPU @ 3.30GHz GenuineIntel GNU/Linux 
I noticed this after an update to core126 first and thought this could be related to this very old install from <2010 but then did a fresh new install and the problem still persists...

Any idea whats going on?

Thanks in advance

SteveR
Posts: 4
Joined: January 2nd, 2019, 9:28 pm

Re: OpenVPN fails to start on boot

Post by SteveR » January 22nd, 2019, 9:25 pm

Same here, after updating from 125>126 and restart from remote, connecting via OpenVPN isnt possible anymore but system is running because haproxy is obviously working. I will try to manually start OpenVPN when I m on-site, check if it still fails to startup after another restart and report..
Image

ummeegge
Community Developer
Community Developer
Posts: 4811
Joined: October 9th, 2010, 10:00 am

Re: OpenVPN fails to start on boot

Post by ummeegge » January 23rd, 2019, 8:06 am

Hi,
this message
jnko wrote:
January 22nd, 2019, 1:47 pm

Code: Select all

Jan 22 11:50:18 vpn openvpnserver[2659]: ERROR: Linux route delete command failed: external program exited with error status: 2
Jan 22 11:50:18 vpn openvpnserver[2659]: Closing TUN/TAP interface
Jan 22 11:50:18 vpn openvpnserver[2659]: /sbin/ip addr del dev tun0 local 10.52.192.1 peer 10.52.192.2
Jan 22 11:50:18 vpn openvpnserver[2659]: Linux ip addr del failed: external program exited with error status: 2
Jan 22 11:50:18 vpn openvpnserver[2659]: SIGTERM[hard,] received, process exiting
comes normally up if you stop the server. The error messages appears because OpenVPN drops his privileges to nobody and nobody can not delete the route nor can close the interface but this is normal behavior under above mentioned circumstances. It seems that the problem happens before, this log entries
jnko wrote:
January 22nd, 2019, 1:47 pm

Code: Select all

Jan 22 11:50:17 vpn dhcpcd[2023]: red0: deleting route to 169.254.0.0/16
Jan 22 11:50:17 vpn dhcpcd.exe[2820]: red0 has been brought down
might be the problem, it seems that there is no link available, also the '169.254.0.0/16' (ZEROCONF) seems that you do not get an IP address.

@SteveR
can you check your logs if something similar has happened ?

UE
Image
Image

User avatar
neopegasus
Posts: 33
Joined: July 12th, 2016, 11:15 pm

Re: OpenVPN fails to start on boot

Post by neopegasus » January 23rd, 2019, 5:43 pm

Hey Ummeegge, I was having kind of the same problem , mine suddenly stop working yesterday still don't know why.
I am not good in German but what Arne say here helps me :viewtopic.php?f=16&t=22192&p=121934&hil ... pn#p121934

He was saying ( in my best translation i can) delete your settings and remake them and let your client have the new settings, after i did that mine works again so maybe you can give it a try?

Best regards

Neopegasus
Image

SteveR
Posts: 4
Joined: January 2nd, 2019, 9:28 pm

Re: OpenVPN fails to start on boot

Post by SteveR » January 23rd, 2019, 5:50 pm

Hi,

getting this messages

Code: Select all

Jan 22 21:43:34 mgw01 openvpnserver[4235]: 89.14.xxx:40884 Assertion failed at ssl_openssl.c:1598 ((ks_ssl->ssl_bio = BIO_new(BIO_f_ssl())))
Jan 22 21:43:34 mgw01 openvpnserver[4235]: 89.14.xxx:40884 Exiting due to fatal error
Jan 22 21:43:34 mgw01 openvpnserver[4235]: 89.14.xxx:40884 /sbin/ip route del 10.28.192.0/24
Jan 22 21:43:34 mgw01 openvpnserver[4235]: 89.14.xxx:40884 ERROR: Linux route delete command failed: external program exited with error status: 2
Jan 22 21:43:34 mgw01 openvpnserver[4235]: 89.14.1xxx:40884 Closing TUN/TAP interface
Jan 22 21:43:34 mgw01 openvpnserver[4235]: 89.14.xxx:40884 /sbin/ip addr del dev tun0 local 10.28.192.1 peer 10.28.192.2
Jan 22 21:43:34 mgw01 openvpnserver[4235]: 89.14.xxx:40884 Linux ip addr del failed: external program exited with error status: 2
I ´ve noticed the RFC3280 warning in OpenVPN-WUI so I updated the ovpn.cnf according to viewtopic.php?f=16&t=21330&sid=7e417ea7 ... 183f995aed deleted host/root-certs and client-connections and added new ones. Connecting from a client shows

Code: Select all

read UDP: Connection reset by peer (WSAECONNRESET) (code=10054) 
and when I look at the services-wui openvpn-service is stopped but in openvpn-wui it still shows up as running. In the end seeing same logs as before

Code: Select all

Jan 23 18:01:27 mgw01 openvpnserver[5173]: OpenVPN 2.4.5 i586-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Apr 27 2018
Jan 23 18:01:27 mgw01 openvpnserver[5173]: library versions: OpenSSL 1.1.1  11 Sep 2018, LZO 2.09
Jan 23 18:01:27 mgw01 openvpnserver[5174]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jan 23 18:01:27 mgw01 openvpnserver[5174]: Diffie-Hellman initialized with 2048 bit key
Jan 23 18:01:27 mgw01 openvpnserver[5174]: WARNING: normally if you use --mssfix and/or --fragment, you should also set --tun-mtu 1500 (currently it is 1400)
Jan 23 18:01:27 mgw01 openvpnserver[5174]: ROUTE_GATEWAY 10.0.x.x/255.255.255.0 IFACE=red0 HWADDR=0c:c4:xx:xx:xx
Jan 23 18:01:27 mgw01 openvpnserver[5174]: TUN/TAP device tun0 opened
Jan 23 18:01:27 mgw01 openvpnserver[5174]: TUN/TAP TX queue length set to 100
Jan 23 18:01:27 mgw01 openvpnserver[5174]: do_ifconfig, tt->did_ifconfig_ipv6_setup=0
Jan 23 18:01:27 mgw01 openvpnserver[5174]: /sbin/ip link set dev tun0 up mtu 1400
Jan 23 18:01:27 mgw01 openvpnserver[5174]: /sbin/ip addr add dev tun0 local 10.28.192.1 peer 10.28.192.2
Jan 23 18:01:27 mgw01 openvpnserver[5174]: /sbin/ip route add 10.28.192.0/24 via 10.28.192.2
Jan 23 18:01:27 mgw01 openvpnserver[5174]: Could not determine IPv4/IPv6 protocol. Using AF_INET
Jan 23 18:01:27 mgw01 openvpnserver[5174]: Socket Buffers: R=[180224->180224] S=[180224->180224]
Jan 23 18:01:27 mgw01 openvpnserver[5174]: UDPv4 link local (bound): [AF_INET][undef]:1194
Jan 23 18:01:27 mgw01 openvpnserver[5174]: UDPv4 link remote: [AF_UNSPEC]
Jan 23 18:01:27 mgw01 openvpnserver[5174]: GID set to nobody
Jan 23 18:01:27 mgw01 openvpnserver[5174]: UID set to nobody
Jan 23 18:01:27 mgw01 openvpnserver[5174]: MULTI: multi_init called, r=256 v=256
Jan 23 18:01:27 mgw01 openvpnserver[5174]: IFCONFIG POOL: base=10.28.192.4 size=62, ipv6=0
Jan 23 18:01:27 mgw01 openvpnserver[5174]: IFCONFIG POOL LIST
Jan 23 18:01:27 mgw01 openvpnserver[5174]: Initialization Sequence Completed
Jan 23 18:02:00 mgw01 openvpnserver[5174]: 87.128.x.x:56091 WARNING: normally if you use --mssfix and/or --fragment, you should also set --tun-mtu 1500 (currently it is 1400)
Jan 23 18:02:00 mgw01 openvpnserver[5174]: 87.128.x.x:56091 Assertion failed at ssl_openssl.c:1598 ((ks_ssl->ssl_bio = BIO_new(BIO_f_ssl())))
Jan 23 18:02:00 mgw01 openvpnserver[5174]: 87.128.x.x:56091 Exiting due to fatal error
Jan 23 18:02:00 mgw01 openvpnserver[5174]: 87.128.x.x:56091 /sbin/ip route del 10.28.192.0/24
Jan 23 18:02:00 mgw01 openvpnserver[5174]: 87.128.x.x:56091 ERROR: Linux route delete command failed: external program exited with error status: 2
Jan 23 18:02:00 mgw01 openvpnserver[5174]: 87.128.x.x:56091 Closing TUN/TAP interface
Jan 23 18:02:00 mgw01 openvpnserver[5174]: 87.128.x.x:56091 /sbin/ip addr del dev tun0 local 10.28.192.1 peer 10.28.192.2
Jan 23 18:02:00 mgw01 openvpnserver[5174]: 87.128.x.x:56091 Linux ip addr del failed: external program exited with error status: 2

Just did another system-restart with the same result, openvpn is running until client tries to connect..
Image

ummeegge
Community Developer
Community Developer
Posts: 4811
Joined: October 9th, 2010, 10:00 am

Re: OpenVPN fails to start on boot

Post by ummeegge » January 23rd, 2019, 7:00 pm

Hi all,
neopegasus wrote:
January 23rd, 2019, 5:43 pm
He was saying ( in my best translation i can) delete your settings and remake them and let your client have the new settings, after i did that mine works again so maybe you can give it a try?
thanks for your feedback but it seems that we have here multiple different problems, the problem in the german topic was that the green subnet was changed but wasn´t recognized in the push route directive in OpenVPN but good that you could solve it that way.
SteveR wrote:
January 23rd, 2019, 5:50 pm

Code: Select all

Jan 23 18:01:27 mgw01 openvpnserver[5173]: library versions: OpenSSL 1.1.1  11 Sep 2018, LZO 2.09
It seems that you use a different OpenSSL library, IPFire uses currently

Code: Select all

Jan 23 08:01:17 ipfire openvpnserver[24176]: library versions: OpenSSL 1.1.0j  20 Nov 2018, LZO 2.09
What did you modified on your IPFire ? From which core version did you do your update ?

UE
Image
Image

SteveR
Posts: 4
Joined: January 2nd, 2019, 9:28 pm

Re: OpenVPN fails to start on boot

Post by SteveR » January 24th, 2019, 2:18 pm

Hi,
What did you modified on your IPFire ? From which core version did you do your update ?
I was setting up a Mailproxy with Postfix, Amavisd, SA according to the official How-To https://wiki.ipfire.org/optimization/mailproxy/start but couldnt get it to work, then I found out about a community project from user gocart viewtopic.php?f=17&t=17360 and switched to that. With version 36 of that project it switched to openssl 1.1.1 so thats the reason for the different openssl.

I was updateing from core 125 to 126. In pakfire i recognized that it shows to update postfix to the version that was already installed through the community-project-installer-script and as gocart is explaining in his documentation, that updating a previous installed postfix through pakfire will break the custom postfix-configuration, I decided to remove the package, do the core-update and may run the installer-script later again and start from scratch. After updateing to core 126 and restarting the system, openvpn stopped working. With your hint of the different openssl version I was installing the community-mailproxy again and openvpn was working again. So at this point problem is fixed, but know i m concerned if ever taking the community-mailproxy into production is a good idea at all and how I could get back to openssl 1.1.0j if needed, apart from recover from a backup.

I will give a feedback to gocart as well and thank you for your help
Image

ummeegge
Community Developer
Community Developer
Posts: 4811
Joined: October 9th, 2010, 10:00 am

Re: OpenVPN fails to start on boot

Post by ummeegge » February 2nd, 2019, 6:29 am

Causing OpenSSL, Core 128 will deliver OpenSSL-1.1.1a this should fix it.

Best,

UE
Image
Image

OdonGarma
Posts: 21
Joined: May 21st, 2015, 7:07 am

Re: OpenVPN fails to start on boot

Post by OdonGarma » April 5th, 2019, 8:12 am

Als workaround habe ich mich mit dem manuellen start via

Code: Select all

/etc/sysconfig/rc.local
beholfen.

Dort einfach mal

Code: Select all

/usr/local/bin/openvpnctrl -s
einfügen, dann startet auch der Dienst nach dem booten.

Greetz

ummeegge
Community Developer
Community Developer
Posts: 4811
Joined: October 9th, 2010, 10:00 am

Re: OpenVPN fails to start on boot

Post by ummeegge » April 5th, 2019, 8:20 am

Hi OdonGarma,
thanks for your help but the above problem was causing by a different OpenSSL library which wasn´t compiled with OpenVPN. The command you´ve posted are already executed by the system --> https://git.ipfire.org/?p=ipfire-2.x.gi ... aa4ea0d4a4 so OpenVPN should start regular.

Best,

UE
Image
Image

OdonGarma
Posts: 21
Joined: May 21st, 2015, 7:07 am

Re: OpenVPN fails to start on boot

Post by OdonGarma » April 6th, 2019, 1:27 pm

Confirmed! My workaround is only necessary under core 127 under core 128 everything works out of the box.

Greetz

Post Reply