Troubleshooting Tip: Debug flow show - policy is not active
Description
This article describes a case where the traffic is dropped and run debug flow with iPrope enabled, which then displays a message 'policy-<n> is not active'. The message is seen as follows:
id=20085 trace_id=25 func=print_pkt_detail line=5384 msg="vd-root:0 received a packet (proto=6, 10.56.240.95:64166->10.56.240.74:25) from port1. flag [S], seq 3216323471, ack 0, win 8192" <----- Packet Received.
id=20085 trace_id=25 func=iprope_dnat_check line=4942 msg="in-[port1], out-[]"
id=20085 trace_id=25 func=iprope_dnat_tree_check line=816 msg="len=1"
id=20085 trace_id=25 func=_iprope_check_one_dnat_policy line=4816 msg="checking gnum-100000 policy-1" <----- Checks for a Virtual IP (VIP) matching the original destination IP/port.
id=20085 trace_id=25 func=get_new_addr line=1140 msg="find DNAT: IP-10.181.0.65, port-25"
id=20085 trace_id=25 func=_iprope_check_one_dnat_policy line=4898 msg="matched policy-1, act=accept, vip, flag=100, sflag=2000000"
id=20085 trace_id=25 func=iprope_dnat_check line=4955 msg="result: skb_flags-02000000, vid-1, ret-matched, act-accept, flag-00000100"
id=20085 trace_id=25 func=fw_pre_route_handler line=102 msg="VIP-10.181.0.65:25, outdev-port1"
id=20085 trace_id=25 func=_ip_session_run_tuple line=3291 msg="DNAT 10.56.240.74:25-10.181.0.65:25" <----- Applies DNAT.
id=20085 trace_id=25 func=vf_ip_route_input_common line=2591 msg="find a route: flag=04000000 gw-10.181.0.65 via port2" <----- Route lookup for the post-DNAT destination (10.181.0.65), Egress interface: port2.
id=20085 trace_id=25 func=iprope_fwd_check line=726 msg="in-[port1], out-[port2], skb_flags-020000c0, vid-1,app_id: 0, url_cat_id: 0"<-----Now evaluates security policies for traffic from port1 to port2 (post-DNAT addresses/interfaces).
id=20085 trace_id=25 func=_iprope_tree_check line=548 msg="gnum-100004, use addr/intf_hash, len=2"
id=20085 trace_id=25 func=_iprope_check_one_policy line=2214 msg="gnum-100004 policy-1 is not active" <-----Policy-1: not active (skipped).
id=20085 trace_id=25 func=_iprope_check_one_policy line=1806 msg="ret-matched"
id=20085 trace_id=25 func=_iprope_user_identity_check line=1806 msg="ret-matched"
id=20085 trace_id=25 func=_iprope_check_one_policy line=2209 msg="policy-0 is matched, act-drop" <----- Falls through to policy-0: matched with action drop.
id=20085 trace_id=25 func=iprope_fwd_auth_check line=781 msg="after iprope_captive_check(): is_captive-0, ret-matched, act-drop, idx-0"
id=20085 trace_id=25 func=fw_forward_handler line=599 msg="Denied by forward policy check (policy 0)"
Solution
The firewall policy is active as follows:
The reason for the iprope message is because of the schedule does not match the day which causes the policy become inactive.
Check the default schedule to ensure it is not modified and apply back the correct setting if being altered.
From the CLI:
Correct the schedule set to the firewall policy to 'always' or the correct one.
config firewall policy
edit 1
set schedule always
next
end
Note:
It is possible to modify the days under the 'always' category. As a result, make sure that all of the days are added in the 'always' object. It would be better not to edit the 'always' setting since it is the default setting for each policy. In case this 'always' schedule is altered carelessly or without any permission from the system administrator, this may cause an outage and can be difficult to pinpoint in the troubleshooting without doing a debug flow.
config firewall schedule recurring
edit "always"
set day sunday monday tuesday wednesday thursday friday saturday
next
end
Additionally, verify that FortiGate has the correct time zone set as the schedule will follow the firewalls date and time.
