Re: blocked FIN packets
On Dec 23 20:17:23, Jan Stary wrote: 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? On Dec 23 02:39:59, Daniel E. Hassler wrote: Timing. State has probably timed out before the blocked packets are received. Log the whole conversation - both ways for both Firefox and lynx. On Dec 23 04:45:04, Brian Seklecki (Mobile) wrote: set timeout tcp.finwait 900 set timeout tcp.closing 900 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 0,sackOK,eol (DF) 12:37:00.052042 www.ihned.cz.www mac.stare.cz.54704: S 3325100471:3325100471(0) ack 3284050249 win 5792 mss 1380,sackOK,timestamp 3998698668 743703555,nop,wscale 7 12:37:00.052393 mac.stare.cz.54704 www.ihned.cz.www: . ack 1 win 65535 nop,nop,timestamp 743703556 3998698668 (DF) 12:37:00.053022 mac.stare.cz.54704 www.ihned.cz.www: P 1:299(298) ack 1 win 65535 nop,nop,timestamp 743703556 3998698668 (DF) 12:37:00.061764 www.ihned.cz.www mac.stare.cz.54704: . ack 299 win 54 nop,nop,timestamp 3998698669 743703556 [...] 12:37:00.220313 www.ihned.cz.www mac.stare.cz.54704: . 82081:83449(1368) ack 299 win 54 nop,nop,timestamp 3998698682 743703557 12:37:00.220486 www.ihned.cz.www mac.stare.cz.54704: . 83449:84817(1368) ack 299 win 54 nop,nop,timestamp 3998698682 743703557 12:37:00.220539 www.ihned.cz.www mac.stare.cz.54704: FP 84817:84919(102) ack 299 win 54 nop,nop,timestamp 3998698682 743703557 12:37:00.220620 mac.stare.cz.54704 www.ihned.cz.www: . ack 82081 win 65535 nop,nop,timestamp 743703557 3998698682 (DF) 12:37:00.220858 mac.stare.cz.54704 www.ihned.cz.www: . ack 84920 win 65309 nop,nop,timestamp 743703557 3998698682 (DF) 12:37:00.222642 mac.stare.cz.54704 www.ihned.cz.www: F 299:299(0) ack 84920 win 65535 nop,nop,timestamp 743703557 3998698682 (DF) 12:37:00.229482 www.ihned.cz.www mac.stare.cz.54704: . ack 300 win 54 nop,nop,timestamp 3998698686 743703557 With firefox on the other hand, this is what happens: six connections are made (ports 54748-54753) to get the page itself and the css and the images. Data is read on the connections; then the remote end sends a FIN for one of these connections (I am isolating port 54768; the very same happens on the other ports, too): [...] 13:08:07.915873 www.ihned.cz.www mac.stare.cz.54748: F 517:517(0) ack 637 win 56 nop,nop,timestamp 3992488807 743721564 The internal client ACKs the FIN ... 13:08:07.916238 mac.stare.cz.54748 www.ihned.cz.www: . ack 518 win 65535 nop,nop,timestamp 743722213 3992488807 (DF) and sends its own FIN later: 13:08:21.284154 mac.stare.cz.54748 www.ihned.cz.www: F 637:637(0) ack 518 win
Re: blocked FIN packets
All of these FINs go through, but never receive an ACK (why?). 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. Is there a way to make sure that thsi is what's happening? At the same time firefox seems to be a snail and needs a lot of time to figure out that a connection got half closed. Keepalive at its best. 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 running applications (wrt how they close connections)? Then, these FINs start to get blocked. First such is 13:10:28.363318 mac.stare.cz.54748 www.ihned.cz.www: F 637:637(0) ack 518 win 65535 nop,nop,timestamp 743723615 3992488807 (DF) The corresponding line from 'tcpdump -e -i pflog0' is 13:10:28.363655 rule 15/(match) block in on vr1: mac.stare.cz.54748 www.ihned.cz.www: F 4189102151:4189102151(0) ack 1081156646 win 65535 nop,nop,timestamp 743723615 3992488807 (DF) (I am assuming it is the same packet, as the timestamp differs by less then a milisecond.) The first FIN we tried to send was at 13:08:21; tcp.closing is 900s; (tcp.closing: The state after the first FIN has been sent.) So we are well within the timeout. 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) 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 finwait?), which never gets ACKed. so you will end up with a much shorter 90s timeout. 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 configuration, pf has a tcp.finwait of 45s. The first FIN we tried to send was at 13:08:21; tcp.closing is 900s; (tcp.closing: The state after the first FIN has been sent.) So we are well within the timeout. 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
Re: blocked FIN packets
On Dec 22 19:54:28, Forman, Jeffrey wrote:
On Wed, Dec 22, 2010 at 5:41 PM, Jan Stary h...@stare.cz wrote:
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?
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.
Yes, that's how I see the blocked packets.
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]
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
nop,nop,timestamp 743577732 1811533502 (DF)
I see this is rule 8. I then run 'pfctl -s rules -vv'
[...]
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.
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 $intfrom 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
Re: blocked FIN packets
Timing. State has probably timed out before the blocked packets are
received. Log the whole conversation - both ways for both Firefox and lynx.
On 12/23/10 12:47 AM, Jan Stary wrote:
On Dec 22 19:54:28, Forman, Jeffrey wrote:
On Wed, Dec 22, 2010 at 5:41 PM, Jan Staryh...@stare.cz wrote:
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?
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.
Yes, that's how I see the blocked packets.
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]
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
nop,nop,timestamp 743577732 1811533502 (DF)
I see this is rule 8. I then run 'pfctl -s rules -vv'
[...]
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.
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 $intfrom 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
Re: blocked FIN packets
set skip on lo set block-policy drop 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: 6 ... net.inet.tcp.finwait2_timeout: FIN-WAIT2 timeout Or something similar ~BAS
Re: blocked FIN packets
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? On Dec 23 02:39:59, Daniel E. Hassler wrote: Timing. State has probably timed out before the blocked packets are received. Log the whole conversation - both ways for both Firefox and lynx. On Dec 23 04:45:04, Brian Seklecki (Mobile) wrote: set timeout tcp.finwait 900 set timeout tcp.closing 900 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 0,sackOK,eol (DF) 12:37:00.052042 www.ihned.cz.www mac.stare.cz.54704: S 3325100471:3325100471(0) ack 3284050249 win 5792 mss 1380,sackOK,timestamp 3998698668 743703555,nop,wscale 7 12:37:00.052393 mac.stare.cz.54704 www.ihned.cz.www: . ack 1 win 65535 nop,nop,timestamp 743703556 3998698668 (DF) 12:37:00.053022 mac.stare.cz.54704 www.ihned.cz.www: P 1:299(298) ack 1 win 65535 nop,nop,timestamp 743703556 3998698668 (DF) 12:37:00.061764 www.ihned.cz.www mac.stare.cz.54704: . ack 299 win 54 nop,nop,timestamp 3998698669 743703556 [...] 12:37:00.220313 www.ihned.cz.www mac.stare.cz.54704: . 82081:83449(1368) ack 299 win 54 nop,nop,timestamp 3998698682 743703557 12:37:00.220486 www.ihned.cz.www mac.stare.cz.54704: . 83449:84817(1368) ack 299 win 54 nop,nop,timestamp 3998698682 743703557 12:37:00.220539 www.ihned.cz.www mac.stare.cz.54704: FP 84817:84919(102) ack 299 win 54 nop,nop,timestamp 3998698682 743703557 12:37:00.220620 mac.stare.cz.54704 www.ihned.cz.www: . ack 82081 win 65535 nop,nop,timestamp 743703557 3998698682 (DF) 12:37:00.220858 mac.stare.cz.54704 www.ihned.cz.www: . ack 84920 win 65309 nop,nop,timestamp 743703557 3998698682 (DF) 12:37:00.222642 mac.stare.cz.54704 www.ihned.cz.www: F 299:299(0) ack 84920 win 65535 nop,nop,timestamp 743703557 3998698682 (DF) 12:37:00.229482 www.ihned.cz.www mac.stare.cz.54704: . ack 300 win 54 nop,nop,timestamp 3998698686 743703557 With firefox on the other hand, this is what happens: six connections are made (ports 54748-54753) to get the page itself and the css and the images. Data is read on the connections; then the remote end sends a FIN for one of these connections (I am isolating port 54768; the very same happens on the other ports, too): [...] 13:08:07.915873 www.ihned.cz.www mac.stare.cz.54748: F 517:517(0) ack 637 win 56 nop,nop,timestamp 3992488807 743721564 The internal client ACKs the FIN ... 13:08:07.916238 mac.stare.cz.54748 www.ihned.cz.www: . ack 518 win 65535 nop,nop,timestamp 743722213 3992488807 (DF) and sends its own FIN later: 13:08:21.284154 mac.stare.cz.54748 www.ihned.cz.www: F 637:637(0) ack 518 win 65535 nop,nop,timestamp 743722346 3992488807 (DF) Comparing the timestamps, that's fourteen seconds after the client sent the ACK for the
Re: blocked FIN packets
On Thu, Dec 23, 2010 at 08:17:23PM +0100, Jan Stary wrote: 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? On Dec 23 02:39:59, Daniel E. Hassler wrote: Timing. State has probably timed out before the blocked packets are received. Log the whole conversation - both ways for both Firefox and lynx. On Dec 23 04:45:04, Brian Seklecki (Mobile) wrote: set timeout tcp.finwait 900 set timeout tcp.closing 900 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 0,sackOK,eol (DF) 12:37:00.052042 www.ihned.cz.www mac.stare.cz.54704: S 3325100471:3325100471(0) ack 3284050249 win 5792 mss 1380,sackOK,timestamp 3998698668 743703555,nop,wscale 7 12:37:00.052393 mac.stare.cz.54704 www.ihned.cz.www: . ack 1 win 65535 nop,nop,timestamp 743703556 3998698668 (DF) 12:37:00.053022 mac.stare.cz.54704 www.ihned.cz.www: P 1:299(298) ack 1 win 65535 nop,nop,timestamp 743703556 3998698668 (DF) 12:37:00.061764 www.ihned.cz.www mac.stare.cz.54704: . ack 299 win 54 nop,nop,timestamp 3998698669 743703556 [...] 12:37:00.220313 www.ihned.cz.www mac.stare.cz.54704: . 82081:83449(1368) ack 299 win 54 nop,nop,timestamp 3998698682 743703557 12:37:00.220486 www.ihned.cz.www mac.stare.cz.54704: . 83449:84817(1368) ack 299 win 54 nop,nop,timestamp 3998698682 743703557 12:37:00.220539 www.ihned.cz.www mac.stare.cz.54704: FP 84817:84919(102) ack 299 win 54 nop,nop,timestamp 3998698682 743703557 12:37:00.220620 mac.stare.cz.54704 www.ihned.cz.www: . ack 82081 win 65535 nop,nop,timestamp 743703557 3998698682 (DF) 12:37:00.220858 mac.stare.cz.54704 www.ihned.cz.www: . ack 84920 win 65309 nop,nop,timestamp 743703557 3998698682 (DF) 12:37:00.222642 mac.stare.cz.54704 www.ihned.cz.www: F 299:299(0) ack 84920 win 65535 nop,nop,timestamp 743703557 3998698682 (DF) 12:37:00.229482 www.ihned.cz.www mac.stare.cz.54704: . ack 300 win 54 nop,nop,timestamp 3998698686 743703557 With firefox on the other hand, this is what happens: six connections are made (ports 54748-54753) to get the page itself and the css and the images. Data is read on the connections; then the remote end sends a FIN for one of these connections (I am isolating port 54768; the very same happens on the other ports, too): [...] 13:08:07.915873 www.ihned.cz.www mac.stare.cz.54748: F 517:517(0) ack 637 win 56 nop,nop,timestamp 3992488807 743721564 The internal client ACKs the FIN ... 13:08:07.916238 mac.stare.cz.54748 www.ihned.cz.www: . ack 518 win 65535 nop,nop,timestamp 743722213 3992488807 (DF) and sends its own FIN later: 13:08:21.284154 mac.stare.cz.54748 www.ihned.cz.www: F
Re: blocked FIN packets
On Wed, Dec 22, 2010 at 5:41 PM, Jan Stary h...@stare.cz wrote: 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? 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
