This is -current/i386 serving as a gateway for a home network. See the full pf.conf below (it does the obvious: let everything out, rdr-to the internal www server, pass internal services such as dns, block everything else). Now /var/log/pflog gets filled with what one could expect - bad guys trying to connect to services I don't even run: 06:16:03.134986 211.161.192.17.6000 > 192.168.167.1.ms-sql-s: S 1081278464:10812 78464(0) win 16384 But among these, there are also sequences such as this one: 11:38:34.334707 mac.stare.cz.51157 > www.ihned.cz.www: F 0:0(0) ack 1 win 65535 <nop,nop,timestamp 743239087 3983291520> (DF) 11:38:34.334755 mac.stare.cz.51156 > www.ihned.cz.www: F 0:0(0) ack 1 win 65535 <nop,nop,timestamp 743239087 3989688120> (DF) 11:38:34.334797 mac.stare.cz.51152 > www.ihned.cz.www: F 0:0(0) ack 1 win 65535 <nop,nop,timestamp 743239087 3983291519> (DF) 11:38:35.436357 mac.stare.cz.51223 > www.ihned.cz.www: F 0:0(0) ack 1 win 65535 <nop,nop,timestamp 743239098 3983291489> (DF) 11:38:35.436405 mac.stare.cz.51191 > www.ihned.cz.www: F 0:0(0) ack 1 win 65535 <nop,nop,timestamp 743239098 3983291492> (DF) 11:38:35.436450 mac.stare.cz.51185 > www.ihned.cz.www: F 0:0(0) ack 1 win 65535 <nop,nop,timestamp 743239098 3983291489> (DF) That's an internal client sending FIN packets (to the webserver www.ihned.cz of a newspaper I read), which gets blocked. How does such a thing ever happen? Speculation: this looks to me like an end of a valid http session: an internal clients reads a web page, and probably a few images, everything goes through, but the last FIN does not. The first SYN creates state that lets the subsequent packets through. Doesn't the last FIN belong to the same state? Also, this is an outgoing packet, which I explicitly allow. What can possibly be blocking these FIN packets? Thank you for your time. Jan ext="vr0" # external int="vr1" # internal dmz="vr2" # dmz stare="192.168.222.2" # the dmz server phone="192.168.111.9" # the voip ...
Jan, I have run into a similiar situation where I had packets getting blocked through my OpenBSD fw and could not figure out why. The couple pieces of code I tend to use to debug such a thing: 1. The 'log' and 'log (all)' statements in pf.conf. Take your pick of the two and throw them on all your block statements. 2. Following that, I run 'tcpdump -n -ttt -e -i pflog0'. This shows me not only the packets being logged, but also the pf rules blocking them. Example: Dec 22 19:24:13.564109 rule 8/(match) block in on vr0: 115.178.83.69.6000 > 96.21.64.23.2967: S 449708032:449708032(0) win 16384 [tos 0x20] I see this is rule 8. I then run 'pfctl -s rules -vv' which among other things, outputs @8 block return in log all label "block_all" [ Evaluations: 1196726 Packets: 5786 Bytes: 352780 States: 0 ] [ Inserted: uid 0 pid 2220 State Creations: 0 ] "@8" corresponding to a particular PF rule. I find that by combining these two debugging tools, I am able to pin point the rule that might be blocking a specific set of connections. Hope that helps. Cheers, Jeffrey
Thanks. It's some time I have read tcpdump(8). 09:07:02.849975 rule 15/(match) block in on vr1: mac.stare.cz.54254 > www.ihned.cz.www: F 2622397051:2622397051(0) ack 1936803033 win 65535 The rule that's blocking my FIN packets is the "block drop log all". Which is the only block rule I have, the rest of pf.conf just explicitly allows the intended traffic (see the original mail). So my question remains: if these are FINs of the few http conections that take place when an internal client looks at www.ihned.cz (which it seems), why are they not let through by the state that was created form these connections? This is blocked 'in' on the internal interface (vr1), where the 'in' rules are (see orig mail for full pf.conf): pass in on $int proto icmp from any to ($int) pass in on $int proto { tcp udp } from any to ($int) port bootps pass in on $int proto { tcp udp } from any to ($int) port domain pass in on $int proto tcp from any to ($int) port ssh pass in on $int from any to !($int) tag INT Maybe I am missing something here: the first four rules are supposed to allow traffic from the internal hosts to the gateway itself (dhcp etc), and the fifth rule is supposed to pass traffic to the outside (which gets natted later on the external interface). A packet such as mac.stare.cz.54254 > www.ihned.cz.www: F 2622397051:2622397051(0) seems to me to be that case (right?). The only communication that the internal client (mac.stare.cz) has with the outside host (www.ihned.cz) is that a browser (firefox) is used to look at a webpage. If the internal clients does the same with lynx, there are no blocked FIN packets on the internal interface. What am I missing here? Thank you for your time Jan
Timing. State has probably timed out before the blocked packets are received. Log the whole conversation - both ways for both Firefox and lynx.
You are both probably right. Thank you. With lynx (that is, an internal client runs 'lynx www.ihned.cz') the conversation looks like this (tcpdump follows): two tcp connections are made (first receives 302 Found, the second one receives 200); the data is read; both connections are correctly FIN'd, the FINs are ack'd. No packets get blocked. 12:36:57.989903 mac.stare.cz.54703 > www.ihned.cz.www: S 2635202717:2635202717(0) win 65535 <mss 1460,nop,wscale 3,nop,nop,timestamp 743703535 0,sackOK,eol> (DF) 12:36:58.006316 www.ihned.cz.www > mac.stare.cz.54703: S 2401821844:2401821844(0) ack 2635202718 win 5792 <mss 1380,sackOK,timestamp 3998698463 743703535,nop,wscale 7> 12:36:58.006483 mac.stare.cz.54703 > www.ihned.cz.www: . ack 1 win 65535 <nop,nop,timestamp 743703535 3998698463> (DF) 12:36:58.006979 mac.stare.cz.54703 > www.ihned.cz.www: P 1:303(302) ack 1 win 65535 <nop,nop,timestamp 743703535 3998698463> (DF) 12:36:58.018389 www.ihned.cz.www > mac.stare.cz.54703: . ack 303 win 54 <nop,nop,timestamp 3998698464 743703535> 12:36:58.036406 www.ihned.cz.www > mac.stare.cz.54703: P 1:169(168) ack 303 win 54 <nop,nop,timestamp 3998698466 743703535> 12:36:58.036774 mac.stare.cz.54703 > www.ihned.cz.www: . ack 169 win 65535 <nop,nop,timestamp 743703535 3998698466> (DF) 12:36:58.036920 www.ihned.cz.www > mac.stare.cz.54703: F 169:169(0) ack 303 win 54 <nop,nop,timestamp 3998698466 743703535> 12:36:58.037094 mac.stare.cz.54703 > www.ihned.cz.www: . ack 170 win 65535 <nop,nop,timestamp 743703535 3998698466> (DF) 12:36:58.037990 mac.stare.cz.54703 > www.ihned.cz.www: F 303:303(0) ack 170 win 65535 <nop,nop,timestamp 743703535 3998698466> (DF) 12:36:58.046266 www.ihned.cz.www > mac.stare.cz.54703: . ack 304 win 54 <nop,nop,timestamp 3998698467 743703535> (The first connection which received 302 Found ends here; the other one starts now.) 12:37:00.040373 mac.stare.cz.54704 > www.ihned.cz.www: S 3284050248:3284050248(0) win 65535 <mss 1460,nop,wscale 3,nop,nop,timestamp 743703555 ...
Because the other side sucks and decided to violate the TCP RFC by fast closing connections without waiting proper session shutdown to free sockets quickly and since that is not enough they even decided to not send a RST back to such FIN packets. So you lose, live with it there is nothing you can do against this. The Internet is full of such suckers. At the same time firefox seems to be a snail and needs a lot of time to You sure that your state is in the closing state and not in FINWAIT or CLOSED? The first FIN will move the state to closing and the other side sending the 2nd FIN will move the state to CLOSED (IIRC) so you will end up with a much shorter 90s timeout.
With 'set optimization conservative', all the timeouts get bumped to much bigger values; I no longer see the blocked FINs. But that's not because they have more time (if the other side never ACKs my FINs, they will lose state at some point), but the application (firefox) now sends its FIN much faster, and it gets ACKed. What does 'optimzation conservative' do besides bumping up the timeout values. How does that influence I am not sure. But the first FIN is sent by the other side (moving the state to closing), we ACK it, and send our FIN (moving the state to This is indeed the first packet that goes over 90s: the first (remote) FIN came at 13:08:07 the last FIN we send that goes through is 13:09:24 (i.e. 77s later) the first FIN that is blocked is at 13:10:28 (i.e. 141s later) But where does the 90s limt come from? Without further I am probably misunderstanding something. "tcp.closing: The state after the first FIN has been sent." That does not mean the first FIN _we_ sent. The first FIN was sent by the other side, at 13:08:07. The state we are in now _is_ tcp.closing, right? The first FIN has been sent. It's not "tcp.finwait: the state after both FINs have been exchanged", right? Because the FINs have not been exchanged - our FIN has not been ACKed. Or does pf consider this finwait already, because we have acked the remote FIN, and sent our FIN? Either way, this packet is not the first one to go over tcp.finwait = 45s. (And it is well withnin tcp.closing = 900s.) So why is this the first one that got blocked? Thank you for your time Jan
"tcp.closing: The state after the first FIN has been sent." That does not mean the first FIN _we_ sent. The first FIN was sent by the other side, at 13:08:07. The state we are in now _is_ tcp.closing, right? The first FIN has been sent. It's not "tcp.finwait: the state after both FINs have been exchanged", right? Because the FINs have not been exchanged - our FIN has not been ACKed. Or does pf consider this finwait already, because we have acked the remote FIN, and sent our FIN? Either way, this packet is not the first one to go over tcp.finwait = 45s. (And it is well withnin tcp.closing = 900s.) So why is this the first one that got blocked? Thank you for your time Jan
set timeout tcp.finwait 900
set timeout tcp.closing 900
(There also an adaptive setting based on load)
Your client, if its really a mac, may have a sysctl like
...net.inet.tcp.finwait2_timeout: 60000
... net.inet.tcp.finwait2_timeout: FIN-WAIT2 timeout
Or something similar ~BAS
