iPhones do not connect to SSL VPN

[fortiFWuser]

Hello, 

I have an ongoing issue with iPhone users and the SSL VPN.  

The users connect with certificate and username/password.
Through windows and android devices they connect normally.
If they use iPhone they get timeout. In the fortigate logs I see this error "sslvpn_login_cert_checked_error"
Forti support said to change the subject because there was no RDN matched.
We did not see any different error after changing the subject.

We have the free app on the mobiles.

Any ideas suggestions?

Thanks and regards,
Konstantinos

[srajeswaran]

Can you share the complete debug as below for the specific IOS user facing the issue.

diag debug disable 
diag debug reset 
diag debug console timestamp enable 
diagnostics vpn ssl debug-filter src-addr4 <ipv4-address> <----- here replace with the public ip of the VPN client 
diag debug app fnbamd -1 
diag debug app sslvpn -1 
diag debug en

[mgoswami]

Hi,

Please execute these commands and try to connect from the ios device.

# diagnose debug console timestamp enable
# diagnose debug app sslvpn -1
# diagnose debug app fnbamd -1
# diagnose debug enable

Once you see the error, please disable the debug using command:

di de di

In addition to this, please share the screenshots for the SSLVPN configuration you are using on the FGT(SSLVPN portal and SSLVPN settings).

[FortiNitish]

As per the error " sslvpn_login_cert_checked_error " you are having certificate issues. 

Since you are able to connect Windows and android devices, the Iphone might not have the required certificate. 

 Please disable  "Require Client Certificate" option in the SSL VPN settings and try to login from Iphone. With this we should be able to isolate the issue

[Shilpa1]

Hello Konstantinos,

Since the issue only occurs on iPhone devices, it's possible that there is a compatibility issue with the SSL VPN configuration and the iOS device.

> Please check the config and compatiblity 
> Ensure that the iOS and the FortiOS  is compatible 

> Please try to test with a differnet forticlient version 

> Verify the certificates

>Also test with a different Auth method and test.
Regards,
Shilpa 

[fortiFWuser]

Hello, 

Thank you for your answers. 

We had performed tests with "Require Client Certificate" disabled and it connected normally. But we need this feature enabled. Plus it cannot be set only for iOS users or a portal. It is global

The versions of iOS device and app are the latest. 

Thanks and regards, 

Konstantinos

[fortiFWuser]

These are the app logs

FortiClientiOS.txt

2023-04-28 10:54:34.275 forticlient[17633:3073278] -canOpenURL: failed for URL: "com.fortinet.forticlient://" - error: "The operation couldn’t be completed. (OSStatus error -10814.)"
2023-04-28 10:54:34.287 forticlient[17633:3073278] unlicensed
2023-04-28 10:54:34.415 forticlient[17633:3073278] -canOpenURL: failed for URL: "com.fortinet.forticlient://" - error: "The operation couldn’t be completed. (OSStatus error -10814.)"
2023-04-28 10:54:35.453 forticlient[17633:3073278] Apply onnet profile
2023-04-28 10:54:35.458 forticlient[17633:3073278] unlicensed
2023-04-28 10:54:35.479 forticlient[17633:3073278] Failed to enable WebFilter : The operation couldn’t be completed. (NEFilterErrorDomain error 1.)
2023-04-28 10:54:37.323 forticlient[17633:3073278] -canOpenURL: failed for URL: "com.fortinet.forticlient://" - error: "The operation couldn’t be completed. (OSStatus error -10814.)"
2023-04-28 10:54:38.424 forticlient[17633:3073278] Apply onnet profile
2023-04-28 10:54:38.430 forticlient[17633:3073278] unlicensed
2023-04-28 10:54:38.435 forticlient[17633:3073278] Failed to enable WebFilter : The operation couldn’t be completed. (NEFilterErrorDomain error 1.)
2023-04-28 10:54:51.803 forticlient[17633:3073278] -canOpenURL: failed for URL: "com.fortinet.forticlient://" - error: "The operation couldn’t be completed. (OSStatus error -10814.)"
2023-04-28 10:54:52.866 forticlient[17633:3073278] Apply onnet profile
2023-04-28 10:54:52.869 forticlient[17633:3073278] unlicensed
2023-04-28 10:54:52.888 forticlient[17633:3073278] Failed to enable WebFilter : The operation couldn’t be completed. (NEFilterErrorDomain error 1.)
2023-04-28 10:55:07.230 forticlient[17633:3073278] unlicensed
2023-04-28 10:55:07.678 forticlient[17633:3073278] -canOpenURL: failed for URL: "com.fortinet.forticlient://" - error: "The operation couldn’t be completed. (OSStatus error -10814.)"
2023-04-28 10:55:08.709 forticlient[17633:3073278] Apply onnet profile
2023-04-28 10:55:08.715 forticlient[17633:3073278] unlicensed
2023-04-28 10:55:08.720 forticlient[17633:3073278] Failed to enable WebFilter : The operation couldn’t be completed. (NEFilterErrorDomain error 1.)
2023-04-28 10:55:28.069 forticlient[17633:3073278] Can't find keyplane that supports type 4 for keyboard iPhone-PortraitChoco-NumberPad; using 27303_PortraitChoco_iPhone-Simple-Pad_Default
2023-04-28 10:55:37.276 forticlient[17633:3073278] invalid mode 'kCFRunLoopCommonModes' provided to CFRunLoopRunSpecific - break on _CFRunLoopError_RunCalledWithInvalidMode to debug. This message will only appear once per execution.
2023-04-28 10:56:25.946 forticlient[17633:3073278] unlicensed
2023-04-28 10:56:26.389 forticlient[17633:3073278] -canOpenURL: failed for URL: "com.fortinet.forticlient://" - error: "The operation couldn’t be completed. (OSStatus error -10814.)"
2023-04-28 10:56:27.427 forticlient[17633:3073278] Apply onnet profile
2023-04-28 10:56:27.433 forticlient[17633:3073278] unlicensed
2023-04-28 10:56:27.436 forticlient[17633:3073278] Failed to enable WebFilter : The operation couldn’t be completed. (NEFilterErrorDomain error 1.)
2023-04-28 10:56:43.129 forticlient[17633:3073278] save password SecItemAdd status : (null)
2023-04-28 10:56:43.129 forticlient[17633:3073278] successfully saved password into keychain (new persistentRef)
2023-04-28 10:56:46.829 forticlient[17633:3073278] selected connectionName : testH&H(0007)
2023-04-28 10:56:46.830 forticlient[17633:3073278] target manager connectionName : testH&H(0007)
2023-04-28 10:56:48.579 forticlient[17633:3073278] successfully saved password into keychain (persistentRef)
2023-04-28 10:56:51.465 forticlient[17633:3073278] OK Pressed
2023-04-28 10:57:02.829 forticlient[17633:3073278] startRec recieved an error : ERROR: Έληξε το χρονικό όριο του αιτήματος.
2023-04-28 10:57:57.654 forticlient[17633:3073278] unlicensed
2023-04-28 10:57:57.968 forticlient[17633:3073278] -canOpenURL: failed for URL: "com.fortinet.forticlient://" - error: "The operation couldn’t be completed. (OSStatus error -10814.)"
2023-04-28 10:57:58.993 forticlient[17633:3073278] Apply onnet profile
2023-04-28 10:57:58.996 forticlient[17633:3073278] unlicensed
2023-04-28 10:57:58.998 forticlient[17633:3073278] Failed to enable WebFilter : The operation couldn’t be completed. (NEFilterErrorDomain error 1.)
2023-04-28 10:58:23.602 forticlient[17633:3073278] selected connectionName : testH&H(0007)
2023-04-28 10:58:23.603 forticlient[17633:3073278] target manager connectionName : testH&H(0007)
2023-04-28 10:58:23.649 forticlient[17633:3073278] Response tunnel info IP: forticlient.UIMessageResponseInfo
2023-04-28 10:58:25.114 forticlient[17633:3073278] successfully saved password into keychain (persistentRef)
2023-04-28 10:58:28.192 forticlient[17633:3073278] OK Pressed
2023-04-28 10:58:39.502 forticlient[17633:3073278] startRec recieved an error : ERROR: Έληξε το χρονικό όριο του αιτήματος.
2023-04-28 11:00:34.751 forticlient[17633:3073278] No old zip file to delete

PacketTunnel.txt

2023-04-28 10:58:25.212: ===== SSL VPN Starting =====
2023-04-28 10:58:25.219: use SSO cookie
2023-04-28 10:58:25.219: use System DNS : Optional(["192.168.82.116", "192.168.80.116"])
2023-04-28 10:58:25.222: Logging into fqdn:10443 ...
2023-04-28 10:58:25.223: setConfigPublicIPHeader: 209.8.196.34
2023-04-28 10:58:25.223: doLogin
2023-04-28 10:58:25.223: Remote fetch info: Send request https://fqdn:10443/remote/info
2023-04-28 10:58:26.013: CancelAuthenticationChallenge with SecTrust Type
2023-04-28 10:58:26.021: Need user input to Confirm Certificate
2023-04-28 10:58:28.193: doLogin
2023-04-28 10:58:28.197: Remote fetch info: Send request https://fqdn:10443/remote/info
2023-04-28 10:58:28.199: Handle user input for confirm cert
2023-04-28 10:58:28.980: SecTrustResultType : SecTrustResultType(rawValue: 5)
2023-04-28 10:58:28.983: ignore cert error : true
2023-04-28 10:58:29.468: Remote fetch info: Received request https://fqdn:10443/remote/info
2023-04-28 10:58:29.471: ParseInfoXml : Optional(<?xml version='1.0' encoding='utf-8'?><info><api encmethod='0' salt='77e546a5' remoteauthtimeout='30' sso_port='8020' f='cdf' /></info>)
2023-04-28 10:58:29.480: ParseInfoXML f: cdf
2023-04-28 10:58:29.482: fInt: 3295
2023-04-28 10:58:29.483: auto_FTM_push_enabled: true
2023-04-28 10:58:29.484: emsSNEnabled: 0
2023-04-28 10:58:29.485: fortiGuardCloudLicensed: false
2023-04-28 10:58:29.486: Do get login page: Send request https://fqdn:10443/remote/login
2023-04-28 10:58:39.493: Do get login page: Received request https://fqdn:10443/remote/login
2023-04-28 10:58:39.498: Tunnel being closed
2023-04-28 10:58:39.500: Closed while starting, canceled TunnelWithError : Optional(Error Domain=NEVPNErrorDomain Code=3 "ERROR: Έληξε το χρονικό όριο του αιτήματος." UserInfo={NSLocalizedDescription=ERROR: Έληξε το χρονικό όριο του αιτήματος.})
2023-04-28 10:58:39.502: authFailed message : ERROR: Έληξε το χρονικό όριο του αιτήματος.
2023-04-28 10:58:39.503: authFailed : ERROR: Έληξε το χρονικό όριο του αιτήματος.

[fortiFWuser]

Here are the debugs.

2023-03-27 10:26:41 [258:root:cb8]allocSSLConn:306 sconn 0x7f8f2b2600 (0:root)
2023-03-27 10:26:41 [258:root:cb8]SSL state:before SSL initialization (public IP)
2023-03-27 10:26:41 [258:root:cb8]SSL state:before SSL initialization (public IP)
2023-03-27 10:26:41 [258:root:cb8]got SNI server name: connection URL realm (null)
2023-03-27 10:26:41 [258:root:cb8]client cert requirement: yes
2023-03-27 10:26:41 [258:root:cb8]SSL state:SSLv3/TLS read client hello (public IP)
2023-03-27 10:26:41 [258:root:cb8]SSL state:SSLv3/TLS write server hello (public IP)
2023-03-27 10:26:41 [258:root:cb8]SSL state:SSLv3/TLS write change cipher spec (public IP)
2023-03-27 10:26:41 [258:root:cb8]SSL state:TLSv1.3 early data (public IP)
2023-03-27 10:26:41 [258:root:cb8]SSL state:TLSv1.3 early data:(null)(public IP)
2023-03-27 10:26:42 [258:root:cb8]SSL state:TLSv1.3 early data (public IP)
2023-03-27 10:26:42 [258:root:cb8]got SNI server name: connection URL realm (null)
2023-03-27 10:26:42 [258:root:cb8]client cert requirement: yes
2023-03-27 10:26:42 [258:root:cb8]SSL state:SSLv3/TLS read client hello (public IP)
2023-03-27 10:26:42 [258:root:cb8]SSL state:SSLv3/TLS write server hello (public IP)
2023-03-27 10:26:42 [258:root:cb8]SSL state:TLSv1.3 write encrypted extensions (public IP)
2023-03-27 10:26:42 [258:root:cb8]SSL state:SSLv3/TLS write certificate request (public IP)
2023-03-27 10:26:42 [258:root:cb8]SSL state:SSLv3/TLS write certificate (public IP)
2023-03-27 10:26:42 [258:root:cb8]SSL state:TLSv1.3 write server certificate verify (public IP)
2023-03-27 10:26:42 [258:root:cb8]SSL state:SSLv3/TLS write finished (public IP)
2023-03-27 10:26:42 [258:root:cb8]SSL state:TLSv1.3 early data (public IP)
2023-03-27 10:26:42 [258:root:cb8]SSL state:TLSv1.3 early data:(null)(public IP)
2023-03-27 10:26:42 [258:root:cb8]SSL state:fatal decode error (public IP)
2023-03-27 10:26:42 [258:root:cb8]SSL state:error:(null)(public IP)
2023-03-27 10:26:42 [258:root:cb8]SSL_accept failed, 1:unexpected eof while reading
2023-03-27 10:26:42 [258:root:cb8]Destroy sconn 0x7f8f2b2600, connSize=1. (root)
2023-03-27 10:26:45 [259:root:cb7]allocSSLConn:306 sconn 0x7f8f2b1f00 (0:root)
2023-03-27 10:26:45 [259:root:cb7]SSL state:before SSL initialization (public IP)
2023-03-27 10:26:45 [259:root:cb7]SSL state:before SSL initialization (public IP)
2023-03-27 10:26:45 [259:root:cb7]got SNI server name: connection URL realm (null)
2023-03-27 10:26:45 [259:root:cb7]client cert requirement: yes
2023-03-27 10:26:45 [259:root:cb7]SSL state:SSLv3/TLS read client hello (public IP)
2023-03-27 10:26:45 [259:root:cb7]SSL state:SSLv3/TLS write server hello (public IP)
2023-03-27 10:26:45 [259:root:cb7]SSL state:SSLv3/TLS write change cipher spec (public IP)
2023-03-27 10:26:45 [259:root:cb7]SSL state:TLSv1.3 early data (public IP)
2023-03-27 10:26:45 [259:root:cb7]SSL state:TLSv1.3 early data:(null)(public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:TLSv1.3 early data (public IP)
2023-03-27 10:26:46 [259:root:cb7]got SNI server name: connection URL realm (null)
2023-03-27 10:26:46 [259:root:cb7]client cert requirement: yes
2023-03-27 10:26:46 [259:root:cb7]SSL state:SSLv3/TLS read client hello (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:SSLv3/TLS write server hello (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:TLSv1.3 write encrypted extensions (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:SSLv3/TLS write certificate request (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:SSLv3/TLS write certificate (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:TLSv1.3 write server certificate verify (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:SSLv3/TLS write finished (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:TLSv1.3 early data (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:TLSv1.3 early data:(null)(public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:TLSv1.3 early data:(null)(public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:TLSv1.3 early data:(null)(public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:TLSv1.3 early data (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:SSLv3/TLS read client certificate (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:SSLv3/TLS read certificate verify (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:SSLv3/TLS read finished (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:SSLv3/TLS write session ticket (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL state:SSLv3/TLS write session ticket (public IP)
2023-03-27 10:26:46 [259:root:cb7]SSL established: TLSv1.3 TLS_AES_256_GCM_SHA384
2023-03-27 10:26:46 [259:root:cb7]req: /remote/info
2023-03-27 10:26:46 [259:root:cb7]capability flags: 0xcdf
2023-03-27 10:26:46 [259:root:cb7]req: /remote/login
2023-03-27 10:26:46 [259:root:cb7]rmt_web_auth_info_parser_common:504 no session id in auth info
2023-03-27 10:26:46 [259:root:cb7]rmt_web_get_access_cache:852 invalid cache, ret=4103
2023-03-27 10:26:46 [259:root:cb7]User Agent: FortiSSLVPN ( iOS; SV1 [SV{v=02.01; f=07;}])
2023-03-27 10:26:46 [259:root:cb7]sslvpn_auth_check_usrgroup:2991 forming user/group list from policy.
2023-03-27 10:26:46 [259:root:cb7]sslvpn_auth_check_usrgroup:3037 got user (0) group (1:3).
2023-03-27 10:26:46 [259:root:cb7]sslvpn_validate_user_group_list:1870 validating with SSL VPN authentication rules (1), realm ().
2023-03-27 10:26:46 [259:root:cb7]sslvpn_validate_user_group_list:1991 checking rule 1 cipher.
2023-03-27 10:26:46 [259:root:cb7]sslvpn_validate_user_group_list:1999 checking rule 1 realm.
2023-03-27 10:26:46 [259:root:cb7]sslvpn_validate_user_group_list:2010 checking rule 1 source intf.
2023-03-27 10:26:46 [259:root:cb7]sslvpn_validate_user_group_list:2049 checking rule 1 vd source intf.
2023-03-27 10:26:46 [259:root:cb7]sslvpn_validate_user_group_list:2592 rule 1 done, got user (0:0) group (1:0) peer group (0).
2023-03-27 10:26:46 [259:root:cb7]sslvpn_validate_user_group_list:2889 got user (0:0), group (1:0) peer group (3).
2023-03-27 10:26:46 [259:root:cb7]fam_cert_send_req:1164 peer group 'test_local_user' is sent for verification.
2023-03-27 10:26:46 [259:root:cb7]fam_cert_send_req:1164 peer group 'test_SSLVPN_user' is sent for verification.
2023-03-27 10:26:46 [259:root:cb7]fam_cert_send_req:1164 peer group 'SSLVPN_user' is sent for verification.
2023-03-27 10:26:46 [259:root:cb7]fam_cert_send_req:1170 doing authentication for 3 group(s).
2023-03-27 10:26:46 [2360] handle_req-Rcvd auth_cert req id=1244516033, len=1120, opt=0
2023-03-27 10:26:46 [980] __cert_auth_ctx_init-req_id=1244516033, opt=0
2023-03-27 10:26:46 [103] __cert_chg_st- 'Init'
2023-03-27 10:26:46 [156] fnbamd_cert_load_certs_from_req-2 cert(s) in req.
2023-03-27 10:26:46 [667] __cert_init-req_id=1244516033
2023-03-27 10:26:46 [716] __cert_build_chain-req_id=1244516033
2023-03-27 10:26:46 [273] fnbamd_chain_build-Chain discovery, opt 0x13, cur total 1
2023-03-27 10:26:46 [291] fnbamd_chain_build-Following depth 0
2023-03-27 10:26:46 [326] fnbamd_chain_build-Extend chain by system trust store. (good: 'CA_Cert_1')
2023-03-27 10:26:46 [291] fnbamd_chain_build-Following depth 1
2023-03-27 10:26:46 [305] fnbamd_chain_build-Self-sign detected.
2023-03-27 10:26:46 [99] __cert_chg_st- 'Init' -> 'Validation'
2023-03-27 10:26:46 [837] __cert_verify-req_id=1244516033
2023-03-27 10:26:46 [838] __cert_verify-Chain is complete.
2023-03-27 10:26:46 [486] fnbamd_cert_verify-Chain number:2
2023-03-27 10:26:46 [500] fnbamd_cert_verify-Following cert chain depth 0
2023-03-27 10:26:46 [567] fnbamd_cert_verify-Issuer found: CA_Cert_1 (SSL_DPI opt 1)
2023-03-27 10:26:46 [500] fnbamd_cert_verify-Following cert chain depth 1
2023-03-27 10:26:46 [675] fnbamd_cert_check_group_list-checking group with name 'test_local_user'
2023-03-27 10:26:46 [490] __check_add_peer-check 'testfortipki'
2023-03-27 10:26:46 [366] peer_subject_cn_check-Cert subject 'CN = username'
2023-03-27 10:26:46 [324] __cert_subject_RDN_compare-Total matched RDNs in cert: 0
2023-03-27 10:26:46 [382] peer_subject_cn_check-Subject checking failed.
2023-03-27 10:26:46 [497] __check_add_peer-'testfortipki' check ret:bad
2023-03-27 10:26:46 [490] __check_add_peer-check 'username2pki'
2023-03-27 10:26:46 [460] __quick_check_peer-CA does not match.
2023-03-27 10:26:46 [497] __check_add_peer-'username2pki' check ret:bad
2023-03-27 10:26:46 [490] __check_add_peer-check 'username2'
2023-03-27 10:26:46 [492] __check_add_peer-'username2' is not a peer user.
2023-03-27 10:26:46 [675] fnbamd_cert_check_group_list-checking group with name 'test_SSLVPN_user'
2023-03-27 10:26:46 [490] __check_add_peer-check 'user1'
2023-03-27 10:26:46 [366] peer_subject_cn_check-Cert subject 'CN = username'
2023-03-27 10:26:46 [77] fnbamd_peer_ldap_push-Check LDAP setting of peer user 'user1'
2023-03-27 10:26:46 [497] __check_add_peer-'user1' check ret:pending
2023-03-27 10:26:46 [490] __check_add_peer-check 'user2'
2023-03-27 10:26:46 [460] __quick_check_peer-CA does not match.
2023-03-27 10:26:46 [497] __check_add_peer-'user2' check ret:bad
2023-03-27 10:26:46 [490] __check_add_peer-check 'user3'
2023-03-27 10:26:46 [366] peer_subject_cn_check-Cert subject 'CN = username'
2023-03-27 10:26:46 [77] fnbamd_peer_ldap_push-Check LDAP setting of peer user 'user3'
2023-03-27 10:26:46 [497] __check_add_peer-'user3' check ret:pending
2023-03-27 10:26:46 [675] fnbamd_cert_check_group_list-checking group with name 'SSLVPN_user'
2023-03-27 10:26:46 [490] __check_add_peer-check 'ActiveDirectory'
2023-03-27 10:26:46 [492] __check_add_peer-'ActiveDirectory' is not a peer user.
2023-03-27 10:26:46 [490] __check_add_peer-check 'ZS_AD'
2023-03-27 10:26:46 [492] __check_add_peer-'ZS_AD' is not a peer user.
2023-03-27 10:26:46 [490] __check_add_peer-check 'user1'
2023-03-27 10:26:46 [425] __quick_check_peer-Peer user 'user1' is already in the list
2023-03-27 10:26:46 [237] fnbamd_peer_remote_server_push-Adding 5 matching rules to 'ActiveDirectory'
2023-03-27 10:26:46 [497] __check_add_peer-'user1' check ret:pending
2023-03-27 10:26:46 [490] __check_add_peer-check 'user2'
2023-03-27 10:26:46 [460] __quick_check_peer-CA does not match.
2023-03-27 10:26:46 [497] __check_add_peer-'user2' check ret:bad
2023-03-27 10:26:46 [490] __check_add_peer-check 'ActiveDirectory2'
2023-03-27 10:26:46 [492] __check_add_peer-'ActiveDirectory2' is not a peer user.
2023-03-27 10:26:46 [490] __check_add_peer-check 'user3'
2023-03-27 10:26:46 [425] __quick_check_peer-Peer user 'user3' is already in the list
2023-03-27 10:26:46 [237] fnbamd_peer_remote_server_push-Adding 5 matching rules to 'ActiveDirectory2'
2023-03-27 10:26:46 [497] __check_add_peer-'user3' check ret:pending
2023-03-27 10:26:46 [709] fnbamd_cert_check_group_list-LDAP servers
2023-03-27 10:26:46 [712] fnbamd_cert_check_group_list-    'ActiveDirectory', (User-Password), ref=2
2023-03-27 10:26:46 [712] fnbamd_cert_check_group_list-    'ActiveDirectory2', (User-Password), ref=2
2023-03-27 10:26:46 [191] __get_default_ocsp_ctx-def_ocsp_ctx=(nil), no_ocsp_query=0, ocsp_enabled=0
2023-03-27 10:26:46 [738] fnbamd_cert_check_group_list-Peer users
2023-03-27 10:26:46 [741] fnbamd_cert_check_group_list-    'user1' ('ActiveDirectory','N/A')
2023-03-27 10:26:46 [741] fnbamd_cert_check_group_list-    'user3' ('ActiveDirectory2','N/A')
2023-03-27 10:26:46 [873] __cert_verify_do_next-req_id=1244516033
2023-03-27 10:26:46 [99] __cert_chg_st- 'Validation' -> 'Status-Query'
2023-03-27 10:26:46 [621] __cert_status_query-req_id=1244516033
2023-03-27 10:26:46 [419] __cert_ldap_query-req_id=1244516033
2023-03-27 10:26:46 [426] __cert_ldap_query-LDAP query, idx 0
2023-03-27 10:26:46 [1717] fnbamd_ldap_init-search filter is: sAMAccountName=
2023-03-27 10:26:46 [1727] fnbamd_ldap_init-search base is: DC=HK,DC=companyName,DC=com
2023-03-27 10:26:46 [1149] __fnbamd_ldap_dns_cb-Resolved ActiveDirectory:pubIpAD to pubIpAD, cur stack size:1
2023-03-27 10:26:46 [924] __fnbamd_ldap_get_next_addr-
2023-03-27 10:26:46 [1154] __fnbamd_ldap_dns_cb-Connection starts ActiveDirectory:pubIpAD, addr pubIpAD over SSL
2023-03-27 10:26:46 [879] __fnbamd_ldap_start_conn-Still connecting pubIpAD.
2023-03-27 10:26:46 [426] __cert_ldap_query-LDAP query, idx 1
2023-03-27 10:26:46 [1717] fnbamd_ldap_init-search filter is: sAMAccountName=
2023-03-27 10:26:46 [1727] fnbamd_ldap_init-search base is: DC=TW,DC=companyName,DC=com
2023-03-27 10:26:46 [1149] __fnbamd_ldap_dns_cb-Resolved ActiveDirectory2:IpAD to IpAD, cur stack size:1
2023-03-27 10:26:46 [924] __fnbamd_ldap_get_next_addr-
2023-03-27 10:26:46 [1154] __fnbamd_ldap_dns_cb-Connection starts ActiveDirectory2:IpAD, addr IpAD over SSL
2023-03-27 10:26:46 [879] __fnbamd_ldap_start_conn-Still connecting IpAD.
2023-03-27 10:26:46 [541] __cert_ocsp_query-req_id=1244516033
2023-03-27 10:26:46 [549] __cert_ocsp_query-Nothing to do.
2023-03-27 10:26:46 [950] __fnbamd_cert_auth_run-Job pending, exit the state machine, req_id=1244516033
2023-03-27 10:26:46 [1688] create_auth_cert_session-fnbamd_cert_auth_init returns 4, id=1244516033
2023-03-27 10:26:46 [1107] __ldap_connect-tcps_connect(pubIpAD) is established.
2023-03-27 10:26:46 [985] __ldap_rxtx-state 3(Admin Binding)
2023-03-27 10:26:46 [363] __ldap_build_bind_req-Binding to 'userAD'
2023-03-27 10:26:46 [1083] fnbamd_ldap_send-sending 37 bytes to pubIpAD
2023-03-27 10:26:46 [1096] fnbamd_ldap_send-Request is sent. ID 1
2023-03-27 10:26:47 [985] __ldap_rxtx-state 4(Admin Bind resp)
2023-03-27 10:26:47 [1127] __fnbamd_ldap_read-Read 8
2023-03-27 10:26:47 [1233] fnbamd_ldap_recv-Leftover 2
2023-03-27 10:26:47 [1127] __fnbamd_ldap_read-Read 14
2023-03-27 10:26:47 [1306] fnbamd_ldap_recv-Response len: 16, svr: pubIpAD
2023-03-27 10:26:47 [987] fnbamd_ldap_parse_response-Got one MESSAGE. ID:1, type:bind
2023-03-27 10:26:47 [1023] fnbamd_ldap_parse_response-ret=0
2023-03-27 10:26:47 [1052] __ldap_rxtx-Change state to 'DN search'
2023-03-27 10:26:47 [985] __ldap_rxtx-state 11(DN search)
2023-03-27 10:26:47 [750] fnbamd_ldap_build_dn_search_req-base:'DC=HK,DC=companyName,DC=com' filter:sAMAccountName=
2023-03-27 10:26:47 [1083] fnbamd_ldap_send-sending 78 bytes to pubIpAD
2023-03-27 10:26:47 [1096] fnbamd_ldap_send-Request is sent. ID 2
2023-03-27 10:26:47 [985] __ldap_rxtx-state 12(DN search resp)
2023-03-27 10:26:47 [1127] __fnbamd_ldap_read-Read 8
2023-03-27 10:26:47 [1233] fnbamd_ldap_recv-Leftover 2
2023-03-27 10:26:47 [1127] __fnbamd_ldap_read-Read 96
2023-03-27 10:26:47 [1306] fnbamd_ldap_recv-Response len: 98, svr: pubIpAD
2023-03-27 10:26:47 [987] fnbamd_ldap_parse_response-Got one MESSAGE. ID:2, type:search-reference
2023-03-27 10:26:47 [1023] fnbamd_ldap_parse_response-ret=0
2023-03-27 10:26:47 [1127] __fnbamd_ldap_read-Read 8
2023-03-27 10:26:47 [1233] fnbamd_ldap_recv-Leftover 2
2023-03-27 10:26:47 [1127] __fnbamd_ldap_read-Read 14
2023-03-27 10:26:47 [1306] fnbamd_ldap_recv-Response len: 16, svr: pubIpAD
2023-03-27 10:26:47 [987] fnbamd_ldap_parse_response-Got one MESSAGE. ID:2, type:search-result
2023-03-27 10:26:47 [1023] fnbamd_ldap_parse_response-ret=0
2023-03-27 10:26:47 [1243] __fnbamd_ldap_dn_next-No DN is found.
2023-03-27 10:26:47 [1052] __ldap_rxtx-Change state to 'Done'
2023-03-27 10:26:47 [985] __ldap_rxtx-state 23(Done)
2023-03-27 10:26:47 [1083] fnbamd_ldap_send-sending 7 bytes to pubIpAD
2023-03-27 10:26:47 [1096] fnbamd_ldap_send-Request is sent. ID 3
2023-03-27 10:26:47 [785] __ldap_done-svr 'ActiveDirectory'
2023-03-27 10:26:47 [755] __ldap_destroy-

[fortiFWuser]

2023-03-27 10:26:47 [724] __ldap_stop-Conn with pubIpAD destroyed.
2023-03-27 10:26:47 [377] __cert_ldap_query_cb-LDAP ret=1, server='ActiveDirectory', req_id=1244516033
2023-03-27 10:26:47 [399] __cert_ldap_query_cb-Continue pending, req_id=1244516033
2023-03-27 10:26:51 [966] __ldap_timeout-ActiveDirectory2:IpAD, addr IpAD
2023-03-27 10:26:51 [934] __ldap_error-ActiveDirectory2:IpAD, addr IpAD
2023-03-27 10:26:51 [724] __ldap_stop-Conn with IpAD destroyed.
2023-03-27 10:26:51 [924] __fnbamd_ldap_get_next_addr-
2023-03-27 10:26:51 [911] __ldap_try_next_server-Try next server 'IpAD2' for 'ActiveDirectory2'.
2023-03-27 10:26:51 [1149] __fnbamd_ldap_dns_cb-Resolved ActiveDirectory2:IpAD2 to IpAD2, cur stack size:1
2023-03-27 10:26:51 [924] __fnbamd_ldap_get_next_addr-
2023-03-27 10:26:51 [1154] __fnbamd_ldap_dns_cb-Connection starts ActiveDirectory2:IpAD2, addr IpAD2 over SSL
2023-03-27 10:26:51 [879] __fnbamd_ldap_start_conn-Still connecting IpAD2.
2023-03-27 10:26:56 [966] __ldap_timeout-ActiveDirectory2:IpAD2, addr IpAD2
2023-03-27 10:26:56 [934] __ldap_error-ActiveDirectory2:IpAD2, addr IpAD2
2023-03-27 10:26:56 [724] __ldap_stop-Conn with IpAD2 destroyed.
2023-03-27 10:26:56 [924] __fnbamd_ldap_get_next_addr-
2023-03-27 10:26:56 [906] __ldap_try_next_server-No more server to try for 'ActiveDirectory2'.
2023-03-27 10:26:56 [785] __ldap_done-svr 'ActiveDirectory2'
2023-03-27 10:26:56 [755] __ldap_destroy-
2023-03-27 10:26:56 [377] __cert_ldap_query_cb-LDAP ret=3, server='ActiveDirectory2', req_id=1244516033
2023-03-27 10:26:56 [271] __cert_resume-req_id=1244516033
2023-03-27 10:26:56 [99] __cert_chg_st- 'Status-Query' -> 'Done'
2023-03-27 10:26:56 [918] __cert_done-req_id=1244516033
2023-03-27 10:26:56 [1651] fnbamd_auth_session_done-Session done, id=1244516033
2023-03-27 10:26:56 [963] __fnbamd_cert_auth_run-Exit, req_id=1244516033
2023-03-27 10:26:56 [1642] __auth_cert_session_done-id=1244516033
2023-03-27 10:26:56 [1607] auth_cert_success-id=1244516033
2023-03-27 10:26:56 [1065] fnbamd_cert_auth_copy_cert_status-req_id=1244516033
2023-03-27 10:26:56 [833] fnbamd_cert_check_matched_groups-checking group with name 'test_local_user'
2023-03-27 10:26:56 [903] fnbamd_cert_check_matched_groups-not matched
2023-03-27 10:26:56 [833] fnbamd_cert_check_matched_groups-checking group with name 'test_SSLVPN_user'
2023-03-27 10:26:56 [903] fnbamd_cert_check_matched_groups-not matched
2023-03-27 10:26:56 [833] fnbamd_cert_check_matched_groups-checking group with name 'SSLVPN_user'
2023-03-27 10:26:56 [903] fnbamd_cert_check_matched_groups-not matched
2023-03-27 10:26:56 [1104] fnbamd_cert_auth_copy_cert_status-Leaf cert status is unchecked.
2023-03-27 10:26:56 [1192] fnbamd_cert_auth_copy_cert_status-Cert st 2c0, req_id=1244516033
2023-03-27 10:26:56 [209] fnbamd_comm_send_result-Sending result 0 (nid 64) for req 1244516033, len=2144
2023-03-27 10:26:56 [1552] destroy_auth_cert_session-id=1244516033
2023-03-27 10:26:56 [1038] fnbamd_cert_auth_uninit-req_id=1244516033
2023-03-27 10:26:56 [755] __ldap_destroy-
2023-03-27 10:26:56 [259:root:cb7]2023-03-27 10:26:56 [755] __ldap_destroy-
fam_cert_proc_resp:1905 No matched group for this certificate.
2023-03-27 10:26:56 [131] fnbamd_peer_ctx_free-Freeing peer ctx 'user1'
2023-03-27 10:26:56 [259:root:cb7]2023-03-27 10:26:56 [1764] fnbamd_ldap_auth_ctx_free-Freeing 'ActiveDirectory' ctx
auth_cert_cb:auth_cert_cb:409 certificate check error (CN = username).
2023-03-27 10:26:56 [131] fnbamd_peer_ctx_free-Freeing peer ctx 'user3'
2023-03-27 10:26:56 [1764] fnbamd_ldap_auth_ctx_free-Freeing 'ActiveDirectory2' ctx
2023-03-27 10:26:56 [259:root:cb7]get_cust_page:123 saml_info 0
2023-03-27 10:26:56 [259:root:cb7]SSL state:warning close notify (public IP)
2023-03-27 10:26:56 [259:root:cb7]sslConnGotoNextState:311 error (last state: 1, closeOp: 0)
2023-03-27 10:26:56 [259:root:cb7]Destroy sconn 0x7f8f2b1f00, connSize=0. (root)
2023-03-27 10:26:56 [259:root:cb7]SSL state:warning close notify (public IP)

[mgoswami]

Hi,

I could see this in the log:

auth_cert_cb:auth_cert_cb:409 certificate check error (CN = username).

May I know the username you are trying to connect with and the CN field in the certificate which you are using?

BR,

Manosh