Unable to see policy deny message when running debug flow check, fortiOS 7.0

[bhuo]

Hey Guys,

I have been testing this debug command for a while.

I have setup a firewall security policy to deny "gmail" traffic from inside to outside (all services deny), I have tested via cmd (tired to ping the gmail FQDN or ip address, confirmed it got blocked)

The issue I have is I couldn't see any denied message from debug flow logs, the command I run is in below:

diagnose debug flow filter addr 142.250.70.197

diagnose debug flow filter proto 1

diagnose debug flow show function-name enabled 

diagnose debug flow show ipprobe enabled

diagnose debug flow trace start 100

diagnose debug flow enabled

This is output from those commands.

abc-101f-fw01 # id=20085 trace_id=622 func=print_pkt_detail line=5723 msg="vd-root:0 received a packet(proto=1, 192.168.253.69:1->142.250.70.197:2048) from vlan_si. type=8, code=0, id=1, seq=98." id=20085 trace_id=622 func=init_ip_session_common line=5894 msg="allocate a new session-02b91e97" id=20085 trace_id=622 func=iprope_dnat_check line=5061 msg="in-[vlan_si], out-[]" id=20085 trace_id=622 func=iprope_dnat_tree_check line=830 msg="len=0" id=20085 trace_id=622 func=iprope_dnat_check line=5074 msg="result: skb_flags-02000000, vid-0, ret-no-match, act-accept, flag-00000000" id=20085 trace_id=622 func=vf_ip_route_input_common line=2621 msg="find a route: flag=04000000 gw-27.33.116.97 via wan1" id=20085 trace_id=622 func=iprope_fwd_check line=781 msg="in-[vlan_si], out-[wan1], skb_flags-02000000, vid-0, app_id: 0, url_cat_id: 0" id=20085 trace_id=622 func=__iprope_tree6_check line=51 msg="gnum-100004, use addr/intf hash, len=3" id=20085 trace_id=622 func=__iprope_check_one_policy line=1941 msg="checked gnum-100004 policy-6, ret-matched, act-accept" id=20085 trace_id=622 func=__iprope_user_identity_check line=1761 msg="ret-matched" id=20085 trace_id=622 func=get_new_addr line=1176 msg="find SNAT: IP-27.33.116.98(from IPPOOL), port-60417" id=20085 trace_id=622 func=__iprope_check_one_policy line=2159 msg="policy-6 is matched, act-accept" id=20085 trace_id=622 func=iprope_fwd_auth_check line=832 msg="after iprope_captive_check(): is_captive-0, ret-matched, act-accept, idx-6" id=20085 trace_id=622 func=iprope_shaping_check line=921 msg="in-[vlan_si], out-[wan1], skb_flags-02000000, vid-0" id=20085 trace_id=622 func=__iprope_check line=2188 msg="15, chegnum-1000ck-ffffffbffc0294c8" id=20085 trace_id=622 func=__iprope_check_one_policy line=1941 msg="checked gnum-100015 policy-1, ret-no-match, act-accept" id=20085 trace_id=622 func=__iprope_check line=2207 msg="gnum-100015 check result: ret-no-match, act-accept, flag-00000000, flag2-00000000" id=20085 trace_id=622 func=iprope_policy_group_check line=4500 msg="after check: ret-no-match, act-accept, flag-00000000, flag2-00000000" id=20085 trace_id=622 func=iprope_reverse_dnat_check line=1252 msg="in-[vlan_si], out-[wan1], skb_flags-02000000, vid-0" id=20085 trace_id=622 func=iprope_reverse_dnat_tree_check line=923 msg="len=0" id=20085 trace_id=622 func=iprope_central_nat_check line=1275 msg="in-[vlan_si], out-[wan1], skb_flags-02000000, vid-0" id=20085 trace_id=622 func=__iprope_check_one_policy line=1941 msg="checked gnum-10000d policy-1, ret-matched, act-accept" id=20085 trace_id=622 func=get_new_addr line=1176 msg="find DNAT: IP-27.33.116.98, port-60417" id=20085 trace_id=622 func=__iprope_check_one_policy line=2159 msg="policy-1 is matched, act-accept" id=20085 trace_id=622 func=fw_forward_handler line=819 msg="Allowed by Policy-6: SNAT" id=20085 trace_id=622 func=ids_receive line=298 msg="send to ips" id=20085 trace_id=623 func=print_pkt_detail line=5723 msg="vd-root:0 received a packet(proto=1, 192.168.253.69:1->142.250.70.197:2048) from vlan_si. type=8, code=0, id=1, seq=99." id=20085 trace_id=623 func=resolve_ip_tuple_fast line=5804 msg="Find an existing session, id-02b91e97, original direction" id=20085 trace_id=623 func=npu_handle_session44 line=1163 msg="Trying to offloading session from vlan_si to wan1, skb.npu_flag=00000000 ses.state=00013204 ses.npu_state=0x00001008" id=20085 trace_id=623 func=fw_forward_dirty_handler line=396 msg="state=00013204, state2=00000000, npu_state=00001008" id=20085 trace_id=624 func=print_pkt_detail line=5723 msg="vd-root:0 received a packet(proto=1, 192.168.253.69:1->142.250.70.197:2048) from vlan_si. type=8, code=0, id=1, seq=100." id=20085 trace_id=624 func=resolve_ip_tuple_fast line=5804 msg="Find an existing session, id-02b91e97, original direction" id=20085 trace_id=624 func=npu_handle_session44 line=1163 msg="Trying to offloading session from vlan_si to wan1, skb.npu_flag=00000000 ses.state=00013204 ses.npu_state=0x00001008" id=20085 trace_id=624 func=fw_forward_dirty_handler line=396 msg="state=00013204, state2=00000000, npu_state=00001008" id=20085 trace_id=625 func=print_pkt_detail line=5723 msg="vd-root:0 received a packet(proto=1, 192.168.253.69:1->142.250.70.197:2048) from vlan_si. type=8, code=0, id=1, seq=101." id=20085 trace_id=625 func=resolve_ip_tuple_fast line=5804 msg="Find an existing session, id-02b91e97, original direction" id=20085 trace_id=625 func=npu_handle_session44 line=1163 msg="Trying to offloading session from vlan_si to wan1, skb.npu_flag=00000000 ses.state=00013204 ses.npu_state=0x00001008" id=20085 trace_id=625 func=fw_forward_dirty_handler line=396 msg="state=00013204, state2=00000000, npu_state=00001008"

I just couldn't see any message re firewall policy deny, so it is really hard for me to troubleshoot traffics flow in production environment.

Any help will be greatly appreciated.

Thanks,

Bill 

[Kangming]

Hey

What is the result of "dia sniffer" packet capture?

# dia sni pa any "host 142.250.70.197" 4 0 l

[bhuo]

Hey LiuKangming,

Thanks for reply, please see output below,

filters=[host 142.250.70.197] 3.716728 vlan_si in 192.168.253.69 -> 142.250.70.197: icmp: echo request 8.409288 vlan_si in 192.168.253.69 -> 142.250.70.197: icmp: echo request 13.403180 vlan_si in 192.168.253.69 -> 142.250.70.197: icmp: echo request 18.413922 vlan_si in 192.168.253.69 -> 142.250.70.197: icmp: echo request

[emnoc]

So your deny policy is it before or after policyid #6?

And that destination address is not gmail from what I can tell.

Ken Felix

[bhuo]

Hi Ken,

I believe policyid #6 is referring to SNAT rule not firewall security rule, correct me if I am wrong.

msg="Allowed by Policy-6: SNAT"

I picked gmail address from fortigate pre defined address object, see policy detail below,

bc-101f-fw01 # show firewall security-policy 84 config firewall security-policy edit 84 set uuid cbbc6d58-bc99-51eb-905f-f3d55044d682 set name "flow_debug" set srcintf "zone_inside" set dstintf "zone_outside" set srcaddr "bill" set dstaddr "gmail.com" set enforce-default-app-port disable set service "ALL" set schedule "always" set logtraffic all next

[bhuo]

I hover mouse to gmail object to get the address 142.250.70.197, I am assuming the fortigate (fortigurad) has resolved this as it is part of their pre- defined address object, correct me if I am wrong.

[emnoc]

I did the same as yours and had the exact same results. If I use a fqdn object for example it does work. Also "diag firewall fqdn list" reflects the correct DNS entry

btw I tried mine with internet-sevice also

config firewall policy    edit 84        set name "flow_debug"        set uuid b20cd99c-bd61-51eb-ceb8-c046f5348a01        set srcintf "internal"        set dstintf "wan1"        set srcaddr "all"        set internet-service enable        set internet-service-name "Google-DNS"        set internet-service-custom "google_dns-object"         set schedule "always"        set utm-status enable        set logtraffic disable    nextend So with the objects in a custom service it ignores and jumps over this policy. if I remove the inernet-service and use a fqdn object that I create for google dns the policy is matched idnk what's happening Ken Felix

[Kangming]

emnoc wrote:

I did the same as yours and had the exact same results. If I use a fqdn object for example it does work. Also "diag firewall fqdn list" reflects the correct DNS entry

btw I tried mine with internet-sevice also

config firewall policy    edit 84        set name "flow_debug"        set uuid b20cd99c-bd61-51eb-ceb8-c046f5348a01        set srcintf "internal"        set dstintf "wan1"        set srcaddr "all"        set internet-service enable        set internet-service-name "Google-DNS"        set internet-service-custom "google_dns-object"         set schedule "always"        set utm-status enable        set logtraffic disable    nextend So with the objects in a custom service it ignores and jumps over this policy. if I remove the inernet-service and use a fqdn object that I create for google dns the policy is matched idnk what's happening Ken Felix

Hi  Ken, 

What is your configuration? The result of my test looks like it can work normally:

config firewall address edit "google_dns_4.4.4.4" set allow-routing enable set subnet 4.4.4.4 255.255.255.255 next end

config firewall internet-service-custom edit "google_dns-object" set comment '' config entry edit 1 set dst "google_dns_4.4.4.4" next end next end

config firewall policy edit 7 set name "Drop_Test" set srcintf "port8" set dstintf "port1" set srcaddr "all" set internet-service enable set internet-service-name "Google-DNS" set internet-service-custom "google_dns-object" set schedule "always" set logtraffic all set logtraffic-start enable next end

Internet-FW (root) # diagnose sniffer packet any "host 4.4.4.4" 4 0 l Using Original Sniffing Mode interfaces=[any] filters=[host 4.4.4.4] 2021-05-26 02:15:50.960310 port8 in 10.254.254.100 -> 4.4.4.4: icmp: echo request 2021-05-26 02:15:52.072866 port8 in 10.254.254.100 -> 4.4.4.4: icmp: echo request 2021-05-26 02:15:53.576840 port8 in 10.254.254.100 -> 4.4.4.4: icmp: echo request 2021-05-26 02:15:55.079863 port8 in 10.254.254.100 -> 4.4.4.4: icmp: echo request 2021-05-26 02:15:56.579866 port8 in 10.254.254.100 -> 4.4.4.4: icmp: echo request 2021-05-26 02:15:58.075831 port8 in 10.254.254.100 -> 4.4.4.4: icmp: echo request 2021-05-26 02:15:59.579864 port8 in 10.254.254.100 -> 4.4.4.4: icmp: echo request 2021-05-26 02:16:01.085857 port8 in 10.254.254.100 -> 4.4.4.4: icmp: echo request 2021-05-26 02:16:02.574900 port8 in 10.254.254.100 -> 4.4.4.4: icmp: echo request 2021-05-26 02:16:04.066865 port8 in 10.254.254.100 -> 4.4.4.4: icmp: echo request ^C 13 packets received by filter 0 packets dropped by kernel

Internet-FW (root) #

Internet-FW (root) # diagnose sys session filter proto 1

Internet-FW (root) # diagnose sys session filter dst 4.4.4.4

Internet-FW (root) # diagnose sys session clear

Internet-FW (root) # Internet-FW (root) # diagnose debug flow filter addr 4.4.4.4

Internet-FW (root) # diagnose debug flow filter proto 1

Internet-FW (root) # diagnose debug flow show function-name enable show function name

Internet-FW (root) # diagnose debug flow trace start 100

Internet-FW (root) # diagnose debug enable

Internet-FW (root) # id=20085 trace_id=78 func=print_pkt_detail line=5723 msg="vd-root:0 received a packet(proto=1, 10.254.254.100:4->4.4.4.4:2048) from port8. type=8, code=0, id=4, seq=4249." id=20085 trace_id=78 func=init_ip_session_common line=5894 msg="allocate a new session-0018957f" id=20085 trace_id=78 func=vf_ip_route_input_common line=2621 msg="find a route: flag=04000000 gw-10.6.30.254 via port1" id=20085 trace_id=78 func=fw_forward_handler line=663 msg="Denied by forward policy check (policy 7)"

Internet-FW (root) # id=20085 trace_id=79 func=print_pkt_detail line=5723 msg="vd-root:0 received a packet(proto=1, 10.254.254.100:4->4.4.4.4:2048) from port8. type=8, code=0, id=4, seq=4250." id=20085 trace_id=79 func=init_ip_session_common line=5894 msg="allocate a new session-00189581" id=20085 trace_id=79 func=vf_ip_route_input_common line=2621 msg="find a route: flag=04000000 gw-10.6.30.254 via port1" id=20085 trace_id=79 func=fw_forward_handler line=663 msg="Denied by forward policy check (policy 7)"

[emnoc]

yeah mine is similar to yours but I used protocol1 , but  I just copied you in and have success also fwiw

config firewall internet-service-custom    edit "soc"        set comment ''        config entry            edit 1                set protocol 1                set dst "goog1"            next            edit 2                set dst "goog2"            next        end    next    edit "google_dns-object"        set comment ''        config entry            edit 1                set dst "google_dns_4.4.4.4"            next        end    nextend  So I do not know why my "soc" is not working and this on fortios7.0 also  Ken Felix

[Kangming]

emnoc wrote:

yeah mine is similar to yours but I used protocol1 , but  I just copied you in and have success also fwiw

config firewall internet-service-custom    edit "soc"        set comment ''        config entry            edit 1                set protocol 1                set dst "goog1"            next            edit 2                set dst "goog2"            next        end    next    edit "google_dns-object"        set comment ''        config entry            edit 1                set dst "google_dns_4.4.4.4"            next        end    nextend  So I do not know why my "soc" is not working and this on fortios7.0 also  Ken Felix

I copied sco, but I still haven’t reproduced the situation, Could you post a more complete configuration, I can try again, thank you.

config firewall address edit "remote_1.1.1.1" set allow-routing enable set subnet 1.1.1.1 255.255.255.255 next end

config firewall internet-service-custom edit "google_dns-object" set comment '' config entry edit 1 set protocol 1 set dst "google_dns_4.4.4.4" next end next edit "soc" set comment '' config entry edit 1 set protocol 1 set dst "remote_1.1.1.1" next end next end

config firewall policy edit 7 set name "Drop_Test" set uuid e624c926-bd82-51eb-970f-828a3009b386 set srcintf "port8" set dstintf "port1" set srcaddr "all" set internet-service enable set internet-service-name "Google-DNS" set internet-service-custom "soc" set schedule "always" set logtraffic all set logtraffic-start enable next end

diagnose debug flow filter addr 1.1.1.1 diagnose debug flow filter proto 1 diagnose debug flow show function-name enable diagnose debug flow trace start 100 diagnose debug enable

Internet-FW (root) # id=20085 trace_id=89 func=print_pkt_detail line=5723 msg="vd-root:0 received a packet(proto=1, 10.254.254.100:4->1.1.1.1:2048) from port8. type=8, code=0, id=4, seq=11070." id=20085 trace_id=89 func=init_ip_session_common line=5894 msg="allocate a new session-00192f6d" id=20085 trace_id=89 func=vf_ip_route_input_common line=2621 msg="find a route: flag=04000000 gw-10.6.30.254 via port1" id=20085 trace_id=89 func=fw_forward_handler line=663 msg="Denied by forward policy check (policy 7)"