VPN intermittent traffic lost, found reverse path check fail, drop

[zxcv3334444]

Hello Fortinet experts, 

We have established a site-to-site VPN between Fortigate(7.0.12) and AWS, where the client runs on AWS and the server is located on the other end of the VPN (on-premise).

client ip: 10.12.140.86 or 10.12.124.160

server ip: 10.60.98.100 listen on port 8080

fortigate port1 ip: 10.60.97.10

Fortigate interface:


Fortigate routing table:

FGVM04 # get router info routing-table all
Codes: K - kernel, C - connected, S - static, R - RIP, B - BGP
       O - OSPF, IA - OSPF inter area
       N1 - OSPF NSSA external type 1, N2 - OSPF NSSA external type 2
       E1 - OSPF external type 1, E2 - OSPF external type 2
       i - IS-IS, L1 - IS-IS level-1, L2 - IS-IS level-2, ia - IS-IS inter area
       * - candidate default

Routing table for VRF=0
S*      0.0.0.0/0 [10/0] via 10.60.97.1, port1, [1/0]
S       10.12.0.0/16 [10/0] via aws-vpn-1 tunnel 52.11.17.158, [1/2]
                     [10/0] via aws-vpn-2 tunnel 52.43.39.105, [1/2]
...
C       10.60.0.0/18 is directly connected, port3
C       10.60.97.0/24 is directly connected, port1
S       169.254.122.x/32 [5/0] via aws-vpn-1 tunnel 52.11.17.158, [1/0]
C       169.254.122.x/32 is directly connected, aws-vpn-1
S       169.254.171.x/32 [5/0] via aws-vpn-2 tunnel 52.43.39.105, [1/0]
C       169.254.171.x/32 is directly connected, aws-vpn-2

FGVM04 # get router info routing-table details 10.60.98.100

Routing table for VRF=0
Routing entry for 0.0.0.0/0
  Known via "static", distance 10, metric 0, best
  * 10.60.97.1, via port1

Most of the time, the connection works well, but occasionally there is a problem with connection timeout on the client side. We want to further investigate why the connection timeout occurs.

Our request flow looks like :

client <-> VPN(AWS & fortigate) <-> server

More detailed :

client <-> fortigate(aws-vpn-1 or aws-vpn-2) <-> fortigate(port1) -> server

To observe the request process in Fortigate, we used the diag debug flow command to check, the following are what we found:

Client 10.12.140.86 -> Server 10.60.98.100:8080, traffic received from aws-vpn-2, through SNAT converted to fortigate port1 IP 10.60.97.10, then forwarded to Server.

To be more specific:

Client 10.12.140.86 -> fortigate(aws-vpn-2) -- SNAT --> fortigate(port1, 10.60.97.10) -> Server (10.60.98.100)

2024-03-19 23:18:41 id=20085 trace_id=25752 func=print_pkt_detail line=5844 msg="vd-root:0 received a packet(proto=6, 10.12.140.86:31003->10.60.98.100:8080) tun_id=52.43.39.105 from aws-vpn-2. flag [S], seq 210231136, ack 0, win 62727"
2024-03-19 23:18:41 id=20085 trace_id=25752 func=init_ip_session_common line=6023 msg="allocate a new session-5389f8ac, tun_id=52.43.39.105"
2024-03-19 23:18:41 id=20085 trace_id=25752 func=vf_ip_route_input_common line=2605 msg="find a route: flag=00000000 gw-10.60.97.1 via port1"
2024-03-19 23:18:41 id=20085 trace_id=25752 func=get_new_addr line=1221 msg="find SNAT: IP-10.60.97.10(from IPPOOL), port-31003"
2024-03-19 23:18:41 id=20085 trace_id=25752 func=fw_forward_handler line=881 msg="Allowed by Policy-3: SNAT"
2024-03-19 23:18:41 id=20085 trace_id=25752 func=__ip_session_run_tuple line=3470 msg="SNAT 10.12.140.86->10.60.97.10:31003"

Server 10.60.98.100:8080 -> Client 10.12.140.86, the server returns packets to Fortigate port1, performs DNAT back to the original client IP, and then goes back through aws-vpn-2.

To be more specific:

Server (10.60.98.100) -> fortigate(port1, 10.60.97.10) -- DNAT --> fortigate(aws-vpn-2) -> Client 10.12.140.86

2024-03-19 23:18:41 id=20085 trace_id=25753 func=print_pkt_detail line=5844 msg="vd-root:0 received a packet(proto=6, 10.60.98.100:8080->10.60.97.10:31003) tun_id=0.0.0.0 from port1. flag [S.], seq 185779377, ack 210231137, win 65160"
2024-03-19 23:18:41 id=20085 trace_id=25753 func=resolve_ip_tuple_fast line=5930 msg="Find an existing session, id-5389f8ac, reply direction"
2024-03-19 23:18:41 id=20085 trace_id=25753 func=__ip_session_run_tuple line=3483 msg="DNAT 10.60.97.10:31003->10.12.140.86:31003"
2024-03-19 23:18:41 id=20085 trace_id=25753 func=vf_ip_route_input_common line=2605 msg="find a route: flag=00000000 gw-52.43.39.105 via aws-vpn-2"
2024-03-19 23:18:41 id=20085 trace_id=25753 func=npu_handle_session44 line=1182 msg="Trying to offloading session from port1 to aws-vpn-2, skb.npu_flag=00000400 ses.state=00000200 ses.npu_state=0x00000100"
2024-03-19 23:18:41 id=20085 trace_id=25753 func=fw_forward_dirty_handler line=410 msg="state=00000200, state2=00000000, npu_state=00000100"
2024-03-19 23:18:41 id=20085 trace_id=25753 func=ip_session_core_in line=6547 msg="dir-1, tun_id=52.43.39.105"
2024-03-19 23:18:41 id=20085 trace_id=25753 func=ipsecdev_hard_start_xmit line=669 msg="enter IPSec interface aws-vpn-2, tun_id=52.43.39.105"
2024-03-19 23:18:41 id=20085 trace_id=25753 func=_do_ipsecdev_hard_start_xmit line=229 msg="output to IPSec tunnel aws-vpn-2"
2024-03-19 23:18:41 id=20085 trace_id=25753 func=esp_output4 line=844 msg="IPsec encrypt/auth"
2024-03-19 23:18:41 id=20085 trace_id=25753 func=ipsec_output_finish line=544 msg="send to 10.60.97.1 via intf-port1"

This above is the situation we expected, but during the client's connection timeout, we observed the following strange errors "reverse path check fail, drop".

2024-03-20 19:05:58 id=20085 trace_id=40148 func=print_pkt_detail line=5844 msg="vd-root:0 received a packet(proto=6, 10.12.124.160:15815->10.60.98.100:8080) tun_id=52.43.39.105 from aws-vpn-2. flag [S], seq 3609468744, ack 0, win 62727"
2024-03-20 19:05:58 id=20085 trace_id=40148 func=init_ip_session_common line=6023 msg="allocate a new session-5397abec, tun_id=52.43.39.105"
2024-03-20 19:05:58 id=20085 trace_id=40148 func=ip_route_input_slow line=2267 msg="reverse path check fail, drop"
2024-03-20 19:05:58 id=20085 trace_id=40148 func=ip_session_handle_no_dst line=6109 msg="trace"

2024-03-20 19:05:58 id=20085 trace_id=40149 func=print_pkt_detail line=5844 msg="vd-root:0 received a packet(proto=6, 10.12.124.160:59380->10.60.98.100:8080) tun_id=52.43.39.105 from aws-vpn-2. flag [S], seq 2250561400, ack 0, win 62727"
2024-03-20 19:05:58 id=20085 trace_id=40149 func=init_ip_session_common line=6023 msg="allocate a new session-5397abed, tun_id=52.43.39.105"
2024-03-20 19:05:58 id=20085 trace_id=40149 func=ip_route_input_slow line=2267 msg="reverse path check fail, drop"
2024-03-20 19:05:58 id=20085 trace_id=40149 func=ip_session_handle_no_dst line=6109 msg="trace"

2024-03-20 19:05:58 id=20085 trace_id=40150 func=print_pkt_detail line=5844 msg="vd-root:0 received a packet(proto=6, 10.12.124.160:64837->10.60.98.100:8080) tun_id=52.43.39.105 from aws-vpn-2. flag [S], seq 844225016, ack 0, win 62727"
2024-03-20 19:05:58 id=20085 trace_id=40150 func=init_ip_session_common line=6023 msg="allocate a new session-5397abee, tun_id=52.43.39.105"
2024-03-20 19:05:58 id=20085 trace_id=40150 func=ip_route_input_slow line=2267 msg="reverse path check fail, drop"
2024-03-20 19:05:58 id=20085 trace_id=40150 func=ip_session_handle_no_dst line=6109 msg="trace"

2024-03-20 19:06:00 id=20085 trace_id=40151 func=print_pkt_detail line=5844 msg="vd-root:0 received a packet(proto=6, 10.12.124.160:3360->10.60.98.100:8080) tun_id=52.43.39.105 from aws-vpn-2. flag [S], seq 2319190026, ack 0, win 62727"
2024-03-20 19:06:00 id=20085 trace_id=40151 func=init_ip_session_common line=6023 msg="allocate a new session-5397ac1f, tun_id=52.43.39.105"
2024-03-20 19:06:00 id=20085 trace_id=40151 func=ip_route_input_slow line=2267 msg="reverse path check fail, drop"
2024-03-20 19:06:00 id=20085 trace_id=40151 func=ip_session_handle_no_dst line=6109 msg="trace"

This error disappeared soon after a few second. I would like to know why this error occurred, after all, we have been operating normally for several days, and only a few connections have this error. 

Thanks for your time. Appreciate for any feedback.

[AEK · Accepted solution]

Hello

While the issue is occurring, do you still see the below entry as is in the routing table?

S        10.12.0.0/16 [10/0] via aws-vpn-1 tunnel x.x.x.x, [1/2]
                      [10/0] via aws-vpn-2 tunnel y.y.y.y, [1/2]

[hbac · Accepted solution]

@zxcv3334444,

Yes, static route will be removed from the routing table if the tunnel goes down. 

Regards, 

[AEK · Accepted solution]

Hello

While the issue is occurring, do you still see the below entry as is in the routing table?

S        10.12.0.0/16 [10/0] via aws-vpn-1 tunnel x.x.x.x, [1/2]
                      [10/0] via aws-vpn-2 tunnel y.y.y.y, [1/2]

[jimsu]

Thanks for your comment.

[AEK]

You're welcome @jimsu , in fact as per my knowledge RPF is due to missing route. In this case the route through aws-vpn-2 is probably removed at certain times.

[zxcv3334444]

Hi AEK,

I can not confirm is the entry still there, but I can sure no one add/delete any route in route table unless fortigate delete the entry by itself.

[hbac]

Hi @zxcv3334444,

Do you have link monitor or performance SLA configured? Is the tunnel status up when the issue occurs? 

Regards, 

[zxcv3334444]

I didn't configure link monitor & performance SLA. When I checked VPN events during the issue time (2024/03/20 19:05:58), it looks like VPN tunnel worked fine.

[zxcv3334444]

Do you think this tunnel down message at (2024/03/20 19:05:56) could be the root cause?

[hbac · Accepted solution]

@zxcv3334444,

Yes, static route will be removed from the routing table if the tunnel goes down. 

Regards, 

[AEK · Accepted solution]

Time is matching.