OpenVPN.service starts before network is up

mrkernelpanic · 2015-03-17 02:11:19

Hello,

I have trouble getting an automatic OpenVPN connection at startup to work with systemd. Some troubleshooting revealed that OpenVPN always starts before the network is up (OpenVPN can't resolve the host adress).

However, I think I have found why it does not work how I want it to:

— dhcpcd.service - dhcpcd on all interfaces
   Loaded: loaded (/usr/lib/systemd/system/dhcpcd.service; enabled; vendor preset: disabled)
   Active: active (running) since Tue 2015-03-17 02:23:50 CET; 7min ago
 Main PID: 276 (dhcpcd)
   CGroup: /system.slice/dhcpcd.service
           â””â”€276 /usr/bin/dhcpcd -q -b

Mar 17 02:23:51 <system> dhcpcd[276]: wlp2s0: carrier lost
Mar 17 02:23:51 <system> dhcpcd[276]: wlp2s0: deleting <address>
Mar 17 02:23:53 <system> dhcpcd[276]: enp8s0: carrier acquired
Mar 17 02:23:53 <system> dhcpcd[276]: enp8s0: IAID 0e:69:ff:09
Mar 17 02:23:53 <system> dhcpcd[276]: enp8s0: rebinding lease of 192.168.32.44
Mar 17 02:23:53 <system> dhcpcd[276]: enp8s0: soliciting an IPv6 router
Mar 17 02:24:01 <system> dhcpcd[276]: enp8s0: leased 192.168.32.44 for 3600 seconds
Mar 17 02:24:01 <system> dhcpcd[276]: enp8s0: adding route to 192.168.32.0/23
Mar 17 02:24:01 <system> dhcpcd[276]: enp8s0: adding default route via 192.168.32.251
Mar 17 02:24:06 <system> dhcpcd[276]: enp8s0: no IPv6 Routers available

Whereas OpenVPN starts much earlier:

Mar 17 02:23:54 <system> openvpn@<profile>[333]: <Process started plus can not resolve Host stuff>
Mar 17 02:23:54 <system> openvpn@<profile>[333]: openvpn@<profile>.service failed.

I tried using

Wants=network-online.target
After=network-online.target

in the openvpn@.service and had enabled

systemd-networkd.service
systemd-networkd-wait-online.service

but it still did not work as these services finished later as well:

Mar 17 02:23:50 <system> systemd[1]: Started Network Service.
Mar 17 02:23:53 <system> systemd-networkd[278]: enp8s0          : gained carrier
Mar 17 02:25:19 <system> systemd-networkd[278]: tun0            : gained carrier

Mar 17 02:23:51 <system> systemd-networkd-wait-online[298]: ignore irrelevant link: lo
Mar 17 02:23:51 <system> systemd-networkd-wait-online[298]: ignore irrelevant link: lo
Mar 17 02:23:51 <system> systemd-networkd-wait-online[298]: ignore irrelevant link: lo
Mar 17 02:23:51 <system> systemd-networkd-wait-online[298]: ignore irrelevant link: lo
Mar 17 02:23:51 <system> systemd-networkd-wait-online[298]: ignore irrelevant link: lo
Mar 17 02:23:51 <system> systemd-networkd-wait-online[298]: ignore irrelevant link: lo
Mar 17 02:23:53 <system> systemd-networkd-wait-online[298]: ignore irrelevant link: lo
Mar 17 02:23:53 <system> systemd-networkd-wait-online[298]: ignore irrelevant link: lo
Mar 17 02:23:53 <system> systemd-networkd-wait-online[298]: ignore irrelevant link: lo
Mar 17 02:23:54 <system> systemd[1]: Started Wait for Network to be Configured.

My guess is, that OpenVPN won't work until this has happened:

Mar 17 02:25:19 <system> systemd-networkd[278]: tun0            : gained carrier

I now tried to modify the .service like this (inspiration taken from this thread):

[Unit]
Description=OpenVPN connection to %i
Requires:sys-devices-virtual-net-tun0.device
After:sys-devices-virtual-net-tun0.device

[Service]
Type=forking
ExecStart=/usr/bin/openvpn --cd /etc/openvpn --config /etc/openvpn/%i.ovpn --daemon openvpn@%i --writepid /run/openvpn@%i.pid
PIDFile=/run/openvpn@%i.pid

[Install]
WantedBy=multi-user.target

However, the status now looks as follows:

— openvpn@stud-wh.service - OpenVPN connection to stud-wh
   Loaded: error (Reason: Bad message)
   Active: inactive (dead)

— sys-devices-virtual-net-tun0.device
   Loaded: loaded
   Active: inactive (dead)

At this point I have no more ideas left. Can anyone confirm my suspicion that OpenVPN needs tun0 gained first? How can I check within a service wheter tun0 has been gained or not? Many thanks!

Edit: The status of tun0 looks like this:

— sys-devices-virtual-net-tun0.device - /sys/devices/virtual/net/tun0
   Loaded: loaded
   Active: active (plugged) since Tue 2015-03-17 03:00:52 CET; 17min ago
   Device: /sys/devices/virtual/net/tun0

but when I try to enable it it says: Failed to execute operation: No such file or directory. This somehow contradicts the earlier status. I guess it got 'plugged' as I started the OpenVPN connection manually?
Maybe OpenVPN has to wait for TAP aswell?

Last edited by mrkernelpanic (2015-03-17 02:22:05)

jasonwryan · 2015-03-17 02:24:27

Works for me with:

After=network.target
Wants=network.target

mrkernelpanic · 2015-03-17 02:26:57

I tried that too, but it did not work. Does the order of After/Wants make a difference? Does systemd-networkd.service have to be enabled?

jasonwryan · 2015-03-17 02:32:34

mrkernelpanic wrote:

Does systemd-networkd.service have to be enabled?

Yes. Assuming that is how you are managing your connection...

mrkernelpanic · 2015-03-17 02:36:48

I just tried your suggestion again and changed the resolv-retry from 0 to 2. Now I have a PID error aswell:

— openvpn@<profile>.service - OpenVPN connection to <profile>
   Loaded: loaded (/usr/lib/systemd/system/openvpn@.service; enabled; vendor preset: disabled)
   Active: failed (Result: resources) since Tue 2015-03-17 03:29:59 CET; 42s ago
  Process: 284 ExecStart=/usr/bin/openvpn --cd /etc/openvpn --config /etc/openvpn/%i.ovpn --daemon openvpn@%i --writepid /run/openvpn@%i.pid (code=exited, status=0/SUCCESS)

Mar 17 03:29:59 <system> openvpn@stud-wh[284]: OpenVPN 2.3.6 x86_64-unknown-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [MH] [IPv6] built on Dec  2 2014
Mar 17 03:29:59 <system> openvpn@stud-wh[284]: library versions: OpenSSL 1.0.2 22 Jan 2015, LZO 2.09
Mar 17 03:29:59 <system> openvpn@stud-wh[284]: WARNING: file '/etc/openvpn/auth.conf' is group or others accessible
Mar 17 03:29:59 <system> openvpn@stud-wh[284]: WARNING: file '/etc/openvpn/ta.key' is group or others accessible
Mar 17 03:29:59 <system> openvpn@stud-wh[284]: Control Channel Authentication: using '/etc/openvpn/ta.key' as a OpenVPN static key file
Mar 17 03:29:59 <system> openvpn@stud-wh[284]: RESOLVE: Cannot resolve host address: <hostaddress>: Name or service not known
Mar 17 03:29:59 <system> systemd[1]: PID 295 read from file /run/openvpn@<profile>.pid does not exist or is a zombie.
Mar 17 03:29:59 <system> systemd[1]: Failed to start OpenVPN connection to <profile>.
Mar 17 03:29:59 <system> systemd[1]: Unit openvpn@<profile>.service entered failed state.
Mar 17 03:29:59 <system> systemd[1]: openvpn@<profile>.service failed.

The config looks like this:

# <a number>
client
dev tun
proto tcp
ca /etc/openvpn/cachain.crt
remote <hostaddress> 2711
remote <hostaddress> 2712
remote <hostaddress> 2713
remote <hostaddress> 2714
remote-random
tls-remote <hostaddress>
resolv-retry 2
connect-retry 2
#connect-retry-max 2
connect-timeout 2
nobind
user nobody
group nogroup
persist-key
persist-tun
mute-replay-warnings
tls-auth /etc/openvpn/ta.key 1
auth-user-pass /etc/openvpn/auth.conf
auth-retry interact
comp-lzo no
reneg-sec 43200

Edit: Tried it with systemd-networkd.service enabled aswell. Not much of a difference:

— openvpn@<profile>.service - OpenVPN connection to stud-wh
   Loaded: loaded (/usr/lib/systemd/system/openvpn@.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Tue 2015-03-17 03:37:51 CET; 26s ago
  Process: 293 ExecStart=/usr/bin/openvpn --cd /etc/openvpn --config /etc/openvpn/%i.ovpn --daemon openvpn@%i --writepid /run/openvpn@%i.pid (code=exited, status=0/SUCCESS)
 Main PID: 306 (code=exited, status=1/FAILURE)

Mar 17 03:37:51 <system> openvpn@stud-wh[293]: library versions: OpenSSL 1.0.2 22 Jan 2015, LZO 2.09
Mar 17 03:37:51 <system> openvpn@stud-wh[293]: WARNING: file '/etc/openvpn/auth.conf' is group or others accessible
Mar 17 03:37:51 <system> openvpn@stud-wh[293]: WARNING: file '/etc/openvpn/ta.key' is group or others accessible
Mar 17 03:37:51 <system> openvpn@stud-wh[293]: Control Channel Authentication: using '/etc/openvpn/ta.key' as a OpenVPN static key file
Mar 17 03:37:51 <system> openvpn@stud-wh[293]: RESOLVE: Cannot resolve host address: <hostaddress>: Name or service not known
Mar 17 03:37:51 <system> openvpn@stud-wh[306]: NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
Mar 17 03:37:51 <system> systemd[1]: Started OpenVPN connection to <profile>.
Mar 17 03:37:51 <system> systemd[1]: openvpn@stud-wh.service: main process exited, code=exited, status=1/FAILURE
Mar 17 03:37:51 <system> systemd[1]: Unit openvpn@<profile>.service entered failed state.
Mar 17 03:37:51 <system> systemd[1]: openvpn@<profile> failed.

Last edited by mrkernelpanic (2015-03-17 02:56:45)

nullified · 2015-03-17 02:43:32

It looks like you have dhcpcd enabled in your first post. It should be either dhcpcd, or systemd-networkd. Start at the beginning again:

1) How exactly is your connection setup?
2) What is the content of the current OpenVPN service file?

mrkernelpanic · 2015-03-17 02:56:11

Yes, let's make things a bit more clear. The latest test I ran was with this configuration:

[Unit]
Description=OpenVPN connection to %i
After=dhcpcd.service
Wants=dhcpcd.service

[Service]
Type=forking
ExecStart=/usr/bin/openvpn --cd /etc/openvpn --config /etc/openvpn/%i.ovpn --daemon openvpn@%i --writepid /run/openvpn@%i.pid
PIDFile=/run/openvpn@%i.pid

[Install]
WantedBy=multi-user.target

dhcpcd.service enabled, systemd-networkd.service disabled.

The output is the following:

— openvpn@stud-wh.service - OpenVPN connection to stud-wh
   Loaded: loaded (/usr/lib/systemd/system/openvpn@.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Tue 2015-03-17 03:50:42 CET; 28s ago
  Process: 285 ExecStart=/usr/bin/openvpn --cd /etc/openvpn --config /etc/openvpn/%i.ovpn --daemon openvpn@%i --writepid /run/openvpn@%i.pid (code=exited, status=0/SUCCESS)
 Main PID: 296 (code=exited, status=1/FAILURE)

Mar 17 03:50:42 lenovo_arch openvpn@stud-wh[285]: library versions: OpenSSL 1.0.2 22 Jan 2015, LZO 2.09
Mar 17 03:50:42 lenovo_arch openvpn@stud-wh[285]: WARNING: file '/etc/openvpn/auth.conf' is group or others accessible
Mar 17 03:50:42 lenovo_arch openvpn@stud-wh[285]: WARNING: file '/etc/openvpn/ta.key' is group or others accessible
Mar 17 03:50:42 lenovo_arch openvpn@stud-wh[285]: Control Channel Authentication: using '/etc/openvpn/ta.key' as a OpenVPN static key file
Mar 17 03:50:42 lenovo_arch openvpn[285]: Tue Mar 17 03:50:42 2015 DEPRECATED OPTION: --tls-remote, please update your configuration
Mar 17 03:50:42 lenovo_arch openvpn@stud-wh[285]: RESOLVE: Cannot resolve host address: <hostaddress>: Name or service not known
Mar 17 03:50:42 lenovo_arch systemd[1]: Started OpenVPN connection to stud-wh.
Mar 17 03:50:42 lenovo_arch systemd[1]: openvpn@stud-wh.service: main process exited, code=exited, status=1/FAILURE
Mar 17 03:50:42 lenovo_arch systemd[1]: Unit openvpn@stud-wh.service entered failed state.
Mar 17 03:50:42 lenovo_arch systemd[1]: openvpn@stud-wh.service failed.

dhcpcd status is the following:

— dhcpcd.service - dhcpcd on all interfaces
   Loaded: loaded (/usr/lib/systemd/system/dhcpcd.service; enabled; vendor preset: disabled)
   Active: active (running) since Tue 2015-03-17 03:50:42 CET; 13min ago
  Process: 274 ExecStart=/usr/bin/dhcpcd -q -b (code=exited, status=0/SUCCESS)
 Main PID: 283 (dhcpcd)
   CGroup: /system.slice/dhcpcd.service
           â””â”€283 /usr/bin/dhcpcd -q -b

Mar 17 03:50:42 lenovo_arch dhcpcd[283]: wlp2s0: carrier lost
Mar 17 03:50:42 lenovo_arch dhcpcd[283]: wlp2s0: deleting address fe80::a6cc:298f:5481:4430
Mar 17 03:50:44 lenovo_arch dhcpcd[283]: enp8s0: carrier acquired
Mar 17 03:50:44 lenovo_arch dhcpcd[283]: enp8s0: IAID 0e:69:ff:09
Mar 17 03:50:44 lenovo_arch dhcpcd[283]: enp8s0: rebinding lease of 192.168.32.44
Mar 17 03:50:45 lenovo_arch dhcpcd[283]: enp8s0: soliciting an IPv6 router
Mar 17 03:50:54 lenovo_arch dhcpcd[283]: enp8s0: leased 192.168.32.44 for 3600 seconds
Mar 17 03:50:54 lenovo_arch dhcpcd[283]: enp8s0: adding route to 192.168.32.0/23
Mar 17 03:50:54 lenovo_arch dhcpcd[283]: enp8s0: adding default route via 192.168.32.251
Mar 17 03:50:58 lenovo_arch dhcpcd[283]: enp8s0: no IPv6 Routers available

The OpenVPN config file is the same as above.

I am connected via Ethernet directly to the outlet. Internet acces is provided trough OpenVPN. I do not have netctl or other network managers (apart from dhcpcd) installed (I think...).

Last edited by mrkernelpanic (2015-03-17 03:04:56)

inside-hex · 2015-04-30 23:28:06

I had nearly the same problem and only got it to work with systemd-networkd, not with dhcpcd.
Is there a reason why you use dhcpcd? If not, you could switch, too.

Raynman · 2015-05-01 07:29:45

There is a difference between enabling dhcpcd.service or dhcpcd@enp8s0.service. AFAIK, the former runs in the background and tries to configure interfaces as they come and go, while the latter does not finish starting until the connection on the specific interface is set up, so that would allow you to start openvpn After it. Not all network managers work equally well with the network-online.target.

Arch Linux

#1 2015-03-17 02:11:19

OpenVPN.service starts before network is up

#2 2015-03-17 02:24:27

Re: OpenVPN.service starts before network is up

#3 2015-03-17 02:26:57

Re: OpenVPN.service starts before network is up

#4 2015-03-17 02:32:34

Re: OpenVPN.service starts before network is up

#5 2015-03-17 02:36:48

Re: OpenVPN.service starts before network is up

#6 2015-03-17 02:43:32

Re: OpenVPN.service starts before network is up

#7 2015-03-17 02:56:11

Re: OpenVPN.service starts before network is up

#8 2015-04-30 23:28:06

Re: OpenVPN.service starts before network is up

#9 2015-05-01 07:29:45

Re: OpenVPN.service starts before network is up

Board footer