|
This sample log is from FortiGate with IP-based transparent proxy configuration and using Kerberos authentication.
To collect authentication logs for Kerberos with proxy, the below commands can be used:
diag wad debug enable category auth
diag wad debug enable level verbose
diag debug enable
Once the user tries to access any browser, the below logs will be generated:
fortigate2K # [I][p:518][s:12154199][r:184591017] wad_auth_rule_match :1329 match auth rule succ: kerberos_rule <---This means that the user request was evaluated against an authentication rule, and it successfully matched the rule named kerberos_rule.
[I][p:518][s:12154199][r:184591017] wad_http_req_get_user :12254 process=518 auth-rule=kerberos_rule user=/0/0 ip-based/auth-cookie/transact=1/0/0 tp_proxy _auth=1 auth_req=(nil) auth_line=(nil) <---- Indicates that this is IP based and Transparent proxy as configured in the auth rule and the proxy policy.
[I][p:518][s:12154199][r:184591017] wad_http_auth_status_proc :11503 authenticate result=cp-redir <--- The FortiGate initially responds with a result of cp-redir, which means the user is being redirected to a captive portal page for authentication.
[I][p:518] wad_hauth_method_chg_get :1505 method:http-mix->http-mix hdr= <--- The method for HTTP authentication is initially http-mix (a mix of different authentication methods).
[I][p:518] wad_http_auth_status_proc :11503 authenticate result=challenge
[V][p:518] wad_hauth_trace :180 trace_no_auth_resp is disabled
[I][p:518] wad_hauth_method_chg_get :1505 method:http-mix->http-mix hdr=
[I][p:518] wad_http_auth_status_proc :11503 authenticate result=challenge
[V][p:518] wad_hauth_trace :180 trace_no_auth_resp is disabled
[I][p:518] wad_hauth_method_chg_get :1505 method:http-mix->Negotiate hdr=Neg <--- The FortiGate switches to using the Negotiate authentication method (a method that supports Kerberos).
[I][p:518] wad_negotiate_try_auth_token :409 Get Kerberos user kerberosuser1@DOMAIN.COM in token valid time:173095 s ret_flags:290 <-- The system retrieves the Kerberos token for kerberosuser1@DOMAIN.COM from the request and checks the token's validity. The log shows that the user has a valid Kerberos ticket with a validity time of 173095 seconds which is 48 hours. This time can be tweaked from the Windows AD group policy for Kerberos.
[V][p:518] wad_usr_info_clt_conn_connected :2232 user info connection:connected <--- A connection to the user’s information is successfully established. This will not initiate a backend check of the user group membership from the LDAP server configured on the FortiGate.
[I][p:518] wad_negotiate_del_ctx :927 release krb nego output buffer:0
[I][p:518] wad_negotiate_del_ctx :934 release krb nego context:0
[I][p:518] wad_http_auth_status_proc :11503 authenticate result=pending <---- The authentication result is pending, as additional steps (like checking group membership or validating the user's information) are required.
[I][p:518] wad_auth_make_group_info :77 group_info returned by fnbamd from ldap LDAP_Server for req_id = 1815061991.
[I][p:518] wad_auth_ms_make_on_fnbam_resp :1058 server=LDAP_Server
[I][p:518] wad_auth_ms_make_on_fnbam_resp :1063 server=LDAP_Server grp=CN=Domain Users,CN=Users,DC=manosh,DC=com
[I][p:518] wad_http_auth_update_user_ext2 :2950 updating user. ip: 10.89.x.x, type:IP ms:2 is_machine: 0
[I][p:518] wad_auth_inc_user_count :1674 increased user count, quota:64000, n_shared_user:2, vd_used: 2, vd_max: 0, vd_gurantee: 0
[V][p:518] wad_hauth_user_put :1781 putting user 0x7fc8c758fb08(1)
[V][p:518] wad_hauth_user_put :1784 user 0x7fc8c758fb08 freed
[I][p:518] wad_auth_dec_user_count :1695 decreased user count, quota:64000, n_shared_user:0, vd_used: 0, vd_max: 0, vd_gurantee: 0
mapping user_node:0x7fc8cd49b948, user_ip:0x7fc8cd375180(0), user:0x7fc8c758f3a8(0)
[V][p:518] __wad_hauth_user_node_hold :2240 wad_http_auth_update_user_ext2 (3188): holding node 0x7fc8cd49b948
[I][p:518] wad_auth_make_group_info :100 Authenticated: User: kerberosuser1 server=LDAP_Server <---- Authenticated user again LDAP server indicating the user is present in AD and needs to check the group info further.
[V][p:518] wad_inform_msg_hdr_get :715 msg=ReqAdd code=OK seq=8
[V][p:497] wad_informer_server_proc_msg_header:2321 msg=ReqAdd code=OK seq=8 data_len=224
[W][p:497] wad_informer_proc_user_adding :1477 reader: ip=10.89.7.253:55629 vf=0 seq=0 grp_type=0 scheme=3 is_ntlm=0 has_fsae=0 active_auth=0 tp_pr
oxy_auth=1 concur_user=65536 domain='DOMAIN.COM' mship:2
[I][p:497] wad_informer_update_user_ext :818 ip=10.89.7.253:55629 name=kerberosuser1 from=worker
[I][p:497] wad_informer_find_user_ip_entries :657 find=false(1) vf=0 ip=10.89.7.253:55629 pr=(nil)
mapping user_node:0x7f77bc595a40, user_ip:0x7f77bc817048(0), user:0x7f77bc5a57d8(0).
[I][p:497] wad_informer_proc_user_adding :1505 Sync User Adding.
[I][p:497] wad_informer_find_user_fsae_pr :699 find=false: count=0 vf=0 ip=10.89.7.253:55629
[V][p:497] wad_inform_msg_hdr_get :715 msg=RespAdd code=OK seq=8
[V][p:9401] wad_usr_info_get_msg :1995 user_info_svr recv msg type:7 size:144, id=0
[V][p:9401] wad_ldap_req_msg_open :700 open msg type=2
[V][p:9401] wad_ldap_server_start_conn_by_type:1373 try to bring up 2 connect to server:10.x.x.x:389, admin=1 <-- Establishing connection to LDAP server to verify the user group membership.
[V][p:9401] wad_ldap_server_tcp_connect :1234 server=0x7f0cd55e6ba8 conn=0x7f0cd5546cb8 n_active=0
[V][p:9401] wad_ldap_server_tcp_connect :1234 server=0x7f0cd55e6ba8 conn=0x7f0cd5546d88 n_active=0
[V][p:9401] wad_ldap_request_submit :996 adding request into the admin que, waits=1 type=2
[V][p:9401] wad_usr_info_proc_msg :2037 user info proc msg ret=1
[V][p:518] wad_authenticated_user_proc_msg_header:1720 msg=RespAdd code=OK seq=8 data_len=0
[I][p:518] wad_authenticated_proc_user_add_resp:840 code=0
[I][p:518] wad_inform_req_user_add_notify :797 Reponse Add-User from informer: succ auth_req=0x7fc8cd49ef78
[W][p:518] wad_user_add_notify :188 auth-st=7 add-auth-st=1
[V][p:518] wad_auth_fw_srcmac_get :1014 Mac address for req 0x7fc8cb1d3cf0: 00:00:00:00:00:00
[I][p:518] wad_auth_membership_match :1222 grp(FAC_LDAP): id=2 type=firewall member_sz=3; user(kerberosuser1): type=firewall ms=0x7fc8cb8813a0 m
s-type=1 member_sz=2
[I][p:518] wad_auth_membership_match :1222 grp(FAC_SAML_Group): id=4 type=firewall member_sz=1; user(kerberosuser1): type=firewall ms=0x7fc8cb88
13a0 ms-type=1 member_sz=2
[I][p:518] wad_auth_membership_match :1222 grp(Guest-group): id=1 type=firewall member_sz=1; user(kerberosuser1): type=firewall ms=0x7fc8cb8813a
0 ms-type=1 member_sz=2
[I][p:518] wad_auth_membership_match :1222 grp(kerberos_group): id=6 type=firewall member_sz=1; user(kerberosuser1): type=firewall ms=0x7fc8cb8813a0 ms-type=1 member_sz=2 <--- The above steps was for matching the user kerberosuser1 against all the groups configured and the user was found in the group kerberos_group which is a remote user group.
[I][p:518] wad_usr_collect_usrgrp :2502 Match grp(kerberos_group): SUCCESS
[I][p:518] wad_auth_membership_match :1222 grp(SSO_Guest_Users): id=16777215 type=guest member_sz=0; user(kerberosuser1): type=firewall ms=0x7fc
8cb8813a0 ms-type=1 member_sz=2
[I][p:518] _wad_usr_add_auth_logon :462 add user/srv: kerberosuser1/LDAP_Server with macaddr=00:00:00:00:00:00
[I][p:518] wad_http_auth_status_proc :11503 authenticate result=success <--- Authentication result changes to Success from Pending.
After this, the user can be verified from the below command in the FortiGate:
diag user wad list
ID: 45, VDOM: root, IPv4: 10.89.x.x
user name : kerberosuser1
worker : 11
duration : 8
auth_type : IP <---- Auth type IP based. It will be a session if session-based auth is used in the auth rule.
auth_method : Negotiate
pol_id : 2 <---- The proxy policy ID.
g_id : 6 <------The group which this used is matched to. To check the group ID, use: sh user group ?.
user_based : 0
expire : no
LAN:
bytes_in=10793 bytes_out=191776
WAN:
bytes_in=189766 bytes_out=12406
|
