Adventures in OpenVPN

OpenVPN has changed the game for secure access to corporate networks. It doesn’t suffer from the many performance, security, and networking drawbacks of Layer Two Tunneling and older Point To Point Tunneling protocols.

OpenVPN Access Server is a popular commercial VPN Server product that is in production with several of our clients and allows for integration into a number of identity management systems, multi-factor-authentication, and key-pair authentication, as well as a combination thereof.

While – offering great, scalable performance –, the system is complex, and when things go wrong it is important to have a resource like mac-tech dedicated to the building and maintenance of the system.

Recently, things did go wrong. An inadvertent image roll-back on the Amazon EC2 instance hosting the service rendered the service inaccessible.

Here’s how we solved the problem:

The OpenVPN Server OS was booted, but the VPN service itself was not responding, nor were its user-facing or administrative web interfaces loading.

In this case, the system processes required for OpenVPN Access Server were installed and loading:
[root@centos]# systemctl status openvpnas.service
● openvpnas.service - OpenVPN Access Server Service
Loaded: loaded (/usr/lib/systemd/system/openvpnas.service; enabled; vendor preset: disabled)
Active: active (running) since Tue 2021-03-02 00:16:33 UTC; 3 days ago
Process: 1054 ExecStart=/usr/local/openvpn_as/scripts/openvpnas --logfile=/var/log/openvpnas.log --pidfile=/run/openvpnas.pid (code=exited, status=0/SUCCESS)
…
The access server itself could not load, however.

The command-line tool for Access Server helps here, as it will issue running state parameters and errors. The command lives under the OpenVPN Access Server install directory inside ‘scripts’:

/usr/local/openvpn_as/scripts/sacli

It does so in JSON format, which is easily readable since it displays the keys and corresponding values in neat pairs. For example:

{ "color":"blue" }

Here’s the output of a regular status query when everything works:

/usr/local/openvpn_as/scripts/sacli Status
{
"active_profile": "Default",
"errors": {},
"last_restarted": “Fri May 7 22:24:28 2021",
"service_status": {
"api": "on",
"auth": "on",
"bridge": "on",
"client_query": "on",
"crl": "on",
"daemon_pre": "on",
"db_push": "on",
"ip6tables_live": "on",
"ip6tables_openvpn": "on",
"iptables_live": "on",
"iptables_openvpn": "on",
"iptables_web": "on",
"log": "on",
"openvpn_0": "on",
"openvpn_1": "on",
"openvpn_2": "on",
"openvpn_3": "on",
"subscription": "on",
"user": "on",
"web": "on"
}
}

If something is amiss, the status query will produce very useful output. Configuration values that collide with other system services are fairly common, such as attempting to bind the web interface to a port already used by a web server (443/TCP). (It will fail.) However, that was not the case here. In this instance, we saw missing configuration keys.

The way this condition could manifest itself is in Log Entries that indicate a constant cycling of the web service starting and stopping. Here’s a look at the log file:

#tail -f -n6 /var/log/openvpnas.log
2021-05-12T21:05:07+0000 [twisted.python.log#info] "-" - - [12/May/2021:21:05:07 +0000] "POST /RPC2 HTTP/1.0" 200 178 "-" "Twisted/XMLRPClib"
2021-05-12T21:05:07+0000 [stdout#info] [WEB] OUT: '2021-05-12T21:05:07+0000 [pyovpn.xml.udscli.UDSProxyQueryFactory#info] Starting factory <pyovpn.xml.udscli.UDSProxyQueryFactory instance at 0x789012345>'
2021-05-12T21:05:07+0000 [stdout#info] [WEB] OUT: '2021-05-12T21:05:07+0000 [pyovpn.xml.udscli.UDSProxyQueryFactory#info] Stopping factory <pyovpn.xml.udscli.UDSProxyQueryFactory instance at 0x789012345>'
2021-05-12T21:05:07+0000 [twisted.python.log#info] "-" - - [12/May/2021:21:05:07 +0000] "POST /RPC2 HTTP/1.0" 200 4577 "-" "Twisted/XMLRPClib"
2021-05-12T21:05:07+0000 [stdout#info] [WEB] OUT: '2021-05-12T21:05:07+0000 [pyovpn.xml.udscli.UDSProxyQueryFactory#info] Starting factory <pyovpn.xml.udscli.UDSProxyQueryFactory instance at 0x7fa81bf10950>'
2021-05-12T21:05:07+0000 [stdout#info] [WEB] OUT: '2021-05-12T21:05:07+0000 [pyovpn.xml.udscli.UDSProxyQueryFactory#info] Stopping factory <pyovpn.xml.udscli.UDSProxyQueryFactory instance at 0x789012345>'

The server stores its configuration in a database. The legacy database format of OpenVPN Server is SQLite, while some newer builds allow you to use MySQL, a requirement for VPN Server clustering. In either case, the configuration values can be queried and manipulated using the same command-line utility commands.

/usr/local/openvpn_as/scripts/sacli

A port collision on port 443 (HTTPS) can be removed by moving the TCP listening port from the default 443 to 4433:

/usr/local/openvpn_as/scripts/sacli --key "vpn.server.daemon.tcp.port" --value "4433” ConfigPut
/usr/local/openvpn_as/scripts/sacli start

And we’re back in business.

The moral of this story is not so much a plug for our problem-solving skills (although we like to think we’re pretty good at it), but a reminder that our systems are knit together in a highly intricate fashion. This is where we get speed, security, and accuracy, but it’s also where inadvertent image rollbacks can render seemingly unrelated systems mysteriously unusable.

Got any OpenVPN Server adventures to share? Post yours in the comments!