On 2007-Feb-17 13:39:06 +1100, Peter Jeremy <peter@turion.vk2pj.dyndns.org>
wrote:
>I've recently upgraded my home firewall from FreeBSD 5.4 (IPfilter
>v3.4.35) to FreeBSD 6.2-RELEASE (IPfilter v4.1.13) and am now having
>problems with IPfilter randomly blocking packets on both the internal
>and external interfaces.
I've done some more investigating and this appears to be related to
the "keep state"+window-scaling bugs that other people have mentioned:
FreeBSD 6.x uses window-scaling by default.
I've tried taking the ip_state.c fixes from FreeBSD -current but this
has not solved the problems. I have found what appear to be two
distinct symptoms.
Part of the problem is that FreeBSD is re-using source ports more
frequently than IPfilter can handle, but since the TCP standard allows
port re-use after 2 minutes, why is IPfilter blocking the following?
In both cases, there is more than 3 minutes between the socket being
cleanly torn down and the reuse attempt. "ipfstat -t" does not show
any state being retained after the teardown.
08:03:47.122179 IP 192.168.234.1.22 > 192.168.234.64.50502: P
434039153:434039281(128) ack 2055586084 win 33304 <nop,nop,timestamp 2215673
58307606>
08:03:47.122636 IP 192.168.234.64.50502 > 192.168.234.1.22: P
2055586084:2055586116(32) ack 434039281 win 33304 <nop,nop,timestamp 58307614
2215673>
08:03:47.122694 IP 192.168.234.64.50502 > 192.168.234.1.22: F
2055586116:2055586116(0) ack 434039281 win 33304 <nop,nop,timestamp 58307615
2215673>
08:03:47.123201 IP 192.168.234.1.22 > 192.168.234.64.50502: . ack 2055586117
win 33288 <nop,nop,timestamp 2215674 58307614>
08:03:47.132805 IP 192.168.234.1.22 > 192.168.234.64.50502: F
434039281:434039281(0) ack 2055586117 win 33288 <nop,nop,timestamp 2215684
58307614>
08:03:47.133049 IP 192.168.234.64.50502 > 192.168.234.1.22: . ack 434039282 win
33303 <nop,nop,timestamp 58307625 2215684>
08:07:17.907597 IP 192.168.234.64.50502 > 192.168.234.1.22: S
2277772418:2277772418(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp
58518399 0,sackOK,eol>
08:07:20.904114 IP 192.168.234.64.50502 > 192.168.234.1.22: S
2277772418:2277772418(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp
58521399 0,sackOK,eol>
08:07:24.104082 IP 192.168.234.64.50502 > 192.168.234.1.22: S
2277772418:2277772418(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp
58524599 0,sackOK,eol>
08:07:27.304042 IP 192.168.234.64.50502 > 192.168.234.1.22: S
2277772418:2277772418(0) win 65535 <mss 1460,sackOK,eol>
08:07:30.504007 IP 192.168.234.64.50502 > 192.168.234.1.22: S
2277772418:2277772418(0) win 65535 <mss 1460,sackOK,eol>
08:07:33.703954 IP 192.168.234.64.50502 > 192.168.234.1.22: S
2277772418:2277772418(0) win 65535 <mss 1460,sackOK,eol>
08:07:39.903878 IP 192.168.234.64.50502 > 192.168.234.1.22: S
2277772418:2277772418(0) win 65535 <mss 1460,sackOK,eol>
Mar 3 08:07:18 fwall ipmon[575]: 08:07:17.907881 fxp1 @10:4 b
192.168.234.64,50502 -> 192.168.234.1,22 PR tcp len 20 64 -S IN OOW
Mar 3 08:07:21 fwall ipmon[575]: 08:07:20.904301 fxp1 @10:4 b
192.168.234.64,50502 -> 192.168.234.1,22 PR tcp len 20 64 -S IN OOW
Mar 3 08:07:24 fwall ipmon[575]: 08:07:24.104258 fxp1 @10:4 b
192.168.234.64,50502 -> 192.168.234.1,22 PR tcp len 20 64 -S IN OOW
Mar 3 08:07:27 fwall ipmon[575]: 08:07:27.304227 fxp1 @10:4 b
192.168.234.64,50502 -> 192.168.234.1,22 PR tcp len 20 48 -S IN OOW
Mar 3 08:07:30 fwall ipmon[575]: 08:07:30.504165 fxp1 @10:4 b
192.168.234.64,50502 -> 192.168.234.1,22 PR tcp len 20 48 -S IN OOW
Mar 3 08:07:34 fwall ipmon[575]: 08:07:33.704096 fxp1 @10:4 b
192.168.234.64,50502 -> 192.168.234.1,22 PR tcp len 20 48 -S IN OOW
Mar 3 08:07:40 fwall ipmon[575]: 08:07:39.904021 fxp1 @10:4 b
192.168.234.64,50502 -> 192.168.234.1,22 PR tcp len 20 48 -S IN OOW
08:08:43.701501 IP 192.168.234.1.22 > 192.168.234.64.49195: P
1894152970:1894153098(128) ack 3769663788 win 33304 <nop,nop,timestamp 2512344
58604189>
08:08:43.701941 IP 192.168.234.64.49195 > 192.168.234.1.22: P
3769663788:3769663820(32) ack 1894153098 win 33304 <nop,nop,timestamp 58604197
2512344>
08:08:43.701998 IP 192.168.234.64.49195 > 192.168.234.1.22: F
3769663820:3769663820(0) ack 1894153098 win 33304 <nop,nop,timestamp 58604197
2512344>
08:08:43.702457 IP 192.168.234.1.22 > 192.168.234.64.49195: . ack 3769663821
win 33288 <nop,nop,timestamp 2512345 58604197>
08:08:43.711679 IP 192.168.234.1.22 > 192.168.234.64.49195: F
1894153098:1894153098(0) ack 3769663821 win 33288 <nop,nop,timestamp 2512354
58604197>
08:08:43.711931 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 1894153099
win 33303 <nop,nop,timestamp 58604207 2512354>
08:11:59.725733 IP 192.168.234.64.49195 > 192.168.234.1.22: S
3976363428:3976363428(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp
58800221 0,sackOK,eol>
08:12:02.722826 IP 192.168.234.64.49195 > 192.168.234.1.22: S
3976363428:3976363428(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp
58803221 0,sackOK,eol>
08:12:05.922699 IP 192.168.234.64.49195 > 192.168.234.1.22: S
3976363428:3976363428(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp
58806421 0,sackOK,eol>
08:12:09.122652 IP 192.168.234.64.49195 > 192.168.234.1.22: S
3976363428:3976363428(0) win 65535 <mss 1460,sackOK,eol>
08:12:12.322614 IP 192.168.234.64.49195 > 192.168.234.1.22: S
3976363428:3976363428(0) win 65535 <mss 1460,sackOK,eol>
08:12:15.522575 IP 192.168.234.64.49195 > 192.168.234.1.22: S
3976363428:3976363428(0) win 65535 <mss 1460,sackOK,eol>
08:12:21.722501 IP 192.168.234.64.49195 > 192.168.234.1.22: S
3976363428:3976363428(0) win 65535 <mss 1460,sackOK,eol>
08:12:33.922361 IP 192.168.234.64.49195 > 192.168.234.1.22: S
3976363428:3976363428(0) win 65535 <mss 1460,sackOK,eol>
Mar 3 08:11:59 fwall ipmon[575]: 08:11:59.725940 fxp1 @10:4 b
192.168.234.64,49195 -> 192.168.234.1,22 PR tcp len 20 64 -S IN OOW
Mar 3 08:12:02 fwall ipmon[575]: 08:12:02.722998 fxp1 @10:4 b
192.168.234.64,49195 -> 192.168.234.1,22 PR tcp len 20 64 -S IN OOW
Mar 3 08:12:06 fwall ipmon[575]: 08:12:05.922888 fxp1 @10:4 b
192.168.234.64,49195 -> 192.168.234.1,22 PR tcp len 20 64 -S IN OOW
Mar 3 08:12:09 fwall ipmon[575]: 08:12:09.122841 fxp1 @10:4 b
192.168.234.64,49195 -> 192.168.234.1,22 PR tcp len 20 48 -S IN OOW
Mar 3 08:12:12 fwall ipmon[575]: 08:12:12.322771 fxp1 @10:4 b
192.168.234.64,49195 -> 192.168.234.1,22 PR tcp len 20 48 -S IN OOW
Mar 3 08:12:15 fwall ipmon[575]: 08:12:15.522740 fxp1 @10:4 b
192.168.234.64,49195 -> 192.168.234.1,22 PR tcp len 20 48 -S IN OOW
Mar 3 08:12:21 fwall ipmon[575]: 08:12:21.722662 fxp1 @10:4 b
192.168.234.64,49195 -> 192.168.234.1,22 PR tcp len 20 48 -S IN OOW
Mar 3 08:12:34 fwall ipmon[575]: 08:12:33.922524 fxp1 @10:4 b
192.168.234.64,49195 -> 192.168.234.1,22 PR tcp len 20 48 -S IN OOW
The other problem occurs during data transfer with IPfilter
arbitrarily blocking the connection, even though "ipfstat -t" showed
that a state entry was present. This is more serious because it is
effectively preventing large data transfers. The following examples
show pairs of connections being broken at similar times - other
connections remain up (though they aren't showing any data transfer
at this time).
[I don't have the setup for this connection]
08:09:57.124191 IP 192.168.234.1.22 > 192.168.234.64.59384: P
4044806139:4044806283(144) ack 3102426529 win 33304 <nop,nop,timestamp 2585790
58676691>
08:09:57.224240 IP 192.168.234.64.59384 > 192.168.234.1.22: . ack 4044806283
win 33304 <nop,nop,timestamp 58677721 2585790>
08:09:58.150932 IP 192.168.234.1.22 > 192.168.234.64.59384: P
4044806283:4044806443(160) ack 3102426529 win 33304 <nop,nop,timestamp 2586817
58677721>
08:09:58.250214 IP 192.168.234.64.59384 > 192.168.234.1.22: . ack 4044806443
win 33304 <nop,nop,timestamp 58678747 2586817>
08:09:59.181153 IP 192.168.234.1.22 > 192.168.234.64.59384: P
4044806443:4044806587(144) ack 3102426529 win 33304 <nop,nop,timestamp 2587847
58678747>
08:09:59.281226 IP 192.168.234.64.59384 > 192.168.234.1.22: . ack 4044806587
win 33304 <nop,nop,timestamp 58679778 2587847>
08:10:00.610156 IP 192.168.234.1.22 > 192.168.234.64.59384: FP
4044806587:4044806859(272) ack 3102426529 win 33304 <nop,nop,timestamp 2589277
58679778>
08:10:00.610395 IP 192.168.234.64.59384 > 192.168.234.1.22: . ack 4044806860
win 33168 <nop,nop,timestamp 58681107 2589277>
08:10:00.610702 IP 192.168.234.64.59384 > 192.168.234.1.22: F
3102426529:3102426529(0) ack 4044806860 win 33168 <nop,nop,timestamp 58681107
2589277>
08:10:00.611106 IP 192.168.234.1.22 > 192.168.234.64.59384: . ack 3102426530
win 33303 <nop,nop,timestamp 2589278 58681107>
Mar 3 08:10:00 fwall sshd[2147]: fatal: Write failed: Network is unreachable
Mar 3 08:10:00 fwall ipmon[575]: 08:10:00.306431 fxp1 @20:4 b 192.168.234.1,22
-> 192.168.234.64,59384 PR tcp len 20 324 -AP OUT
Mar 3 08:10:00 fwall ipmon[575]: 08:10:00.358704 2x fxp1 @20:4 b
192.168.234.1,22 -> 192.168.234.64,59384 PR tcp len 20 324 -AFP OUT
07:57:23.947534 IP 192.168.234.64.59561 > 192.168.234.1.22: S
1763158715:1763158715(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp
57924435 0,sackOK,eol>
07:57:23.948069 IP 192.168.234.1.22 > 192.168.234.64.59561: S
1982415851:1982415851(0) ack 1763158716 win 65535 <mss 1460,nop,wscale
1,nop,nop,timestamp 1832381 57924435,sackOK,eol>
07:57:23.948293 IP 192.168.234.64.59561 > 192.168.234.1.22: . ack 1982415852
win 33304 <nop,nop,timestamp 57924436 1832381>
...
08:08:40.662213 IP 192.168.234.1.22 > 192.168.234.64.59561: P
1982428467:1982428643(176) ack 1763162811 win 33304 <nop,nop,timestamp 2509304
58583240>
08:08:40.662449 IP 192.168.234.64.59561 > 192.168.234.1.22: . ack 1982428643
win 33216 <nop,nop,timestamp 58601158 2509302>
08:08:48.667564 IP 192.168.234.1.22 > 192.168.234.64.59561: P
1982428643:1982428947(304) ack 1763162811 win 33304 <nop,nop,timestamp 2517312
58601158>
08:08:48.767108 IP 192.168.234.64.59561 > 192.168.234.1.22: . ack 1982428947
win 33304 <nop,nop,timestamp 58609263 2517312>
08:10:00.709144 IP 192.168.234.1.22 > 192.168.234.64.59561: FP
1982428947:1982429075(128) ack 1763162811 win 33304 <nop,nop,timestamp 2589376
58609263>
08:10:00.709374 IP 192.168.234.64.59561 > 192.168.234.1.22: . ack 1982429076
win 33240 <nop,nop,timestamp 58681206 2589376>
08:10:00.709712 IP 192.168.234.64.59561 > 192.168.234.1.22: F
1763162811:1763162811(0) ack 1982429076 win 33240 <nop,nop,timestamp 58681206
2589376>
08:10:00.710107 IP 192.168.234.1.22 > 192.168.234.64.59561: . ack 1763162812
win 33303 <nop,nop,timestamp 2589377 58681206>
Mar 3 08:10:00 fwall ipmon[575]: 08:10:00.331436 fxp1 @20:4 b 192.168.234.1,22
-> 192.168.234.64,59561 PR tcp len 20 180 -AP OUT
Mar 3 08:10:00 fwall ipmon[575]: 08:10:00.447691 2x fxp1 @20:4 b
192.168.234.1,22 -> 192.168.234.64,59561 PR tcp len 20 180 -AFP OUT
Mar 3 08:10:00 fwall sshd[2517]: fatal: Write failed: Network is unreachable
10:35:19.256117 IP 192.168.234.64.56081 > 192.168.234.1.22: S
812758778:812758778(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp
67399848 0,sackOK,eol>
10:35:19.256714 IP 192.168.234.1.22 > 192.168.234.64.56081: S
3417842247:3417842247(0) ack 812758779 win 65535 <mss 1460,nop,wscale
1,nop,nop,timestamp 11310611 67399848,sackOK,eol>
10:35:19.256903 IP 192.168.234.64.56081 > 192.168.234.1.22: . ack 3417842248
win 33304 <nop,nop,timestamp 67399849 11310611>
...
10:39:58.893090 IP 192.168.234.1.22 > 192.168.234.64.56081: P
3417882991:3417883119(128) ack 812761578 win 33304 <nop,nop,timestamp 11590334
67678565>
10:39:58.993261 IP 192.168.234.64.56081 > 192.168.234.1.22: . ack 3417883119
win 33304 <nop,nop,timestamp 67679589 11590334>
10:39:59.917836 IP 192.168.234.1.22 > 192.168.234.64.56081: P
3417883119:3417883231(112) ack 812761578 win 33304 <nop,nop,timestamp 11591359
67679589>
10:40:00.017354 IP 192.168.234.64.56081 > 192.168.234.1.22: . ack 3417883231
win 33304 <nop,nop,timestamp 67680613 11591359>
10:40:01.308970 IP 192.168.234.1.22 > 192.168.234.64.56081: FP
3417883231:3417883359(128) ack 812761578 win 33304 <nop,nop,timestamp 11592751
67680613>
10:40:01.309237 IP 192.168.234.64.56081 > 192.168.234.1.22: . ack 3417883360
win 33240 <nop,nop,timestamp 67681904 11592751>
10:40:01.309555 IP 192.168.234.64.56081 > 192.168.234.1.22: F
812761578:812761578(0) ack 3417883360 win 33240 <nop,nop,timestamp 67681905
11592751>
10:40:01.309968 IP 192.168.234.1.22 > 192.168.234.64.56081: . ack 812761579 win
33303 <nop,nop,timestamp 11592752 67681905>
Mar 3 10:40:01 fwall sshd[6219]: fatal: Write failed: Network is unreachable
Mar 3 10:40:01 fwall ipmon[575]: 10:40:01.007860 fxp1 @20:4 b 192.168.234.1,22
-> 192.168.234.64,56081 PR tcp len 20 180 -AP OUT
Mar 3 10:40:02 fwall ipmon[575]: 10:40:01.058499 2x fxp1 @20:4 b
192.168.234.1,22 -> 192.168.234.64,56081 PR tcp len 20 180 -AFP OUT
10:35:25.524645 IP 192.168.234.64.56082 > 192.168.234.1.22: S
1175923020:1175923020(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp
67406117 0,sackOK,eol>
10:35:25.525233 IP 192.168.234.1.22 > 192.168.234.64.56082: S
581176389:581176389(0) ack 1175923021 win 65535 <mss 1460,nop,wscale
1,nop,nop,timestamp 11316882 67406117,sackOK,eol>
10:35:25.525422 IP 192.168.234.64.56082 > 192.168.234.1.22: . ack 581176390 win
33304 <nop,nop,timestamp 67406117 11316882>
...
10:38:53.000522 IP 192.168.234.1.22 > 192.168.234.64.56082: P
581184701:581184877(176) ack 1175927116 win 33304 <nop,nop,timestamp 11524421
67612690>
10:38:53.100141 IP 192.168.234.64.56082 > 192.168.234.1.22: . ack 581184877 win
33304 <nop,nop,timestamp 67613695 11524421>
10:39:33.035596 IP 192.168.234.1.22 > 192.168.234.64.56082: P
581184877:581185053(176) ack 1175927116 win 33304 <nop,nop,timestamp 11564468
67613695>
10:39:33.135557 IP 192.168.234.64.56082 > 192.168.234.1.22: . ack 581185053 win
33304 <nop,nop,timestamp 67653731 11564468>
10:40:01.376923 IP 192.168.234.1.22 > 192.168.234.64.56082: FP
581185053:581185181(128) ack 1175927116 win 33304 <nop,nop,timestamp 11592819
67653731>
10:40:01.377158 IP 192.168.234.64.56082 > 192.168.234.1.22: . ack 581185182 win
33240 <nop,nop,timestamp 67681972 11592819>
10:40:01.377489 IP 192.168.234.64.56082 > 192.168.234.1.22: F
1175927116:1175927116(0) ack 581185182 win 33240 <nop,nop,timestamp 67681973
11592819>
10:40:01.377898 IP 192.168.234.1.22 > 192.168.234.64.56082: . ack 1175927117
win 33303 <nop,nop,timestamp 11592820 67681973>
Mar 3 10:40:01 fwall sshd[6227]: fatal: Write failed: Network is unreachable
Mar 3 10:40:01 fwall ipmon[575]: 10:40:01.045183 fxp1 @20:4 b 192.168.234.1,22
-> 192.168.234.64,56082 PR tcp len 20 180 -AP OUT
Mar 3 10:40:02 fwall ipmon[575]: 10:40:01.178259 2x fxp1 @20:4 b
192.168.234.1,22 -> 192.168.234.64,56082 PR tcp len 20 180 -AFP OUT
--
Peter Jeremy
pgpwnufZmtNN4.pgp
Description: PGP signature
|