pfSense

unable to reproduce it on 2.5.0.a.20201230.0250,
I can successfully authenticate to OpenVPN server with a mix of RADIUS/LDAP auth backends

Please provide more info

Hi Viktor, when my openvpn server have multiple ldap backends I simply got AUTH_FAIL in logs. Could you please provide info which debug logging I need to enable and where to provide more details on this case, thank you in advance.

Also Viktor you mention 2.5.0.a.20201230.0250 version, when for my instance 2.5.0.a.20201127.0650 is reported as latest available. I also have another instance on 2.4.5_p1 and if I change to 2.5.x devel branch on it, it also reports 2.5.0.a.20201127.0650 as latest. To note I speak in both cases about pfSense non-Community edition on XG-7100U.

I can successfully authenticate with two LDAP backends (FreeIPA + Win2012)
maybe related to #10704 and #9417

Not sure about #10704 as on 2.4.5_p1 it was working correctly. Issue appear right after update to 2.5.0.a.

I have in my case Win2012R2 also.
1st: dc1.ldap.company.com
2nd: dc2.ldap.company.com
Both Auth servers use SSL 636 and their certs issued by same CA. This is internal CA is trusted by pfSense (certificate issued from pfSense managed CA).

As you asked I changed Peer Certificate Authority for Auth servers from exact match of my internal CA to Global Root CA List. Tried diagnostic -> auth - it works as expected, same it was works with exact math. While not work under OpenVPN. I can't test\change OpenVPN setting now, sorry, as there now many clients and I doesn't want to interrupt them. I will provide feedback later when I can restart OpenVPN.

Now I had workaround by creating one ldap.company.com Auth entry in pfSense which point to ldap.company.com. As I think it use SRV records to find dc1 and dc2 automatically. I was need to reissue for dc1 and for dc2 certs to get SubjAltName additional DNS=ldap.company.com and after this it works fine. To note: my Peer Certificate Authority in this workaround point to exactly my internal CA.
So this also one of possible workarounds till issue not resolved :).

Hi Viktor, changed OpenVPN settings to use 2 auth backends after adjust CA to Global CA list, and still same AUTH_FAILED. Change it back to only one (any of both) auth backend - all works. I changed OpenVPN log level to 6, but this not provide any details on why it fails.

Jan 4 01:03:29     openvpn     57180     MANAGEMENT: Client disconnected
Jan 4 01:03:29     openvpn     57180     MANAGEMENT: CMD 'quit'
Jan 4 01:03:28     openvpn     57180     MANAGEMENT: CMD 'status 2'
Jan 4 01:03:28     openvpn     57180     TCP/UDP: Closing socket
Jan 4 01:03:28     openvpn     57180     *CLIENTIP*:51086 SIGUSR1[soft,connection-reset] received, client-instance restarting
Jan 4 01:03:28     openvpn     57180     *CLIENTIP*:51086 Connection reset, restarting [0]
Jan 4 01:03:28     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER WRITE [88] to [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_V1 kid=0 [ ] pid=2655 DATA len=74
Jan 4 01:03:28     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER WRITE [62] to [AF_INET6]::ffff:*CLIENTIP*:51086: P_ACK_V1 kid=0 [ ]
Jan 4 01:03:28     openvpn     57180     *CLIENTIP*:51086 SENT CONTROL [*USERNAME*]: 'AUTH_FAILED' (status=1)
Jan 4 01:03:28     openvpn     57180     *CLIENTIP*:51086 Delayed exit in 5 seconds
Jan 4 01:03:28     openvpn     57180     *CLIENTIP*:51086 PUSH: Received control message: 'PUSH_REQUEST'
Jan 4 01:03:28     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER READ [89] from [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_V1 kid=0 [ ] pid=2911 DATA len=75
Jan 4 01:03:28     openvpn     57180     MANAGEMENT: Client connected from /var/etc/openvpn/server2/sock
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 [*USERNAME*] Peer Connection Initiated with [AF_INET6]::ffff:*CLIENTIP*:51086
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER READ [62] from [AF_INET6]::ffff:*CLIENTIP*:51086: P_ACK_V1 kid=0 [ ]
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER READ [62] from [AF_INET6]::ffff:*CLIENTIP*:51086: P_ACK_V1 kid=0 [ ]
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER WRITE [289] to [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_V1 kid=0 [ ] pid=2143 DATA len=275
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER WRITE [224] to [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_V1 kid=0 [ ] pid=1887 DATA len=210
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TLS: Username/Password authentication deferred for username '*USERNAME*' [CN SET]
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 peer info: IV_GUI_VER=OpenVPN_GUI_11
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 peer info: IV_TCPNL=1
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 peer info: IV_COMP_STUBv2=1
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 peer info: IV_COMP_STUB=1
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 peer info: IV_LZO=1
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 peer info: IV_LZ4v2=1
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 peer info: IV_LZ4=1
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 peer info: IV_CIPHERS=AES-256-GCM:AES-256-CBC:AES-128-GCM:AES-128-CBC
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 peer info: IV_NCP=2
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 peer info: IV_PROTO=6
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 peer info: IV_PLAT=win
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 peer info: IV_VER=2.5.0
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER READ [668] from [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_V1 kid=0 [ ] pid=2143 DATA len=654
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER READ [62] from [AF_INET6]::ffff:*CLIENTIP*:51086: P_ACK_V1 kid=0 [ ]
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER READ [62] from [AF_INET6]::ffff:*CLIENTIP*:51086: P_ACK_V1 kid=0 [ ]
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER READ [62] from [AF_INET6]::ffff:*CLIENTIP*:51086: P_ACK_V1 kid=0 [ ]
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER WRITE [248] to [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_V1 kid=0 [ ] pid=1631 DATA len=234
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER READ [62] from [AF_INET6]::ffff:*CLIENTIP*:51086: P_ACK_V1 kid=0 [ ]
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER WRITE [1112] to [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_V1 kid=0 [ ] pid=1375 DATA len=1098
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER WRITE [1112] to [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_V1 kid=0 [ ] pid=1119 DATA len=1098
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER WRITE [1112] to [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_V1 kid=0 [ ] pid=863 DATA len=1098
Jan 4 01:03:27     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER WRITE [1124] to [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_V1 kid=0 [ ] pid=607 DATA len=1110
Jan 4 01:03:26     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER READ [331] from [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_V1 kid=0 [ ] pid=863 DATA len=317
Jan 4 01:03:26     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER READ [62] from [AF_INET6]::ffff:*CLIENTIP*:51086: P_ACK_V1 kid=0 [ ]
Jan 4 01:03:26     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER WRITE [66] to [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ ] pid=351 DATA len=52
Jan 4 01:03:26     openvpn     57180     *CLIENTIP*:51086 TLS: Initial packet from [AF_INET6]::ffff:*CLIENTIP*:51086, sid=43be6a3d 470c83a2
Jan 4 01:03:26     openvpn     57180     *CLIENTIP*:51086 TCPv6_SERVER READ [54] from [AF_INET6]::ffff:*CLIENTIP*:51086: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=351 DATA len=40
Jan 4 01:03:26     openvpn     57180     TCPv6_SERVER link remote: [AF_INET6]::ffff:*CLIENTIP*:51086
Jan 4 01:03:26     openvpn     57180     TCPv6_SERVER link local: (not bound)
Jan 4 01:03:26     openvpn     57180     TCP connection established with [AF_INET6]::ffff:*CLIENTIP*:51086
Jan 4 01:03:26     openvpn     57180     Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1551,tun-mtu 1500,proto TCPv4_CLIENT,cipher AES-256-GCM,auth [null-digest],keysize 256,key-method 2,tls-client'
Jan 4 01:03:26     openvpn     57180     Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1551,tun-mtu 1500,proto TCPv4_SERVER,cipher AES-256-GCM,auth [null-digest],keysize 256,key-method 2,tls-server'
Jan 4 01:03:26     openvpn     57180     Data Channel MTU parms [ L:1623 D:1450 EF:123 EB:406 ET:0 EL:3 ]
Jan 4 01:03:26     openvpn     57180     Control Channel MTU parms [ L:1623 D:1154 EF:96 EB:0 ET:0 EL:3 ]
Jan 4 01:03:26     openvpn     57180     Incoming Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication
Jan 4 01:03:26     openvpn     57180     Incoming Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key
Jan 4 01:03:26     openvpn     57180     Outgoing Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication
Jan 4 01:03:26     openvpn     57180     Outgoing Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key
Jan 4 01:03:26     openvpn     57180     Re-using SSL/TLS context
Jan 4 01:03:26     openvpn     57180     MULTI: multi_create_instance called

Also I found that in my log this 3 lines permanently spamming my pfsense log. It appear 5 times in one second and repeat endlessly with debug log enabled:

Jan 4 00:29:13     openvpn     29277     MANAGEMENT: Client disconnected
Jan 4 00:29:13     openvpn     29277     MANAGEMENT: CMD 'status 2'
Jan 4 00:29:13     openvpn     29277     MANAGEMENT: Client connected from /var/etc/openvpn/server2/sock

Maybe if I provide openvpn config or auth server config this can help?
Or how I can debug plugin "/usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so /usr/local/sbin/ovpn_auth_verify_async" or "/etc/inc/openvpn.auth-user.php"?

If I rapidly run "cat /tmp/openvpn_acf_*" I can see that with both auth servers I get 0 (failed?) in tmp files and with only one server get 1 (success?) in reply which mean that this "/etc/inc/openvpn.auth-user.php" return incorrect response, yes?

• I done testing when I was only one person who was used OpenVPN server.
• For me issue solved as workaround with one server which point to root of ldap domain, but I want help find root case of issue to fix this for other people :)