Reauthentication failure using auth-gen-token and Google Authenticator

Need help configuring your VPN? Just post here and you'll get that help.

Moderators: TinCanTech, TinCanTech, TinCanTech, TinCanTech, TinCanTech, TinCanTech

Forum rules
Please use the [oconf] BB tag for openvpn Configurations. See viewtopic.php?f=30&t=21589 for an example.
Post Reply
gmb
OpenVpn Newbie
Posts: 7
Joined: Sat Jan 12, 2019 2:40 am

Reauthentication failure using auth-gen-token and Google Authenticator

Post by gmb » Sat Jan 12, 2019 12:21 pm

So here's a little conundrum that has me scratching my head.

Server is running Ubuntu 18.04LTS with OpenVPN 2.4.6.

server.conf
port 1194
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}
/usr/lib/systemd/system/openvpn-server@.service:

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
Server logs:

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
Client is on iPhone XR running iOS 12.1.2 and OpenVPN Connect 3.0.2 (894).

client.conf
client
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
So, in summary the server runs OpenVPN with root privileges dropped to non-sudo user "openvpn". Authentication is via certificate (with passphrase) and OTP via Google Authenticator (token called via non-sudo user "gauth").

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!
Last edited by gmb on Sat Jan 12, 2019 6:42 pm, edited 1 time in total.

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Reauthentication failure using auth-gen-token and Google Authenticator

Post by TinCanTech » Sat Jan 12, 2019 2:38 pm

To end your misery .. --auth-gen-token does not work properly at this time ..

gmb
OpenVpn Newbie
Posts: 7
Joined: Sat Jan 12, 2019 2:40 am

Re: Reauthentication failure using auth-gen-token and Google Authenticator

Post by gmb » Sat Jan 12, 2019 6:57 pm

Thanks for the quick reply. That’s disappointing.. :cry:

I did see some posts on this forum and SourceForge about 2 years ago from David Sommerseth about the option and issues but naively hoped they had all been sorted.

Sigh...

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Reauthentication failure using auth-gen-token and Google Authenticator

Post by TinCanTech » Sat Jan 12, 2019 8:55 pm

Yes, the problems are conflicting interests and not enough developer time.

You can always try to help by contributing 8-)

Sorry about that ..

gmb
OpenVpn Newbie
Posts: 7
Joined: Sat Jan 12, 2019 2:40 am

Re: Reauthentication failure using auth-gen-token and Google Authenticator

Post by gmb » Mon Jan 14, 2019 12:12 am

TinCanTech wrote:
Sat Jan 12, 2019 8:55 pm
You can always try to help by contributing 8-)
I would if I could - I last coded in C more than 25 years ago.. :lol:

My comments weren't intended as a criticism of the developers.

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Reauthentication failure using auth-gen-token and Google Authenticator

Post by TinCanTech » Mon Jan 14, 2019 3:55 am

There is so much more to contributing than coding in C .. :o

gmb
OpenVpn Newbie
Posts: 7
Joined: Sat Jan 12, 2019 2:40 am

Re: Reauthentication failure using auth-gen-token and Google Authenticator

Post by gmb » Mon Jan 14, 2019 4:28 am

OK, I will inquire into it.

Post Reply