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



  • 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!


  • LAYER 8 Global Moderator

    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
    
    


  • 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…



  • 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.



  • 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



  • 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.



  • 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


  • LAYER 8 Global Moderator

    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



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

    Best regards,
    V


  • LAYER 8 Global Moderator

    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.



  • 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



  • 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


Log in to reply