Upgrade to OpenVPN 1.2.5 (iOS): reconnection issue when using PKCS#12 or password

[Tg92]

Hi,

I have VPN on, it is working fine. IPhone is locking by itself when I reopen it, the vpn is disabled. I have to reactivate it manually.

This trouble is also reported here viewtopic.php?f=36&t=25627

client configuration

Code: Select all

#OpenVPN Client conf
tls-client
client
nobind
dev tun
proto tcp
tun-mtu 1400
remote a.mydomain.com 1234
cipher AES-256-CBC
auth SHA256
verb 3
ns-cert-type server
redirect-gateway def1
tls-remote a.mydomain.com
verify-x509-name a.mydomain.com name
#mssfix ##optional!
key-direction 0

server configuration

Code: Select all

#OpenVPN Server conf
daemon openvpnserver
writepid /var/run/openvpn.pid
#DAN prepare OpenVPN for listening on blue and orange
;local a.myDomain.name
dev tun
proto tcp
port 1234
script-security 3 system
ifconfig-pool-persist /path/leases.db 3600
client-config-dir /another/Path
tls-server
ca /path/cacert.pem
cert /path/servercert.pem
key /path/serverkey.pem
dh /path/dh1024.pem
server x.x.x.x 255.255.255.0
tun-mtu 1500
mtu-disc maybe
keepalive 15 47
status-version 1
status /path/log.log 30
cipher AES-256-CBC
auth SHA256
tls-auth /path/ta.key 1
push "redirect-gateway def1"
push "dhcp-option DNS y.y.y.y"
max-clients 100
tls-verify /path/verify
crl-verify /path/cacrl.pem
user nobody
group nobody
persist-key
persist-tun
verb 3

OpenVPN settings

[anatoli]

Tg92, when you open OpenVPN, do you see there that the app is trying to connect (State: connecting) or it's turned off as if you've turned it off manually?

Please upload client and server logs for the period in question, i.e. from the moment you turn the screen of the phone off to the moment you open OpenVPN again.

[Tg92]

On the screen, It looks like the application is not trying to establish the connection. It is turned off as if i have done it manually.
But, logs seems to tell exactly the opposite but it fails.
Connection pause at 23:52:05 and unlock the devise at 23:52:14

server log

Code: Select all

23:52:05	openvpnserver[9018]: 	ProfilName/xxx.xxx.xxx.xxx:59651 SIGUSR1[soft,connection-reset] received, client-ins tance restarting
23:52:05	openvpnserver[9018]: 	ProfilName/xxx.xxx.xxx.xxx:59651 Connection reset, restarting [0]
23:51:32	openvpnserver[9018]:    ProfilName/xxx.xxx.xxx.xxx:59651 SENT CONTROL [ProfilName]: 	'PUSH_REPLY,redirect-gateway def1,dhcp-option DNS 212.27.40.241,route yyy.yyy.yyy.1 ,topology net30,ping 15,ping-restart 47,redirect-gateway,dhcp-option DNS 212.27.40.241,dhcp-option DNS 8.8.8.8,ifconfig yyy.yyy.yyy.14 yyy.yyy.yyy.13' (status=1)
23:51:32	openvpnserver[9018]: 	ProfilName/xxx.xxx.xxx.xxx:59651 send_push_reply(): safe_cap=940
23:51:32	openvpnserver[9018]: 	ProfilName/xxx.xxx.xxx.xxx:59651 PUSH: Received control message: 'PUSH_REQUEST'
23:51:32	openvpnserver[9018]: 	ProfilName/xxx.xxx.xxx.xxx:59651 MULTI: primary virtual IP for ProfilName/xxx.xxx.xxx.xxx:59651: yyy.yyy.yyy.14
23:51:32	openvpnserver[9018]: 	ProfilName/xxx.xxx.xxx.xxx:59651 MULTI: Learn: yyy.yyy.yyy.14 -> ProfilName/xxx.xxx.xxx.xxx :59651
23:51:32	openvpnserver[9018]: 	ProfilName/xxx.xxx.xxx.xxx:59651 MULTI_sva: pool returned IPv4=yyy.yyy.yyy.14, IPv6=(No t enabled)

client side 23:52:05 lock of the ios device

Code: Select all

2018-01-12 23:52:05 EVENT: PAUSE    
2018-01-12 23:52:14 OS Event: WAKEUP
2018-01-12 23:52:17 RESUME TEST: Internet:ReachableViaWiFi/-R t------
2018-01-12 23:52:17 STANDARD RESUME
2018-01-12 23:52:17 EVENT: RESUME
2018-01-12 23:52:17 EVENT: RECONNECTING
2018-01-12 23:52:17 EVENT: RESOLVE
2018-01-12 23:52:17 Contacting [zzz.zzz.zzz.zzz]:1234/TCP via TCP
2018-01-12 23:52:17 EVENT: WAIT
2018-01-12 23:52:17 Connecting to [a.myDomain.com]:1234 (zzz.zzz.zzz.zzz) via TCPv4
2018-01-12 23:52:17 EVENT: CONNECTING
2018-01-12 23:52:17 Tunnel Options:V4,dev-type tun,link-mtu 1471,tun-mtu 1400,proto TCPv4_CLIENT,keydir 0,cipher AES-256-CBC,auth SHA256,keysize 256,tls-auth,key-method 2,tls-client
2018-01-12 23:52:17 Creds: UsernameEmpty/PasswordEmpty
2018-01-12 23:52:17 Peer Info:
IV_GUI_VER=net.openvpn.connect.ios 1.2.5-1
IV_VER=3.1.2
IV_PLAT=ios
IV_NCP=2
IV_TCPNL=1
IV_PROTO=2
IV_AUTO_SESS=1

2018-01-12 23:52:17 VERIFY OK : depth=1
cert. version     : 3
serial number     : AA:AA:AA:AA:AA:AA:AA:AA
issuer name       : C=FR, ST=IdF, L=Paris, O=a.myDomain.com, CN=a.myDomain.com CA, emailAddress=myemail@email.domain.fr
subject name      : C=FR, ST=IdF, L=Paris, O=a.myDomain.com, CN=a.myDomain.com CA, emailAddress=myemail@email.domain.fr
issued  on        : yyyy-mm-dd 17:48:50
expires on        : YYYY-mm-dd 17:48:50
signed using      : RSA with SHA-512
RSA key size      : 4096 bits
basic constraints : CA=true

2018-01-12 23:52:17 VERIFY OK : depth=0
cert. version     : 3
serial number     : 01
issuer name       : C=FR, ST=IdF, L=Paris, O=a.myDomain.com, CN=a.myDomain.com CA, emailAddress=myemail@email.domain.fr
subject name      : C=FR, ST=IdF, O=a.myDomain.com, CN=a.myDomain.com
issued  on        : yyyy-mm-dd 17:48:50
expires on        : YYYY-mm-dd 17:48:50
signed using      : RSA with SHA-256
RSA key size      : 2048 bits
basic constraints : CA=false
cert. type        : SSL Server

2018-01-12 23:52:17 tls-remote validation
  tls-remote: 'a.myDomain.com'
  Subj: '/C=FR/ST=IdF/O=a.myDomain.com/CN=a.myDomain.com'
  CN: 'a.myDomain.com'
2018-01-12 23:52:17 EVENT: EPKI_INVALID_ALIAS 69646e740000000000000016 [ERR]
2018-01-12 23:52:17 EVENT: EPKI_ERROR 69646e740000000000000016 : external_pki_error: identity not found [ERR]
2018-01-12 23:52:17 MbedTLSContext::epki_sign: ssl_external_pki: MbedTLS: could not obtain signature
2018-01-12 23:52:17 Client exception in transport_recv_excode: mbed TLS: SSL read error : RSA - Bad input parameters to function
2018-01-12 23:52:17 EVENT: DISCONNECTED

[Tg92]

Hi,

When I look at the log, the only difference between the manual activation and then the automatic reconnection at unlocking the ios device is :
At establishing the connection (manual activation)

Code: Select all

2018-01-13 00:10:35 tls-remote validation
  tls-remote: 'a.myDomain.com'
  Subj: '/C=FR/ST=IdF/O=a.myDomain.com/CN=a.myDomain.com'
  CN: 'a.myDomain.com'
2018-01-13 00:10:35 SSL Handshake: TLSv1.2/TLS-DHE-RSA-WITH-AES-256-GCM-SHA384
2018-01-13 00:10:35 Session is ACTIVE
2018-01-13 00:10:35 EVENT: GET_CONFIG
2018-01-13 00:10:35 Sending PUSH_REQUEST to server...
2018-01-13 00:10:35 OPTIONS:
0 [redirect-gateway] [def1] 
1 [redirect-gateway] [def1] 
2 [dhcp-option] [DNS] [212.27.40.241] 
3 [route] [yyy.yyy.yyy.1] 
4 [topology] [net30] 
5 [ping] [15] 
6 [ping-restart] [47] 
7 [redirect-gateway] 
8 [dhcp-option] [DNS] [212.27.40.241] 
9 [dhcp-option] [DNS] [8.8.8.8] 
10 [ifconfig] [yyy.yyy.yyy.14] [yyy.yyy.yyy.13] 

After the pause (automatic activation)

Code: Select all

2018-01-13 00:11:19 tls-remote validation
  tls-remote: 'a.myDomain.com'
  Subj: '/C=FR/ST=IdF/O=a.myDomain.com/CN=a.myDomain.com'
  CN: 'a.myDomain.com'
2018-01-13 00:11:19 EVENT: EPKI_INVALID_ALIAS 69646e740000000000000016 [ERR]
2018-01-13 00:11:19 EVENT: EPKI_ERROR 69646e740000000000000016 : external_pki_error: identity not found [ERR]
2018-01-13 00:11:19 MbedTLSContext::epki_sign: ssl_external_pki: MbedTLS: could not obtain signature
2018-01-13 00:11:19 Client exception in transport_recv_excode: mbed TLS: SSL read error : RSA - Bad input parameters to function
2018-01-13 00:11:19 EVENT: DISCONNECTED

[anatoli]

I guess now the dev team has enough information to debug it further.

[ordex]

Hi guys, this problem is likely to be addressed by our next release. We have the new version running through our beta testers at the moment.
However, if we already have a thread talking about the same problem, why opening a new one?

[Tg92]

Hi,

The other threads has 2 points and no log at all. So, for a dev team, it is easier to have on point by thread to by able to follow them and full log to able to reproduce it or to understand the trouble

[ordex]

Hi there. You are right, well done! This is a different issue.
I didn't notice you were using an external certificate bundle (.ovpn12). Apparently the core is not able to retrieve the key material upon reconnection (at wakeup).

edit: we already have an internal ticket for this. I am appending your log data.

edit2: I modified the title of this thread to make it more clear about the problem being discussed

[ordex]

This problem seems to have found a solution too. Again, Apple has increased its security model compared to the old API and this needed some additional tweaking to allow connections using keychain items to work when the device is still locked.

A fix will be part of the next release.