Help me to understand the debug logs - Connectivity Issue

[NeerajSofat1]

Dear Friends,

I am facing the connectivity issue from 172.28.140.10 to 172.47.7.1 w.r.t port 6712.

Can you please help  e understand the issue from below debug logs ?

2024-09-18 09:44:15 id=65308 trace_id=35526 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 1
72.28.140.10:19311->172.47.7.1:6712) tun_id=0.0.0.0 from Lan-Zone. flag [S], seq 1197133717, ack 0, win 64240"
2024-09-18 09:44:15 id=65308 trace_id=35526 func=init_ip_session_common line=6020 msg="allocate a new session-2e378527"
2024-09-18 09:44:15 id=65308 trace_id=35526 func=vf_ip_route_input_common line=2612 msg="find a route: flag=00000000 gw-172.28.254.2
via wan2"
2024-09-18 09:44:15 id=65308 trace_id=35526 func=__iprope_tree_check line=528 msg="gnum-100004, use int hash, slot=35, len=13"
2024-09-18 09:44:15 id=65308 trace_id=35526 func=fw_forward_handler line=985 msg="Allowed by Policy-345:"
2024-09-18 09:44:15 id=65308 trace_id=35526 func=np6_hif_nturbo_build_vtag line=1227 msg="vtag->magic d153beef, vtag->coretag 156, vt
ag->vid 0
vtag->sip[0] 0, vtag->sip[1] 0, vtag->sip[2] 0, vtag->sip[3] 0
vtag->sport 0, vtag->mtu 1500, vtag->flags 10, vtag->np6_flag 0x280, skb->npu_flag=0xc0880"
2024-09-18 09:44:16 id=65308 trace_id=35527 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.140.10:1
9312->172.47.7.1:6712) tun_id=0.0.0.0 from Lan-Zone. flag [S], seq 2718409641, ack 0, win 64240"
2024-09-18 09:44:16 id=65308 trace_id=35527 func=init_ip_session_common line=6020 msg="allocate a new session-2e3786a6"
2024-09-18 09:44:16 id=65308 trace_id=35527 func=vf_ip_route_input_common line=2612 msg="find a route: flag=00000000 gw-172.28.254.2
via wan2"
2024-09-18 09:44:16 id=65308 trace_id=35527 func=__iprope_tree_check line=528 msg="gnum-100004, use int hash, slot=35, len=13"
2024-09-18 09:44:16 id=65308 trace_id=35527 func=fw_forward_handler line=985 msg="Allowed by Policy-345:"
2024-09-18 09:44:16 id=65308 trace_id=35527 func=np6_hif_nturbo_build_vtag line=1227 msg="vtag->magic d153beef, vtag->coretag 156, vt
ag->vid 0
vtag->sip[0] 0, vtag->sip[1] 0, vtag->sip[2] 0, vtag->sip[3] 0
vtag->sport 0, vtag->mtu 1500, vtag->flags 10, vtag->np6_flag 0x280, skb->npu_flag=0xc0880"
2024-09-18 09:44:16 id=65308 trace_id=35528 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.140.10:1
9311->172.47.7.1:6712) tun_id=0.0.0.0 from Lan-Zone. flag [S], seq 1197133717, ack 0, win 64240"
2024-09-18 09:44:16 id=65308 trace_id=35528 func=resolve_ip_tuple_fast line=5924 msg="Find an existing session, id-2e378527, original
direction"
2024-09-18 09:44:16 id=65308 trace_id=35528 func=npu_handle_session44 line=1213 msg="Trying to offloading session from Lan-Zone to wa
n2, skb.npu_flag=00000000 ses.state=04012204 ses.npu_state=0x00003094"
2024-09-18 09:44:16 id=65308 trace_id=35528 func=fw_forward_dirty_handler line=447 msg="state=04012204, state2=00000001, npu_state=00
003094"
2024-09-18 09:44:16 id=65308 trace_id=35528 func=np6_hif_nturbo_build_vtag line=1227 msg="vtag->magic d153beef, vtag->coretag 156, vt
ag->vid 0
vtag->sip[0] 0, vtag->sip[1] 0, vtag->sip[2] 0, vtag->sip[3] 0
vtag->sport 0, vtag->mtu 1500, vtag->flags 0, vtag->np6_flag 0x280, skb->npu_flag=0xc0880"
2024-09-18 09:44:17 id=65308 trace_id=35529 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.140.10:1
9312->172.47.7.1:6712) tun_id=0.0.0.0 from Lan-Zone. flag [S], seq 2718409641, ack 0, win 64240"
2024-09-18 09:44:17 id=65308 trace_id=35529 func=resolve_ip_tuple_fast line=5924 msg="Find an existing session, id-2e3786a6, original
direction"
2024-09-18 09:44:17 id=65308 trace_id=35529 func=npu_handle_session44 line=1213 msg="Trying to offloading session from Lan-Zone to wa
n2, skb.npu_flag=00000000 ses.state=04012204 ses.npu_state=0x00003094"
2024-09-18 09:44:17 id=65308 trace_id=35529 func=fw_forward_dirty_handler line=447 msg="state=04012204, state2=00000001, npu_state=00
003094"
2024-09-18 09:44:17 id=65308 trace_id=35529 func=np6_hif_nturbo_build_vtag line=1227 msg="vtag->magic d153beef, vtag->coretag 156, vt
ag->vid 0
vtag->sip[0] 0, vtag->sip[1] 0, vtag->sip[2] 0, vtag->sip[3] 0
vtag->sport 0, vtag->mtu 1500, vtag->flags 0, vtag->np6_flag 0x280, skb->npu_flag=0xc0880"
2024-09-18 09:44:18 id=65308 trace_id=35530 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.140.10:1
9311->172.47.7.1:6712) tun_id=0.0.0.0 from Lan-Zone. flag [S], seq 1197133717, ack 0, win 64240"
2024-09-18 09:44:18 id=65308 trace_id=35530 func=resolve_ip_tuple_fast line=5924 msg="Find an existing session, id-2e378527, original
direction"
2024-09-18 09:44:18 id=65308 trace_id=35530 func=npu_handle_session44 line=1213 msg="Trying to offloading session from Lan-Zone to wa
n2, skb.npu_flag=00000000 ses.state=04012204 ses.npu_state=0x00003094"
2024-09-18 09:44:18 id=65308 trace_id=35530 func=fw_forward_dirty_handler line=447 msg="state=04012204, state2=00000001, npu_state=00
003094"
2024-09-18 09:44:18 id=65308 trace_id=35530 func=np6_hif_nturbo_build_vtag line=1227 msg="vtag->magic d153beef, vtag->coretag 156, vt
ag->vid 0
vtag->sip[0] 0, vtag->sip[1] 0, vtag->sip[2] 0, vtag->sip[3] 0
vtag->sport 0, vtag->mtu 1500, vtag->flags 0, vtag->np6_flag 0x280, skb->npu_flag=0xc0880"
2024-09-18 09:44:19 id=65308 trace_id=35531 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.140.10:1
9312->172.47.7.1:6712) tun_id=0.0.0.0 from Lan-Zone. flag [S], seq 2718409641, ack 0, win 64240"
2024-09-18 09:44:19 id=65308 trace_id=35531 func=resolve_ip_tuple_fast line=5924 msg="Find an existing session, id-2e3786a6, original
direction"
2024-09-18 09:44:19 id=65308 trace_id=35531 func=npu_handle_session44 line=1213 msg="Trying to offloading session from Lan-Zone to wa
n2, skb.npu_flag=00000000 ses.state=04012204 ses.npu_state=0x00003094"
2024-09-18 09:44:19 id=65308 trace_id=35531 func=fw_forward_dirty_handler line=447 msg="state=04012204, state2=00000001, npu_state=00
003094"
2024-09-18 09:44:19 id=65308 trace_id=35531 func=np6_hif_nturbo_build_vtag line=1227 msg="vtag->magic d153beef, vtag->coretag 156, vt
ag->vid 0
vtag->sip[0] 0, vtag->sip[1] 0, vtag->sip[2] 0, vtag->sip[3] 0
vtag->sport 0, vtag->mtu 1500, vtag->flags 0, vtag->np6_flag 0x280, skb->npu_flag=0xc0880"
2024-09-18 09:44:21 id=65308 trace_id=35532 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.140.10:1
9313->172.47.7.1:6712) tun_id=0.0.0.0 from Lan-Zone. flag [S], seq 3866270571, ack 0, win 64240"
2024-09-18 09:44:21 id=65308 trace_id=35532 func=init_ip_session_common line=6020 msg="allocate a new session-2e379f0c"
2024-09-18 09:44:21 id=65308 trace_id=35532 func=vf_ip_route_input_common line=2612 msg="find a route: flag=00000000 gw-172.28.254.2
via wan2"
2024-09-18 09:44:21 id=65308 trace_id=35532 func=__iprope_tree_check line=528 msg="gnum-100004, use int hash, slot=35, len=13"
2024-09-18 09:44:21 id=65308 trace_id=35532 func=fw_forward_handler line=985 msg="Allowed by Policy-345:"
2024-09-18 09:44:21 id=65308 trace_id=35532 func=np6_hif_nturbo_build_vtag line=1227 msg="vtag->magic d153beef, vtag->coretag 156, vt
ag->vid 0
vtag->sip[0] 0, vtag->sip[1] 0, vtag->sip[2] 0, vtag->sip[3] 0
vtag->sport 0, vtag->mtu 1500, vtag->flags 10, vtag->np6_flag 0x280, skb->npu_flag=0xc0880"

Ludhiana_HO # diagnose 2024-09-18 09:44:22 id=65308 trace_id=35533 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(p
roto=6, 172.28.140.10:19311->172.47.7.1:6712) tun_id=0.0.0.0 from Lan-Zone. flag [S], seq 1197133717, ack 0, win 64240"
2024-09-18 09:44:22 id=65308 trace_id=35533 func=resolve_ip_tuple_fast line=5924 msg="Find an existing session, id-2e378527, original
direction"
2024-09-18 09:44:22 id=65308 trace_id=35533 func=npu_handle_session44 line=1213 msg="Trying to offloading session from Lan-Zone to wa
n2, skb.npu_flag=00000000 ses.state=04012204 ses.npu_state=0x00003094"
2024-09-18 09:44:22 id=65308 trace_id=35533 func=fw_forward_dirty_handler line=447 msg="state=04012204, state2=00000001, npu_state=00
003094"
2024-09-18 09:44:22 id=65308 trace_id=35533 func=np6_hif_nturbo_build_vtag line=1227 msg="vtag->magic d153beef, vtag->coretag 156, vt
ag->vid 0
vtag->sip[0] 0, vtag->sip[1] 0, vtag->sip[2] 0, vtag->sip[3] 0
vtag->sport 0, vtag->mtu 1500, vtag->flags 0, vtag->np6_flag 0x280, skb->npu_flag=0xc0880"
debug 2024-09-18 09:44:24 id=65308 trace_id=35534 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.14
0.10:19313->172.47.7.1:6712) tun_id=0.0.0.0 from Lan-Zone. flag [S], seq 3866270571, ack 0, win 64240"
2024-09-18 09:44:24 id=65308 trace_id=35534 func=resolve_ip_tuple_fast line=5924 msg="Find an existing session, id-2e379f0c, original
direction"
2024-09-18 09:44:24 id=65308 trace_id=35534 func=npu_handle_session44 line=1213 msg="Trying to offloading session from Lan-Zone to wa
n2, skb.npu_flag=00000000 ses.state=04012204 ses.npu_state=0x00003094"
2024-09-18 09:44:24 id=65308 trace_id=35534 func=fw_forward_dirty_handler line=447 msg="state=04012204, state2=00000001, npu_state=00
003094"
2024-09-18 09:44:24 id=65308 trace_id=35534 func=np6_hif_nturbo_build_vtag line=1227 msg="vtag->magic d153beef, vtag->coretag 156, vt
ag->vid 0
vtag->sip[0] 0, vtag->sip[1] 0, vtag->sip[2] 0, vtag->sip[3] 0
vtag->sport 0, vtag->mtu 1500, vtag->flags 0, vtag->np6_flag 0x280, skb->npu_flag=0xc0880"
disable

[onikloy1]

Are you using Retrofit or okhttp for your network requests? You can maybe use an http interceptor to log exceptions and errors to an analytics events service and investigate from there https://tutuapp.uno/ .

[NeerajSofat1]

Hi,

We are not using Retrofit or okhttp..

[AlexC-FTNT]

vd-root:0 received a packet(proto=6, 172.28.140.10:19313->172.47.7.1:6712) from Lan-Zone. flag [S]

>> SYN packet received, route lookup and policy match follows

msg="allocate a new session

msg="find a route gw-172.28.254.2 via wan2"

>> check next if policy allows this traffic

msg="Allowed by Policy-345:"

>> check if session can be offloaded to the NP/nTurbo

In your case it seems that offloading checks don't "pass" or the problem occurs with offloading.
Disable offloading on policy, or nTurbo globally. See if that helps the traffic pass.
Technical Tip: Nturbo functions within FortiOS

[NeerajSofat1]

Hi,

Disabling offloading/nTurbo did not helped.

[AlexC-FTNT]

If that did not help, then check the debug flow again (clear the sessions from this host after disabling). Disabling offloading should show more info in the debug flow

[Toshi_Esumi]

The source port 19313 is the app's 3rd attempt after 19311 and 19312. But at least the first 19311 attempt should have gone out through wan2 without an offload attempt. But it didn't get any reply back (SYN/ACK) from the destination. What filter did you apply to the flow debug?
In any case, the main problem should be after the packets have left from wan2. I would check the destination side if it's receiving those packets.

Toshi

[NeerajSofat1]

Hi Toshi_Esumi,

Destination side logs are attached herewith:

2024-09-19 09:44:44 id=65308 trace_id=14 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 1
72.28.140.10:46127->172.47.7.1:6712) tun_id=0.0.0.0 from wan1. flag [S], seq 2663198951, ack 0, win 64240"
2024-09-19 09:44:44 id=65308 trace_id=14 func=init_ip_session_common line=6020 msg="allocate a new session-0d07336d"
2024-09-19 09:44:44 id=65308 trace_id=14 func=vf_ip_route_input_common line=2612 msg="find a route: flag=80000000 gw-172.47.7.1 via root"
2024-09-19 09:44:44 id=65308 trace_id=14 func=__iprope_tree_check line=528 msg="gnum-100004, use int hash, slot=42, len=5"
2024-09-19 09:44:44 id=65308 trace_id=14 func=fw_local_in_handler line=609 msg="iprope_in_check() check failed on policy 0, drop"
2024-09-19 09:44:44 id=65308 trace_id=15 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.140.10:46128->172
.47.7.1:6712) tun_id=0.0.0.0 from wan1. flag [S], seq 476271427, ack 0, win 64240"
2024-09-19 09:44:44 id=65308 trace_id=15 func=init_ip_session_common line=6020 msg="allocate a new session-0d073393"
2024-09-19 09:44:44 id=65308 trace_id=15 func=vf_ip_route_input_common line=2612 msg="find a route: flag=80000000 gw-172.47.7.1 via root"
2024-09-19 09:44:44 id=65308 trace_id=15 func=__iprope_tree_check line=528 msg="gnum-100004, use int hash, slot=42, len=5"
2024-09-19 09:44:44 id=65308 trace_id=15 func=fw_local_in_handler line=609 msg="iprope_in_check() check failed on policy 0, drop"
2024-09-19 09:44:45 id=65308 trace_id=16 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.140.10:46127->172
.47.7.1:6712) tun_id=0.0.0.0 from wan1. flag [S], seq 2663198951, ack 0, win 64240"
2024-09-19 09:44:45 id=65308 trace_id=16 func=init_ip_session_common line=6020 msg="allocate a new session-0d0733bc"
2024-09-19 09:44:45 id=65308 trace_id=16 func=vf_ip_route_input_common line=2612 msg="find a route: flag=80000000 gw-172.47.7.1 via root"
2024-09-19 09:44:45 id=65308 trace_id=16 func=__iprope_tree_check line=528 msg="gnum-100004, use int hash, slot=42, len=5"
2024-09-19 09:44:45 id=65308 trace_id=16 func=fw_local_in_handler line=609 msg="iprope_in_check() check failed on policy 0, drop"
2024-09-19 09:44:45 id=65308 trace_id=17 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.140.10:46128->172
.47.7.1:6712) tun_id=0.0.0.0 from wan1. flag [S], seq 476271427, ack 0, win 64240"
2024-09-19 09:44:45 id=65308 trace_id=17 func=init_ip_session_common line=6020 msg="allocate a new session-0d0733cf"
2024-09-19 09:44:45 id=65308 trace_id=17 func=vf_ip_route_input_common line=2612 msg="find a route: flag=80000000 gw-172.47.7.1 via root"
2024-09-19 09:44:45 id=65308 trace_id=17 func=__iprope_tree_check line=528 msg="gnum-100004, use int hash, slot=42, len=5"
2024-09-19 09:44:45 id=65308 trace_id=17 func=fw_local_in_handler line=609 msg="iprope_in_check() check failed on policy 0, drop"
2024-09-19 09:44:47 id=65308 trace_id=18 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.140.10:46128->172
.47.7.1:6712) tun_id=0.0.0.0 from wan1. flag [S], seq 476271427, ack 0, win 64240"
2024-09-19 09:44:47 id=65308 trace_id=18 func=init_ip_session_common line=6020 msg="allocate a new session-0d073527"
2024-09-19 09:44:47 id=65308 trace_id=18 func=vf_ip_route_input_common line=2612 msg="find a route: flag=80000000 gw-172.47.7.1 via root"
2024-09-19 09:44:47 id=65308 trace_id=18 func=__iprope_tree_check line=528 msg="gnum-100004, use int hash, slot=42, len=5"
2024-09-19 09:44:47 id=65308 trace_id=18 func=fw_local_in_handler line=609 msg="iprope_in_check() check failed on policy 0, drop"
2024-09-19 09:44:51 id=65308 trace_id=19 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.140.10:46127->172
.47.7.1:6712) tun_id=0.0.0.0 from wan1. flag [S], seq 2663198951, ack 0, win 64240"
2024-09-19 09:44:51 id=65308 trace_id=19 func=init_ip_session_common line=6020 msg="allocate a new session-0d073742"
2024-09-19 09:44:51 id=65308 trace_id=19 func=vf_ip_route_input_common line=2612 msg="find a route: flag=80000000 gw-172.47.7.1 via root"
2024-09-19 09:44:51 id=65308 trace_id=19 func=__iprope_tree_check line=528 msg="gnum-100004, use int hash, slot=42, len=5"
2024-09-19 09:44:51 id=65308 trace_id=19 func=fw_local_in_handler line=609 msg="iprope_in_check() check failed on policy 0, drop"
2024-09-19 09:44:51 id=65308 trace_id=20 func=print_pkt_detail line=5836 msg="vd-root:0 received a packet(proto=6, 172.28.140.10:46128->172
.47.7.1:6712) tun_id=0.0.0.0 from wan1. flag [S], seq 476271427, ack 0, win 64240"
2024-09-19 09:44:51 id=65308 trace_id=20 func=init_ip_session_common line=6020 msg="allocate a new session-0d073761"
2024-09-19 09:44:51 id=65308 trace_id=20 func=vf_ip_route_input_common line=2612 msg="find a route: flag=80000000 gw-172.47.7.1 via root"
2024-09-19 09:44:51 id=65308 trace_id=20 func=__iprope_tree_check line=528 msg="gnum-100004, use int hash, slot=42, len=5"
2024-09-19 09:44:51 id=65308 trace_id=20 func=fw_local_in_handler line=609 msg="iprope_in_check() check failed on policy 0, drop"

[Toshi_Esumi]

First, 172.47.7.1 is one of this destination FGT's interfaces.
     msg= "find a route: flag=80000000 gw-172.47.7.1 via root"
What is your app, or are you, trying to establish at TCP port 6712? I don't think that's not one of FGT's listening ports.

Then, there seems to be no matching policy from wan1 to this interface. So it's simply dropped.
    msg="iprope_in_check() check failed on policy 0, drop"

Toshi

[NeerajSofat1]

Hi, yes we are trying to access FGT with port 6712 and policy is already created on both sides with all source and all destination..