OTP OpenVPN Road Warrior broken after update 8.7 and 8.7.1

Send · October 30, 2025, 3:35pm

Hi

After update to 8.7 Roadwarrior has stop to work with otp auth, but work with username and password and username, password and certificate. I try to delete and recreate user, in local db, and qrcode, also check the time sync, without success. In to the log i found nothing strange eccept the open vpn client address.

ct 30 16:05:39 fw openvpn(ns_roadwarrior1)[5233]: 192.168.100.223:62474 peer info: IV_SSO=openurl,webauth,crtext
Oct 30 16:05:39 fw openvpn(ns_roadwarrior1)[5233]: 192.168.100.223:62474 TLS Auth Error: Auth Username/Password verification failed for peer
Oct 30 16:05:39 fw openvpn(ns_roadwarrior1)[5233]: 192.168.100.223:62474 TLS: move_session: dest=TM_ACTIVE src=TM_INITIAL reinit_src=1
Oct 30 16:05:39 fw openvpn(ns_roadwarrior1)[5233]: 192.168.100.223:62474 TLS: tls_multi_process: initial untrusted session promoted to semi-trusted
Oct 30 16:05:39 fw openvpn(ns_roadwarrior1)[5233]: 192.168.100.223:62474 Delayed exit in 5 seconds
Oct 30 16:05:39 fw openvpn(ns_roadwarrior1)[5233]: 192.168.100.223:62474 SENT CONTROL [UNDEF]: ‘AUTH_FAILED’ (status=1)
Oct 30 16:05:39 fw openvpn(ns_roadwarrior1)[5233]: 192.168.100.223:62474 SENT CONTROL [P*****.A******]: ‘AUTH_FAILED’ (status=1)
Oct 30 16:05:39 fw openvpn(ns_roadwarrior1)[5233]: 192.168.100.223:62474 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bits RSA, signature: RSA-SHA256, peer temporary key: 253 bits X25519
Oct 30 16:05:39 fw openvpn(ns_roadwarrior1)[5233]: 192.168.100.223:62474 [P*****.A******] Peer Connection Initiated with [AF_INET]192.168.100.223:62474 (via [AF_INET]62.xx.xx.xx%eth1)
Oct 30 16:05:41 fw openvpn(ns_roadwarrior1)[5233]: MANAGEMENT: Client connected from /var/run/openvpn_ns_roadwarrior1.socket
Oct 30 16:05:41 fw openvpn(ns_roadwarrior1)[5233]: MANAGEMENT: CMD ‘status 3’
Oct 30 16:05:41 fw openvpn(ns_roadwarrior1)[5233]: MANAGEMENT: Client disconnected
Oct 30 16:05:44 fw openvpn(ns_roadwarrior1)[5233]: 192.168.100.223:62474 SIGTERM[soft,delayed-exit] received, client-instance exiting
Oct 30 16:05:51 fw openvpn(ns_roadwarrior1)[5233]: MANAGEMENT: Client connected from /var/run/openvpn_ns_roadwarrior1.socket
Oct 30 16:05:51 fw openvpn(ns_roadwarrior1)[5233]: MANAGEMENT: CMD ‘status 3’
Oct 30 16:05:51 fw openvpn(ns_roadwarrior1)[5233]: MANAGEMENT: Client disconnected
Oct 30 16:05:54 fw openvpn(ns_roadwarrior1)[5233]: MANAGEMENT: Client connected from /var/run/openvpn_ns_roadwarrior1.socket
Oct 30 16:05:54 fw openvpn(ns_roadwarrior1)[5233]: MANAGEMENT: CMD ‘status 3’
Oct 30 16:05:54 fw openvpn(ns_roadwarrior1)[5233]: MANAGEMENT: Client disconnected

davide_marini · October 31, 2025, 8:17am

HI @Send

I tried to reproduce the issue but was not able to replicate it.
I upgraded from 8.6.0 to 8.7.1, and my existing user can still authenticate correctly with OTP.
I also created a new user (both the user account and the VPN account) on version 8.7.1, and in this case as well, the OTP authentication worked properly.

this is my client log with the already created account (davide)

Enter Auth Username: davide
Enter Auth Password: ••••••                  
2025-10-31 08:59:08 TCP/UDP: Preserving recently used remote address: [AF_INET]192.168.20.102:1194
2025-10-31 08:59:08 Socket Buffers: R=[212992->212992] S=[212992->212992]
2025-10-31 08:59:08 UDPv4 link local: (not bound)
2025-10-31 08:59:08 UDPv4 link remote: [AF_INET]192.168.20.102:1194
2025-10-31 08:59:08 TLS: Initial packet from [AF_INET]192.168.20.102:1194, sid=ba4f48b1 2a9731b4
2025-10-31 08:59:09 VERIFY OK: depth=1, CN=ROUTER-FW3
2025-10-31 08:59:09 VERIFY KU OK
2025-10-31 08:59:09 Validating certificate extended key usage
2025-10-31 08:59:09 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
2025-10-31 08:59:09 VERIFY EKU OK
2025-10-31 08:59:09 VERIFY OK: depth=0, CN=server
2025-10-31 08:59:09 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bits RSA, signature: RSA-SHA256, peer temporary key: 253 bits X25519
2025-10-31 08:59:09 [server] Peer Connection Initiated with [AF_INET]192.168.20.102:1194
2025-10-31 08:59:09 TLS: move_session: dest=TM_ACTIVE src=TM_INITIAL reinit_src=1
2025-10-31 08:59:09 TLS: tls_multi_process: initial untrusted session promoted to trusted
2025-10-31 08:59:10 SENT CONTROL [server]: 'PUSH_REQUEST' (status=1)
2025-10-31 08:59:10 PUSH: Received control message: 'PUSH_REPLY,route 10.20.20.0 255.255.255.0,route 10.10.10.0 255.255.255.0,route-gateway 10.173.214.1,topology subnet,ping 20,ping-restart 120,ifconfig 10.173.214.50 255.255.255.0,peer-id 0,cipher AES-256-GCM,protocol-flags cc-exit tls-ekm dyn-tls-crypt,tun-mtu 1500'
2025-10-31 08:59:10 OPTIONS IMPORT: --ifconfig/up options modified
2025-10-31 08:59:10 OPTIONS IMPORT: route options modified
2025-10-31 08:59:10 OPTIONS IMPORT: route-related options modified
2025-10-31 08:59:10 OPTIONS IMPORT: tun-mtu set to 1500
2025-10-31 08:59:10 net_route_v4_best_gw query: dst 0.0.0.0
2025-10-31 08:59:10 net_route_v4_best_gw result: via 192.168.20.1 dev wlp0s20f3
2025-10-31 08:59:10 ROUTE_GATEWAY 192.168.20.1/255.255.255.0 IFACE=wlp0s20f3 HWADDR=e4:0d:36:87:dc:82
2025-10-31 08:59:10 TUN/TAP device tun0 opened
2025-10-31 08:59:10 net_iface_mtu_set: mtu 1500 for tun0
2025-10-31 08:59:10 net_iface_up: set tun0 up
2025-10-31 08:59:10 net_addr_v4_add: 10.173.214.50/24 dev tun0
2025-10-31 08:59:10 net_route_v4_add: 10.20.20.0/24 via 10.173.214.1 dev [NULL] table 0 metric -1
2025-10-31 08:59:10 net_route_v4_add: 10.10.10.0/24 via 10.173.214.1 dev [NULL] table 0 metric -1
2025-10-31 08:59:10 Initialization Sequence Completed
2025-10-31 08:59:10 Data Channel: cipher 'AES-256-GCM', peer-id: 0
2025-10-31 08:59:10 Timers: ping 20, ping-restart 120
2025-10-31 08:59:10 Protocol options: explicit-exit-notify 1, protocol-flags cc-exit tls-ekm dyn-tls-crypt

this is my server log at the same time (timezone is different)

Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 VERIFY OK: depth=1, CN=ROUTER-FW3
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 VERIFY OK: depth=0, CN=davide
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 peer info: IV_VER=2.6.14
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 peer info: IV_PLAT=linux
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 peer info: IV_TCPNL=1
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 peer info: IV_MTU=1600
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 peer info: IV_NCP=2
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 peer info: IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 peer info: IV_PROTO=990
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 peer info: IV_LZO_STUB=1
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 peer info: IV_COMP_STUB=1
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 peer info: IV_COMP_STUBv2=1
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 TLS: Username/Password authentication succeeded for username 'davide' 
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 TLS: move_session: dest=TM_ACTIVE src=TM_INITIAL reinit_src=1
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 TLS: tls_multi_process: initial untrusted session promoted to trusted
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bits RSA, signature: RS
A-SHA256, peer temporary key: 253 bits X25519
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:35990 [davide] Peer Connection Initiated with [AF_INET]192.168.20.11:35990 (via [AF_INET]192.168.20.102%eth3)
Oct 31 07:59:08 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: davide/192.168.20.11:35990 MULTI_sva: pool returned IPv4=10.173.214.50, IPv6=(Not enabled)
Oct 31 07:59:10 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: davide/192.168.20.11:35990 OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_2bd878ee8c8643f63aff5d2b2a4cfa26.t
mp
Oct 31 07:59:10 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: davide/192.168.20.11:35990 MULTI: Learn: 10.173.214.50 -> davide/192.168.20.11:35990
Oct 31 07:59:10 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: davide/192.168.20.11:35990 MULTI: primary virtual IP for davide/192.168.20.11:35990: 10.173.214.50
Oct 31 07:59:10 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: davide/192.168.20.11:35990 SENT CONTROL [davide]: 'PUSH_REPLY,route 10.20.20.0 255.255.255.0,route 10.10.10.0 255.255.255.0,route-g
ateway 10.173.214.1,topology subnet,ping 20,ping-restart 120,ifconfig 10.173.214.50 255.255.255.0,peer-id 0,cipher AES-256-GCM,protocol-flags cc-exit tls-ekm dyn-tls-crypt,tun-mtu 1500' (sta
tus=1)
Oct 31 07:59:10 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: davide/192.168.20.11:35990 Data Channel: cipher 'AES-256-GCM', peer-id: 0
Oct 31 07:59:10 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: davide/192.168.20.11:35990 Timers: ping 20, ping-restart 240
Oct 31 07:59:10 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: davide/192.168.20.11:35990 Protocol options: protocol-flags cc-exit tls-ekm dyn-tls-crypt
Oct 31 07:59:10 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: davide/192.168.20.11:35990 PUSH: Received control message: 'PUSH_REQUEST'

An this is the client log again wityh the freshly created account (test-otp):

Enter Auth Username: test-otp
Enter Auth Password: ••••••                  
2025-10-31 09:06:14 TCP/UDP: Preserving recently used remote address: [AF_INET]192.168.20.102:1194
2025-10-31 09:06:14 Socket Buffers: R=[212992->212992] S=[212992->212992]
2025-10-31 09:06:14 UDPv4 link local: (not bound)
2025-10-31 09:06:14 UDPv4 link remote: [AF_INET]192.168.20.102:1194
2025-10-31 09:06:14 TLS: Initial packet from [AF_INET]192.168.20.102:1194, sid=716ea0fd f6ae0fdc
2025-10-31 09:06:14 VERIFY OK: depth=1, CN=ROUTER-FW3
2025-10-31 09:06:14 VERIFY KU OK
2025-10-31 09:06:14 Validating certificate extended key usage
2025-10-31 09:06:14 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
2025-10-31 09:06:14 VERIFY EKU OK
2025-10-31 09:06:14 VERIFY OK: depth=0, CN=server
2025-10-31 09:06:15 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bits RSA, signature: RSA-SHA256, peer temporary key: 253 bits X25519
2025-10-31 09:06:15 [server] Peer Connection Initiated with [AF_INET]192.168.20.102:1194
2025-10-31 09:06:15 TLS: move_session: dest=TM_ACTIVE src=TM_INITIAL reinit_src=1
2025-10-31 09:06:15 TLS: tls_multi_process: initial untrusted session promoted to trusted
2025-10-31 09:06:16 SENT CONTROL [server]: 'PUSH_REQUEST' (status=1)
2025-10-31 09:06:16 PUSH: Received control message: 'PUSH_REPLY,route 10.20.20.0 255.255.255.0,route 10.10.10.0 255.255.255.0,route-gateway 10.173.214.1,topology subnet,ping 20,ping-restart 120,ifconfig 10.173.214.51 255.255.255.0,peer-id 0,cipher AES-256-GCM,protocol-flags cc-exit tls-ekm dyn-tls-crypt,tun-mtu 1500'
2025-10-31 09:06:16 OPTIONS IMPORT: --ifconfig/up options modified
2025-10-31 09:06:16 OPTIONS IMPORT: route options modified
2025-10-31 09:06:16 OPTIONS IMPORT: route-related options modified
2025-10-31 09:06:16 OPTIONS IMPORT: tun-mtu set to 1500
2025-10-31 09:06:16 net_route_v4_best_gw query: dst 0.0.0.0
2025-10-31 09:06:16 net_route_v4_best_gw result: via 192.168.20.1 dev wlp0s20f3
2025-10-31 09:06:16 ROUTE_GATEWAY 192.168.20.1/255.255.255.0 IFACE=wlp0s20f3 HWADDR=e4:0d:36:87:dc:82
2025-10-31 09:06:16 TUN/TAP device tun0 opened
2025-10-31 09:06:16 net_iface_mtu_set: mtu 1500 for tun0
2025-10-31 09:06:16 net_iface_up: set tun0 up
2025-10-31 09:06:16 net_addr_v4_add: 10.173.214.51/24 dev tun0
2025-10-31 09:06:16 net_route_v4_add: 10.20.20.0/24 via 10.173.214.1 dev [NULL] table 0 metric -1
2025-10-31 09:06:16 net_route_v4_add: 10.10.10.0/24 via 10.173.214.1 dev [NULL] table 0 metric -1
2025-10-31 09:06:16 Initialization Sequence Completed
2025-10-31 09:06:16 Data Channel: cipher 'AES-256-GCM', peer-id: 0
2025-10-31 09:06:16 Timers: ping 20, ping-restart 120
2025-10-31 09:06:16 Protocol options: explicit-exit-notify 1, protocol-flags cc-exit tls-ekm dyn-tls-crypt

and finally my server log:

Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 VERIFY OK: depth=1, CN=ROUTER-FW3
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 VERIFY OK: depth=0, CN=test-otp
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 peer info: IV_VER=2.6.14
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 peer info: IV_PLAT=linux
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 peer info: IV_TCPNL=1
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 peer info: IV_MTU=1600
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 peer info: IV_NCP=2
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 peer info: IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 peer info: IV_PROTO=990
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 peer info: IV_LZO_STUB=1
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 peer info: IV_COMP_STUB=1
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 peer info: IV_COMP_STUBv2=1
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 TLS: Username/Password authentication succeeded for username 'test-otp' 
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 TLS: move_session: dest=TM_ACTIVE src=TM_INITIAL reinit_src=1
Oct 31 08:06:14 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 TLS: tls_multi_process: initial untrusted session promoted to trusted
Oct 31 08:06:15 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bits RSA, signature: RSA-SHA256, peer temporary key: 253 bits X25519
Oct 31 08:06:15 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: 192.168.20.11:45466 [test-otp] Peer Connection Initiated with [AF_INET]192.168.20.11:45466 (via [AF_INET]192.168.20.102%eth3)
Oct 31 08:06:15 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: test-otp/192.168.20.11:45466 MULTI_sva: pool returned IPv4=10.173.214.51, IPv6=(Not enabled)
Oct 31 08:06:16 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: test-otp/192.168.20.11:45466 OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_56a1a69eea8ed7e84e45ab8f48c0f06e.tmp
Oct 31 08:06:16 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: test-otp/192.168.20.11:45466 MULTI: Learn: 10.173.214.51 -> test-otp/192.168.20.11:45466
Oct 31 08:06:16 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: test-otp/192.168.20.11:45466 MULTI: primary virtual IP for test-otp/192.168.20.11:45466: 10.173.214.51
Oct 31 08:06:16 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: test-otp/192.168.20.11:45466 SENT CONTROL [test-otp]: 'PUSH_REPLY,route 10.20.20.0 255.255.255.0,route 10.10.10.0 255.255.255.0,route-gateway 10.173.214.1,topology subnet,ping 20,ping-restart 120,ifconfig 10.173.214.51 255.255.255.0,peer-id 0,cipher AES-256-GCM,protocol-flags cc-exit tls-ekm dyn-tls-crypt,tun-mtu 1500' (status=1)
Oct 31 08:06:16 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: test-otp/192.168.20.11:45466 Data Channel: cipher 'AES-256-GCM', peer-id: 0
Oct 31 08:06:16 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: test-otp/192.168.20.11:45466 Timers: ping 20, ping-restart 240
Oct 31 08:06:16 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: test-otp/192.168.20.11:45466 Protocol options: protocol-flags cc-exit tls-ekm dyn-tls-crypt
Oct 31 08:06:16 ROUTER-FW3 openvpn(ns_roadwarrior1)[5015]: test-otp/192.168.20.11:45466 PUSH: Received control message: 'PUSH_REQUEST'

everything seem to be ok and the traffic flows correctly.

Send · October 31, 2025, 5:04pm

Hi Davide

I solved the problem. I’m a bit embarrassed, but when I checked the NTP synchronization, I didn’t notice that I was a full 20 seconds early.
I don’t understand why the OTP verification worked until the update, and why, even though I synchronized with ntp1.inrim.it, time.inrim.it and ntp2.inrim.it, it didn’t work.
It seems to be working now, but I’ll check it over the next few days and keep you updated.

davide_marini · October 31, 2025, 5:23pm

HI @Send ,

no problem at all, I’m happy you figured out what was wrong and solved it