Server is running Ubuntu 18.04LTS with OpenVPN 2.4.6.
proto udp
dev tun0
topology subnet
persist-key
persist-tun
keepalive 10 120
auth-gen-token
push "route 10.0.1.0 255.255.255.0"
ca /etc/openvpn/server/ca.crt
cert /etc/openvpn/server/server.crt
key /etc/openvpn/server/server.key
dh /etc/openvpn/server/dh.pem
server 10.8.0.0 255.255.255.0
explicit-exit-notify 1
crl-verify /etc/openvpn/server/crl.pem
user openvpn
group openvpn
tls-version-min 1.2
tls-crypt /etc/openvpn/server/ta.key
cipher AES-256-CBC
auth SHA512
tls-cipher TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384:TLS-DHE-RSA-WITH-AES-256-GCM-SHA384:TLS-DHE-RSA-WITH-AES-256-CBC-SHA256
ifconfig-pool-persist /etc/openvpn/server/ipp.txt
log /var/log/openvpn-server.log
verb 4
plugin /usr/lib/openvpn/plugins/openvpn-plugin-auth-pam.so openvpn
reneg-sec 0
OpenVPN PAM module:
Code: Select all
@include common-account
auth required pam_google_authenticator.so debug user=gauth secret=/etc/google-authenticator/${USER}
Code: Select all
[Unit]
Description=OpenVPN service for %I
After=syslog.target network-online.target
Wants=network-online.target
Documentation=man:openvpn(8)
Documentation=https://community.openvpn.net/openvpn/wiki/Openvpn24ManPage
Documentation=https://community.openvpn.net/openvpn/wiki/HOWTO
[Service]
Type=notify
PrivateTmp=true
WorkingDirectory=/etc/openvpn/server
ExecStart=/usr/sbin/openvpn --status %t/openvpn-server/status-%i.log --status-version 2 --suppress-timestamps --config %i.conf
CapabilityBoundingSet=CAP_IPC_LOCK CAP_NET_ADMIN CAP_NET_BIND_SERVICE CAP_NET_RAW CAP_SETGID CAP_SETUID CAP_SYS_CHROOT CAP_DAC_OVERRIDE CAP_AUDIT_WRITE
LimitNPROC=10
DeviceAllow=/dev/null rw
DeviceAllow=/dev/net/tun rw
ProtectSystem=true
ProtectHome=true
KillMode=process
RestartSec=5s
Restart=on-failure
[Install]
WantedBy=multi-user.target
Code: Select all
MULTI: multi_create_instance called
x.x.x.x:44747 Re-using SSL/TLS context
x.x.x.x:44747 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
x.x.x.x:44747 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
x.x.x.x:44747 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-server'
x.x.x.x:44747 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-client'
x.x.x.x:44747 TLS: Initial packet from [AF_INET]x.x.x.x:44747, sid=a5e21872 d04aa954
x.x.x.x:44747 VERIFY OK: depth=1, CN=Server CA
x.x.x.x:44747 VERIFY OK: depth=0, CN=iphone
x.x.x.x:44747 peer info: IV_GUI_VER=net.openvpn.connect.ios_3.0.2-894
x.x.x.x:44747 peer info: IV_VER=3.2
x.x.x.x:44747 peer info: IV_PLAT=ios
x.x.x.x:44747 peer info: IV_NCP=2
x.x.x.x:44747 peer info: IV_TCPNL=1
x.x.x.x:44747 peer info: IV_PROTO=2
AUTH-PAM: BACKGROUND: received command code: 0
AUTH-PAM: BACKGROUND: USER: user
AUTH-PAM: BACKGROUND: my_conv[0] query='Verification code: ' style=1
x.x.x.x:44747 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-auth-pam.so/PLUGIN_AUTH_USER_PASS_VERIFY status=0
x.x.x.x:44747 TLS: Username/Password authentication succeeded for username 'user'
x.x.x.x:44747 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 4096 bit RSA
x.x.x.x:44747 [iphone] Peer Connection Initiated with [AF_INET]x.x.x.x:44747
iphone/x.x.x.x:44747 MULTI_sva: pool returned IPv4=10.8.0.2, IPv6=(Not enabled)
iphone/x.x.x.x:44747 MULTI: Learn: 10.8.0.2 -> iphone/x.x.x.x:44747
iphone/x.x.x.x:44747 MULTI: primary virtual IP for iphone/x.x.x.x:44747: 10.8.0.2
iphone/x.x.x.x:44747 PUSH: Received control message: 'PUSH_REQUEST'
iphone/x.x.x.x:44747 SENT CONTROL [iphone]: 'PUSH_REPLY,route 10.0.1.0 255.255.255.0,route-gateway 10.8.0.1,topology subnet,ping 10,ping-restart 120,ifconfig 10.8.0.2 255.255.255.0,peer-id 0,cipher AES-256-GCM,auth-token' (status=1)
iphone/x.x.x.x:44747 Data Channel: using negotiated cipher 'AES-256-GCM'
iphone/x.x.x.x:44747 Data Channel MTU parms [ L:1549 D:1450 EF:49 EB:406 ET:0 EL:3 ]
iphone/x.x.x.x:44747 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
iphone/x.x.x.x:44747 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
iphone/x.x.x.x:44747 SIGTERM[soft,remote-exit] received, client-instance exiting
MULTI: multi_create_instance called
x.x.x.x:33774 Re-using SSL/TLS context
x.x.x.x:33774 Control Channel MTU parms [ L:1621 D:1156 EF:94 EB:0 ET:0 EL:3 ]
x.x.x.x:33774 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
x.x.x.x:33774 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-server'
x.x.x.x:33774 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-client'
x.x.x.x:33774 TLS: Initial packet from [AF_INET]x.x.x.x:33774, sid=d7255b09 84a86ab9
x.x.x.x:33774 VERIFY OK: depth=1, CN=Server CA
x.x.x.x:33774 VERIFY OK: depth=0, CN=iphone
x.x.x.x:33774 peer info: IV_GUI_VER=net.openvpn.connect.ios_3.0.2-894
x.x.x.x:33774 peer info: IV_VER=3.2
x.x.x.x:33774 peer info: IV_PLAT=ios
x.x.x.x:33774 peer info: IV_NCP=2
x.x.x.x:33774 peer info: IV_TCPNL=1
x.x.x.x:33774 peer info: IV_PROTO=2
AUTH-PAM: BACKGROUND: received command code: 0
AUTH-PAM: BACKGROUND: USER: user
AUTH-PAM: BACKGROUND: my_conv[0] query='Verification code: ' style=1
AUTH-PAM: BACKGROUND: user 'user' failed to authenticate: Authentication failure
x.x.x.x:33774 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-auth-pam.so/PLUGIN_AUTH_USER_PASS_VERIFY status=1
x.x.x.x:33774 PLUGIN_CALL: plugin function PLUGIN_AUTH_USER_PASS_VERIFY failed with status 1: /usr/lib/openvpn/plugins/openvpn-plugin-auth-pam.so
x.x.x.x:33774 TLS Auth Error: Auth Username/Password verification failed for peer
x.x.x.x:33774 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 4096 bit RSA
x.x.x.x:33774 [iphone] Peer Connection Initiated with [AF_INET]x.x.x.x:33774
x.x.x.x:33774 PUSH: Received control message: 'PUSH_REQUEST'
x.x.x.x:33774 Delayed exit in 5 seconds
x.x.x.x:33774 SENT CONTROL [iphone]: 'AUTH_FAILED' (status=1)
x.x.x.x:33774 SIGTERM[soft,delayed-exit] received, client-instance exiting
dev tun0
proto udp
remote xxx.xxx.xxx 1194
resolv-retry infinite
nobind
user openvpn
group openvpn
persist-key
persist-tun
remote-cert-tls server
tls-version-min 1.2
cipher AES-256-CBC
auth SHA512
auth-user-pass
reneg-sec 0
verb 4
Client logs:
Code: Select all
2019-01-12 21:58:52 1
2019-01-12 21:58:52 ----- OpenVPN Start -----
OpenVPN core 3.2 ios arm64 64-bit PT_PROXY built on Oct 3 2018 06:35:04
2019-01-12 21:58:52 Frame=512/2048/512 mssfix-ctrl=1250
2019-01-12 21:58:52 UNUSED OPTIONS
4 [resolv-retry] [infinite]
5 [nobind]
6 [user] [openvpn]
7 [group] [openvpn]
8 [persist-key]
9 [persist-tun]
16 [verb] [4]
2019-01-12 21:58:52 EVENT: RESOLVE
2019-01-12 21:58:52 Contacting [x.x.x.x]:1194/UDP via UDP
2019-01-12 21:58:52 EVENT: WAIT
2019-01-12 21:58:52 Connecting to [xxx.xxx.xxx]:1194 (x.x.x.x) via UDPv4
2019-01-12 21:58:52 EVENT: CONNECTING
2019-01-12 21:58:52 Tunnel Options:V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-client
2019-01-12 21:58:52 Creds: Username/Password
2019-01-12 21:58:52 Peer Info:
IV_GUI_VER=net.openvpn.connect.ios 3.0.2-894
IV_VER=3.2
IV_PLAT=ios
IV_NCP=2
IV_TCPNL=1
IV_PROTO=2
2019-01-12 21:58:52 VERIFY OK : depth=1
cert. version : 3
serial number : x:x:x:x:x:x:x:x
issuer name : CN=Server CA
subject name : CN=Server CA
issued on : 2019-01-07 06:14:59
expires on : 2029-01-04 06:14:59
signed using : RSA with SHA-512
RSA key size : 4096 bits
basic constraints : CA=true
key usage : Key Cert Sign, CRL Sign
2019-01-12 21:58:52 VERIFY OK : depth=0
cert. version : 3
serial number : x:x:x:x:x:x:x:x
issuer name : CN=Server CA
subject name : CN=Server
issued on : 2019-01-07 06:32:43
expires on : 2021-12-22 06:32:43
signed using : RSA with SHA-512
RSA key size : 4096 bits
basic constraints : CA=false
subject alt name : Server
key usage : Digital Signature, Key Encipherment
ext key usage : TLS Web Server Authentication
2019-01-12 21:58:53 SSL Handshake: TLSv1.2/TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
2019-01-12 21:58:53 Session is ACTIVE
2019-01-12 21:58:53 EVENT: GET_CONFIG
2019-01-12 21:58:53 Sending PUSH_REQUEST to server...
2019-01-12 21:58:53 OPTIONS:
0 [route] [10.0.1.0] [255.255.255.0]
1 [route-gateway] [10.8.0.1]
2 [topology] [subnet]
3 [ping] [10]
4 [ping-restart] [120]
5 [ifconfig] [10.8.0.2] [255.255.255.0]
6 [peer-id] [0]
7 [cipher] [AES-256-GCM]
8 [auth-token] ...
2019-01-12 21:58:53 Session token: [redacted]
2019-01-12 21:58:53 PROTOCOL OPTIONS:
cipher: AES-256-GCM
digest: SHA512
compress: NONE
peer ID: 0
2019-01-12 21:58:53 EVENT: ASSIGN_IP
2019-01-12 21:58:53 NIP: preparing TUN network settings
2019-01-12 21:58:53 NIP: init TUN network settings with endpoint: x.x.x.x
2019-01-12 21:58:53 NIP: adding IPv4 address to network settings 10.8.0.2/255.255.255.0
2019-01-12 21:58:53 NIP: adding (included) IPv4 route 10.8.0.0/24
2019-01-12 21:58:53 NIP: adding (included) IPv4 route 10.0.1.0/24
2019-01-12 21:58:53 Connected via NetworkExtensionTUN
2019-01-12 21:58:53 EVENT: CONNECTED user@xxx.xxx.xxx:1194 (x.x.x.x) via /UDPv4 on NetworkExtensionTUN/10.8.0.2/ gw=[/]
2019-01-12 22:00:58 OS Event: SLEEP
2019-01-12 22:00:58 EVENT: PAUSE
2019-01-12 22:01:03 OS Event: WAKEUP
2019-01-12 22:01:06 RESUME TEST: Internet:ReachableViaWiFi/-R t------
2019-01-12 22:01:06 STANDARD RESUME
2019-01-12 22:01:06 EVENT: RESUME
2019-01-12 22:01:06 EVENT: RECONNECTING
2019-01-12 22:01:06 EVENT: RESOLVE
2019-01-12 22:01:06 Contacting [x.x.x.x]:1194/UDP via UDP
2019-01-12 22:01:06 EVENT: WAIT
2019-01-12 22:01:06 Connecting to [xxx.xxx.xxx]:1194 (x.x.x.x) via UDPv4
2019-01-12 22:01:06 EVENT: CONNECTING
2019-01-12 22:01:06 Tunnel Options:V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,cipher AES-256-CBC,auth SHA512,keysize 256,key-method 2,tls-client
2019-01-12 22:01:06 Creds: Username/SessionID
2019-01-12 22:01:06 Peer Info:
IV_GUI_VER=net.openvpn.connect.ios 3.0.2-894
IV_VER=3.2
IV_PLAT=ios
IV_NCP=2
IV_TCPNL=1
IV_PROTO=2
2019-01-12 22:01:06 VERIFY OK : depth=1
cert. version : 3
serial number : A5:E3:B7:B0:58:E5:52:E5
issuer name : CN=Server CA
subject name : CN=Server CA
issued on : 2019-01-07 06:14:59
expires on : 2029-01-04 06:14:59
signed using : RSA with SHA-512
RSA key size : 4096 bits
basic constraints : CA=true
key usage : Key Cert Sign, CRL Sign
2019-01-12 22:01:06 VERIFY OK : depth=0
cert. version : 3
serial number : 30:1B:CE:4E:7D:89:BA:57:06:8E:80:D2:D4:5E:95:3A
issuer name : CN=Server CA
subject name : CN=Server
issued on : 2019-01-07 06:32:43
expires on : 2021-12-22 06:32:43
signed using : RSA with SHA-512
RSA key size : 4096 bits
basic constraints : CA=false
subject alt name : Server
key usage : Digital Signature, Key Encipherment
ext key usage : TLS Web Server Authentication
2019-01-12 22:01:07 SSL Handshake: TLSv1.2/TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
2019-01-12 22:01:07 Session is ACTIVE
2019-01-12 22:01:07 EVENT: GET_CONFIG
2019-01-12 22:01:07 Sending PUSH_REQUEST to server...
2019-01-12 22:01:07 AUTH_FAILED
2019-01-12 22:01:07 EVENT: AUTH_FAILED [ERR]
2019-01-12 22:01:07 Raw stats on disconnect:
BYTES_IN : 15519
BYTES_OUT : 36149
PACKETS_IN : 97
PACKETS_OUT : 100
TUN_BYTES_IN : 27456
TUN_BYTES_OUT : 4482
TUN_PACKETS_IN : 68
TUN_PACKETS_OUT : 64
N_PAUSE : 1
N_RECONNECT : 1
2019-01-12 22:01:07 Performance stats on disconnect:
CPU usage (microseconds): 426016
Tunnel compression ratio (uplink): 1.31662
Tunnel compression ratio (downlink): 3.46252
Network bytes per CPU second: 121281
Tunnel bytes per CPU second: 74969
2019-01-12 22:01:07 EVENT: DISCONNECTED
2019-01-12 22:01:07 Raw stats on disconnect:
BYTES_IN : 15519
BYTES_OUT : 36149
PACKETS_IN : 97
PACKETS_OUT : 100
TUN_BYTES_IN : 27456
TUN_BYTES_OUT : 4482
TUN_PACKETS_IN : 68
TUN_PACKETS_OUT : 64
AUTH_FAILED : 1
N_PAUSE : 1
N_RECONNECT : 1
2019-01-12 22:01:07 Performance stats on disconnect:
CPU usage (microseconds): 426016
Tunnel compression ratio (uplink): 1.31662
Tunnel compression ratio (downlink): 3.46252
Network bytes per CPU second: 121281
Tunnel bytes per CPU second: 74969
This setup works fine to connect. iPhone OpenVPN Connect prompts for username ("user" in above logs) and OTP, and then for certificate passphrase.
The issue arises with reauthentication. There is no reauthentication as a matter of course, given "reneg-sec=0" on server and client. However, if the iPhone sleeps or there is a mobile reception dropout, the OpenVPN client disconnects, and then tries to reconnect when the iPhone wakes or reception returns. It then reports an authentication failure.
I can't understand why this is happening. The server config includes "auth-gen-token" and the client config does NOT include "auth-nocache". The iPhone logs indicate that a session token has been provided and, it appears, that on reconnection that token is used instead of the OTP (that is what I interpret the reference to "SessionID" to be).
But then it fails. I can't understand the reason - is the token actually not being sent by the client, or is the server not using the token, or is there some other reason? Could there be a permissions issue relating to the unprivileged user running the OpenVPN daemon?
One thought was that it might be related to the certificate passphrase. But before I recently implemented OTP MFA, reauthentication with just the certificate (including passphrase) worked fine - the VPN would disconnect and reconnect automatically many times and run for hours. I don't see why that behaviour should change now that OTP MFA has been implemented over the top.
This issue is pretty much making the VPN on the iPhone unusable. I have also tried Viscosity on the MacBook to see if I could get a different outcome, but that's even worse because it prompts for full reauthentication (or doesn't attempt reauthentication at all, depending on options set).
Any assistance would be greatly appreciated!