OpenVPN process status says not running when it is. #3223

marjohn56 · 2019-02-11T22:36:54Z

https://forum.opnsense.org/index.php?topic=11562.0

This seems to be a stick pid issue. We are testing a solution for it.

AdSchellevis · 2019-02-12T07:44:48Z

the status check connects to the socket, if that doesn't work, this might happen. (I've seen something similar over here too)

core/src/etc/inc/plugins.inc.d/openvpn.inc

Line 1304 in d27cc83

function openvpn_get_server_status($server, $socket)

If it reports an error, we might want to check for a running pid before returning not active, if I'm not mistaken, you can't restart the server in these cases (since reported running), right?

marjohn56 · 2019-02-12T07:53:35Z

The pid's don't match. The running process pid and the one in var/run are different. Thus the dashboard says nay but openvpn says yay!

You can't restart no, as the pid is wrong. Manually killing it will not help either as you also need to delete the stuck pid, do that and all is good. What I've done in my test is to force a clean up of the stuck pid in the openvpn restart function, at present it just deletes the stuck pid. What really should be done is to check that the process is actually not running - THEN delete the pid, however lets see what happens with my tester and see what he reports.

AdSchellevis · 2019-02-12T07:54:50Z

sounds like a plan :)

fichtner · 2019-02-12T08:04:26Z

From previous tickets this seems to be a race in OpenVPN or maybe in the way we restart it in an edge case. However, it was not reproducible from my end.

…

On 12. Feb 2019, at 08:54, Ad Schellevis ***@***.***> wrote: sounds like a plan :) — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or mute the thread.

marjohn56 · 2019-02-12T08:13:32Z

No and I cannot reproduce it either, or at least only on rare occasions. Ned however can reproduce it at will. He's had the issue since the early 18 series, but now it's starting to annoy him so I said I'd tale a look.

I think it only happens on restart, not sure if it does it on IF down/up. Whichever way this occurs, the only usual way a process would leave its pid behind is if it exits abnormally.

Space2Man · 2019-02-12T19:42:21Z

Hi,

some things I found out. This happens always after a restart:

root@OPNvirt:~ # ls -lT /var/run/openvpn_server1.pid 
-rw-r--r--  1 root  wheel  6 Feb 12 20:31:58 2019 /var/run/openvpn_server1.pid

After reboot I see three times a Resync

Feb 12 20:31:45 OPNvirt opnsense: /usr/local/etc/rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP6.
Feb 12 20:31:45 OPNvirt opnsense: /usr/local/etc/rc.openvpn: OpenVPN: Resync server1 SpaceNet OpenVPN Server
Feb 12 20:31:47 OPNvirt opnsense: /usr/local/etc/rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_IPv4_Dokom21.
Feb 12 20:31:51 OPNvirt opnsense: /usr/local/etc/rc.openvpn: OpenVPN: Resync server1 SpaceNet OpenVPN Server
Feb 12 20:31:57 OPNvirt opnsense: /usr/local/etc/rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP6.
Feb 12 20:31:57 OPNvirt opnsense: /usr/local/etc/rc.openvpn: OpenVPN: Resync server1 SpaceNet OpenVPN Server

My guess is that the restarts are too close to each other so one get's started while the previous one still did not finish. And maybe the third one created the PID but then failed to start ...

marjohn56 · 2019-02-13T12:02:54Z

#3229 possible fix ... needs testing

@marjohn56

PR: #3223 Suggested by: @marjohn56

fichtner · 2019-02-14T17:39:13Z

@BPtLNfxZWo @Space2Man can you please try c217bee ?

# opnsense-patch c217bee

fichtner · 2019-02-14T17:53:57Z

Some patches from pfSense:

pfsense/pfsense@8845e13
pfsense/pfsense@ce98375

BPtLNfxZWo · 2019-02-14T18:00:06Z

Seems to work right now.
GUI information correct, error messages gone, tunnel could be established
Thanks

Space2Man · 2019-02-14T21:36:43Z

Seems to work fine! After reboot service is listed as started!

fichtner · 2019-02-15T07:30:05Z

Ok, I cannot guarantee that this will not fail later anyway. Patches posted earlier suggest that OpenVPN may be issuing its PID files too late, but we'll see when we get there.

Thanks everyone! ❤️

(cherry picked from commit c217bee) (cherry picked from commit 156d6f7) (cherry picked from commit f10b710)

BPtLNfxZWo · 2019-02-16T09:49:35Z

Hi,
checked today, same issue again :-(

marjohn56 · 2019-02-18T08:51:42Z

@Space2Man & @BPtLNfxZWo

Looking at some debug info that I have been sent. Are you using a Dyn DNS service and are you using dhcp6 for WAN?

BPtLNfxZWo · 2019-02-19T19:47:54Z

Hi, in my case I'm using Dynamic DNS but no dhcpv6 on WAN.

nivek1612 · 2019-02-20T13:34:05Z

@marjohn56 I'll be in France from Friday my set up there is Dynamic DNS and dhcp6c on WAN. Want me to test anything ? Currently on 18.7.9 without issues planning to take the test system out and try 19.1.1

marjohn56 · 2019-02-20T13:39:28Z

Yes, everything!

marjohn56 · 2019-02-20T14:05:08Z

@BPtLNfxZWo > Hi, in my case I'm using Dynamic DNS but no dhcpv6 on WAN.

so no ipv6?

BPtLNfxZWo · 2019-02-20T19:06:22Z

Hi, I'm have ipv6 activated, but only for (internal) testing purposes and not on the WAN Interface.

marjohn56 · 2019-02-20T19:12:31Z

Thanks, that rules something out, so no ipv6. Can you disable your Dyn DNS update and see if that has any effect on your openvpn issue. I'm trying to rule things out, I have no issues at all and I'm trying to replicate it.

kkohio · 2019-02-21T18:04:53Z

I just wanted to add that I am on a fresh setup on 19.1 LibreSSL side with very little configured. No IPv6 or DynDNS... just two WANs with failover, ipv4 DHCP on the LAN. I single port forwarding rule and pretty much everything else is pristine.

Benqer0 · 2019-03-07T20:29:20Z

I have the same problem:

Mar 7 21:14:33	openvpn[34459]: Exiting due to fatal error
Mar 7 21:14:33	openvpn[34459]: Cannot open TUN/TAP dev /dev/tun1: Device busy (errno=16)
Mar 7 21:14:33	openvpn[34459]: TUN/TAP device ovpns1 exists previously, keep at program end
Mar 7 21:14:33	openvpn[34459]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Mar 7 21:14:33	openvpn[34138]: library versions: OpenSSL 1.0.2q 20 Nov 2018, LZO 2.10
Mar 7 21:14:33	openvpn[34138]: OpenVPN 2.4.7 amd64-portbld-freebsd11.2 [SSL (OpenSSL)] [LZO] [LZ4] [MH/RECVDA] [AEAD] built on Feb 27 2019

OPNsense 19.1.2-amd64
FreeBSD 11.2-RELEASE-p9-HBSD
OpenSSL 1.0.2q 20 Nov 2018

JasMan78 · 2019-03-19T06:24:01Z

Same issue here. It suddendly appeared after I've changed all my LAN subnet addresses by replacing them in the config backup file and restore it back.

OPNsense 19.1.4-amd64
Intel(R) Celeron(R) CPU J1900 @ 1.99GHz (4 cores)

Space2Man · 2019-04-05T10:02:59Z

FYI: I am on 19.1.4 and issue is back ... yes, I am using IPv6 on WAN but no DynDNS.

Space2Man · 2019-04-05T10:17:04Z

Funny, right after posting this 19.1.5 was released ... I just updated and OpenVPN is in status green again ... I will monitor.

Thanks!

fichtner · 2019-04-05T10:18:21Z

I'll be back eventually. This is a race condition inside OpenVPN and its PID file creation in which OpenVPN backgrounds itself before the PID file is written. Someone needs to write safeguard code here in order to fix this. I don't think OpenVPN will....

Space2Man · 2019-04-05T10:30:53Z

Hi, can confirm ... after "saving" WAN interface to trigger reload issue is back ... really seems to be some race condition. Nevertheless thanks for all the support ... I mean, it's working ... so it's only a display issue.

fichtner · 2019-04-05T10:32:32Z

I'll try to look at it for 19.7. At the moment, however, priorities lie elsewhere.

Seethaar · 2020-01-27T21:14:36Z

I tested this on a VM. When I built the new OPNsense firewall on version 19.7 (not the latest but just 19.7), there were no issues. But I took a VMware snapshot and spun a new firewall up from that template, which carried the CA, self-signed cert, VPN server and OTP server and I observed that the firewall is exhibiting the same behaviour mentioned on this issue.

Dashboard says OPENVPN not working.
Server error log : openvpn[66505]: Exiting due to fatal error
VPN server 'Connection Status' indeterminable.
Clients can connect successfully.

Thought worth sharing.

fichtner · 2020-01-27T22:01:02Z

This is a closed ticket. If you experience this OpenVPN takes more than 10 seconds to come up. There’s a log message in any case you haven’t provided here. It probably points to the former timeout comment.

…

On 27. Jan 2020, at 22:14, Ayyappan Ramanan ***@***.***> wrote: I tested this on a VM. When I built the new OPNsense firewall on version 19.7 (not the latest but just 19.7), there were no issues. But I took a VMware snapshot and spun a new firewall up from that template, which carried the CA, self-signed cert, VPN server and OTP server and I observed that the firewall is exhibiting the same behaviour mentioned on this issue. Dashboard says OPENVPN not working. Server error log : openvpn[66505]: Exiting due to fatal error VPN server 'Connection Status' indeterminable. Clients can connect successfully. Thought worth sharing. — You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub, or unsubscribe.

fichtner added a commit that referenced this issue Feb 14, 2019

openvpn: remove stale PID file as well

f10b710

PR: #3223 Suggested by: @marjohn56

fichtner assigned fichtner and marjohn56 Feb 14, 2019

fichtner added the bug Production bug label Feb 14, 2019

fichtner added this to the 19.7 milestone Feb 14, 2019

fichtner added a commit that referenced this issue Feb 14, 2019

openvpn: proper daemonize instead of background job #3223

c217bee

fichtner added a commit that referenced this issue Feb 14, 2019

openvpn: daemon is already in the config #3223

156d6f7

fichtner closed this as completed Feb 15, 2019

fichtner added a commit that referenced this issue Feb 15, 2019

openvpn: proper daemonize instead of background job #3223

2251cf5

(cherry picked from commit c217bee) (cherry picked from commit 156d6f7) (cherry picked from commit f10b710)

fichtner mentioned this issue Feb 16, 2019

[Bug] OpenVPN - unable to contact Daemon / device busy #1931

Closed

fichtner reopened this Feb 16, 2019

fichtner closed this as completed in 1669dde Apr 29, 2019

fichtner added a commit that referenced this issue Apr 29, 2019

openvpn: minor tweaks #3223

82b8cf7

EugenMayer pushed a commit to KontextWork/opnsense_core that referenced this issue Jul 22, 2019

openvpn: waitforpid() use to catch race; closes opnsense#3223

5e1781c

EugenMayer pushed a commit to KontextWork/opnsense_core that referenced this issue Jul 22, 2019

openvpn: minor tweaks opnsense#3223

d7372f2

EugenMayer pushed a commit to KontextWork/opnsense_core that referenced this issue Jul 22, 2019

openvpn: waitforpid() use to catch race; closes opnsense#3223

0c8ba20

EugenMayer pushed a commit to KontextWork/opnsense_core that referenced this issue Jul 22, 2019

openvpn: minor tweaks opnsense#3223

d372218

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

OpenVPN process status says not running when it is. #3223

OpenVPN process status says not running when it is. #3223

marjohn56 commented Feb 11, 2019

AdSchellevis commented Feb 12, 2019

marjohn56 commented Feb 12, 2019

AdSchellevis commented Feb 12, 2019

fichtner commented Feb 12, 2019 via email

marjohn56 commented Feb 12, 2019

Space2Man commented Feb 12, 2019

marjohn56 commented Feb 13, 2019

fichtner commented Feb 14, 2019

fichtner commented Feb 14, 2019

BPtLNfxZWo commented Feb 14, 2019

Space2Man commented Feb 14, 2019

fichtner commented Feb 15, 2019

BPtLNfxZWo commented Feb 16, 2019

marjohn56 commented Feb 18, 2019

BPtLNfxZWo commented Feb 19, 2019

nivek1612 commented Feb 20, 2019 •

edited

Loading

marjohn56 commented Feb 20, 2019 via email •

edited

Loading

marjohn56 commented Feb 20, 2019 •

edited

Loading

BPtLNfxZWo commented Feb 20, 2019

marjohn56 commented Feb 20, 2019

kkohio commented Feb 21, 2019

Benqer0 commented Mar 7, 2019

JasMan78 commented Mar 19, 2019

Space2Man commented Apr 5, 2019

Space2Man commented Apr 5, 2019

fichtner commented Apr 5, 2019 •

edited

Loading

Space2Man commented Apr 5, 2019

fichtner commented Apr 5, 2019

Seethaar commented Jan 27, 2020

fichtner commented Jan 27, 2020 via email

OpenVPN process status says not running when it is. #3223

OpenVPN process status says not running when it is. #3223

Comments

marjohn56 commented Feb 11, 2019

AdSchellevis commented Feb 12, 2019

marjohn56 commented Feb 12, 2019

AdSchellevis commented Feb 12, 2019

fichtner commented Feb 12, 2019 via email

marjohn56 commented Feb 12, 2019

Space2Man commented Feb 12, 2019

marjohn56 commented Feb 13, 2019

fichtner commented Feb 14, 2019

fichtner commented Feb 14, 2019

BPtLNfxZWo commented Feb 14, 2019

Space2Man commented Feb 14, 2019

fichtner commented Feb 15, 2019

BPtLNfxZWo commented Feb 16, 2019

marjohn56 commented Feb 18, 2019

BPtLNfxZWo commented Feb 19, 2019

nivek1612 commented Feb 20, 2019 • edited Loading

marjohn56 commented Feb 20, 2019 via email • edited Loading

marjohn56 commented Feb 20, 2019 • edited Loading

BPtLNfxZWo commented Feb 20, 2019

marjohn56 commented Feb 20, 2019

kkohio commented Feb 21, 2019

Benqer0 commented Mar 7, 2019

JasMan78 commented Mar 19, 2019

Space2Man commented Apr 5, 2019

Space2Man commented Apr 5, 2019

fichtner commented Apr 5, 2019 • edited Loading

Space2Man commented Apr 5, 2019

fichtner commented Apr 5, 2019

Seethaar commented Jan 27, 2020

fichtner commented Jan 27, 2020 via email

nivek1612 commented Feb 20, 2019 •

edited

Loading

marjohn56 commented Feb 20, 2019 via email •

edited

Loading

marjohn56 commented Feb 20, 2019 •

edited

Loading

fichtner commented Apr 5, 2019 •

edited

Loading