Description
This article describes the first steps to troubleshooting explicit proxy connections through FortiProxy.
Scope
FortiProxy.
Solution
Step 1 - Check the explicit proxy configuration.
1) Configuration on the FortiProxy.
FortiProxy GUI: Navigate to Proxy Setting -> Explicit Proxy.
FortiProxy CLI:
# config web-proxy explicit-proxy
edit "web-proxy" <-
set status enable
set interface "port2" -> port2 IP = 192.168.1.1.
set http-incoming-port 8080
set https-incoming-port 8080
next
end
2) Configuration on the client machine.
Check in the Windows Proxy setting or the browser’s proxy setting.
Make sure the address should be matching with the interface IP of the explicit proxy, in this case, it is port2. Also, the port should match the configuration of the explicit proxy.
Step 2 - Check if the traffic is matching the configured policy.
1) When the traffic is not matched, expect to see 'No policy matched!' in WAD debugs as shown below:
GET http://apple.com/ HTTP/1.1 <-
Host: apple.com
Proxy-Connection: keep-alive
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Safari/537.36 Edg/112.0.1722.34
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9
[I]2023-04-07 11:03:59.155959 [p:11089][s:2060731322][r:592] __wad_dns_send_query :772 0:0: sending DNS request for remote peer apple.com id=0 IPv4
[I]2023-04-07 11:03:59.178897 [p:11089] wad_dns_parse_name_resp :205 0: DNS response received for remote host apple.com req-id=0 ipv4=1 <---- DNS response received for host apple.com.
[V]2023-04-07 11:03:59.178929 [p:11089] wad_dns_parse_name_resp :324 apple.com: resp_type=1 notify=1 cdata=0 17.253.144.10
[I]2023-04-07 11:03:59.178932 [p:11089][s:2060731322][r:592] wad_http_dns_request_done :12241 [0x7fc5a1c8b1f8] DNS resolved: 17.253.144.10
[V]2023-04-07 11:03:59.179002 [p:11089][s:2060731322][r:592] wad_http_req_proc_dst :12160 HTTP req=0x7fc5a1c8b1f8 check destination/quarantine ret=0
[V]2023-04-07 11:03:59.179007 [p:11089][s:2060731322][r:592] wad_http_req_check_policy :11785 start match policy vd=0(ses_ctx:x|Phx|M|Hh|C|A7|O) (192.168.1.100
:63364@6->17.253.144.10:80@3) absUrl=1 <-
[I]2023-04-07 11:03:59.179011 [p:11089][s:2060731322][r:592] wad_fast_match_is_enable :3703 fast matching is enabled
[V]2023-04-07 11:03:59.179015 [p:11089][s:2060731322][r:592] wad_fast_match_get_addr :3440 Get key src:192.168.1.100 ---> source address.
[W]2023-04-07 11:03:59.179016 [p:11089][s:2060731322][r:592] wad_fast_match_one :3607 No policy matched!
The following is the proxy policy configuration in this case.
# config firewall policy
edit 1 <-
set type explicit-web
set uuid b4e26394-cc23-51ed-a4d3-e79a5789c19e
set dstintf "port1"
set srcaddr "192.168.1.2/32" <-
set dstaddr "all"
set action accept
set schedule "always"
set service "webproxy"
set explicit-web-proxy "web-proxy" <-
set logtraffic all
set ssl-ssh-profile "certificate-inspection"
next
end
As the source address of the traffic is not matching the source address in the policy, the traffic is failing to match the policy.
2) After correcting the policy, the following output can be expected:
[V]2023-04-20 11:34:55.530516 [p:1656][s:562102499][r:50331693] wad_http_req_proc_dst :12160 HTTP req=0x7f687632b0b0 check destination/quarantine ret=0
[V]2023-04-20 11:34:55.530522 [p:1656][s:562102499][r:50331693] wad_http_req_check_policy :11785 start match policy vd=0(ses_ctx:x|Phx|M|Hh|C|A7|O) (192.168.1.
100:58660@6->17.253.144.10:443@3) absUrl=1
[I]2023-04-20 11:34:55.530527 [p:1656][s:562102499][r:50331693] wad_fast_match_is_enable :3703 fast matching is enabled
[V]2023-04-20 11:34:55.530530 [p:1656][s:562102499][r:50331693] wad_fast_match_get_addr :3440 Get key src:192.168.1.100
[V]2023-04-20 11:34:55.530533 [p:1656][s:562102499][r:50331693] wad_fast_match_get_dst_intf :3470 Get key dst intf:1
[V]2023-04-20 11:34:55.530535 [p:1656][s:562102499][r:50331693] wad_fast_match_pol_array :3507 Try to maching pol:0, 0/1(pos/sz)
[V]2023-04-20 11:34:55.530537 [p:1656][s:562102499][r:50331693] wad_fw_policy_set_check_id :5335 pol_id=1 dev_cked=0
[I]2023-04-20 11:34:55.530541 [p:1656][s:562102499][r:50331693] wad_fw_policy_async_match :5466 pol_ctx:xhcf|Ad|7?|=d
[I]2023-04-20 11:34:55.530544 [p:1656][s:562102499][r:50331693] wad_http_req_policy_set :10206 match policy-id=1(pol_ctx:xhcf|Ad|7?|=d) vd=0(ses_ctx:x|Phx|Md <---- Matched policy id = 1
e|Hh|C|A7|O) (192.168.1.100:58660@6 -> 17.253.144.10:443@3)
[V]2023-04-20 11:34:55.530605 [p:1656][s:562102499][r:50331693] wad_http_connect_original_server :7051 [0x7f687632b0b0] Connect to server: 17.253.144.10:443/17.253.1
44.10:443
[I]2023-04-20 11:34:55.536133 [p:1656][s:562102499][r:50331693] wad_dump_fwd_http_resp :2694 hreq=0x7f687632b0b0 Forward response from Internal:
HTTP/1.1 200 Connection established
Proxy-Agent: Fortinet-Proxy/1.0
Step 3 - If there is authentication, check if the authentication is successful.
1) Authentication rule configuration:
# config authentication scheme
edit "Test-LDAP" <-
set method basic
set user-database "LDAP=LAB"
next
end
# config authentication rule
edit "LDAP-Rule"
set srcintf "port2"
set srcaddr "all"
set dstaddr "all"
set active-auth-method "Test-LDAP" <-
next
end
# config firewall policy
edit 1
set type explicit-web
set uuid b4e26394-cc23-51ed-a4d3-e79a5789c19e
set dstintf "port1"
set srcaddr "192.168.1.100/32" <-
set dstaddr "all"
set action accept
set schedule "always"
set service "webproxy"
set explicit-web-proxy "web-proxy"
set logtraffic all
set groups "LDAP-Group" <-
set ssl-ssh-profile "certificate-inspection"
next
end
2) When authentication is not successful, the following can be expected.
[I]2023-04-20 12:36:15.460477 [p:1656][s:562102644][r:50331870] wad_fast_match_pol_array :3537 fw_pol_id=1(pol_ctx:xhf|Ad|7|=p) pol_id=0(pflag:H|W|U|A) asyn_
info=1
[V]2023-04-20 12:36:15.460479 [p:1656][s:562102644][r:50331870] wad_fw_policy_set_check_id :5335 pol_id=1 dev_cked=0 --> Checking policy id = 1 for this traffic.
[I]2023-04-20 12:36:15.460483 [p:1656][s:562102644][r:50331870] wad_http_req_get_user :11298 process=1656 auth-rule=LDAP-Rule user=/0/0 ip-based/auth-cooki ---> Found Authentication rule 'LDAP-Rule'.
e/transact=1/0/0 tp_proxy_auth=0 auth_req=0x7f68764b0480 auth_line=0x7f68764f9748
[I]2023-04-20 12:36:15.460492 [p:1656][s:562102644][r:50331870] wad_usr_pass_authenticate :532 try to authenticate abhi/ tfa=0 --> Found username=abhi.
[I]2023-04-20 12:36:15.460495 [p:1656][s:562102644][r:50331870] wad_hauth_is_sso_guest :1444 check guest for abhi/4
[V]2023-04-20 12:36:15.460498 [p:1656][s:562102644][r:50331870] wad_usr_info_clt_conn_connected :2825 user info connection:connected
[V]2023-04-20 12:36:15.460509 [p:1656][s:562102644][r:50331870] wad_auth_request :1378 user:abhi send auth reqest with no=1 ldaps
[I]2023-04-20 12:36:15.460512 [p:1656][s:562102644][r:50331870] wad_http_auth_status_proc :10582 ses_ctx: ses_ctx:cx|Phx|Me|Hh|C|A7|O authenticate result=pending
[V]2023-04-20 12:36:15.463403 [p:1644] wad_usr_info_get_msg :2106 user_info_svr recv msg type:4 size:35, id=2 --> WAD User_info handles authentication in explicit proxy, and it received the authentication request for the user.
[V]2023-04-20 12:36:15.463437 [p:1644] wad_usr_info_auth_req_handler :981 recv ldap auth request, username=abhi, n_ldaps=1
[V]2023-04-20 12:36:15.463444 [p:1644] wad_ldap_usr_dn_filter :1211 filter=(SAMAccountName=abhi)
[V]2023-04-20 12:36:15.463447 [p:1644] wad_ldap_build_dn_search_req :2111 dn is dc=abhineet,dc=com, filter is (SAMAccountName=abhi)
[I]2023-04-20 12:36:15.469755 [p:1656][s:562102644][r:50331870] wad_http_auth_status_proc :10582 ses_ctx: ses_ctx:cx|Phx|Me|Hh|C|A7|O authenticate result=failure <-
[I]2023-04-20 12:36:15.469923 [p:1656][s:562102644][r:50331870] wad_dump_fwd_http_resp :2694 hreq=0x7f687632abc8
Forward response from Internal:
Based on the above results, the authentication for user=abhi has failed. In this case, the password provided was incorrect.
3) After providing the correct password, the following outputs were observed.
[V]2023-04-20 12:46:31.047982 [p:1644] wad_usr_info_proc_msg :2148 user info proc msg ret=1 <-
[V]2023-04-20 12:46:31.047848 [p:1656] wad_unix_stream_on_read_data :426 WAD unix stream socket 27 read (0,4080) <-
[1656] read [(0,12) (1f 00 00 00 02 00 00 00 00 00 00 00 )(............)] --> Received response from wad user_info.
[V]2023-04-20 12:46:31.047868 [p:1656] wad_authenticated_user_proc_msg_header:1472 msg=RespAdd code=OK seq=2 data_len=0
[I]2023-04-20 12:46:31.047871 [p:1656] wad_authenticated_proc_user_add_resp:712 code=0
[I]2023-04-20 12:46:31.047873 [p:1656][s:562102730][r:50331957] wad_inform_req_user_add_notify :669 Reponse Add-User from informer: succ auth_req=0x7f68764b20f0
[W]2023-04-20 12:46:31.047875 [p:1656][s:562102730][r:50331957] wad_basic_user_add_notify :1156 auth-st=7 add-auth-st=1 is-local=0
[I]2023-04-20 12:46:31.047879 [p:1656][s:562102730][r:50331957] wad_auth_membership_match :1292 grp(Guest-group): id=1 type=firewall member_sz=1; user(abhi@abhineet.com): type=firewall ms=0x7f68763d4828 ms-type=1 member_sz=7
[I]2023-04-20 12:46:31.047881 [p:1656][s:562102730][r:50331957] wad_auth_membership_match :1292 grp(LDAP-Group): id=2 type=firewall member_sz=1; user(abhi@abhineet.com): type=firewall ms=0x7f68763d4828 ms-type=1 member_sz=7 <-
[I]2023-04-20 12:46:31.047914 [p:1656][s:562102730][r:50331957] wad_usr_collect_usrgrp :2141 Match grp(LDAP-Group): SUCCESS
[I]2023-04-20 12:46:31.047917 [p:1656][s:562102730][r:50331957] wad_auth_membership_match :1292 grp(SSO_Guest_Users): id=16777215 type=guest member_sz=0; user
(abhi@abhineet.com): type=firewall ms=0x7f68763d4828 ms-type=1 member_sz=7
[I]2023-04-20 12:46:31.047958 [p:1656][s:562102730][r:50331957] wad_http_auth_status_proc :10582 ses_ctx: ses_ctx:x|Phx|M|Hh|C|A7|O authenticate result=success
[I]2023-04-20 12:46:31.052482 [p:1656][s:562102730][r:50331957] wad_dump_fwd_http_resp :2694 hreq=0x7f6876329d10 Forward response from Internal:
HTTP/1.1 200 Connection established
Proxy-Agent: Fortinet-Proxy/1.0
Some useful WAD debug commands:
# diag debug disable
# diag deb reset
# diag wad filter clear
# diag deb console time en
# diag wad filter <filter-value> <-For example – diag wad filter src 192.168.1.1.
# diag wad debug enable all
# diag deb en
Check WAD session:
# diag wad session list
1) With Filters:
# diag wad filter <filter-value>
# diag wad session list
2) To clear wad session:
# diag wad session clear
To check authenticated users for explicit proxy connection:
1)
# diag deb enable
# diag wad user list
2)
# diag deb en
# diag test app wad 2400 ---> To go into WAD Informer context.
# diag test app wad 110
