The pfSense Store

Author Topic: pfsense 2.3: TLS handshake failed/ Failed running command (--tls-verify script)  (Read 2625 times)

0 Members and 1 Guest are viewing this topic.

Offline pfff

  • Newbie
  • *
  • Posts: 12
  • Karma: +1/-0
    • View Profile
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)
Code: [Select]
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
Code: [Select]
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
Code: [Select]
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!
« Last Edit: April 14, 2016, 02:09:14 pm by pfff »

Online johnpoz

  • Hero Member
  • *****
  • Posts: 14816
  • Karma: +1374/-202
  • Not a pfSense employee, they cannot fire me...
    • View Profile
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"

Code: [Select]
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

« Last Edit: April 14, 2016, 01:25:24 pm by johnpoz »
- An intelligent man is sometimes forced to be drunk to spend time with his fools.
- Please don't PM me for personal help
- if you want to say thanks applaud or https://www.freebsdfoundation.org/donate/
1x SG-2440 2.4.2-RELEASE-p1 (work)
1x SG-4860 2.4.2-RELEASE-p1 (home)

Offline bennyc

  • Full Member
  • ***
  • Posts: 285
  • Karma: +20/-0
    • View Profile
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...

Offline pfff

  • Newbie
  • *
  • Posts: 12
  • Karma: +1/-0
    • View Profile
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.

Offline emel_punk

  • Jr. Member
  • **
  • Posts: 25
  • Karma: +0/-0
    • View Profile
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

Code: [Select]
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

Offline pfff

  • Newbie
  • *
  • Posts: 12
  • Karma: +1/-0
    • View Profile
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.

Offline v0lZy

  • Newbie
  • *
  • Posts: 5
  • Karma: +0/-0
    • View Profile
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



Online johnpoz

  • Hero Member
  • *****
  • Posts: 14816
  • Karma: +1374/-202
  • Not a pfSense employee, they cannot fire me...
    • View Profile
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
- An intelligent man is sometimes forced to be drunk to spend time with his fools.
- Please don't PM me for personal help
- if you want to say thanks applaud or https://www.freebsdfoundation.org/donate/
1x SG-2440 2.4.2-RELEASE-p1 (work)
1x SG-4860 2.4.2-RELEASE-p1 (home)

Offline v0lZy

  • Newbie
  • *
  • Posts: 5
  • Karma: +0/-0
    • View Profile
Is your installation fresh or a setup that was carried over?

Best regards,
V

Online johnpoz

  • Hero Member
  • *****
  • Posts: 14816
  • Karma: +1374/-202
  • Not a pfSense employee, they cannot fire me...
    • View Profile
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.
- An intelligent man is sometimes forced to be drunk to spend time with his fools.
- Please don't PM me for personal help
- if you want to say thanks applaud or https://www.freebsdfoundation.org/donate/
1x SG-2440 2.4.2-RELEASE-p1 (work)
1x SG-4860 2.4.2-RELEASE-p1 (home)