OpenVPN assert in ssl.c (line 1857) on Feb 8 snap (was fine on Feb 4 snap)

wernerj

This is a new error I've never experienced before with pfSense and OpenVPN. This system has been working fine most recently with the Feb 4 snapshot without any OpenVPN-related issued. This morning I upgraded to the Feb 8 snapshot and now any attempts to connect a client to OpenVPN makes the openvpn process assert and crash:

Feb 8 11:24:50 pfsense openvpn[53076]: OpenVPN 2.3.0 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Jan 27 2013
Feb 8 11:24:50 pfsense openvpn[53076]: WARNING: using –duplicate-cn and --client-config-dir together is probably not what you want
Feb 8 11:24:50 pfsense openvpn[53076]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
Feb 8 11:24:50 pfsense openvpn[53076]: Initializing OpenSSL support for engine 'cryptodev'
Feb 8 11:24:50 pfsense openvpn[53076]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
Feb 8 11:24:50 pfsense openvpn[53076]: TUN/TAP device ovpns1 exists previously, keep at program end
Feb 8 11:24:50 pfsense openvpn[53076]: TUN/TAP device /dev/tun1 opened
Feb 8 11:24:50 pfsense openvpn[53076]: do_ifconfig, tt->ipv6=1, tt->did_ifconfig_ipv6_setup=1
Feb 8 11:24:50 pfsense openvpn[53076]: /sbin/ifconfig ovpns1 xx.xx.xx.xx xx.xx.xx.xx mtu 1500 netmask 255.255.255.255 up
Feb 8 11:24:50 pfsense openvpn[53076]: /sbin/ifconfig ovpns1 inet6 fe80:ffff::1/64
Feb 8 11:24:50 pfsense openvpn[53076]: /usr/local/sbin/ovpn-linkup ovpns1 1500 1558 xx.xx.xx.xx xx.xx.xx.xx init
Feb 8 11:24:50 pfsense openvpn[60804]: UDPv4 link local (bound): [AF_INET]xx.xx.xx.xx:1194
Feb 8 11:24:50 pfsense openvpn[60804]: UDPv4 link remote: [undef]
Feb 8 11:24:50 pfsense openvpn[60804]: Initialization Sequence Completed
Feb 8 11:26:36 pfsense openvpn[60804]: xx.xx.xx.xx:20135 Assertion failed at ssl.c:1857
Feb 8 11:26:36 pfsense openvpn[60804]: xx.xx.xx.xx:20135 Exiting due to fatal error
Feb 8 11:26:36 pfsense openvpn[60804]: xx.xx.xx.xx:20135 /usr/local/sbin/ovpn-linkdown ovpns1 1500 1558 xx.xx.xx.xx xx.xx.xx.xx init
pfsense openvpn[24373]: xx/xx.xx.xx.xx:23074 send_push_reply(): safe_cap=960

ssl.c hasn't been touched for 10 months so I assume the line corresponds to this assert at that exact line number in the current repository:

/* discard leading uint32 */
ASSERT (buf_advance (buf, 4));

(which is in function key_method_2_read)

Has anyone else seen this problem? Searching for asserts in OpenVPN turned up a lot of asserts in crypto.c because of malformed/broken certificates but not in ssl.c. Not sure if the configuration has been broken by the upgrade of if something else changed (as the openvpn binary seems to be the same as in the Feb 4 snap).

This is what the same connection looked like with the Feb 4 snap:

Feb 4 23:49:04 pfsense openvpn[53034]: OpenVPN 2.3.0 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Jan 27 2013
Feb 4 23:49:04 pfsense openvpn[53034]: WARNING: using –duplicate-cn and --client-config-dir together is probably not what you want
Feb 4 23:49:04 pfsense openvpn[53034]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
Feb 4 23:49:04 pfsense openvpn[53034]: Initializing OpenSSL support for engine 'cryptodev'
Feb 4 23:49:04 pfsense openvpn[53034]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
Feb 4 23:49:04 pfsense openvpn[53034]: TUN/TAP device ovpns1 exists previously, keep at program end
Feb 4 23:49:04 pfsense openvpn[53034]: TUN/TAP device /dev/tun1 opened
Feb 4 23:49:04 pfsense openvpn[53034]: do_ifconfig, tt->ipv6=1, tt->did_ifconfig_ipv6_setup=1
Feb 4 23:49:04 pfsense openvpn[53034]: /sbin/ifconfig ovpns1 xx.xx.xx.xx xx.xx.xx.xx mtu 1500 netmask 255.255.255.255 up
Feb 4 23:49:04 pfsense openvpn[53034]: /sbin/ifconfig ovpns1 inet6 fe80:ffff::1/64
Feb 4 23:49:04 pfsense openvpn[53034]: /usr/local/sbin/ovpn-linkup ovpns1 1500 1558 xx.xx.xx.xx xx.xx.xx.xx init
Feb 4 23:49:04 pfsense openvpn[54409]: UDPv4 link local (bound): [AF_INET]xx.xx.xx.xx:1194
Feb 4 23:49:04 pfsense openvpn[54409]: UDPv4 link remote: [undef]
Feb 4 23:49:04 pfsense openvpn[54409]: Initialization Sequence Completed
Feb 4 23:49:48 pfsense openvpn: user 'xx' authenticated
Feb 4 23:49:48 pfsense openvpn[54409]: xx.xx.xx.xx:17685 WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
Feb 4 23:49:48 pfsense openvpn[54409]: xx.xx.xx.xx:17685 [xx] Peer Connection Initiated with [AF_INET]xx.xx.xx.xx:17685
Feb 4 23:49:48 pfsense openvpn[54409]: xx/xx.xx.xx.xx:17685 MULTI_sva: pool returned IPv4=xx.xx.xx.xx, IPv6=fe80:ffff::1000
Feb 4 23:49:50 pfsense openvpn[54409]: xx/xx.xx.xx.xx:17685 send_push_reply(): safe_cap=940

/wj

wernerj

I have tried rebooting a few times and re-applying the openvpn config (disabling/re-enabling in web configurator) and sometimes it won't assert but instead give me these errors:

openvpn[37554]: 216.75.224.218:7393 TLS_ERROR: BIO read tls_read_plaintext error: error:1408F06B:SSL routines:SSL3_GET_RECORD:bad decompression
openvpn[37554]: 216.75.224.218:7393 TLS Error: TLS object -> incoming plaintext read error
openvpn[37554]: 216.75.224.218:7393 TLS Error: TLS handshake failed

I have tried disabling AES-NI as well with no changes in the results.

/wj

wernerj

Manually replacing /usr/local/lib/libssl.so* with the version from the Feb 04 snapshot will let the OpenVPN server run again. Not an ideal solution, but shows that the openssl upgrade seems to cause the issue.

/wj

eri--

Yeah seems an openssl issue that will resolve as soon as upstream resolves the issue.
The urgent upgrade was done due to security issues released lately.

wernerj

Understood. Will keep an eye out for changes in either OpenVPN or OpenSSL. Not sure if the updated OpenSSL triggered a bug somewhere in OpenVPN or if this is an actual issue within OpenSSL itself. Doesn't seem to be a very common problem though, as I couldn't locate any other bug reports that looked similar to this case…

UPDATE: Well, after some more Googling posts like this turned up: http://lists.freebsd.org/pipermail/freebsd-ports/2013-February/081259.html
(basically explaining that OpenSSL 1.0.1d is broken) - so let's see how 1.0.1e performs when that is available from upstream.

/wj

eri--

Thanks merging the fix in our port until final 1.0.1e comes out.

wernerj

I have now successfully gotten OpenVPN to work again with the 20130209-1139 snapshot, so the fix seems to be just what was needed, thanks for the quick fix!!

Don't be fooled by the reported 1.0.1.d Feb 5 2013 label from /usr/loca/bin/openssl version, this snapshot definitely comes with a patched version.

/wj

lucky

Had this same problem and the update today fixed the issues for me as well.

However, for some reason I had no default route when pfsense booted. I had to add it manually from the shell. I checked my config and it seems correct…I'm not sure what happened. I'll have to test more later...

cforger

I can confirm the lack of default route after an upgrade to today's snapshot. I too was having the ssl issue, so went for an update.

I think I'll make this a separate post, as something must be broken if I'm not the only one with the default gateway issue after today's snapshot.

wernerj

@lucky:

However, for some reason I had no default route when pfsense booted.

@cforger:

I can confirm the lack of default route after an upgrade to today's snapshot.

That's odd, it's been a long time since I saw routes not being applied during boot, but in my case the default route is provisioned using DHCP. Are yours a static default route by any chance?

/wj

cforger

(I'll switch this over to the new thread I just started)