Technical Tip: Identifying packet drops caused by DOS Policy

[ashaikh]

Description

This article describes the order of operations a packet undergoes inside the CPU of the FortiGate and how this knowledge can be used to identify packet drops caused by DOS policy configuration.

Scope

FortiGate.

Solution

Order of operation during session setup inside CPU for passthrough traffic (no UTM).

RECEIVE PACKET -> ALLOCATE SESSION ID -> VIP/DNAT -> DOS POLICY CHECK -> ROUTE LOOKUP -> POLICY LOOKUP & SNAT -> SEND PACKET

Session setup happens inside the CPU for non-hyperscale firewalls.

When a packet is received by the CPU, first it tries to find if this packet belongs to an existing session.

Session matching happens based on 5 Tuple information (source IP, destination IP, source port, destination port, protocol).

For creating a new TCP session on the FortiGate, the first packet seen by the CPU needs to be a SYN packet. For non-SYN packets, FortiGate will try to find a matching session. If no matching session is found, the packet will be dropped (default behavior).

For UDP, the first step is to match the packet to an existing session and if there is no matching session, FortiGate will try to set up a new connection.

The following checks and lookups are performed by the CPU before successfully creating a connection.

1. Packet received by CPU along with information about ingress interface.
2. Allocate a session ID
3. Translate the destination IP of the packet to a real IP if the packet matches a configured Destination NAT or VIP.
4. Evaluate packet against thresholds configured in DOS policy.
5. Route lookup is performed for the destination IP to determine the egress interface.
6. Based on packet information, Ingress, and egress interface, Policy lookup is performed. In flow mode, the matching policy also determines if Source NAT will happen for this traffic.
7. The packet is sent out successfully if there is no explicit configuration for dropping it in any of the steps mentioned above.

Debug flow for first packet of a session (no UTM in policy).

2024-09-17 06:26:37 id=65308 trace_id=109109 func=print_pkt_detail line=5920 msg="vd-root:0 received a packet(proto=1, 10.100.3.115:30755->10.101.3.109:3328) tun_id=0.0.0.0 from port3. type=13, code=0, id=30755, seq=0."

2024-09-17 06:26:37 id=65308 trace_id=109109 func=init_ip_session_common line=6110 msg="allocate a new session-000547a4"

2024-09-17 06:26:37 id=65308 trace_id=109109 func=iprope_dnat_check line=5480 msg="in-[port3], out-[]"

2024-09-17 06:26:37 id=65308 trace_id=109109 func=iprope_dnat_tree_check line=824 msg="len=0"

2024-09-17 06:26:37 id=65308 trace_id=109109 func=iprope_dnat_check line=5505 msg="result: skb_flags-02000000, vid-0, ret-no-match, act-accept, flag-00000000"

2024-09-17 06:26:37 id=65308 trace_id=109109 func=__vf_ip_route_input_rcu line=1988 msg="find a route: flag=00000000 gw-0.0.0.0 via port9"

2024-09-17 06:26:37 id=65308 trace_id=109109 func=__iprope_fwd_check line=810 msg="in-[port3], out-[port9], skb_flags-02000000, vid-0, app_id: 0, url_cat_id: 0"

2024-09-17 06:26:37 id=65308 trace_id=109109 func=fw_forward_handler line=998 msg="Allowed by Policy-2:"

2024-09-17 06:26:37 id=65308 trace_id=109109 func=ip_session_confirm_final line=3128 msg="npu_state=0x1, hook=4"

Sniffers on FortiGate and adjacent devices simultaneously should be used to determine if the packets are being dropped on FortiGate.

Carefully analyzing the debug flow and comparing it with the expected order of operation will ease the process of troubleshooting packet loss.

The following are some examples of scenarios when packets are being dropped because of various signatures in DOS policy.

1. Pass through traffic drops (no DNAT/VIP).

2024-09-17 06:26:54 id=65308 trace_id=109232 func=print_pkt_detail line=5920 msg="vd-root:0 received a packet(proto=6, 10.100.3.115:63331->10.101.3.109:16815) tun_id=0.0.0.0 from port3. flag [S], seq 3804140195, ack 0, win 1024"

2024-09-17 06:26:54 id=65308 trace_id=109232 func=init_ip_session_common line=6110 msg="allocate a new session-000547fb"

2024-09-17 06:26:54 id=65308 trace_id=109232 func=iprope_dnat_check line=5480 msg="in-[port3], out-[]" 

2024-09-17 06:26:54 id=65308 trace_id=109232 func=iprope_dnat_tree_check line=824 msg="len=0"

2024-09-17 06:26:54 id=65308 trace_id=109232 func=iprope_dnat_check line=5505 msg="result: skb_flags-02000000, vid-0, ret-no-match, act-accept, flag-00000000"

>>>NO FURTHER PROCESSING:  NO ROUTE LOOKUP, POLICY LOOKUP

2. Pass through traffic drop (Destination IP has DNAT/VIP configured).

   2024-09-17 10:26:21 id=20085 trace_id=1233 func=print_pkt_detail line=5810 msg="vd-root:0 received a packet(proto=6, 100.100.100.72:1024->15.15.15.19:443) from port3. flag [S], seq 1414392314, ack 0, win 64240"

   2024-09-17 10:26:21 id=20085 trace_id=1233 func=init_ip_session_common line=5981 msg="allocate a new session-cc55bea5"

   2024-09-17 10:26:21 id=20085 trace_id=1233 func=iprope_dnat_check line=5121 msg="in-[port3], out-[]"

   2024-09-17 10:26:21 id=20085 trace_id=1233 func=iprope_dnat_tree_check line=830 msg="len=1"

   2024-09-17 10:26:21 id=20085 trace_id=1233 func=__iprope_check_one_dnat_policy line=4994 msg="checking gnum-100000 policy-54"

   2024-09-17 10:26:21 id=20085 trace_id=1233 func=get_new_addr line=1193 msg="find DNAT: IP-10.10.10.1, port-0"

   2024-09-17 10:26:21 id=20085 trace_id=1233 func=__iprope_check_one_dnat_policy line=5077 msg="matched policy-54, act=accept, vip=54, flag=100, sflag=2000000"

   2024-09-17 10:26:21 id=20085 trace_id=1233 func=iprope_dnat_check line=5134 msg="result: skb_flags-02000000, vid-54, ret-matched, act-accept, flag-00000100"    <<< Found VIP

   2024-09-17 10:26:21 id=20085 trace_id=1233 func=fw_pre_route_handler line=181 msg="VIP-10.10.10.1:443, outdev-unknown"

   2024-09-17 10:26:21 id=20085 trace_id=1233 func=__ip_session_run_tuple line=3522 msg="DNAT 15.15.15.19:443->10.10.10.1:443"

    >>>> NO FURTHER PROCESSING AFTER VIP/DNAT: NO ROUTE LOOKUP, POLICY LOOKUP

3. Dos policy also applies to LOCAL-IN traffic.

For example, IKE traffic drops during tunnel setup.

In situations when the VPN tunnel is not coming up or is flapping, it is possible that Dos is triggering drops for UDP or ESP packets through UDP and IP related signatures because of lower thresholds configured in the DOS policy.  

Be aware of the possibility of drops happening in DOS and look at Anomaly logs to see if there are indeed any Dos related drops for any of the VPN gateway IP addresses.

date=2024-09-18 time=04:31:42 eventtime=1726659102977615864 tz="-0700" logid="0720018432" type="utm" subtype="anomaly" eventtype="anomaly" level="alert" vd="root" severity="critical" srcip=100.100.100.101 srccountry="Reserved" dstip=100.100.100.50 dstcountry="Reserved" srcintf="port2" srcintfrole="undefined" sessionid=0 action="clear_session" proto=17 service="IKE" count=10 attack="udp_flood" srcport=500 dstport=500 attackid=285212772 policyid=1 policytype="DoS-policy" ref="http://www.fortinet.com/ids/VID285212772" msg="anomaly: udp_flood, 11 > threshold 10, repeats 10 times" crscore=50 craction=4096 crlevel="critical"

diag ips anomaly list

list nids meter:

id=udp_flood          ip=100.100.100.50 dos_id=1 exp=266 pps=4 freq=4

In conclusion, DOS policy check (when dos offload is disabled) happens inside the CPU and sometimes finding the reason of packet drop using just debug flow is difficult. It is better to actively look at the Security event -> Anomaly logs to understand if DOS is being triggered.