Content

Introduction

This how-to article describes how to activate tracing in fortigate using diag debug commands

Detailed information about tracing fortigate can be found on the Fortinet Help and Knowledge Base websites

Step 1: Check the current diag setting state and reset

Example

diagnose settings info

Sample output

debug output:           disable
console timestamp:      disable
console no user log message:    disable
CLI debug level:        3
sessionsync test level: 1
ipsmonitor test level:  22
reportd test level:     6
quarantined test level: 1

diagnose seetings can be reset using the reset command option :

Example

diagnose settings reset

Sample output

debug output:           disable
console timestamp:      disable
console no user log message:    disable
CLI debug level:        3

Step 2: Activate traces for all network packets related to an IP address.

Example

diag debug enable
diag debug flow filter addr 8.8.8.8
diag debug flow show console enable
diag debug flow show function-name enable
diag debug flow trace start 1000

Sample output

id=20085 trace_id=59 func=resolve_ip_tuple_fast line=4946 msg="Find an existing session, id-014d61fc, original direction"
id=20085 trace_id=59 func=npu_handle_session44 line=905 msg="Trying to offloading session from internal1 to wan2, skb.npu_flag=00000400 ses.state=00010200 ses.npu_state=0x00000000"
id=20085 trace_id=59 func=__ip_session_run_tuple line=2842 msg="SNAT 192.168.11.22->192.168.11.4:57701"
id=20085 trace_id=59 func=__ip_session_run_tuple line=2893 msg="run helper-dns-udp(dir=original)"
id=20085 trace_id=60 func=print_pkt_detail line=4882 msg="vd-root received a packet(proto=1, 192.168.99.100:1003->8.8.8.8:2048) from internal4. type=8, code=0, id=1003, seq=0."
id=20085 trace_id=60 func=init_ip_session_common line=5026 msg="allocate a new session-014d6512"
id=20085 trace_id=60 func=vf_ip4_route_input line=1598 msg="find a route: flags=00000000 gw-48.18.3.1 via wan22"
id=20085 trace_id=60 func=fw_forward_handler line=712 msg="Allowed by Policy-122: SNAT"
id=20085 trace_id=60 func=__ip_session_run_tuple line=2842 msg="SNAT 192.168.99.100->48.18.3.1:62464"
id=20085 trace_id=61 func=print_pkt_detail line=4882 msg="vd-root received a packet(proto=1, 8.8.8.8:62464->48.18.3.1:0) from wan2. type=0, code=0, id=62464, seq=0."

Alternate command example

diag debug reset
diag debug flow filter clear
diag debug flow filter addr 8.8.8.8
diag debug flow show console enable
diag debug flow show iprope enable
diag debug flow show function-name enable
diag debug console timestamp enable
diag debug enable
diag debug flow trace start 1000

Sample output

2018-02-15 09:42:28 id=20085 trace_id=5747 func=print_pkt_detail line=4882 msg="vd-root received a packet(proto=1, 192.168.222.11:20->8.8.8.8:2048) from msc-guest. type=8, code=0, id=20, seq=1."
2018-02-15 09:42:28 id=20085 trace_id=5747 func=init_ip_session_common line=5026 msg="allocate a new session-0319942b"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=iprope_dnat_check line=4562 msg="in-[msc-guest], out-[]"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=iprope_dnat_tree_check line=835 msg="len=0"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=iprope_dnat_check line=4575 msg="result: skb_flags-00800000, vid-0, ret-no-match, act-accept, flag-00000000"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=vf_ip4_route_input line=1598 msg="find a route: flags=00000000 gw-47.188.39.1 via wan2"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=iprope_fwd_check line=703 msg="in-[msc-guest], out-[wan2], skb_flags-00800000, vid-0"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=__iprope_tree_check line=543 msg="gnum-100004, use addr/intf hash, len=2"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=__iprope_check_one_policy line=1700 msg="checked gnum-100004 policy-97, ret-matched, act-accept"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=__iprope_user_identity_check line=1526 msg="ret-matched"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=get_new_addr line=2730 msg="find SNAT: IP-47.188.39.2(from IPPOOL), port-14933"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=__iprope_check_one_policy line=1896 msg="policy-97 is matched, act-accept"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=iprope_fwd_auth_check line=755 msg="after iprope_captive_check(): is_captive-0, ret-matched, act-accept, idx-97"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=iprope_reverse_dnat_check line=914 msg="in-[msc-guest], out-[wan2], skb_flags-00800000, vid-0"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=fw_forward_handler line=712 msg="Allowed by Policy-97: SNAT"
2018-02-15 09:42:28 id=20085 trace_id=5747 func=__ip_session_run_tuple line=2842 msg="SNAT 192.168.222.11->47.188.39.2:14933"

Alternate command example

diag debug enable
diag debug application dnsproxy -1

Sample output

udp_receive_request()-1991
handle_dns_request()-1395: id:0x9b0e pktlen=44, qr=0 req_type=3
get_intf_policy()-848: ifindex=7
dns_parse_message()-654
dns_nat64_update_request()-270
dns_local_lookup()-2107: vfid=0 qname=docs.google.com, qtype=1, qclass=1, offset=33, map#=3 max_sz=512
dns_lookup_aa_zone()-496: vfid=0, fqdn=docs.google.com
dns_forward_request()-930
dns_send_resol_request()-762: id=0xc089 domain=docs.google.com
dns_find_best_server()-366: vfid=0 profiled=0
dns_send_resol_request()-849: Send 44B to 62.72.64.237:53 via fd=16 request:1 dns_num:2
udp_receive_request()-1991
batch_on_read()-2317
udp_receive_response()-2198
udp_receive_response()-2217: vd-0: len=60, addr=62.72.64.237:53
handle_dns_response()-1791: id:0xc089 domain=docs.google.com pktlen=60
dns_set_min_ttl()-163: QR: docs.google.com
dns_set_min_ttl()-171: Offset of 1st RR: 33 Number of RR's: 2
dns_set_min_ttl()-181: RR TTL: 170
dns_set_min_ttl()-181: RR TTL: 32768
dns_cache_response()-246: Min ttl = 170
dns_forward_response()-1131
dns_secure_forward_response()-1077: category=255 profile=none
dns_visibility_log_hostname()-235: vd=0 pktlen=60
hostname_entry_insert()-140: af=2 domain=docs.google.com
__dns_forward_response()-989
__dns_forward_response()-995: vd-0 Send 60B via fd=13, family=2
__dns_forward_response()-998: set svf of fd to 0
dns_query_delete()-398: id:0xc089 active tcp_req=(nil)
udp_receive_response()-2198
udp_receive_request()-1991
handle_dns_request()-1395: id:0x3349 pktlen=65, qr=0 req_type=3
get_intf_policy()-848: ifindex=7
dns_parse_message()-654
dns_nat64_update_request()-270
dns_local_lookup()-2107: vfid=0 qname=p24-keyvalueservice.fe.apple-dns.net, qtype=1, qclass=1, offset=54, map#=4 max_sz=512
dns_lookup_aa_zone()-496: vfid=0, fqdn=p24-keyvalueservice.fe.apple-dns.net
dns_forward_request()-930
dns_send_resol_request()-762: id=0xc0da domain=p24-keyvalueservice.fe.apple-dns.net
dns_find_best_server()-366: vfid=0 profiled=0
dns_send_resol_request()-849: Send 65B to 62.72.64.237:53 via fd=16 request:1 dns_num:2
udp_receive_request()-1991
batch_on_read()-2317
udp_receive_response()-2198
udp_receive_response()-2217: vd-0: len=330, addr=62.72.64.237:53
handle_dns_response()-1791: id:0xc0da domain=p24-keyvalueservice.fe.apple-dns.net pktlen=330
dns_set_min_ttl()-163: QR: p24-keyvalueservice.fe.apple-dns.net
dns_set_min_ttl()-171: Offset of 1st RR: 54 Number of RR's: 13
dns_set_min_ttl()-181: RR TTL: 178
dns_set_min_ttl()-181: RR TTL: 178
dns_set_min_ttl()-181: RR TTL: 7562
dns_set_min_ttl()-181: RR TTL: 32768
dns_cache_response()-246: Min ttl = 178
dns_forward_response()-1131
dns_secure_forward_response()-1077: category=255 profile=none
dns_visibility_log_hostname()-235: vd=0 pktlen=330
hostname_entry_insert()-140: af=2 domain=p24-keyvalueservice.fe.apple-dns.net
hostname_entry_insert()-140: af=2 domain=p24-keyvalueservice.fe.apple-dns.net
hostname_entry_insert()-140: af=2 domain=p24-keyvalueservice.fe.apple-dns.net
__dns_forward_response()-989
__dns_forward_response()-995: vd-0 Send 330B via fd=13, family=2
__dns_forward_response()-998: set svf of fd to 0
__dns_forward_response()-1033: vd=0 send 330B response 192.168.10.254:53=>192.168.10.22:57872
dns_query_delete()-398: id:0xc0da active tcp_req=(nil)
udp_receive_response()-2198
handle_hostname_add_msg()-545
dns_visibility_log_hostname()-235: vd=0 pktlen=182
hostname_entry_insert()-140: af=2 domain=p24-keyvalueservice.fe.apple-dns.net
hostname_entry_insert()-140: af=2 domain=p24-keyvalueservice.fe.apple-dns.net
hostname_entry_insert()-140: af=2 domain=p24-keyvalueservice.fe.apple-dns.net
batch_on_read()-2317
udp_receive_request()-1991
udp_receive_request()-2045: vd=0, intf=7, len=48, alen=16, 192.168.10.22:57588=>192.168.10.254
handle_dns_request()-1395: id:0xe831 pktlen=48, qr=0 req_type=3
get_intf_policy()-848: ifindex=7
dns_parse_message()-654
dns_nat64_update_request()-270
dns_local_lookup()-2107: vfid=0 qname=s-0001.s-msedge.net, qtype=1, qclass=1, offset=37, map#=3 max_sz=512
dns_lookup_aa_zone()-496: vfid=0, fqdn=s-0001.s-msedge.net