[karmic] openvpn service starts before dhclient

[Peter Matulis]

Binary package hint: openvpn

I have a server that was upgraded from 9.04 to 9.10. I cannot say with certainty what was happening during 9.04 but systematically when I reboot the daemon does not come up:

$ sudo service openvpn status
[sudo] password for blah:
 * could not access PID file for VPN 'server'

$ sudo service openvpn start
 * Starting virtual private network daemon(s)...
 * Autostarting VPN 'server'
   ...done.

 $ sudo service openvpn status
 * VPN 'server' is running

The server is currently being assigned an IP address (DHCP). It looks like that OpenVPN is coming up before that address is provided. From /var/log/syslog:

openvpn[815]: TCP/UDP: Socket bind failed on local address 11.153.118.61:1194: Cannot assign requested address
openvpn[815]: Exiting
kernel: [ 13.380034] br0: port 1(eth0) entering forwarding state
dhclient: Internet Systems Consortium DHCP Client V3.1.2
dhclient: Copyright 2004-2008 Internet Systems Consortium.
dhclient: All rights reserved.
dhclient: For info, please visit http://www.isc.org/sw/dhcp/
dhclient:
kernel: [ 14.364042] eth0: no IPv6 routers present
kernel: [ 14.428029] br0: no IPv6 routers present
dhclient: Listening on LPF/br0/54:52:00:5e:0a:26
dhclient: Sending on LPF/br0/54:52:00:5e:0a:26
dhclient: Sending on Socket/fallback
dhclient: DHCPDISCOVER on br0 to 255.255.255.255 port 67 interval 4
dhclient: DHCPOFFER of 11.153.118.61 from 11.153.118.1
dhclient: DHCPREQUEST of 11.153.108.61 on br0 to 255.255.255.255 port 67
dhclient: DHCPACK of 11.153.108.61 from 11.153.118.1
dhclient: bound to 11.153.108.61 -- renewal in 102522 seconds

[Alvin (alvind)]

Does this also happen when you use a static IP?

[Peter Matulis (petermatulis)]

I doubt it.

[Chuck Short (zulcss)]

This might be an upstart race.

Regards
chuck

[yiun (yiun)]

I had the same problem with a static ip. I think the problem is that openvpn starts before ip-binding does. Even when openvpn is the last script in the rc, the problem occurs furthermore.

I solved the problem by removing the line "local xxx.xxx.xxx.xxx." out of the server.conf.

[imagine (imagine-de)]

Problem still exists in 10.04 (probably also 10.10).
Another workaround: Add a sleep time at the autostart section of /etc/init.d/openvpn before the "start_vpn" command.
if ! ip addr show dev eth0 | grep -q 'inet' ; then
  sleep 10
fi

Of course change eth0 to whatever device OpenVPN is listening on.

[Jim Cheetham (jim.cheetham)]

Problem also occurs on a 10.04.1 machine, where OpenVPN is supposed to be listening to connections coming in on a bridged interface (ultimately to place client sessions on that same interface).

Section of syslog:
Dec 8 11:45:40 moonshine ovpn-areo[849]: TCP/UDP: Socket bind failed on local address [AF_INET]10.1.1.2:1194: Cannot assign requested address
Dec 8 11:45:40 moonshine ovpn-areo[849]: Exiting
Dec 8 11:45:41 moonshine kernel: [ 9.870963] e1000e: officenet NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX/TX
Dec 8 11:45:41 moonshine kernel: [ 9.871441] ADDRCONF(NETDEV_CHANGE): officenet: link becomes ready
Dec 8 11:45:41 moonshine kernel: [ 9.871659] officebr: port 1(officenet) entering learning state
Dec 8 11:45:41 moonshine ntpd[1179]: listening on 127.0.0.1
Dec 8 11:45:41 moonshine ntpd[1179]: listening on 10.90.1.1
Dec 8 11:45:41 moonshine ntpd[1179]: listening on ::1
Dec 8 11:45:41 moonshine ntpd[1179]: listening on fe80::206:4fff:fe86:e747%prodnet
Dec 8 11:45:41 moonshine ntpd[1179]: listening on fe80::213:72ff:fe2d:ddd6%officenet
Dec 8 11:45:41 moonshine ntpd[1179]: fatal: bind: Cannot assign requested address
Dec 8 11:45:41 moonshine ntpd[1178]: dispatch_imsg in main: pipe closed
Dec 8 11:45:41 moonshine ntpd[1178]: Terminating
Dec 8 11:45:43 moonshine kernel: [ 11.909297] ip_tables: (C) 2000-2006 Netfilter Core Team
Dec 8 11:45:43 moonshine kernel: [ 11.962461] nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
Dec 8 11:45:43 moonshine kernel: [ 11.962707] CONFIG_NF_CT_ACCT is deprecated and will be removed soon. Please use
Dec 8 11:45:43 moonshine kernel: [ 11.962710] nf_conntrack.acct=1 kernel parameter, acct=1 nf_conntrack module option or
Dec 8 11:45:43 moonshine kernel: [ 11.962712] sysctl net.netfilter.nf_conntrack_acct=1 to enable it.
Dec 8 11:45:48 moonshine kernel: [ 17.021256] prodnet: no IPv6 routers present
Dec 8 11:45:48 moonshine kernel: [ 17.490006] officebr: no IPv6 routers present
Dec 8 11:45:50 moonshine kernel: [ 18.870010] officebr: port 1(officenet) entering forwarding state

Looking at that log segment, we can also see that ntpd has failed in the same way, so this is not an openvpn-specific problem

[penzoiders (fungoiders)]

Same issue here as describen by Jim Cheetham on 2010-12-09. This is ubuntu server 10.04.2 all updates installed as 2011-07-12.

tried to change start sequence with: update-rc.d openvpn defaults 99 10

but this not help.

If I boot machine, log and "sudo service openvpn start" it just works.

is there a workaround to automatically start the vpn as last service?

[samarth bhargava (samarth-bhargava)]

I am also facing the same problem. Any workarounds available?

[Peter Matulis (petermatulis)]

Sure, use /etc/rc.local.

service openvpn restart

[sefs (sefsinc)]

I just ran into this problem on Ubuntu Server 10.04.4. Glad to see there is a work-around.

[Peter Matulis (petermatulis)]

I noticed the errant behaviour does not exist starting with Ubuntu 11.04.

[Simon Déziel (sdeziel)]

Marking as Fix released based on Peter's comment (#11). Thanks