packet loss between interfaces on the router

From: Eugene M. Zheganin <eugene_at_zhegan.in>
Date: Mon, 15 Nov 2021 02:14:26 +0500
Hello,

I'm using FreeBSD 12.2 as a router and I'm kinda stuck investigation an 
issue: TCP sessions frequently stall when the several ACK packets are 
somehow dropped instide the stack. The most weird thing that seems like 
all of them are suddenly dropped (client in the outer world is 
downloading a file, downloading stalls and never reinitializes, see 
below why).

Same host, different interfaces, showing the session stuck moment, from 
last successfully received ACK.

62.109.28.82 downloads the file from 91.206.242.9, using HTTP.

outer interface:

===Cut===

[...]

02:01:53.442193 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14468417, win 1692, options [nop,nop,TS val 2683353443 ecr 
1549922800], length 0
02:01:53.443350 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14517649:14519097, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443484 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14519097:14520545, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443495 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14520545:14521993, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443598 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14521993:14523441, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443613 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14523441:14524889, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443622 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14524889:14526337, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443638 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14526337:14527785, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443650 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14527785:14529233, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443662 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14529233:14530681, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443676 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14530681:14532129, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443688 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14532129:14533577, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443704 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14533577:14535025, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443719 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14535025:14536473, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443734 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14536473:14537921, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443750 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14537921:14539369, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443760 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14539369:14540817, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.449897 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14474209, win 1782, options [nop,nop,TS val 2683353451 ecr 
1549922810], length 0
02:01:53.451284 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14487241, win 1714, options [nop,nop,TS val 2683353452 ecr 
1549922810], length 0
02:01:53.458259 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14494481, win 1774, options [nop,nop,TS val 2683353459 ecr 
1549922818], length 0
02:01:53.459134 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14503169, win 1788, options [nop,nop,TS val 2683353460 ecr 
1549922818], length 0
02:01:53.459687 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14508961, win 1788, options [nop,nop,TS val 2683353461 ecr 
1549922818], length 0
02:01:53.467738 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14533577, win 1692, options [nop,nop,TS val 2683353469 ecr 
1549922818], length 0
02:01:53.475246 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14540817, win 1774, options [nop,nop,TS val 2683353476 ecr 
1549922828], length 0
02:01:53.709627 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549923099 ecr 2683353443], length 1448: HTTP
02:01:53.727598 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14540817, win 1788, options [nop,nop,TS val 2683353729 ecr 
1549922828,nop,nop,sack 1 {14468417:14469865}], length 0
02:01:54.028543 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549923418 ecr 2683353443], length 1448: HTTP
02:01:54.046545 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14540817, win 1788, options [nop,nop,TS val 2683354048 ecr 
1549922828,nop,nop,sack 1 {14468417:14469865}], length 0
02:01:54.478654 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549923871 ecr 2683353443], length 1448: HTTP
02:01:54.496679 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14540817, win 1788, options [nop,nop,TS val 2683354498 ecr 
1549922828,nop,nop,sack 1 {14468417:14469865}], length 0
02:01:55.198593 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549924589 ecr 2683353443], length 1448: HTTP
02:01:55.216598 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14540817, win 1788, options [nop,nop,TS val 2683355218 ecr 
1549922828,nop,nop,sack 1 {14468417:14469865}], length 0
02:01:56.358617 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549925750 ecr 2683353443], length 1448: HTTP
02:01:56.376583 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14540817, win 1788, options [nop,nop,TS val 2683356378 ecr 
1549922828,nop,nop,sack 1 {14468417:14469865}], length 0
02:01:58.498505 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549927888 ecr 2683353443], length 1448: HTTP
02:01:58.516397 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14540817, win 1788, options [nop,nop,TS val 2683358517 ecr 
1549922828,nop,nop,sack 1 {14468417:14469865}], length 0
02:02:02.538536 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549931928 ecr 2683353443], length 1448: HTTP
02:02:02.556439 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14540817, win 1788, options [nop,nop,TS val 2683362557 ecr 
1549922828,nop,nop,sack 1 {14468417:14469865}], length 0
^C

===Cut===

inner interface:

===Cut===

02:01:53.442208 IP 62.109.28.82.39690 > 91.206.242.9.8080: Flags [.], 
ack 14468417, win 1692, options [nop,nop,TS val 2683353443 ecr 
1549922800], length 0
02:01:53.443339 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14517649:14519097, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443467 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14519097:14520545, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443488 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14520545:14521993, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443590 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14521993:14523441, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443603 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14523441:14524889, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443616 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14524889:14526337, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443629 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14526337:14527785, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443643 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14527785:14529233, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443655 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14529233:14530681, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443670 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14530681:14532129, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443681 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14532129:14533577, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443695 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14533577:14535025, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443710 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14535025:14536473, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443726 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14536473:14537921, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443742 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14537921:14539369, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.443753 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14539369:14540817, ack 150, win 4107, options [nop,nop,TS val 
1549922828 ecr 2683353443], length 1448: HTTP
02:01:53.709604 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549923099 ecr 2683353443], length 1448: HTTP
02:01:54.028525 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549923418 ecr 2683353443], length 1448: HTTP
02:01:54.478640 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549923871 ecr 2683353443], length 1448: HTTP
02:01:55.198574 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549924589 ecr 2683353443], length 1448: HTTP
02:01:56.358594 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549925750 ecr 2683353443], length 1448: HTTP
02:01:58.498487 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549927888 ecr 2683353443], length 1448: HTTP
02:02:02.538521 IP 91.206.242.9.8080 > 62.109.28.82.39690: Flags [.], 
seq 14468417:14469865, ack 150, win 4107, options [nop,nop,TS val 
1549931928 ecr 2683353443], length 1448: HTTP
^C

===Cut===

Here  you can see that the ACK no. 14540817 never made it to the target, 
despite several retransmissions ! Cannot relly undertsand the latter. 
And yup, thats why downloading cannor regain and contunue.

The host is running PF as a packet filter, several dozens of rules. I 
disable the scrub on outer interface (since the lost packet wasn'ta  
fragment, I was sceptical about it, and it doesn't help indeed).

Further stuff:

- tcpdump -netti pflog0 host 62.109.28.82 is silent about PF packet drops.

- netstat -idb shows output error counter at the same value.

- pfctl -s info:

[root_at_gw0:/var/log]# pfctl -s info
Status: Enabled for 0 days 00:39:51           Debug: Urgent

State Table                          Total             Rate
   current entries                   118209
   searches                        86578020        36210.0/s
   inserts                         15887667         6644.8/s
   removals                        15769683         6595.4/s
Counters
   match                           29150209        12191.6/s
   bad-offset                             0            0.0/s
   fragment                               0            0.0/s
   short                                  0            0.0/s
   normalize                             21            0.0/s
   memory                                 0            0.0/s
   bad-timestamp                          0            0.0/s
   congestion                             0            0.0/s
   ip-option                             50            0.0/s
   proto-cksum                            1            0.0/s
   state-mismatch                      5319            2.2/s
   state-insert                           1            0.0/s
   state-limit                            0            0.0/s
   src-limit                              0            0.0/s
   synproxy                               0            0.0/s
   map-failed                             0            0.0/s


Thanks.

Eugene.
Received on Sun Nov 14 2021 - 21:14:26 UTC

Original text of this message