Our users keep having problems logging in with Forticlient VPN only. It happens very often that Forticlient stops at 48% and issues the warning -7200. Sometimes you have to repeat the login process 3-7 times and then the client asks for the Fortitoken and can then log in successfully.
FortiOS v6.4.15
We are using LDAP authentication with Fortitoken.
It doesn't matter whether I set username-sensitivity to disable or leave it at default enable.
Does anyone know the problem and can help?
[326:root:d3a]allocSSLConn:298 sconn 0x7f268edacd00 (0:root) [326:root:d3a]SSL state:before SSL initialization (77.239.xy.xyx) [326:root:d3a]SSL state:before SSL initialization:DH lib(77.239.xy.xyx) [326:root:d3a]SSL_accept failed, 5:(null) [326:root:d3a]Destroy sconn 0x7f268edacd00, connSize=1. (root) [327:root:d3c]allocSSLConn:298 sconn 0x7f268edac800 (0:root) [327:root:d3c]SSL state:before SSL initialization (77.239.xy.xyx) [327:root:d3c]SSL state:before SSL initialization (77.239.xy.xyx) [327:root:d3c]got SNI server name: sslvpn.url.com realm (null) [327:root:d3c]client cert requirement: no [327:root:d3c]SSL state:SSLv3/TLS read client hello (77.239.xy.xyx) [327:root:d3c]SSL state:SSLv3/TLS write server hello (77.239.xy.xyx) [327:root:d3c]SSL state:SSLv3/TLS write certificate (77.239.xy.xyx) [327:root:d3c]SSL state:SSLv3/TLS write key exchange (77.239.xy.xyx) [327:root:d3c]SSL state:SSLv3/TLS write server done (77.239.xy.xyx) [327:root:d3c]SSL state:SSLv3/TLS write server done:system lib(77.239.xy.xyx) [327:root:d3c]SSL state:SSLv3/TLS write server done (77.239.xy.xyx) [327:root:d3c]SSL state:SSLv3/TLS read client key exchange (77.239.xy.xyx) [327:root:d3c]SSL state:SSLv3/TLS read change cipher spec (77.239.xy.xyx) [327:root:d3c]SSL state:SSLv3/TLS read finished (77.239.xy.xyx) [327:root:d3c]SSL state:SSLv3/TLS write session ticket (77.239.xy.xyx) [327:root:d3c]SSL state:SSLv3/TLS write change cipher spec (77.239.xy.xyx) [327:root:d3c]SSL state:SSLv3/TLS write finished (77.239.xy.xyx) [327:root:d3c]SSL state:SSL negotiation finished successfully (77.239.xy.xyx) [327:root:d3c]SSL established: TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384 [327:root:d3c]req: /remote/info [327:root:d3c]capability flags: 0xdf [327:root:d3c]req: /remote/login?realm=mts [327:root:d3c]rmt_web_auth_info_parser_common:465 no session id in auth info [327:root:d3c]rmt_web_get_access_cache:808 invalid cache, ret=4103 [327:root:d3c]User Agent: FortiSSLVPN (Windows NT; SV1 [SV{v=02.01; f=07;}]) [327:root:d3c]get_cust_page:127 saml_info 0 [327:root:d3c]req: /remote/logincheck [327:root:d3c]rmt_web_auth_info_parser_common:465 no session id in auth info [327:root:d3c]rmt_web_access_check:727 access failed, uri=[/remote/logincheck],ret=4103, [327:root:d3c]User Agent: FortiSSLVPN (Windows NT; SV1 [SV{v=02.01; f=07;}]) [327:root:d3c]rmt_logincheck_cb_handler:1255 user 'max' has a matched local entry. [327:root:d3c]sslvpn_auth_check_usrgroup:2719 forming user/group list from policy. [327:root:d3c]sslvpn_auth_check_usrgroup:2757 got user (0) group (3:0). [327:root:d3c]sslvpn_validate_user_group_list:1843 validating with SSL VPN authentication rules (3), realm (mts). [327:root:d3c]sslvpn_validate_user_group_list:1928 checking rule 2 cipher. [327:root:d3c]sslvpn_validate_user_group_list:1936 checking rule 2 realm. [327:root:d3c]sslvpn_validate_user_group_list:1947 checking rule 2 source intf. [327:root:d3c]sslvpn_validate_user_group_list:1986 checking rule 2 vd source intf. [327:root:d3c]sslvpn_validate_user_group_list:2267 rule 2 done, got user (0:0) group (1:0) peer group (0). [327:root:d3c]sslvpn_validate_user_group_list:1928 checking rule 3 cipher. [327:root:d3c]sslvpn_validate_user_group_list:1936 checking rule 3 realm. [327:root:d3c]sslvpn_validate_user_group_list:1928 checking rule 4 cipher. [327:root:d3c]sslvpn_validate_user_group_list:1936 checking rule 4 realm. [327:root:d3c]sslvpn_validate_user_group_list:2275 got user (0:0) group (1:0) peer group (0). [327:root:d3c]sslvpn_validate_user_group_list:2618 got user (0:0), group (1:0) peer group (0). [327:root:d3c]sslvpn_update_user_group_list:1750 got user (0:0), group (1:0), peer group (0) after update. [327:root:d3c]two factor check for max: off [327:root:d3c]sslvpn_authenticate_user:167 authenticate user: [max] [327:root:d3c]sslvpn_authenticate_user:174 create fam state [327:root:d3c][fam_auth_send_req_internal:425] Groups sent to FNBAM: [327:root:d3c]group_desc[0].grpname = ldap_dl-fg-sslvpn-realm-mts [327:root:d3c][fam_auth_send_req_internal:437] FNBAM opt = 0X200420 [327:root:d3c]fam_auth_send_req_internal:513 fnbam_auth return: 4 [327:root:d3c]fam_auth_proc_resp:1287 fnbam_auth_update_result return: 3 [327:root:d3c][fam_auth_proc_resp:1385] Authenticated groups (1) by FNBAM: [327:root:d3c]Received: auth_rsp_data.grp_list[0] = 3054238368 [327:root:d3c]login_failed:391 user[max],auth_type=1 failed [sslvpn_login_no_matching_policy]
Those two requests have failed for an "Unknown" reason (Res 3):
Res 3: 1586 <---- before debug
2024-06-28 11:45:07 Res 3: 1588 <---- after debug
It looks like there is a problem with the DNS resolution of the server mts.local, FortiGate is unable to find its correct IP address:
2024-06-28 11:44:51 [596] create_auth_session-Total 1 server(s) to try 2024-06-28 11:44:51 [246] fnbamd_dns_parse_resp-got IPv6 DNS reply, req-id=0x3dc0 2024-06-28 11:44:51 [267] fnbamd_dns_parse_resp-req 0x1dc0: wrong dns format, qr=1, opcode=0, qdc=1, ancount=0 2024-06-28 11:44:51 [1146] __fnbamd_ldap_dns_cb-Resolved mts.local:mts-dc02.mts.local to ::, cur stack size:-1 2024-06-28 11:44:51 [1160] __fnbamd_ldap_dns_cb-No valid address is found for mts.local:mts-dc02.mts.local 2024-06-28 11:44:51 [246] fnbamd_dns_parse_resp-got IPv4 DNS reply, req-id=0x1dc0 2024-06-28 11:44:51 [267] fnbamd_dns_parse_resp-req 0x1dc0: wrong dns format, qr=1, opcode=0, qdc=1, ancount=0 2024-06-28 11:44:51 [36] __fnbamd_dns_req_del-DNS req 0x1dc0 (0x14353740) is removed. Current total: 2 2024-06-28 11:44:51 [47] __fnbamd_dns_req_del-DNS maintainer stopped. 2024-06-28 11:44:51 [1146] __fnbamd_ldap_dns_cb-Resolved mts.local:mts-dc02.mts.local to 0.0.0.0, cur stack size:-1 2024-06-28 11:44:51 [1160] __fnbamd_ldap_dns_cb-No valid address is found for mts.local:mts-dc02.mts.local 2024-06-28 11:44:51 [907] __ldap_try_next_server-Try next server 'mts-dc03.mts.local' for 'mts.local'. 2024-06-28 11:44:51 [115] fnbamd_dns_resolv_ex-DNS req ipv4 0x1dc1 'mts-dc03.mts.local' 2024-06-28 11:44:51 [125] fnbamd_dns_resolv_ex-DNS req ipv6 0x3dc1 'mts-dc03.mts.local' 2024-06-28 11:44:51 [137] fnbamd_dns_resolv_ex-DNS maintainer started. 2024-06-28 11:44:51 [246] fnbamd_dns_parse_resp-got IPv4 DNS reply, req-id=0x1dc1 2024-06-28 11:44:51 [267] fnbamd_dns_parse_resp-req 0x1dc1: wrong dns format, qr=1, opcode=0, qdc=1, ancount=0 2024-06-28 11:44:51 [1146] __fnbamd_ldap_dns_cb-Resolved mts.local:mts-dc03.mts.local to 0.0.0.0, cur stack size:-1 2024-06-28 11:44:51 [1160] __fnbamd_ldap_dns_cb-No valid address is found for mts.local:mts-dc03.mts.local 2024-06-28 11:44:51 [246] fnbamd_dns_parse_resp-got IPv6 DNS reply, req-id=0x3dc1 2024-06-28 11:44:51 [267] fnbamd_dns_parse_resp-req 0x1dc1: wrong dns format, qr=1, opcode=0, qdc=1, ancount=0 2024-06-28 11:44:51 [36] __fnbamd_dns_req_del-DNS req 0x1dc1 (0x14353740) is removed. Current total: 2 2024-06-28 11:44:51 [47] __fnbamd_dns_req_del-DNS maintainer stopped. 2024-06-28 11:44:51 [1146] __fnbamd_ldap_dns_cb-Resolved mts.local:mts-dc03.mts.local to ::, cur stack size:-1 2024-06-28 11:44:51 [1160] __fnbamd_ldap_dns_cb-No valid address is found for mts.local:mts-dc03.mts.local 2024-06-28 11:44:51 [902] __ldap_try_next_server-No more server to try for 'mts.local'.
Please try to investigate why the DNS name resolution is failing. You could run a packet sniffer on the FortiGate at the same time of the ssl/fnbamd debug. As a temporary workaround you could try configuring the IP rather than the name of the LDAP server.
Best regards,
--- If you have found a useful article or a solution, please like and accept it to make it easily accessible to others.
I changed it to IP for the moment and will check if it still occurs.
Our internal DNS is set as secondary and primary is our ISP. I read somewhere that the internal DNS has to be configured as secondary for internal queries to work.
Hi @sidp , You are welcome. Please let us know if the issue occurs again.
Can you provide the following outputs, please: show system dns show system dns-database diag test application dnsproxy 2 #<---run this x2 times diag test application dnsproxy 3 #<---run this x2 times
Best regards,
--- If you have found a useful article or a solution, please like and accept it to make it easily accessible to others.
