On 2007-Feb-17 13:39:06 +1100, Peter Jeremy <[EMAIL PROTECTED]> 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

Attachment: pgpY2yhCGx9Cc.pgp
Description: PGP signature

Reply via email to