Bug 13097

Summary:	OpenVPN, 2FA infrastructure is not working using ANY client EXCEPT windows community edition
Product:	IPFire	Reporter:	cfusco <carlo.fusco>
Component:	---	Assignee:	Assigned to nobody - feel free to grab it and work on it <nobody>
Status:	NEW ---	QA Contact:
Severity:	- Unknown -
Priority:	- Unknown -	CC:	adolf.belka, michael.tremer, stefan.schantl, ummeegge
Version:	2
Hardware:	unspecified
OS:	Unspecified
Attachments:	IPFire witout 2FA, succesful Client without 2FA, succesful IPFire 2FA, unsuccesful Client 2FA, unsuccesful

Description cfusco 2023-05-10 12:54:44 UTC

Two factor authentication in IPFire fails with ANY OpenVPN Connect client, with the remarkable exception of OpenVPN Connect-community edition. 

What happens is this: upon trying to connect, the client never gives a UI to send the token, nor there is any calling to an external TOTP app, and consequently the authentication fails after a while.

You can find many reports in the forum in the community forum, this one, 

https://community.ipfire.org/t/unable-to-connect-openvpn-with-2fa-cu-174/9724 

being the last one. I discussed the issue with Erik Kapfer (ummeegge) some time ago, and he did a preliminary analysis, which you can find in this post: 

https://community.ipfire.org/t/two-openvpn-problems-2fa-support-and-perfect-forward-security-disabled/9502/7

Please let me know if there is any way I can help.

Comment 1 Michael Tremer 2023-05-10 15:20:32 UTC

What other clients to you expect to be supported?

OpenVPN Connect is a proprietary service which has never worked with IPFire.

Comment 2 cfusco 2023-05-10 15:44:55 UTC

Maybe I am not understanding the situation and I would like pretty much to clarify this point. 

"OpenVPN connect" is the official client and it is available for all the platforms, including IOS and Android mobile phones. I tested both these two, and they do work well with IPFire. Just the 2FA is not working. These are the clients the large majority of users will download to interact with OpenVPN.

Which mobile clients or more in general, which client would work with IPFire then?

For Windows there is the community edition which is open source and it supports IPFire fully. 

In Android there is Arne Schwabe open source client, which also doesn't work with 2FA but otherwise works well with IPFire.

What other clients are there?

Comment 3 Michael Tremer 2023-05-10 15:56:39 UTC

Could we have some proper log output from those clients then including the server log?

Comment 4 cfusco 2023-05-10 16:56:23 UTC

These are the logs for a connection 

- without 2FA. First the server then the client. 
- with 2FA. Same certificate but with the 2FA activated. T

here is no UI to enter the token and therefore the log is clear even for me.

------------- Without 2FA --------------
** IPFire logs

18:23:12 openvpnserver[3272]:  130.223.147.248:42597 Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 TLS: Initial packet from [AF_INET]130.223.147.248:42597, sid=75f55247 8ab513af
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 VERIFY SCRIPT OK: depth=1, C=CH, O=cfusco, CN=cfusco CA
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 VERIFY OK: depth=1, C=CH, O=cfusco, CN=cfusco CA
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 VERIFY SCRIPT OK: depth=0, C=CH, O=cfusco, CN=ipfire
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 VERIFY OK: depth=0, C=CH, O=cfusco, CN=ipfire
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 peer info: IV_VER=3.git::081bfebe:RelWithDebInfo
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 peer info: IV_PLAT=android
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 peer info: IV_NCP=2
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 peer info: IV_TCPNL=1
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 peer info: IV_PROTO=30
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 peer info: IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 peer info: IV_AUTO_SESS=1
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 peer info: IV_GUI_VER=net.openvpn.connect.android_3.3.4-9290
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 peer info: IV_SSO=webauth,openurl,crtext
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 TLS: Username/Password authentication deferred for username '' 
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1409', remote='link-mtu 1381'
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 4096 bit RSA, signature: RSA-SHA256
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 [ipfire] Peer Connection Initiated with [AF_INET]130.223.147.248:42597
18:23:12 openvpnserver[3272]:  130.223.147.248:42597 PUSH: Received control message: 'PUSH_REQUEST'
18:23:12 openvpnserver[3272]:  MANAGEMENT: CMD 'client-auth-nt 46 0'
18:23:13 openvpnserver[3272]:  130.223.147.248:42597 PUSH: Received control message: 'PUSH_REQUEST'
18:23:13 openvpnserver[3272]:  ipfire/130.223.147.248:42597 MULTI_sva: pool returned IPv4=10.1.4.14, IPv6=(Not enabled)
18:23:13 openvpnserver[3272]:  ipfire/130.223.147.248:42597 OPTIONS IMPORT: reading client specific options from: /var/ipfire/ovpn/ccd/ipfire
18:23:14 openvpnserver[3272]:  ipfire/130.223.147.248:42597 OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_326893a690d967ed40245b038b647f8d.tmp
18:23:14 openvpnserver[3272]:  ipfire/130.223.147.248:42597 MULTI: Learn: 10.1.4.14 -> ipfire/130.223.147.248:42597
18:23:14 openvpnserver[3272]:  ipfire/130.223.147.248:42597 MULTI: primary virtual IP for ipfire/130.223.147.248:42597: 10.1.4.14
18:23:14 openvpnserver[3272]:  ipfire/130.223.147.248:42597 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
18:23:14 openvpnserver[3272]:  ipfire/130.223.147.248:42597 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
18:23:14 openvpnserver[3272]: ipfire/130.223.147.248:42597 SENT CONTROL [ipfire]:  'PUSH_REPLY,route 10.1.4.0 255.255.255.0,route 10.1.3.0 255.255.255.0,route 10.1.2.0 255.255.255.0,redirect-gateway def1,dhcp-option DOMAIN localdomain,dhcp-option DNS 10.1.4.1,dhcp-option HTTPPROXY 10.1.1.1:800,dhcp-option HTTPSPROXY 10.1.1.1:800,dhcp-option PROXY_HTTP 10.1.1.1 800,dhcp-option PROXY_HTTPS 10.1.1.1 800,dhcp-option float,route 10.1.4.1,topology net30,ping 10,ping-restart 60,route 10.1.1.0 255.255.255.0,ifconfig 10.1.4.14 10.1.4.13,peer-id 1,cipher AES-256-GCM' (status=1)

** OpenVPN Connect Logs

[May 10, 2023, 18:23:14] ----- OpenVPN Start -----

[May 10, 2023, 18:23:14] EVENT: CORE_THREAD_ACTIVE

[May 10, 2023, 18:23:14] OpenVPN core 3.git::081bfebe:RelWithDebInfo android arm64 64-bit PT_PROXY

[May 10, 2023, 18:23:14] Frame=512/2048/512 mssfix-ctrl=1250

[May 10, 2023, 18:23:14] UNUSED OPTIONS
0 [tls-client]
2 [nobind]
9 [verb] [3]
13 [auth-nocache]
14 [auth-token-user] [USER]
15 [auth-token] [TOTP]
16 [auth-retry] [interact]

[May 10, 2023, 18:23:14] Contacting 80.253.88.254:1194 via UDP

[May 10, 2023, 18:23:14] Connecting to [80.253.88.254]:1194 (80.253.88.254) via UDPv4

[May 10, 2023, 18:23:14] Tunnel Options:V4,dev-type tun,link-mtu 1381,tun-mtu 1360,proto UDPv4,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-client

[May 10, 2023, 18:23:14] Creds: UsernameEmpty/PasswordEmpty

[May 10, 2023, 18:23:14] Peer Info:
IV_VER=3.git::081bfebe:RelWithDebInfo
IV_PLAT=android
IV_NCP=2
IV_TCPNL=1
IV_PROTO=30
IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305
IV_AUTO_SESS=1
IV_GUI_VER=net.openvpn.connect.android_3.3.4-9290
IV_SSO=webauth,openurl,crtext


[May 10, 2023, 18:23:14] EVENT: RESOLVE

[May 10, 2023, 18:23:14] VERIFY OK: depth=1, /C=CH/O=cfusco/CN=cfusco CA, signature: RSA-SHA512

[May 10, 2023, 18:23:14] VERIFY OK: depth=0, /C=CH/O=cfusco/CN=80-253-88-254.init7.net, signature: RSA-SHA256

[May 10, 2023, 18:23:14] EVENT: WAIT

[May 10, 2023, 18:23:14] EVENT: CONNECTING

[May 10, 2023, 18:23:15] SSL Handshake: peer certificate: CN=80-253-88-254.init7.net, 2048 bit RSA, cipher: TLS_AES_256_GCM_SHA384 TLSv1.3 Kx=any Au=any Enc=AESGCM(256) Mac=AEAD


[May 10, 2023, 18:23:15] Session is ACTIVE

[May 10, 2023, 18:23:15] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:23:15] EVENT: GET_CONFIG

[May 10, 2023, 18:23:16] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:23:16] OPTIONS:
0 [route] [10.1.4.0] [255.255.255.0]
1 [route] [10.1.3.0] [255.255.255.0]
2 [route] [10.1.2.0] [255.255.255.0]
3 [redirect-gateway] [def1]
4 [dhcp-option] [DOMAIN] [localdomain]
5 [dhcp-option] [DNS] [10.1.4.1]
6 [dhcp-option] [HTTPPROXY] [10.1.1.1:800]
7 [dhcp-option] [HTTPSPROXY] [10.1.1.1:800]
8 [dhcp-option] [PROXY_HTTP] [10.1.1.1] [800]
9 [dhcp-option] [PROXY_HTTPS] [10.1.1.1] [800]
10 [dhcp-option] [float]
11 [route] [10.1.4.1]
12 [topology] [net30]
13 [ping] [10]
14 [ping-restart] [60]
15 [route] [10.1.1.0] [255.255.255.0]
16 [ifconfig] [10.1.4.14] [10.1.4.13]
17 [peer-id] [1]
18 [cipher] [AES-256-GCM]


[May 10, 2023, 18:23:16] PROTOCOL OPTIONS:
cipher: AES-256-GCM
digest: NONE
key-derivation: OpenVPN PRF
compress: NONE
peer ID: 1
control channel: tls-auth enabled

[May 10, 2023, 18:23:16] EVENT: ASSIGN_IP

[May 10, 2023, 18:23:16] Unknown pushed DHCP option: [dhcp-option] [HTTPPROXY] [10.1.1.1:800]

[May 10, 2023, 18:23:16] Unknown pushed DHCP option: [dhcp-option] [HTTPSPROXY] [10.1.1.1:800]

[May 10, 2023, 18:23:16] Unknown pushed DHCP option: [dhcp-option] [float]

[May 10, 2023, 18:23:16] exception setting dhcp-option for proxy: tun_prop_dhcp_option_error: tun_builder_set_proxy_http

[May 10, 2023, 18:23:16] Connected via tun

[May 10, 2023, 18:23:16] EVENT: CONNECTED info='80.253.88.254:1194 (80.253.88.254) via /UDPv4 on tun/10.1.4.14/ gw=[10.1.4.13/]' trans=TO_CONNECTED

------------- With 2FA --------------
** IPFire logs

18:43:26 openvpnserver[3272]:  130.223.147.134:46380 Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 TLS: Initial packet from [AF_INET]130.223.147.134:46380, sid=653cb4b9 2422a4b2
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 VERIFY SCRIPT OK: depth=1, C=CH, O=cfusco, CN=cfusco CA
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 VERIFY OK: depth=1, C=CH, O=cfusco, CN=cfusco CA
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 VERIFY SCRIPT OK: depth=0, C=CH, O=cfusco, CN=ipfire
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 VERIFY OK: depth=0, C=CH, O=cfusco, CN=ipfire
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 peer info: IV_VER=3.git::081bfebe:RelWithDebInfo
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 peer info: IV_PLAT=android
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 peer info: IV_NCP=2
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 peer info: IV_TCPNL=1
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 peer info: IV_PROTO=30
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 peer info: IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 peer info: IV_AUTO_SESS=1
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 peer info: IV_GUI_VER=net.openvpn.connect.android_3.3.4-9290
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 peer info: IV_SSO=webauth,openurl,crtext
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 TLS: Username/Password authentication deferred for username '' 
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1409', remote='link-mtu 1381'
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 4096 bit RSA, signature: RSA-SHA256
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 [ipfire] Peer Connection Initiated with [AF_INET]130.223.147.134:46380
18:43:26 openvpnserver[3272]:  130.223.147.134:46380 PUSH: Received control message: 'PUSH_REQUEST'
18:43:27 openvpnserver[3272]:  130.223.147.134:46380 PUSH: Received control message: 'PUSH_REQUEST'
18:43:35 openvpnserver[3272]:  130.223.147.134:46380 PUSH: Received control message: 'PUSH_REQUEST'
18:43:38 openvpnserver[3272]:  130.223.147.134:46380 PUSH: Received control message: 'PUSH_REQUEST'
18:43:41 openvpnserver[3272]:  130.223.147.134:46380 PUSH: Received control message: 'PUSH_REQUEST'
18:43:44 openvpnserver[3272]:  130.223.147.134:46380 PUSH: Received control message: 'PUSH_REQUEST'
18:43:47 openvpnserver[3272]:  130.223.147.134:46380 PUSH: Received control message: 'PUSH_REQUEST'

** OpenVPN Connect Logs

[May 10, 2023, 18:23:14] ----- OpenVPN Start -----

[May 10, 2023, 18:23:14] EVENT: CORE_THREAD_ACTIVE

[May 10, 2023, 18:23:14] OpenVPN core 3.git::081bfebe:RelWithDebInfo android arm64 64-bit PT_PROXY

[May 10, 2023, 18:23:14] Frame=512/2048/512 mssfix-ctrl=1250

[May 10, 2023, 18:23:14] UNUSED OPTIONS
0 [tls-client]
2 [nobind]
9 [verb] [3]
13 [auth-nocache]
14 [auth-token-user] [USER]
15 [auth-token] [TOTP]
16 [auth-retry] [interact]

[May 10, 2023, 18:23:14] Contacting 80.253.88.254:1194 via UDP

[May 10, 2023, 18:23:14] Connecting to [80.253.88.254]:1194 (80.253.88.254) via UDPv4

[May 10, 2023, 18:23:14] Tunnel Options:V4,dev-type tun,link-mtu 1381,tun-mtu 1360,proto UDPv4,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-client

[May 10, 2023, 18:23:14] Creds: UsernameEmpty/PasswordEmpty

[May 10, 2023, 18:23:14] Peer Info:
IV_VER=3.git::081bfebe:RelWithDebInfo
IV_PLAT=android
IV_NCP=2
IV_TCPNL=1
IV_PROTO=30
IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305
IV_AUTO_SESS=1
IV_GUI_VER=net.openvpn.connect.android_3.3.4-9290
IV_SSO=webauth,openurl,crtext


[May 10, 2023, 18:23:14] EVENT: RESOLVE

[May 10, 2023, 18:23:14] VERIFY OK: depth=1, /C=CH/O=cfusco/CN=cfusco CA, signature: RSA-SHA512

[May 10, 2023, 18:23:14] VERIFY OK: depth=0, /C=CH/O=cfusco/CN=80-253-88-254.init7.net, signature: RSA-SHA256

[May 10, 2023, 18:23:14] EVENT: WAIT

[May 10, 2023, 18:23:14] EVENT: CONNECTING

[May 10, 2023, 18:23:15] SSL Handshake: peer certificate: CN=80-253-88-254.init7.net, 2048 bit RSA, cipher: TLS_AES_256_GCM_SHA384  TLSv1.3 Kx=any      Au=any  Enc=AESGCM(256) Mac=AEAD


[May 10, 2023, 18:23:15] Session is ACTIVE

[May 10, 2023, 18:23:15] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:23:15] EVENT: GET_CONFIG

[May 10, 2023, 18:23:16] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:23:16] OPTIONS:
0 [route] [10.1.4.0] [255.255.255.0]
1 [route] [10.1.3.0] [255.255.255.0]
2 [route] [10.1.2.0] [255.255.255.0]
3 [redirect-gateway] [def1]
4 [dhcp-option] [DOMAIN] [localdomain]
5 [dhcp-option] [DNS] [10.1.4.1]
6 [dhcp-option] [HTTPPROXY] [10.1.1.1:800]
7 [dhcp-option] [HTTPSPROXY] [10.1.1.1:800]
8 [dhcp-option] [PROXY_HTTP] [10.1.1.1] [800]
9 [dhcp-option] [PROXY_HTTPS] [10.1.1.1] [800]
10 [dhcp-option] [float]
11 [route] [10.1.4.1]
12 [topology] [net30]
13 [ping] [10]
14 [ping-restart] [60]
15 [route] [10.1.1.0] [255.255.255.0]
16 [ifconfig] [10.1.4.14] [10.1.4.13]
17 [peer-id] [1]
18 [cipher] [AES-256-GCM]


[May 10, 2023, 18:23:16] PROTOCOL OPTIONS:
  cipher: AES-256-GCM
  digest: NONE
  key-derivation: OpenVPN PRF
  compress: NONE
  peer ID: 1
  control channel: tls-auth enabled

[May 10, 2023, 18:23:16] EVENT: ASSIGN_IP

[May 10, 2023, 18:23:16] Unknown pushed DHCP option: [dhcp-option] [HTTPPROXY] [10.1.1.1:800]

[May 10, 2023, 18:23:16] Unknown pushed DHCP option: [dhcp-option] [HTTPSPROXY] [10.1.1.1:800]

[May 10, 2023, 18:23:16] Unknown pushed DHCP option: [dhcp-option] [float]

[May 10, 2023, 18:23:16] exception setting dhcp-option for proxy: tun_prop_dhcp_option_error: tun_builder_set_proxy_http

[May 10, 2023, 18:23:16] Connected via tun

[May 10, 2023, 18:23:16] EVENT: CONNECTED info='80.253.88.254:1194 (80.253.88.254) via /UDPv4 on tun/10.1.4.14/ gw=[10.1.4.13/]' trans=TO_CONNECTED

[May 10, 2023, 18:31:18] EVENT: CANCELLED

[May 10, 2023, 18:31:18] EVENT: DISCONNECTED

[May 10, 2023, 18:31:18] Tunnel bytes per CPU second: 0

[May 10, 2023, 18:31:18] ----- OpenVPN Stop -----

[May 10, 2023, 18:31:18] EVENT: CORE_THREAD_DONE

[May 10, 2023, 18:31:21] ----- OpenVPN Start -----

[May 10, 2023, 18:31:21] EVENT: CORE_THREAD_ACTIVE

[May 10, 2023, 18:31:21] OpenVPN core 3.git::081bfebe:RelWithDebInfo android arm64 64-bit PT_PROXY

[May 10, 2023, 18:31:21] Frame=512/2048/512 mssfix-ctrl=1250

[May 10, 2023, 18:31:21] UNUSED OPTIONS
0 [tls-client]
2 [nobind]
9 [verb] [3]
13 [auth-nocache]
14 [auth-token-user] [USER]
15 [auth-token] [TOTP]
16 [auth-retry] [interact]

[May 10, 2023, 18:31:21] EVENT: RESOLVE

[May 10, 2023, 18:31:21] Contacting 80.253.88.254:1194 via UDP

[May 10, 2023, 18:31:21] EVENT: WAIT

[May 10, 2023, 18:31:21] Connecting to [80.253.88.254]:1194 (80.253.88.254) via UDPv4

[May 10, 2023, 18:31:21] EVENT: CONNECTING

[May 10, 2023, 18:31:21] Tunnel Options:V4,dev-type tun,link-mtu 1381,tun-mtu 1360,proto UDPv4,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-client

[May 10, 2023, 18:31:21] Creds: UsernameEmpty/PasswordEmpty

[May 10, 2023, 18:31:21] Peer Info:
IV_VER=3.git::081bfebe:RelWithDebInfo
IV_PLAT=android
IV_NCP=2
IV_TCPNL=1
IV_PROTO=30
IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305
IV_AUTO_SESS=1
IV_GUI_VER=net.openvpn.connect.android_3.3.4-9290
IV_SSO=webauth,openurl,crtext


[May 10, 2023, 18:31:21] VERIFY OK: depth=1, /C=CH/O=cfusco/CN=cfusco CA, signature: RSA-SHA512

[May 10, 2023, 18:31:21] VERIFY OK: depth=0, /C=CH/O=cfusco/CN=80-253-88-254.init7.net, signature: RSA-SHA256

[May 10, 2023, 18:31:21] SSL Handshake: peer certificate: CN=80-253-88-254.init7.net, 2048 bit RSA, cipher: TLS_AES_256_GCM_SHA384  TLSv1.3 Kx=any      Au=any  Enc=AESGCM(256) Mac=AEAD


[May 10, 2023, 18:31:21] Session is ACTIVE

[May 10, 2023, 18:31:21] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:31:21] EVENT: GET_CONFIG

[May 10, 2023, 18:31:22] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:31:23] OPTIONS:
0 [route] [10.1.4.0] [255.255.255.0]
1 [route] [10.1.3.0] [255.255.255.0]
2 [route] [10.1.2.0] [255.255.255.0]
3 [redirect-gateway] [def1]
4 [dhcp-option] [DOMAIN] [localdomain]
5 [dhcp-option] [DNS] [10.1.4.1]
6 [dhcp-option] [HTTPPROXY] [10.1.1.1:800]
7 [dhcp-option] [HTTPSPROXY] [10.1.1.1:800]
8 [dhcp-option] [PROXY_HTTP] [10.1.1.1] [800]
9 [dhcp-option] [PROXY_HTTPS] [10.1.1.1] [800]
10 [dhcp-option] [float]
11 [route] [10.1.4.1]
12 [topology] [net30]
13 [ping] [10]
14 [ping-restart] [60]
15 [route] [10.1.1.0] [255.255.255.0]
16 [ifconfig] [10.1.4.14] [10.1.4.13]
17 [peer-id] [1]
18 [cipher] [AES-256-GCM]


[May 10, 2023, 18:31:23] PROTOCOL OPTIONS:
  cipher: AES-256-GCM
  digest: NONE
  key-derivation: OpenVPN PRF
  compress: NONE
  peer ID: 1
  control channel: tls-auth enabled

[May 10, 2023, 18:31:23] EVENT: ASSIGN_IP

[May 10, 2023, 18:31:23] Unknown pushed DHCP option: [dhcp-option] [HTTPPROXY] [10.1.1.1:800]

[May 10, 2023, 18:31:23] Unknown pushed DHCP option: [dhcp-option] [HTTPSPROXY] [10.1.1.1:800]

[May 10, 2023, 18:31:23] Unknown pushed DHCP option: [dhcp-option] [float]

[May 10, 2023, 18:31:23] exception setting dhcp-option for proxy: tun_prop_dhcp_option_error: tun_builder_set_proxy_http

[May 10, 2023, 18:31:23] Connected via tun

[May 10, 2023, 18:31:23] EVENT: CONNECTED info='80.253.88.254:1194 (80.253.88.254) via /UDPv4 on tun/10.1.4.14/ gw=[10.1.4.13/]'

[May 10, 2023, 18:35:48] EVENT: CANCELLED

[May 10, 2023, 18:35:48] EVENT: DISCONNECTED

[May 10, 2023, 18:35:48] Tunnel bytes per CPU second: 0

[May 10, 2023, 18:35:48] ----- OpenVPN Stop -----

[May 10, 2023, 18:35:48] EVENT: CORE_THREAD_DONE

[May 10, 2023, 18:43:25] ----- OpenVPN Start -----

[May 10, 2023, 18:43:25] EVENT: CORE_THREAD_ACTIVE

[May 10, 2023, 18:43:25] OpenVPN core 3.git::081bfebe:RelWithDebInfo android arm64 64-bit PT_PROXY

[May 10, 2023, 18:43:25] Frame=512/2048/512 mssfix-ctrl=1250

[May 10, 2023, 18:43:25] UNUSED OPTIONS
0 [tls-client]
2 [nobind]
9 [verb] [3]
13 [auth-nocache]
14 [auth-token-user] [USER]
15 [auth-token] [TOTP]
16 [auth-retry] [interact]

[May 10, 2023, 18:43:25] Contacting 80.253.88.254:1194 via UDP

[May 10, 2023, 18:43:25] EVENT: RESOLVE

[May 10, 2023, 18:43:25] Connecting to [80.253.88.254]:1194 (80.253.88.254) via UDPv4

[May 10, 2023, 18:43:25] EVENT: WAIT

[May 10, 2023, 18:43:25] EVENT: CONNECTING

[May 10, 2023, 18:43:25] Tunnel Options:V4,dev-type tun,link-mtu 1381,tun-mtu 1360,proto UDPv4,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-client

[May 10, 2023, 18:43:25] Creds: UsernameEmpty/PasswordEmpty

[May 10, 2023, 18:43:25] Peer Info:
IV_VER=3.git::081bfebe:RelWithDebInfo
IV_PLAT=android
IV_NCP=2
IV_TCPNL=1
IV_PROTO=30
IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305
IV_AUTO_SESS=1
IV_GUI_VER=net.openvpn.connect.android_3.3.4-9290
IV_SSO=webauth,openurl,crtext


[May 10, 2023, 18:43:25] VERIFY OK: depth=1, /C=CH/O=cfusco/CN=cfusco CA, signature: RSA-SHA512

[May 10, 2023, 18:43:25] VERIFY OK: depth=0, /C=CH/O=cfusco/CN=80-253-88-254.init7.net, signature: RSA-SHA256

[May 10, 2023, 18:43:26] SSL Handshake: peer certificate: CN=80-253-88-254.init7.net, 2048 bit RSA, cipher: TLS_AES_256_GCM_SHA384  TLSv1.3 Kx=any      Au=any  Enc=AESGCM(256) Mac=AEAD


[May 10, 2023, 18:43:26] Session is ACTIVE

[May 10, 2023, 18:43:26] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:43:26] EVENT: GET_CONFIG

[May 10, 2023, 18:43:27] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:43:29] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:43:32] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:43:35] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:43:38] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:43:41] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:43:44] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:43:47] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:43:50] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:43:53] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:43:56] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:43:59] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:44:02] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:44:05] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:44:08] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:44:11] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:44:14] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:44:17] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:44:20] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:44:23] Sending PUSH_REQUEST to server...

[May 10, 2023, 18:44:25] EVENT: CONNECTION_TIMEOUT info='  BYTES_IN : 6689
  BYTES_OUT : 7927
  PACKETS_IN : 31
  PACKETS_OUT : 32
  CONNECTION_TIMEOUT : 1
'

[May 10, 2023, 18:44:25] EVENT: DISCONNECTED

[May 10, 2023, 18:44:25] Tunnel bytes per CPU second: 0

[May 10, 2023, 18:44:25] ----- OpenVPN Stop -----

[May 10, 2023, 18:44:25] EVENT: CORE_THREAD_DONE

Comment 5 Michael Tremer 2023-05-10 17:01:24 UTC

Please upload any log files as attachments. Otherwise it is impossible to read them.

I cannot tell for sure whether the client ever initiated the authentication that is required for OTP. It might be possible that the client does not support that.

Could you also provide the log file of the OpenVPN Authenticator on IPFire?

Comment 6 cfusco 2023-05-10 17:17:54 UTC

Created attachment 1160 [details]
IPFire witout 2FA, succesful

Comment 7 cfusco 2023-05-10 17:19:32 UTC

Created attachment 1161 [details]
Client without 2FA, succesful

Comment 8 cfusco 2023-05-10 17:20:13 UTC

Created attachment 1162 [details]
IPFire 2FA, unsuccesful

Comment 9 cfusco 2023-05-10 17:21:28 UTC

Created attachment 1163 [details]
Client 2FA, unsuccesful

Comment 10 cfusco 2023-05-10 17:25:17 UTC

How can I find the logs for OpenVPN Authenticator? grep of /var/log/messages with Authenticator gives nothing and I cannot find another place for it.

Comment 11 cfusco 2023-05-10 17:31:07 UTC

OPNsense has successfully implemented the 2FA with all the "OpenVPN Connect" clients. The way they do it is to have, in addition to the certificate, the 2FA bundled with username/password, where in the password they put first the token and then the password.

Comment 12 Michael Tremer 2023-05-11 09:11:28 UTC

(In reply to cfusco from comment #9)
> Created attachment 1163 [details]
> Client 2FA, unsuccesful

The client does not perform the dynamic authentication sequence and therefore does not authenticate.

So this is quite likely a client configuration issue, or the client does not support what we would require.

It is those two options:

> https://git.ipfire.org/?p=ipfire-2.x.git;a=blob;f=html/cgi-bin/ovpnmain.cgi;h=51d6e8431d6a00ffbb87aa24591c1fb67f0059b8;hb=HEAD#l2296

Comment 13 Erik Kapfer 2023-05-18 18:55:53 UTC

Hi all,
(In reply to Michael Tremer from comment #12)
> (In reply to cfusco from comment #9)
> > Created attachment 1163 [details]
> > Client 2FA, unsuccesful
> 
> The client does not perform the dynamic authentication sequence and
> therefore does not authenticate.
> 
> So this is quite likely a client configuration issue, or the client does not
> support what we would require.
> 
> It is those two options:
> 
> > https://git.ipfire.org/?p=ipfire-2.x.git;a=blob;f=html/cgi-bin/ovpnmain.cgi;h=51d6e8431d6a00ffbb87aa24591c1fb67f0059b8;hb=HEAD#l2296

the same comes a little more detailed up without specific OpenVPN client software but only via Linux terminal --> https://community.ipfire.org/t/two-openvpn-problems-2fa-support-and-perfect-forward-security-disabled/9502/7 where i used a modified client configuration by circumvent the dynamic way and set "auth-user-pass" whereby "AUTH_FAILED,CRV1:R,E:dGVzdG5vZXhwaXJpbmdydw==:VE9UUA==:One Time Token" points to a specific section in openvpn-authenticator.

Another one i wanted to point out in this development, "--reneg-sec" has been set hardcoded to 86400 seconds ..> https://git.ipfire.org/?p=ipfire-2.x.git;a=blob;f=html/cgi-bin/ovpnmain.cgi;h=87bda4f1efda44c926f04bc8393283e23637a6af;hb=refs/heads/next#l357 whereby it doesn´t matter if you use 2FA or not. The old default was 3600 seconds this just weakens the PFS since the session key will be renewed only after 24 hours not every hour as before.

Best,

Erik