Bug 259864 - PF periodically drops packets that belong to established session, thus stalling the session
Summary: PF periodically drops packets that belong to established session, thus stalli...
Status: New
Alias: None
Product: Base System
Classification: Unclassified
Component: kern (show other bugs)
Version: 12.2-RELEASE
Hardware: Any Any
: --- Affects Only Me
Assignee: freebsd-bugs (Nobody)
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2021-11-15 18:22 UTC by emz
Modified: 2021-11-23 22:38 UTC (History)
1 user (show)

See Also:

Attachments
PF config from the 91.206.242.1 (18.00 KB, text/plain)
2021-11-15 19:21 UTC, emz 		no flags Details
View All Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description emz 2021-11-15 18:22:54 UTC 
PF periodically drops  packets of established session, stalling the session.

Here's an example of such session.

Flow:

62.109.28.82 <---> WAN <---> 91.206.242.1 <---> 91.206.242.9

Client is downloading a 14 MB file via HTTP, 91.206.242.9 is server, 62.109.28.82 is a client. Packet dumps and PF debug log is taken on 91.206.242.1. Since the file is rather large, only the stalled end of the session is displayed. However, PF debug massages for this session are displayed for the entire session. Notice the ACK 15333017 that never makes it to the destination. It's also weird, but there's no PF state mismatches or error for the packet containing the ack itself. Both captures ends when the session is already stalled (final RST exchange is out of the scope), by Ctrl-Break.

Also, the tcpdump on the default pflog0 device is silent for such packets.

Why I'm sure this is related to the PF: because it isn't reproducing with the packet filter switched off.

Outer interface:
===Cut===
[...]
12:16:37.545209 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15291025, win 1652, options [nop,nop,TS val 2720237534 ecr 2777961105], length 0
12:16:37.545278 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15296817, win 1652, options [nop,nop,TS val 2720237534 ecr 2777961105], length 0
12:16:37.545436 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15304057, win 1652, options [nop,nop,TS val 2720237535 ecr 2777961105], length 0
12:16:37.545985 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15308401, win 1652, options [nop,nop,TS val 2720237535 ecr 2777961105], length 0
12:16:37.546086 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15314193, win 1652, options [nop,nop,TS val 2720237536 ecr 2777961105], length 0
12:16:37.563993 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15319985, win 1652, options [nop,nop,TS val 2720237554 ecr 2777961125], length 0
12:16:37.564063 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15324329, win 1652, options [nop,nop,TS val 2720237555 ecr 2777961125], length 0
12:16:37.564445 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15327225, win 1652, options [nop,nop,TS val 2720237556 ecr 2777961135], length 0
12:16:37.564696 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15331569, win 1652, options [nop,nop,TS val 2720237557 ecr 2777961135], length 0
12:16:37.607557 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15333017, win 1652, options [nop,nop,TS val 2720237598 ecr 2777961135], length 0
12:16:37.768865 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777961365 ecr 2720237530], length 1448: HTTP
12:16:37.797072 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15333017, win 1652, options [nop,nop,TS val 2720237787 ecr 2777961135,nop,nop,sack 1 {15260617:15262065}], length 0
12:16:38.026968 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777961625 ecr 2720237530], length 1448: HTTP
12:16:38.044806 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15333017, win 1652, options [nop,nop,TS val 2720238045 ecr 2777961135,nop,nop,sack 1 {15260617:15262065}], length 0
12:16:38.349576 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777961945 ecr 2720237530], length 1448: HTTP
12:16:38.385464 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15333017, win 1652, options [nop,nop,TS val 2720238368 ecr 2777961135,nop,nop,sack 1 {15260617:15262065}], length 0
12:16:38.798092 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777962395 ecr 2720237530], length 1448: HTTP
12:16:38.826845 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15333017, win 1652, options [nop,nop,TS val 2720238816 ecr 2777961135,nop,nop,sack 1 {15260617:15262065}], length 0
12:16:39.477080 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777963075 ecr 2720237530], length 1448: HTTP
12:16:39.510688 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15333017, win 1652, options [nop,nop,TS val 2720239497 ecr 2777961135,nop,nop,sack 1 {15260617:15262065}], length 0
12:16:40.643251 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777964235 ecr 2720237530], length 1448: HTTP
12:16:40.673700 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15333017, win 1652, options [nop,nop,TS val 2720240661 ecr 2777961135,nop,nop,sack 1 {15260617:15262065}], length 0
12:16:42.759423 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777966355 ecr 2720237530], length 1448: HTTP
12:16:42.790404 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15333017, win 1652, options [nop,nop,TS val 2720242777 ecr 2777961135,nop,nop,sack 1 {15260617:15262065}], length 0
12:16:46.809355 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777970405 ecr 2720237530], length 1448: HTTP
12:16:46.840079 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15333017, win 1652, options [nop,nop,TS val 2720246827 ecr 2777961135,nop,nop,sack 1 {15260617:15262065}], length 0
12:16:54.692330 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777978285 ecr 2720237530], length 1448: HTTP
12:16:54.723206 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15333017, win 1652, options [nop,nop,TS val 2720254710 ecr 2777961135,nop,nop,sack 1 {15260617:15262065}], length 0
12:17:09.157762 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [F.], seq 150, ack 15333017, win 1652, options [nop,nop,TS val 2720269144 ecr 2777961135], length 0
12:17:09.377353 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [F.], seq 150, ack 15333017, win 1652, options [nop,nop,TS val 2720269378 ecr 2777961135], length 0
^C
===Cut===

Innter interface:
===Cut===
[...]
12:16:37.537666 IP 62.109.28.82.52982 > 91.206.242.9.8080: Flags [.], ack 15260617, win 1652, options [nop,nop,TS val 2720237530 ecr 2777961105], length 0
12:16:37.538251 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15324329:15325777, ack 150, win 4107, options [nop,nop,TS val 2777961135 ecr 2720237529], length 1448: HTTP
12:16:37.538266 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15325777:15327225, ack 150, win 4107, options [nop,nop,TS val 2777961135 ecr 2720237529], length 1448: HTTP
12:16:37.538274 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15327225:15328673, ack 150, win 4107, options [nop,nop,TS val 2777961135 ecr 2720237530], length 1448: HTTP
12:16:37.538282 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15328673:15330121, ack 150, win 4107, options [nop,nop,TS val 2777961135 ecr 2720237530], length 1448: HTTP
12:16:37.538312 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15330121:15331569, ack 150, win 4107, options [nop,nop,TS val 2777961135 ecr 2720237530], length 1448: HTTP
12:16:37.538328 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15331569:15333017, ack 150, win 4107, options [nop,nop,TS val 2777961135 ecr 2720237530], length 1448: HTTP
12:16:37.768852 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777961365 ecr 2720237530], length 1448: HTTP
12:16:38.026950 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777961625 ecr 2720237530], length 1448: HTTP
12:16:38.349553 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777961945 ecr 2720237530], length 1448: HTTP
12:16:38.798075 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777962395 ecr 2720237530], length 1448: HTTP
12:16:39.477063 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777963075 ecr 2720237530], length 1448: HTTP
12:16:40.643234 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777964235 ecr 2720237530], length 1448: HTTP
12:16:42.759404 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777966355 ecr 2720237530], length 1448: HTTP
12:16:46.809338 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777970405 ecr 2720237530], length 1448: HTTP
12:16:54.692313 IP 91.206.242.9.8080 > 62.109.28.82.52982: Flags [.], seq 15260617:15262065, ack 150, win 4107, options [nop,nop,TS val 2777978285 ecr 2720237530], length 1448: HTTP
^C
===Cut===

PF debug:
===Cut===
Nov 15 12:16:25 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1424 modulator=0 wscale=7] [lo=782592198 high=782801846 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=782670390 len=0 ackskew=-78192 pkts=394:1710 dir=in,fwd
Nov 15 12:16:25 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:25 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1424 modulator=0 wscale=7] [lo=782592198 high=782801846 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=782674734 len=0 ackskew=-82536 pkts=394:1710 dir=in,fwd
Nov 15 12:16:25 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:25 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1424 modulator=0 wscale=7] [lo=782592198 high=782801846 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=782684870 len=0 ackskew=-92672 pkts=394:1710 dir=in,fwd
Nov 15 12:16:25 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:25 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1424 modulator=0 wscale=7] [lo=782592198 high=782801846 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=782690662 len=0 ackskew=-98464 pkts=394:1710 dir=in,fwd
Nov 15 12:16:25 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:25 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1424 modulator=0 wscale=7] [lo=782592198 high=782801846 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=782692110 len=0 ackskew=-99912 pkts=394:1710 dir=in,fwd
Nov 15 12:16:25 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:32 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1424 modulator=0 wscale=7] [lo=786691630 high=786937614 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=786766926 len=0 ackskew=-75296 pkts=1069:4605 dir=in,fwd
Nov 15 12:16:32 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:32 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1424 modulator=0 wscale=7] [lo=786691630 high=786937614 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=786788646 len=0 ackskew=-97016 pkts=1072:4636 dir=in,fwd
Nov 15 12:16:32 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:32 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1424 modulator=0 wscale=7] [lo=786691630 high=786937614 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=786792990 len=0 ackskew=-101360 pkts=1072:4636 dir=in,fwd
Nov 15 12:16:32 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:32 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1424 modulator=0 wscale=7] [lo=786691630 high=786937614 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=786804574 len=0 ackskew=-112944 pkts=1072:4636 dir=in,fwd
Nov 15 12:16:32 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:32 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1424 modulator=0 wscale=7] [lo=786691630 high=786937614 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=786810366 len=0 ackskew=-118736 pkts=1072:4636 dir=in,fwd
Nov 15 12:16:32 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:32 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1424 modulator=0 wscale=7] [lo=786691630 high=786937614 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=786829190 len=0 ackskew=-137560 pkts=1072:4636 dir=in,fwd
Nov 15 12:16:32 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:34 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1494 modulator=0 wscale=7] [lo=789374774 high=789626822 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=789444278 len=0 ackskew=-69504 pkts=1494:6459 dir=in,fwd
Nov 15 12:16:34 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795483886 len=0 ackskew=-68056 pkts=2452:10662 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795486782 len=0 ackskew=-70952 pkts=2452:10662 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4pf: state reuse  TCP outA wire:  seq=1741467272 (1741467272) ack=795496918 len=0 ackskew=-81088 pkts=2452:10662 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: 192.168.0.247pf: State failure on:     3   |    
--
Nov 15 12:16:37 gw0 kernel:  wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795502710 len=0 ackskew=-86880 pkts=2452:10662 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795507054 len=0 ackskew=-91224 pkts=2452:10668 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795511398 len=0 ackskew=-95568 pkts=2452:10668 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795517190 len=0 ackskew=-101360 pkts=2452:10668 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795524430 len=0 ackskew=-108600 pkts=2452:10668 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795528774 len=0 ackskew=-112944 pkts=2452:10668 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795534566 len=0 ackskew=-118736 pkts=2452:10668 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795540358 len=0 ackskew=-124528 pkts=2452:10668 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795544702 len=0 ackskew=-128872 pkts=2452:10668 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795547598 len=0 ackskew=-131768 pkts=2452:10668 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795551942 len=0 ackskew=-136112 pkts=2452:10668 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795415830 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-137560 pkts=2452:10668 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:37 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10669 dir=in,fwd
Nov 15 12:16:37 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:38 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10670 dir=in,fwd
Nov 15 12:16:38 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:38 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10671 dir=in,fwd
Nov 15 12:16:38 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:39 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10672 dir=in,fwd
Nov 15 12:16:39 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:39 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10673 dir=in,fwd
Nov 15 12:16:39 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:40 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10674 dir=in,fwd
Nov 15 12:16:40 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:42 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10675 dir=in,fwd
Nov 15 12:16:42 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:46 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10676 dir=in,fwd
Nov 15 12:16:46 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:16:54 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10677 dir=in,fwd
Nov 15 12:16:54 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:17:09 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 FA seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10677 dir=in,fwd
Nov 15 12:17:09 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:17:09 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 FA seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10677 dir=in,fwd
Nov 15 12:17:09 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:17:09 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 FA seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10677 dir=in,fwd
Nov 15 12:17:09 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:17:10 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 FA seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10677 dir=in,fwd
Nov 15 12:17:10 gw0 kernel: pf: State failure on:     3   |    
Nov 15 12:17:10 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467273) ack=795553390 len=0 ackskew=-70952 pkts=2452:10678 dir=in,fwd
Nov 15 12:17:10 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:17:11 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 FA seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10678 dir=in,fwd
Nov 15 12:17:11 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:17:13 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 FA seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10678 dir=in,fwd
Nov 15 12:17:13 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:17:16 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 FA seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10678 dir=in,fwd
Nov 15 12:17:16 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:17:24 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 FA seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10678 dir=in,fwd
Nov 15 12:17:24 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:17:25 gw0 kernel: pf: BAD state: pf: OK ICMP 5:1 TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6192.168.0.248 -> 192.168.0.230 state: TCP out wire: 192.168.0.230:3340 192.168.11.4] 4:4 A seq=1741467272 (1741467273) ack=795553390 len=0 ackskew=-70952 pkts=2452:10679 dir=in,fwd
Nov 15 12:17:25 gw0 kernel: :59016pf: State failure on:     3   |    
--
Nov 15 12:17:39 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 FA seq=1741467272 (1741467272) ack=795553390 len=0 ackskew=-70952 pkts=2452:10679 dir=in,fwd
Nov 15 12:17:39 gw0 kernel: pf: State failure on:     3   |    
--
Nov 15 12:17:41 gw0 kernel: pf: BAD state: TCP in wire: 62.109.28.82:52982 91.206.242.9:8080 stack: - [lo=1741467272 high=1741730120 win=1652 modulator=0 wscale=7] [lo=795482438 high=795692446 win=4107 modulator=0 wscale=6] 4:4 A seq=1741467272 (1741467273) ack=795553390 len=0 ackskew=-70952 pkts=2452:10680 dir=in,fwd
Nov 15 12:17:41 gw0 kernel: pf: State failure on:     3   |    
===Cut===

Please let me know if full session capture is needed, can recapture and attach as gzipped files.
Comment 1 Kristof Provost freebsd_committer freebsd_triage 2021-11-15 18:29:08 UTC 
Please attach full ruleset as well as captures on both sides of the pf system, and a full description of the network layout.
Comment 2 emz 2021-11-15 19:18:04 UTC 
File limit doesn't allow to attach the captures directly, so I've made them available on a publicly reachable web-server:

https://files2.enazadev.ru/stub-data/full-session.zip

This archive contains full session that was stalled, 91.206.242.9:8080 -> 62.109.28.82:37086, which shows that ACK 9184665 (packet no. 7721 in the outer capture) never makes it out of the 91.206.242.1.

And 91.206.242.1 and .9 are in the same attached network, so there's no possibility that packet got forwarded to some other interface.
Comment 3 emz 2021-11-15 19:21:08 UTC 
Created attachment 229523 [details]
PF config from the 91.206.242.1

Attached a PF config from the system where the captures were taken.
Comment 4 emz 2021-11-15 19:25:43 UTC 
Network layout:

WAN <---> (vlan11/188.234.141.201/30)PF host(vlan2/91.206.242.1) <---91.206.242.0/24---> (vlan2/91.206.242.9) Web Server

ifconfigs:

[root@gw0:pf/pr]# ifconfig vlan11
vlan11: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
        options=600703<RXCSUM,TXCSUM,TSO4,TSO6,LRO,RXCSUM_IPV6,TXCSUM_IPV6>
        ether 00:25:90:06:b7:9f
        inet 188.234.141.201/30 broadcast 188.234.141.203
        groups: vlan
        vlan: 11 vlanpcp: 0 parent interface: igb1
        media: Ethernet autoselect (1000baseT <full-duplex>)
        status: active
        nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
[root@gw0:pf/pr]# ifconfig vlan2
vlan2: flags=8943<UP,BROADCAST,RUNNING,PROMISC,SIMPLEX,MULTICAST> metric 0 mtu 1500
        options=600703<RXCSUM,TXCSUM,TSO4,TSO6,LRO,RXCSUM_IPV6,TXCSUM_IPV6>
        ether 00:25:90:06:b7:9f
        inet 91.206.242.1/28 broadcast 91.206.242.15
        inet 91.206.242.5/28 broadcast 91.206.242.15
        inet 91.206.242.12/28 broadcast 91.206.242.15 vhid 3
        inet 91.206.242.8/28 broadcast 91.206.242.15
        groups: vlan
        carp: MASTER vhid 3 advbase 1 advskew 100
        vlan: 2 vlanpcp: 0 parent interface: igb1
        media: Ethernet autoselect (1000baseT <full-duplex>)
        status: active
        nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>

Parent interface:

igb1: flags=8943<UP,BROADCAST,RUNNING,PROMISC,SIMPLEX,MULTICAST> metric 0 mtu 1500
        options=e527bb<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,TSO4,TSO6,LRO,WOL_MAGIC,VLAN_HWFILTER,VLAN_HWTSO,RXCSUM_IPV6,TXCSUM_IPV6>
        ether 00:25:90:06:b7:9f
        inet 192.168.0.248/24 broadcast 192.168.0.255
        inet 192.168.0.246/24 broadcast 192.168.0.255 vhid 1
        inet 192.168.0.254/32 broadcast 192.168.0.254
        carp: MASTER vhid 1 advbase 1 advskew 100
        media: Ethernet autoselect (1000baseT <full-duplex>)
        status: active
        nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
Comment 5 Kristof Provost freebsd_committer freebsd_triage 2021-11-23 22:38:00 UTC 
I've managed to spend a little time looking at this, and I am very confused.

When we see the error messages pf rejects the packet because the acknowledgement number is too far out of the window it thinks the TCP session got to.
However, it looks like it stopped updating the ack window some time ago, and I have no idea why it'd do that. The packets that should have updated it passed through just fine.

Is this 100% reproducible for this setup, or does it only happen occasionally? If so, how often? When did this problem start happening (I don't think we've touched any of the relevant code any time recently.)?