Pfsense 2.3: TLS handshake failed/ Failed running command (–tls-verify script)

pfff · Apr 14, 2016, 7:09 PM

Hi

After upgrade to 2.3-RC and then 2.3-RELEASE I am unable to authenticate to the openvpn server using Openvpn Connect on iOS when I try to connect. The same problem occurs regardsless of whether I try over a cellular network from the WAN side or from inside my LAN. It worked fine with the same certificates, users and passwords for the last 1-2 years on 2.1-2.2x before the upgrade. I have tried reentering the user passwords in pfsense User Manager and reexporting the configs with Openvpn Client Export to the iOS devices. Here are some logs:

Log from Openvpn Connect on iOS (latest version)

2016-04-14 19:44:24 EVENT: RESOLVE
2016-04-14 19:44:24 LZO-ASYM init swap=0 asym=0
2016-04-14 19:44:24 Contacting A.B.229.237:443 via UDP
2016-04-14 19:44:24 EVENT: WAIT
2016-04-14 19:44:24 SetTunnelSocket returned 1
2016-04-14 19:44:24 Connecting to A.B.229.237:443 (A.B.229.237) via UDPv4
2016-04-14 19:44:25 EVENT: CONNECTING
2016-04-14 19:44:25 Tunnel Options:V4,dev-type tun,link-mtu 1602,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA512,keysize 256,tls-auth,key-method 2,tls-client
2016-04-14 19:44:25 Creds: Username/Password
2016-04-14 19:44:25 Peer Info:
IV_GUI_VER=net.openvpn.connect.ios 1.0.5-177
IV_VER=3.0
IV_PLAT=ios
IV_NCP=1
IV_LZO=1

2016-04-14 19:44:25 VERIFY OK: depth=1
cert. version    : 3
serial number    : 00
issuer name      : C=se, ST=state, L=city, O=hemma, emailAddress=mymail@me.com, CN=openvpn.ca
subject name      : C=se, ST=state, L=city, O=hemma, emailAddress=mymail@me.com, CN=openvpn.ca
issued  on        : 2015-08-05 06:49:37
expires on        : 2025-08-02 06:49:37
signed using      : RSA with SHA-256
RSA key size      : 4096 bits
basic constraints : CA=true
key usage        : Key Cert Sign, CRL Sign

2016-04-14 19:44:25 VERIFY OK: depth=0
cert. version    : 3
serial number    : 01
issuer name      : C=se, ST=state, L=city, O=hemma, emailAddress=mymail@me.com, CN=openvpn.ca
subject name      : C=se, ST=state, L=city, O=hemma, emailAddress=mymail@me.com, CN=openvpn.udp
issued  on        : 2015-08-05 06:49:38
expires on        : 2025-08-02 06:49:38
signed using      : RSA with SHA-256
RSA key size      : 4096 bits
basic constraints : CA=false
cert. type        : SSL Server
key usage        : Digital Signature, Key Encipherment
ext key usage    : TLS Web Server Authentication, ???

Log from pfsense openvpn

Apr 14 19:45:09	openvpn	42435	78.79.40.42:56957 TLS Error: TLS handshake failed
Apr 14 19:45:09	openvpn	42435	78.79.40.42:56957 TLS Error: TLS object -> incoming plaintext read error
Apr 14 19:45:09	openvpn	42435	78.79.40.42:56957 TLS_ERROR: BIO read tls_read_plaintext error: error:140890B2:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:no certificate returned
Apr 14 19:45:09	openvpn	42435	78.79.40.42:56957 WARNING: Failed running command (--tls-verify script): external program exited with error status: 1
Apr 14 19:44:26	openvpn	42435	78.79.40.42:52979 TLS Error: TLS handshake failed
Apr 14 19:44:26	openvpn	42435	78.79.40.42:52979 TLS Error: TLS object -> incoming plaintext read error
Apr 14 19:44:26	openvpn	42435	78.79.40.42:52979 TLS_ERROR: BIO read tls_read_plaintext error: error:140890B2:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:no certificate returned
Apr 14 19:44:26	openvpn	42435	78.79.40.42:52979 WARNING: Failed running command (--tls-verify script): external program exited with error status: 1
Apr 14 19:06:37	openvpn	42435	78.79.40.42:61740 TLS Error: TLS handshake failed

Log from pfsense general

Apr 14 19:43:29	php-fpm		/index.php: Successful login for user 'myadminuser' from: 10.12.12.20
Apr 14 17:54:00	xinetd	21257	Reconfigured: new=0 old=1 dropped=0 (services)
Apr 14 17:54:00	xinetd	21257	readjusting service 6969-udp
Apr 14 17:54:00	xinetd	21257	Swapping defaults
Apr 14 17:54:00	xinetd	21257	Starting reconfiguration
Apr 14 17:53:59	check_reload_status		Reloading filter
Apr 14 17:53:04	xinetd	21257	Reconfigured: new=0 old=1 dropped=0 (services)
Apr 14 17:53:04	xinetd	21257	readjusting service 6969-udp
Apr 14 17:53:04	xinetd	21257	Swapping defaults
Apr 14 17:53:04	xinetd	21257	Starting reconfiguration
Apr 14 17:53:03	check_reload_status		Reloading filter
Apr 14 17:53:03	check_reload_status		Syncing firewall
Apr 14 17:45:22	check_reload_status		Syncing firewall
Apr 14 17:44:56	check_reload_status		Syncing firewall
Apr 14 17:44:29	check_reload_status		Syncing firewall
Apr 14 17:43:08	php-fpm		/index.php: Successful login for user 'myadminuser' from: 10.12.12.38
Apr 13 23:49:14	kernel		arp: 10.12.12.20 moved from 20:c9:d0:44:3e:65 to 90:72:40:0a:a4:c1 on em0
Apr 13 22:45:16	xinetd	21257	Reconfigured: new=0 old=1 dropped=0 (services)
Apr 13 22:45:16	xinetd	21257	readjusting service 6969-udp
Apr 13 22:45:16	xinetd	21257	Swapping defaults
Apr 13 22:45:16	xinetd	21257	Starting reconfiguration
Apr 13 22:45:15	check_reload_status		Reloading filter
Apr 13 22:45:13	check_reload_status		Syncing firewall
Apr 13 22:44:52	xinetd	21257	Reconfigured: new=0 old=1 dropped=0 (services)
Apr 13 22:44:52	xinetd	21257	readjusting service 6969-udp
Apr 13 22:44:52	xinetd	21257	Swapping defaults
Apr 13 22:44:52	xinetd	21257	Starting reconfiguration
Apr 13 22:44:51	check_reload_status		Reloading filter
Apr 13 22:44:48	check_reload_status		Syncing firewall
Apr 13 22:43:29	xinetd	21257	Reconfigured: new=0 old=1 dropped=0 (services)
Apr 13 22:43:29	xinetd	21257	readjusting service 6969-udp
Apr 13 22:43:29	xinetd	21257	Swapping defaults
Apr 13 22:43:29	xinetd	21257	Starting reconfiguration
Apr 13 22:43:28	check_reload_status		Reloading filter
Apr 13 22:43:20	check_reload_status		Syncing firewall
Apr 13 22:40:28	xinetd	21257	Reconfigured: new=0 old=1 dropped=0 (services)
Apr 13 22:40:28	xinetd	21257	readjusting service 6969-udp
Apr 13 22:40:28	xinetd	21257	Swapping defaults
Apr 13 22:40:28	xinetd	21257	Starting reconfiguration
Apr 13 22:40:27	check_reload_status		Reloading filter
Apr 13 22:40:27	check_reload_status		Syncing firewall
Apr 13 22:38:46	xinetd	21257	Reconfigured: new=0 old=1 dropped=0 (services)
Apr 13 22:38:46	xinetd	21257	readjusting service 6969-udp
Apr 13 22:38:46	xinetd	21257	Swapping defaults
Apr 13 22:38:46	xinetd	21257	Starting reconfiguration
Apr 13 22:38:45	check_reload_status		Reloading filter
Apr 13 22:38:45	check_reload_status		Syncing firewall
Apr 13 22:21:00	sshd	92637	Disconnected from 10.12.12.20 port 53463
Apr 13 22:21:00	sshd	92637	Received disconnect from 10.12.12.20 port 53463:11: disconnected by user
Apr 13 22:01:05	pkg		pfSense downgraded: 2.3.1.a.20160412.1112 -> 2.3

I upgraded from 2.3-RC 160406 to 2.3.1 and to 2.3-RELEASE as per instructions by cmb in another post.

I suppose the line '(–tls-verify script): external program exited with error status: 1' points to the problem. I will be happy to help debugging this if necessary. Thank you in any case for a very nice release!

johnpoz · Apr 14, 2016, 6:25 PM

So I was running 2.3RC, and upgraded to 2.3 Release and having no issues with openvpn.. Just fired up a connection via my phone and boom connected..

Your problem is not the warning, but that fact that no cert was returned

"SSL3_GET_CLIENT_CERTIFICATE:no certificate returned"


2016-04-14 13:15:09 LZO-ASYM init swap=0 asym=0
2016-04-14 13:15:09 EVENT: RESOLVE
2016-04-14 13:15:09 Contacting 24.13.snipped:1194 via UDP
2016-04-14 13:15:09 EVENT: WAIT
2016-04-14 13:15:09 SetTunnelSocket returned 1
2016-04-14 13:15:09 Connecting to 24.13.snipped:1194 (24.13.snipped) via UDPv4
2016-04-14 13:15:09 EVENT: CONNECTING
2016-04-14 13:15:09 Tunnel Options:V4,dev-type tun,link-mtu 1570,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA256,keysize 256,tls-auth,key-method 2,tls-client
2016-04-14 13:15:09 Peer Info:
IV_GUI_VER=net.openvpn.connect.ios 1.0.5-177
IV_VER=3.0
IV_PLAT=ios
IV_NCP=1
IV_LZO=1

2016-04-14 13:15:09 VERIFY OK: depth=1
cert. version    : 3
serial number    : 00
issuer name      : C=US, ST=IL, L=Schaumburg, O=Home, emailAddress=johnpoz@snipped, CN=openvpn
subject name      : C=US, ST=IL, L=Schaumburg, O=Home, emailAddress=johnpoz@snipped, CN=openvpn
issued  on        : 2015-01-10 14:15:11
expires on        : 2025-01-07 14:15:11
signed using      : RSA with SHA-256
RSA key size      : 2048 bits
basic constraints : CA=true

2016-04-14 13:15:09 VERIFY OK: depth=0
cert. version    : 3
serial number    : 01
issuer name      : C=US, ST=IL, L=Schaumburg, O=Home, emailAddress=johnpoz@snipped, CN=openvpn
subject name      : C=US, ST=IL, L=Schaumburg, O=Home, emailAddress=johnpoz@snipped, CN=pfsenseopenvpn
issued  on        : 2015-01-10 14:15:12
expires on        : 2025-01-07 14:15:12
signed using      : RSA with SHA-256
RSA key size      : 2048 bits
basic constraints : CA=false
cert. type        : SSL Server
key usage        : Digital Signature, Key Encipherment
ext key usage    : TLS Web Server Authentication

2016-04-14 13:15:11 SSL Handshake: TLSv1.2/TLS-DHE-RSA-WITH-AES-256-CBC-SHA
2016-04-14 13:15:11 Session is ACTIVE
2016-04-14 13:15:11 EVENT: GET_CONFIG
2016-04-14 13:15:11 Sending PUSH_REQUEST to server...
2016-04-14 13:15:11 OPTIONS:
0 [route] [192.168.9.0] [255.255.255.0]
1 [route] [192.168.2.0] [255.255.255.0]
2 [route] [192.168.3.0] [255.255.255.0]
3 [dhcp-option] [DOMAIN] [local.lan]
4 [dhcp-option] [DNS] [192.168.9.253]
5 [route-gateway] [10.0.200.1]
6 [topology] [subnet]
7 [ping] [10]
8 [ping-restart] [60]
9 [ifconfig] [10.0.200.2] [255.255.255.0]

2016-04-14 13:15:11 LZO-ASYM init swap=0 asym=0
2016-04-14 13:15:11 EVENT: ASSIGN_IP
2016-04-14 13:15:11 Connected via tun
2016-04-14 13:15:11 EVENT: CONNECTED @24.13.snipped:1194 (24.13.snipped) via /UDPv4 on tun/10.0.200.2/
2016-04-14 13:15:12 SetStatus Connected

bennyc · Apr 14, 2016, 7:23 PM

That looks very similar to what I have encountered a while ago, see: https://forum.pfsense.org/index.php?topic=97572.msg543520

My issue was caused by a space in the certificate's CN. Any chance yours has one too? If not, I would anyway give it a try with recreating the server cert…

pfff · Apr 15, 2016, 3:07 PM

Hi bennyc, thank you for the suggestion! I tried deleting and then recreating all the certs (CA, server, user) without any spaces or other punctuation marks but with the same errors unfortunately. I haven't been able to do any further testing since I posted because of work but will continue trying.

emel_punk · Apr 15, 2016, 9:30 PM

So how is thing going?. I have installed Pfsense 2.2.6 and openvpn doesn't work, I cannot connect my clients. The error is


Fri Apr 15 16:27:55 2016 us=478668 ACK mark active incoming ID 24
Fri Apr 15 16:27:55 2016 us=478686 ACK acknowledge ID 24 (ack->len=1)
Fri Apr 15 16:27:55 2016 us=478707 BIO write tls_write_ciphertext 100 bytes
Fri Apr 15 16:27:55 2016 us=479154 VERIFY ERROR: depth=1, error=certificate is not yet valid: C=CA, ST=bogota, L=bogota, O=mdc, emailAddress=info@mdc.com.co, CN=internal-ca
Fri Apr 15 16:27:55 2016 us=479201 SSL alert (write): fatal: bad certificate
Fri Apr 15 16:27:55 2016 us=479300 TLS_ERROR: BIO read tls_read_plaintext error: error:14090086:SSL routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed
Fri Apr 15 16:27:55 2016 us=479334 TLS Error: TLS object -> incoming plaintext read error
Fri Apr 15 16:27:55 2016 us=479369 TLS Error: TLS handshake failed
Fri Apr 15 16:27:55 2016 us=479411 PID packet_id_free
Fri Apr 15 16:27:55 2016 us=479448 SSL alert (write): warning: close notify

I do not have firewall problems or anything, I repeated the process a lot and I am stuck at it. Please help

pfff · Apr 16, 2016, 9:47 AM

FYI I just reinstalled 2.3 and now it works as expected and as on 2.2.6. Something must have failed during the upgrade. Thank you for your help.

v0lZy · Dec 28, 2017, 12:25 PM

Some necromancy seems to have brought this back from the depths of hell and is now pulling at my leg…

Have a fresh pfSense install (2.4.2-RELEASE-p1 (amd64)) and I am encountering an issue with a self-signed setup. Here is what I'm seeing:

1 - Created my own CA, created a CRL for said CA, created a server certificate issued by said CA, created a user certificate issued by said CA when creating my user.
2 - Configured an OpenVPN server and set it to "Remote Access ( SSL/TLS + User Auth )", used said CA, CRL and server certificate.
3 - Used 'OpenVPN Client Export' and grabbed the Archive for said user.
4 - When connecting the VPN and after providing username and password, on pfSense I see:

WARNING: Failed running command (--tls-verify script): external program exited with error status: 1
OpenSSL: error:14089086:SSL routines:ssl3_get_client_certificate:certificate verify failed
TLS_ERROR: BIO read tls_read_plaintext error
TLS Error: TLS object -> incoming plaintext read error
TLS Error: TLS handshake failed

On the client side, I see timeouts and the VPN fails to establish.

After hours of fighting with this issue I found this thread; I noted that my "Certificate Depth" was set to 'One (Client + Server)' and I was getting the above errors. I then changed "Certificate Depth" to "Do not check" and my issue went away.

On older pfSense installations, I never had any problems with "Certificate Depth" set to "One (Client + Server)" so I assume this is some kind of a regression?

Can anyone suggest how to keep "Certificate Detph" at "One (Client + Server)" and not have --tls-verify script fail?

Best regards
V

johnpoz · Dec 28, 2017, 2:35 PM

I have always run one for depth (client+server) and never had such issues. I double checked my setting and yup running client+server with no connection issues. Running 2.4.2_p1

v0lZy · Dec 29, 2017, 9:21 AM

Is your installation fresh or a setup that was carried over?

Best regards,
V

johnpoz · Dec 29, 2017, 11:25 PM

Well its fresh on my sg4860.. Upgrade to p1 from 2.4.2.. might of come with 2.4.0 that updated to 2.4.2 and then to p1.. Only had it a couple of weeks.

v0lZy · Jan 31, 2018, 1:44 PM

Experiencing this issue now on 3 VMs …
Quick glance at the forum says I'm not alone.

Was anyone able to work this out?
Best regards
V

reswob10 · Feb 17, 2018, 5:18 PM

I had this same problem. I tried a bunch of the solutions found from googling and such.

In my case, my NIC was bad. I swapped in a new NIC and the connection came up.

pfsense version didn't matter, client OS didn't matter. NIC card fail.

6 hrs troubleshooting argh