Re: blocked FIN packets

Previous thread: Print server by Jean-Francois on Wednesday, December 22, 2010 - 3:20 pm. (4 messages)

Next thread: Notícias Automotivas...Venha me conhecer!!! by Auto-Motivos on Wednesday, December 22, 2010 - 5:28 pm. (1 message)
From: Jan Stary
Date: Wednesday, December 22, 2010 - 3:41 pm

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 ...
From: Forman, Jeffrey
Date: Wednesday, December 22, 2010 - 5:54 pm

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

From: Jan Stary
Date: Thursday, December 23, 2010 - 1:47 am

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

From: Daniel E. Hassler
Date: Thursday, December 23, 2010 - 3:39 am

Timing. State has probably timed out before the blocked packets are 
received. Log the whole conversation - both ways for both Firefox and lynx.


From: Jan Stary
Date: Thursday, December 23, 2010 - 12:17 pm

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 ...
From: Claudio Jeker
Date: Thursday, December 23, 2010 - 1:11 pm

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.


From: Jan Stary
Date: Saturday, December 25, 2010 - 12:29 pm

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

From: Jan Stary
Date: Saturday, December 25, 2010 - 3:07 am

"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

From: Brian Seklecki (Mobile)
Date: Thursday, December 23, 2010 - 2:45 am

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

Previous thread: Print server by Jean-Francois on Wednesday, December 22, 2010 - 3:20 pm. (4 messages)

Next thread: Notícias Automotivas...Venha me conhecer!!! by Auto-Motivos on Wednesday, December 22, 2010 - 5:28 pm. (1 message)