| Description |
This article describes how a FortiGate acts within a different radius authentication methods. |
| Scope | FortiGate. |
| Solution |
By default, the FortiGate firewall uses a ‘default’ method of authentication. It means the FortiGate tries to negotiate with a Radius server using PAP, Mschapv2, and CHAP methods at once unless it gets accepted response. For example, if a user types an incorrect password, the FortiGate sends three radius-access requests, which in theory could lead to the user being locked on the server side.
These debugs should be enabled on the FortiGate for troubleshooting:
diag debug reset diag debug app sslvpn -1
Example 1: Radius settings on a FortiGate are as follows:
Debug outputs when a testing user types incorrect password:
2024-10-27 13:44:32 [342] fnbamd_create_radius_socket-Opened radius socket 11 2024-10-27 13:44:32 2024-10-27 13:44:32 [2042:root:12bd]fam_auth_send_req:1017 task finished with 4 2024-10-27 13:44:32 [1433] fnbamd_rad_dns_cb-172.20.20.20->172.20.20.20 2024-10-27 13:44:32 [1405] __fnbamd_rad_send-Sent radius req to server 'FAC': fd=11, IP=172.20.20.20(172.20.20.20:1812) code=1 id=20 len=142 user="aduser01" using PAP <<< the first attempt 2024-10-27 13:44:32 [319] radius_server_auth-Timer of rad 'FAC' is added 2024-10-27 13:44:32 [764] auth_tac_plus_start-Didn't find tac_plus servers (0) 2024-10-27 13:44:32 [1009] __fnbamd_cfg_get_ldap_list_by_group- 2024-10-27 13:44:32 [1117] fnbamd_cfg_get_ldap_list-Total ldap servers to try: 0 2024-10-27 13:44:32 [497] ldap_start-Didn't find ldap servers 2024-10-27 13:44:32 [480] fnbamd_cfg_get_ext_idp_list- 2024-10-27 13:44:32 [454] __fnbamd_cfg_get_ext_idp_list_by_group- 2024-10-27 13:44:32 [460] __fnbamd_cfg_get_ext_idp_list_by_group-Group 'radius' 2024-10-27 13:44:32 [490] fnbamd_cfg_get_ext_idp_list-Total external identity provider servers to try: 0 2024-10-27 13:44:32 [652] create_auth_session-Total 1 server(s) to try 2024-10-27 13:44:32 [1950] handle_req-r=4 2024-10-27 13:44:33 [1522] fnbamd_auth_handle_radius_result-Timer of rad 'FAC' is deleted 2024-10-27 13:44:33 [1890] fnbamd_radius_auth_validate_pkt-RADIUS resp code 3 2024-10-27 13:44:33 [1548] fnbamd_auth_handle_radius_result-->Result for radius svr 'FAC' 172.20.20.20(1) is 1 >>> code 1 = deny 2024-10-27 13:44:33 [1476] fnbamd_radius_auth_send-Compose RADIUS request 2024-10-27 13:44:33 [1405] __fnbamd_rad_send-Sent radius req to server 'FAC': fd=11, IP=172.20.20.20(172.20.20.20:1812) code=1 id=21 len=206 user="aduser01" using MS-CHAPv2 >>> Attempt #2 2024-10-27 13:44:33 [319] radius_server_auth-Timer of rad 'FAC' is added 2024-10-27 13:44:33 [2765] handle_auth_rsp-Continue pending for req 1055061428 2024-10-27 13:44:34 [1522] fnbamd_auth_handle_radius_result-Timer of rad 'FAC' is deleted 2024-10-27 13:44:34 [1890] fnbamd_radius_auth_validate_pkt-RADIUS resp code 3 2024-10-27 13:44:34 [1548] fnbamd_auth_handle_radius_result-->Result for radius svr 'FAC' 172.20.20.20(1) is 1 >>> code 1 = deny 2024-10-27 13:44:34 [1476] fnbamd_radius_auth_send-Compose RADIUS request 2024-10-27 13:44:34 [1405] __fnbamd_rad_send-Sent radius req to server 'FAC': fd=11, IP=172.20.20.20(172.20.20.20:1812) code=1 id=22 len=143 user="aduser01" using CHAP >>> Attempt #3 2024-10-27 13:44:34 [319] radius_server_auth-Timer of rad 'FAC' is added 2024-10-27 13:44:34 [2765] handle_auth_rsp-Continue pending for req 1055061428 2024-10-27 13:44:35 [1522] fnbamd_auth_handle_radius_result-Timer of rad 'FAC' is deleted 2024-10-27 13:44:35 [1890] fnbamd_radius_auth_validate_pkt-RADIUS resp code 3 2024-10-27 13:44:35 [1548] fnbamd_auth_handle_radius_result-->Result for radius svr 'FAC' 172.20.20.20(1) is 1 >>> code 1 = deny
To avoid such errors, it is recommended to specify radius authentication method:
As an example below is the debug snippet for the MSCHAPv2 method, when the end user types an incorrect password:
2024-10-27 13:50:30 [1909] handle_req-Rcvd auth req 1055061432 for aduser01 in opt=00200421 prot=11 2024-10-27 13:50:30 [489] __compose_group_list_from_req-Group 'radius', type 1 2024-10-27 13:50:30 [616] fnbamd_pop3_start-aduser01 2024-10-27 13:50:30 2024-10-27 13:50:30 [2042:root:12c7]fam_auth_send_req_internal:517 fnbam_auth return: 4 [573] __fnbamd_cfg_get_radius_list_by_group-Loading RADIUS server 'FAC' for usergroup 'radius' (6) 2024-10-27 13:50:30 2024-10-27 13:50:30 [342] fnbamd_create_radius_socket-Opened radius socket 11 2024-10-27 13:50:30 [2042:root:12c7]fam_auth_send_req:1017 task finished with 4 [342] fnbamd_create_radius_socket-Opened radius socket 12 2024-10-27 13:50:30 [1476] fnbamd_radius_auth_send-Compose RADIUS request 2024-10-27 13:50:30 [1433] fnbamd_rad_dns_cb-172.20.20.20->172.20.20.20 2024-10-27 13:50:30 [1405] __fnbamd_rad_send-Sent radius req to server 'FAC': fd=11, IP=172.20.20.20(172.20.20.20:1812) code=1 id=26 len=206 user="aduser01" using MS-CHAPv2 2024-10-27 13:50:30 [319] radius_server_auth-Timer of rad 'FAC' is added 2024-10-27 13:50:30 [764] auth_tac_plus_start-Didn't find tac_plus servers (0) 2024-10-27 13:50:30 [1009] __fnbamd_cfg_get_ldap_list_by_group- 2024-10-27 13:50:30 [1117] fnbamd_cfg_get_ldap_list-Total ldap servers to try: 0 2024-10-27 13:50:30 [497] ldap_start-Didn't find ldap servers 2024-10-27 13:50:30 [480] fnbamd_cfg_get_ext_idp_list- 2024-10-27 13:50:30 [454] __fnbamd_cfg_get_ext_idp_list_by_group- 2024-10-27 13:50:30 [460] __fnbamd_cfg_get_ext_idp_list_by_group-Group 'radius' 2024-10-27 13:50:30 [490] fnbamd_cfg_get_ext_idp_list-Total external identity provider servers to try: 0 2024-10-27 13:50:30 [652] create_auth_session-Total 1 server(s) to try 2024-10-27 13:50:30 [1950] handle_req-r=4 2024-10-27 13:50:31 [1522] fnbamd_auth_handle_radius_result-Timer of rad 'FAC' is deleted 2024-10-27 13:50:31 [1890] fnbamd_radius_auth_validate_pkt-RADIUS resp code 3 2024-10-27 13:50:31 [1548] fnbamd_auth_handle_radius_result-->Result for radius svr 'FAC' 172.20.20.20(1) is 1 >>> code 1 = deny 2024-10-27 13:50:31 [209] fnbamd_comm_send_result-Sending result 1 (nid 0) for req 1055061432, len=2536 2024-10-27 13:50:31 [2042:root:12c7]fam_auth_proc_resp:1369 fnbam_auth_update_result return: 1 (invalue username/password) 2024-10-27 13:50:31 2024-10-27 13:50:31 [808] destroy_auth_session-delete session 1055061432 |
