Weird nat/conntrack Problem with PASV FTP upload

Weird nat/conntrack Problem with PASV FTP upload

[Thomas Bätzler]

Hi & thank you for taking the time to have a look at this.

The basic setup is like this:

(ftp client)<=>(my nat box)<=big pipe=>(their nat box)<=>(ftp server)

The FTP client is PHP5's FTP library on a Debian Etch box with kernel 2.6.23 built from a Debian source package.
My NAT box is also Debian Etch, recently upgraded to 2.6.25 using the current Debian source package.
I Don't know much about the remote side, except that their FTP server is supposedly ProFTPd on Debian Etch.

We use PASV FTP transfers for our uploads and that's been working o.k. for us most of the time.

I say "most of the time" because we lose the data connection in about 1% of the transfers (mostly files in the 100kB to 5MB Range).

I've tcpdump'ed a some of those transfers on the external interface of my NAT box and on the client, and I don't understand what's going on. Let me give you an example:

tcpdump -rtttS on myclient:

000000 IP myclient.56785 > server.39790: SWE 427872165:427872165(0) win 5840 <mss 1460,sackOK,timestamp 481846634 0,nop,w
scale 7>
015646 IP server.39790 > myclient.56785: SE 2283192455:2283192455(0) ack 427872166 win 5792 <mss 1460,sackOK,timestamp 16317902 481846634,nop,wscale 7>
000010 IP myclient.56785 > server.39790: . ack 2283192456 win 46 <nop,nop,timestamp 481846636 16317902>
[...]
000002 IP myclient.56785 > server.39790: . 428128803:428131699(2896) ack 2283192456 win 46 <nop,nop,timestamp 481846649 16317934>
000784 IP server.39790 > myclient.56785: . ack 428044995 win 696 <nop,nop,timestamp 16317935 481846647,nop,nop,sack 1 {428046443:428047891}>
000006 IP myclient.56785 > server.39790: . 428131699:428134083(2384) ack 2283192456 win 46 <nop,nop,timestamp 481846649 16317935>
000002 IP server.39790 > myclient.56785: . ack 428047891 win 686 <nop,nop,timestamp 16317935 481846647>
000003 IP myclient.56785 > server.39790: . 428134083:428135699(1616) ack 2283192456 win 46 <nop,nop,timestamp 481846649 16317935>
000004 IP server.39790 > myclient.56785: . ack 428049339 win 675 <nop,nop,timestamp 16317935 481846647>

tcpdump -rtttS on natbox:

000000 IP mynatbox.56785 > server.39790: SWE 427872165:427872165(0) win 5840 <mss 1460,sackOK,timestamp 481846634 0,nop,wscale 7>
015564 IP server.39790 > mynatbox.56785: SE 2283192455:2283192455(0) ack 427872166 win 5792 <mss 1460,sackOK,timestamp 16317902 481846634,nop,wscale 7>
000062 IP mynatbox.56785 > server.39790: . ack 2283192456 win 46 <nop,nop,timestamp 481846636 16317902>
[...]
000004 IP mynatbox.56785 > server.39790: . 428128803:428130251(1448) ack 2283192456 win 46 <nop,nop,timestamp 481846649 16317934>
000034 IP mynatbox.56785 > server.39790: . 428130251:428131699(1448) ack 2283192456 win 46 <nop,nop,timestamp 481846649 16317934>
000560 IP server.39790 > mynatbox.56785: . ack 428042099 win 700 <nop,nop,timestamp 16317935 481846647,nop,nop,sack 1 {428046443:428047891}>
000020 IP mynatbox.56785 > server.39790: R 428042099:428042099(0) win 0
000002 IP server.39790 > mynatbox.56785: . ack 428042099 win 700 <nop,nop,timestamp 16317935 481846647,nop,nop,sack 2 {428043547:428044995}{428046443:428047891}>
000005 IP mynatbox.56785 > server.39790: R 428042099:428042099(0) win 0
000002 IP server.39790 > mynatbox.56785: . ack 428044995 win 696 <nop,nop,timestamp 16317935 481846647,nop,nop,sack 1 {428046443:428047891}>
000006 IP server.39790 > mynatbox.56785: . ack 428047891 win 686 <nop,nop,timestamp 16317935 481846647>
000005 IP server.39790 > mynatbox.56785: . ack 428049339 win 675 <nop,nop,timestamp 16317935 481846647>


Now I don't know why myclient thinks it's sending 2k+ byte segments, since its interface MTU is definitely 1500, and it also agreed on a mss of 1460. Since myclient's NIC is an e1000, it might be tcp segmentation offload at work.

No, what's really scaring me is that natbox tries to tear down the data connection for no apparent reason. Like in the example shown, it seems to happen mostly when server sends a selective ack for an out-of-order segment. Sometimes server just shrugs the rst off and keeps on acking data, but at other times it gives in and tears down the connection.

I'm grateful for any pointer or explanation you might have for me. Right now I'm at my wit's end.

TIA,
Thomas
-- 
BRINGE Informationstechnik GmbH
Zur Seeplatte 12
D-76228 Karlsruhe
Germany

Fon: +49 721 94246-0
Fon: +49 171 5438457
Fax: +49 721 94246-66
Web: http://www.bringe.de/

Geschäftsführer: Dipl.-Ing. (FH) Martin Bringe
Ust.Id: DE812936645, HRB 108943 Mannheim 

Re: Weird nat/conntrack Problem with PASV FTP upload

[Patrick McHardy]

Thomas Bätzler wrote:
> Hi & thank you for taking the time to have a look at this.
> 
> The basic setup is like this:
> 
> (ftp client)<=>(my nat box)<=big pipe=>(their nat box)<=>(ftp server)
> 
> The FTP client is PHP5's FTP library on a Debian Etch box with kernel 2.6.23 built from a Debian source package.
> My NAT box is also Debian Etch, recently upgraded to 2.6.25 using the current Debian source package.
> I Don't know much about the remote side, except that their FTP server is supposedly ProFTPd on Debian Etch.
> 
> We use PASV FTP transfers for our uploads and that's been working o.k. for us most of the time.
> 
> I say "most of the time" because we lose the data connection in about 1% of the transfers (mostly files in the 100kB to 5MB Range).
> 
> I've tcpdump'ed a some of those transfers on the external interface of my NAT box and on the client, and I don't understand what's going on. Let me give you an example:
> 
> tcpdump -rtttS on myclient:
> 
> 000000 IP myclient.56785 > server.39790: SWE 427872165:427872165(0) win 5840 <mss 1460,sackOK,timestamp 481846634 0,nop,w
> scale 7>
> 015646 IP server.39790 > myclient.56785: SE 2283192455:2283192455(0) ack 427872166 win 5792 <mss 1460,sackOK,timestamp 16317902 481846634,nop,wscale 7>
> 000010 IP myclient.56785 > server.39790: . ack 2283192456 win 46 <nop,nop,timestamp 481846636 16317902>
> [...]
> 000002 IP myclient.56785 > server.39790: . 428128803:428131699(2896) ack 2283192456 win 46 <nop,nop,timestamp 481846649 16317934>
> 000784 IP server.39790 > myclient.56785: . ack 428044995 win 696 <nop,nop,timestamp 16317935 481846647,nop,nop,sack 1 {428046443:428047891}>
> 000006 IP myclient.56785 > server.39790: . 428131699:428134083(2384) ack 2283192456 win 46 <nop,nop,timestamp 481846649 16317935>
> 000002 IP server.39790 > myclient.56785: . ack 428047891 win 686 <nop,nop,timestamp 16317935 481846647>
> 000003 IP myclient.56785 > server.39790: . 428134083:428135699(1616) ack 2283192456 win 46 <nop,nop,timestamp 481846649 16317935>
> 000004 IP server.39790 > myclient.56785: . ack 428049339 win 675 <nop,nop,timestamp 16317935 481846647>
> 
> tcpdump -rtttS on natbox:
> 
> 000000 IP mynatbox.56785 > server.39790: SWE 427872165:427872165(0) win 5840 <mss 1460,sackOK,timestamp 481846634 0,nop,wscale 7>
> 015564 IP server.39790 > mynatbox.56785: SE 2283192455:2283192455(0) ack 427872166 win 5792 <mss 1460,sackOK,timestamp 16317902 481846634,nop,wscale 7>
> 000062 IP mynatbox.56785 > server.39790: . ack 2283192456 win 46 <nop,nop,timestamp 481846636 16317902>
> [...]
> 000004 IP mynatbox.56785 > server.39790: . 428128803:428130251(1448) ack 2283192456 win 46 <nop,nop,timestamp 481846649 16317934>
> 000034 IP mynatbox.56785 > server.39790: . 428130251:428131699(1448) ack 2283192456 win 46 <nop,nop,timestamp 481846649 16317934>
> 000560 IP server.39790 > mynatbox.56785: . ack 428042099 win 700 <nop,nop,timestamp 16317935 481846647,nop,nop,sack 1 {428046443:428047891}>
> 000020 IP mynatbox.56785 > server.39790: R 428042099:428042099(0) win 0
> 000002 IP server.39790 > mynatbox.56785: . ack 428042099 win 700 <nop,nop,timestamp 16317935 481846647,nop,nop,sack 2 {428043547:428044995}{428046443:428047891}>
> 000005 IP mynatbox.56785 > server.39790: R 428042099:428042099(0) win 0
> 000002 IP server.39790 > mynatbox.56785: . ack 428044995 win 696 <nop,nop,timestamp 16317935 481846647,nop,nop,sack 1 {428046443:428047891}>
> 000006 IP server.39790 > mynatbox.56785: . ack 428047891 win 686 <nop,nop,timestamp 16317935 481846647>
> 000005 IP server.39790 > mynatbox.56785: . ack 428049339 win 675 <nop,nop,timestamp 16317935 481846647>
> 
> 
> Now I don't know why myclient thinks it's sending 2k+ byte segments, since its interface MTU is definitely 1500, and it also agreed on a mss of 1460. Since myclient's NIC is an e1000, it might be tcp segmentation offload at work.

Probably.

> No, what's really scaring me is that natbox tries to tear down the data connection for no apparent reason. Like in the example shown, it seems to happen mostly when server sends a selective ack for an out-of-order segment. Sometimes server just shrugs the rst off and keeps on acking data, but at other times it gives in and tears down the connection.
> 
> I'm grateful for any pointer or explanation you might have for me. Right now I'm at my wit's end.

I guess you're seeing INVALID packets (from the view of conntrack)
and they're thus not NATed but delivered locally, causing a RST.
Does dropping -m state --state INVALID packets in PREROUTING make
any difference?

Re: Weird nat/conntrack Problem with PASV FTP upload

[Thomas Bätzler]

Patrick McHardy wrote:
> I guess you're seeing INVALID packets (from the view of conntrack)
> and they're thus not NATed but delivered locally, causing a RST.
> Does dropping -m state --state INVALID packets in PREROUTING make
> any difference?

I've tried that for a day, to no avail:

(client)

000199 IP myclient.39268 > server.50857: . 3928342114:3928346458(4344) 
ack 716921888 win 46 <nop,nop,timestamp 491865886 41364954>
000197 IP myclient.39268 > server.50857: . 3928346458:3928348623(2165) 
ack 716921888 win 46 <nop,nop,timestamp 491865886 41364954>
214707 IP myclient.39268 > server.50857: . 3928162255:3928163703(1448) 
ack 716921888 win 46 <nop,nop,timestamp 491865908 41364954>
tcpdump: pcap_loop: truncated dump file; tried to read 66 captured 
bytes, only got 62
016181 IP server.50857 > myclient.39268: R 716921888:716921888(0) win 0

(natbox external)

000204 IP natbox.39268 > server.50857: . 3928342114:3928343562(1448) ack 
716921888 win 46 <nop,nop,timestamp 491865886 41364954>
000005 IP natbox.39268 > server.50857: . 3928343562:3928345010(1448) ack 
716921888 win 46 <nop,nop,timestamp 491865886 41364954>
000003 IP natbox.39268 > server.50857: . 3928345010:3928346458(1448) ack 
716921888 win 46 <nop,nop,timestamp 491865886 41364954>
000187 IP natbox.39268 > server.50857: . 3928346458:3928347906(1448) ack 
716921888 win 46 <nop,nop,timestamp 491865886 41364954>
000005 IP natbox.39268 > server.50857: . 3928347906:3928348623(717) ack 
716921888 win 46 <nop,nop,timestamp 491865886 41364954>
007712 IP server.50857 > natbox.39268: . ack 3928162255 win 1456 
<nop,nop,timestamp 41364957 491865884,nop,nop,sack 1 
{3928165151:3928165154}>
000011 IP natbox.39268 > server.50857: R 3928162255:3928162255(0) win 0
206983 IP natbox.39268 > server.50857: . 3928162255:3928163703(1448) ack 
716921888 win 46 <nop,nop,timestamp 491865908 41364954>
016041 IP server.50857 > natbox.39268: R 716921888:716921888(0) win 0

My nat rules currently look like this:

iptables -t nat -A PREROUTING -m state --state INVALID -j LOG
iptables -t nat -A PREROUTING -m state --state INVALID -j DROP
iptables -t nat -A POSTROUTING -s client -d server -p tcp -j SNAT 
--to-source natbox
iptables -t nat -A POSTROUTING -s clientnet/24 -o eth0 -j SNAT 
--to-source natbox-base

natbox is an ifalias on the external interface.

Any further ideas on how I could debug/fix this?

TIA,
Thomas

Re: Weird nat/conntrack Problem with PASV FTP upload

[Patrick McHardy]

Thomas Bätzler wrote:
> Patrick McHardy wrote:
>> I guess you're seeing INVALID packets (from the view of conntrack)
>> and they're thus not NATed but delivered locally, causing a RST.
>> Does dropping -m state --state INVALID packets in PREROUTING make
>> any difference?
> 
> I've tried that for a day, to no avail:
> ..
> My nat rules currently look like this:
> 
> iptables -t nat -A PREROUTING -m state --state INVALID -j LOG
> iptables -t nat -A PREROUTING -m state --state INVALID -j DROP

These rules need to go in mangle, that nat table is only
traversed for the first packet of a connection.

Re: Weird nat/conntrack Problem with PASV FTP upload

[Jan Engelhardt]

On Friday 2008-06-06 17:02, Patrick McHardy wrote:
>> I've tried that for a day, to no avail:
>> ..
>> My nat rules currently look like this:
>> 
>> iptables -t nat -A PREROUTING -m state --state INVALID -j LOG
>> iptables -t nat -A PREROUTING -m state --state INVALID -j DROP
>
> These rules need to go in mangle, that nat table is only
> traversed for the first packet of a connection.

These rules should go into filter, because that's what "filter"
is for... filtering.

Re: Weird nat/conntrack Problem with PASV FTP upload

[Patrick McHardy]

Jan Engelhardt wrote:
> On Friday 2008-06-06 17:02, Patrick McHardy wrote:
>   
>>> I've tried that for a day, to no avail:
>>> ..
>>> My nat rules currently look like this:
>>>
>>> iptables -t nat -A PREROUTING -m state --state INVALID -j LOG
>>> iptables -t nat -A PREROUTING -m state --state INVALID -j DROP
>>>       
>> These rules need to go in mangle, that nat table is only
>> traversed for the first packet of a connection.
>>     
>
> These rules should go into filter, because that's what "filter"
> is for... filtering.

As you are well aware, there is no PREROUTING chain in filter.
So I'm guessing you're trying to pull me into a discussion
about that, in an irritating way.

Re: Weird nat/conntrack Problem with PASV FTP upload

[Jan Engelhardt]

On Monday 2008-06-09 11:09, Patrick McHardy wrote:
>>   
>> > > I've tried that for a day, to no avail:
>> > > ..
>> > > My nat rules currently look like this:
>> > >
>> > > iptables -t nat -A PREROUTING -m state --state INVALID -j LOG
>> > > iptables -t nat -A PREROUTING -m state --state INVALID -j DROP
>> > >       
>> > These rules need to go in mangle, that nat table is only
>> > traversed for the first packet of a connection.
>>
>> These rules should go into filter, because that's what "filter"
>> is for... filtering.
>
> As you are well aware, there is no PREROUTING chain in filter.
> So I'm guessing you're trying to pull me into a discussion
> about that, in an irritating way.
>
I overlooked that. In that case, it has to be done in INPUT/FORWARD then.
-t filter -A INPUT -m conntrack --ctstate INVALID -j LOG (and DROP)
-t filter -A FORWARD -m conntrack --ctstate INVALID -j LOG (and DROP)

RE: Weird nat/conntrack Problem with PASV FTP upload

[Thomas Bätzler]

Patrick McHardy wrote:

> Thomas Bätzler wrote:
> > iptables -t nat -A PREROUTING -m state --state INVALID \
> >   -j  LOG
> > iptables -t nat -A PREROUTING -m state --state INVALID \
> >   -j DROP
> 
> These rules need to go in mangle, that nat table is only 
> traversed for the first packet of a connection.

I've changed my ruleset as you suggested, and now I'm seeing
packets being filtered. I'll wait and see how that's affecting
stability and throughput of the connection.

In any case I'm wondering why netfilter doesn't consider these
packets to be part of a connection. Is there a known problem
with netfilter and TCP SACK? Or did I miss something while
looking at the rejected packets? I've enabled logging via ulogd
now and have a look at what's being filtered now.

In the meantime thanks a lot for your help!

Cheers,
Thomas
-- 
BRINGE Informationstechnik GmbH
Zur Seeplatte 12
D-76228 Karlsruhe
Germany

Fon: +49 721 94246-0
Fon: +49 171 5438457
Fax: +49 721 94246-66
Web: http://www.bringe.de/

Geschäftsführer: Dipl.-Ing. (FH) Martin Bringe
Ust.Id: DE812936645, HRB 108943 Mannheim 

RE: Weird nat/conntrack Problem with PASV FTP upload

[Jozsef Kadlecsik]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 1304 bytes --]

On Mon, 9 Jun 2008, Thomas Bätzler wrote:

> Patrick McHardy wrote:
> 
> > Thomas Bätzler wrote:
> > > iptables -t nat -A PREROUTING -m state --state INVALID \
> > >   -j  LOG
> > > iptables -t nat -A PREROUTING -m state --state INVALID \
> > >   -j DROP
> > 
> > These rules need to go in mangle, that nat table is only 
> > traversed for the first packet of a connection.
> 
> I've changed my ruleset as you suggested, and now I'm seeing
> packets being filtered. I'll wait and see how that's affecting
> stability and throughput of the connection.
> 
> In any case I'm wondering why netfilter doesn't consider these
> packets to be part of a connection. Is there a known problem
> with netfilter and TCP SACK? 

In these cases usually there is a device sitting between the firewall 
running netfilter and the server/client machine, which randomizes the TCP 
sequence numbers but fails to propagate the changes to the SACK fields. 
Thus the SACK values are totally bogus and therefore netfilter marks them 
as INVALID.

Best regards,
Jozsef
-
E-mail  : kadlec@blackhole.kfki.hu, kadlec@mail.kfki.hu
PGP key : http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address : KFKI Research Institute for Particle and Nuclear Physics
          H-1525 Budapest 114, POB. 49, Hungary

RE: Weird nat/conntrack Problem with PASV FTP upload

[Thomas Bätzler]

Jozsef Kadlecsik wrote:
> On Mon, 9 Jun 2008, Thomas Bätzler wrote:
>> In any case I'm wondering why netfilter doesn't consider
>> these packets  to be part of a connection. Is there a
>> known problem with netfilter and TCP SACK?
> 
> In these cases usually there is a device sitting between the 
> firewall running netfilter and the server/client machine, 
> which randomizes the TCP sequence numbers but fails to 
> propagate the changes to the SACK fields. 
> Thus the SACK values are totally bogus and therefore 
> netfilter marks them as INVALID.

I thought of that, too, but it doesn't seem to be the case.
Let's have a look at an excerpt (tcpdump -S):

22:37:44.830784 IP gateway.41803 > server.37890: SWE 1599996997:1599996997(0) win 5840 <mss 1460,sackOK,timestamp 495055487 0,nop,wscale 7>
22:37:44.846411 IP server.37890 > gateway.41803: SE 23582050:23582050(0) ack 1599996998 win 5792 <mss 1460,sackOK,timestamp 49338617 495055487,nop,wscale 7>
22:37:44.846533 IP gateway.41803 > server.37890: . ack 23582051 win 46 <nop,nop,timestamp 495055488 49338617>

[...]

22:37:44.974253 IP gateway.41803 > server.37890: . 1600282667:1600284115(1448) ack 23582051 win 46 <nop,nop,timestamp 495055501 49338649>

[...]

22:37:44.989794 IP server.37890 > gateway.41803: . ack 1600281219 win 892 <nop,nop,timestamp 49338653 495055501>
22:37:44.990228 IP gateway.41803 > server.37890: . 1600358775:1600360223(1448) ack 23582051 win 46 <nop,nop,timestamp 495055502 49338653>

[...]

22:37:44.990397 IP server.37890 > gateway.41803: . ack 1600281219 win 892 <nop,nop,timestamp 49338653 495055501,nop,nop,sack 1 {1600282667:1600284115}>
22:37:44.990417 IP gateway.41803 > server.37890: R 1600281219:1600281219(0) win 0

As you can see, the SACK data matches a previously sent segment,
so it's not scrambled.

HTH,
Thomas

RE: Weird nat/conntrack Problem with PASV FTP upload

[Jozsef Kadlecsik]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 2350 bytes --]

On Mon, 9 Jun 2008, Thomas Bätzler wrote:

> Jozsef Kadlecsik wrote:
> > On Mon, 9 Jun 2008, Thomas Bätzler wrote:
> >> In any case I'm wondering why netfilter doesn't consider
> >> these packets  to be part of a connection. Is there a
> >> known problem with netfilter and TCP SACK?
> > 
> > In these cases usually there is a device sitting between the 
> > firewall running netfilter and the server/client machine, 
> > which randomizes the TCP sequence numbers but fails to 
> > propagate the changes to the SACK fields. 
> > Thus the SACK values are totally bogus and therefore 
> > netfilter marks them as INVALID.
> 
> I thought of that, too, but it doesn't seem to be the case.
> Let's have a look at an excerpt (tcpdump -S):
> 
> 22:37:44.830784 IP gateway.41803 > server.37890: SWE 1599996997:1599996997(0) win 5840 <mss 1460,sackOK,timestamp 495055487 0,nop,wscale 7>
> 22:37:44.846411 IP server.37890 > gateway.41803: SE 23582050:23582050(0) ack 1599996998 win 5792 <mss 1460,sackOK,timestamp 49338617 495055487,nop,wscale 7>
> 22:37:44.846533 IP gateway.41803 > server.37890: . ack 23582051 win 46 <nop,nop,timestamp 495055488 49338617>
> 
> [...]
> 
> 22:37:44.974253 IP gateway.41803 > server.37890: . 1600282667:1600284115(1448) ack 23582051 win 46 <nop,nop,timestamp 495055501 49338649>
> 
> [...]
> 
> 22:37:44.989794 IP server.37890 > gateway.41803: . ack 1600281219 win 892 <nop,nop,timestamp 49338653 495055501>
> 22:37:44.990228 IP gateway.41803 > server.37890: . 1600358775:1600360223(1448) ack 23582051 win 46 <nop,nop,timestamp 495055502 49338653>
> 
> [...]
> 
> 22:37:44.990397 IP server.37890 > gateway.41803: . ack 1600281219 win 892 <nop,nop,timestamp 49338653 495055501,nop,nop,sack 1 {1600282667:1600284115}>
> 22:37:44.990417 IP gateway.41803 > server.37890: R 1600281219:1600281219(0) win 0
> 
> As you can see, the SACK data matches a previously sent segment,
> so it's not scrambled.

Then the best were if you could capture a full TCP session by tcpdump and 
send it so that we could replay and analyze the traffic.

Best regards,
Jozsef
-
E-mail  : kadlec@blackhole.kfki.hu, kadlec@mail.kfki.hu
PGP key : http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address : KFKI Research Institute for Particle and Nuclear Physics
          H-1525 Budapest 114, POB. 49, Hungary

RE: Weird nat/conntrack Problem with PASV FTP upload

[Thomas Bätzler]

Jozsef Kadlecsik wrote:
> Then the best were if you could capture a full TCP session by 
> tcpdump and send it so that we could replay and analyze the traffic.

I've uploaded an archive to http://baetzler.de/sandbox/dump.tar.bz2.
There is a complete tcp session of a file upload and a second dump
that contains a segment from that connection that was IMHO erroneously
logged/dropped by a rule that filters by state INVALID in the
PREROUTING chain of the mangle table.

Inititator is my NAT box, target is the FTP server.

TIA,
Thomas
-- 
BRINGE Informationstechnik GmbH
Zur Seeplatte 12
D-76228 Karlsruhe
Germany

Fon: +49 721 94246-0
Fon: +49 171 5438457
Fax: +49 721 94246-66
Web: http://www.bringe.de/

Geschäftsführer: Dipl.-Ing. (FH) Martin Bringe
Ust.Id: DE812936645, HRB 108943 Mannheim 

RE: Weird nat/conntrack Problem with PASV FTP upload

[Jozsef Kadlecsik]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 615 bytes --]

On Mon, 9 Jun 2008, Thomas Bätzler wrote:

> Jozsef Kadlecsik wrote:
> > Then the best were if you could capture a full TCP session by 
> > tcpdump and send it so that we could replay and analyze the traffic.
> 
> I've uploaded an archive to http://baetzler.de/sandbox/dump.tar.bz2.

Thanks, I have downloaded it and will try to replay and analyze.

Best regards,
Jozsef
-
E-mail  : kadlec@blackhole.kfki.hu, kadlec@mail.kfki.hu
PGP key : http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address : KFKI Research Institute for Particle and Nuclear Physics
          H-1525 Budapest 114, POB. 49, Hungary

RE: Weird nat/conntrack Problem with PASV FTP upload

[Jozsef Kadlecsik]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 1059 bytes --]

On Mon, 9 Jun 2008, Thomas Bätzler wrote:

> Jozsef Kadlecsik wrote:
> > Then the best were if you could capture a full TCP session by 
> > tcpdump and send it so that we could replay and analyze the traffic.
> 
> I've uploaded an archive to http://baetzler.de/sandbox/dump.tar.bz2.
> There is a complete tcp session of a file upload and a second dump
> that contains a segment from that connection that was IMHO erroneously
> logged/dropped by a rule that filters by state INVALID in the
> PREROUTING chain of the mangle table.

In the first dump there is no dropped packet and the second one contains a 
single packet. Neither of the dumps help. I need a full record of a TCP 
session in which packets were marked as INVALID. If you can attach the log 
record, that'd be even better.

Best regards,
Jozsef
-
E-mail  : kadlec@blackhole.kfki.hu, kadlec@mail.kfki.hu
PGP key : http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address : KFKI Research Institute for Particle and Nuclear Physics
          H-1525 Budapest 114, POB. 49, Hungary

Re: Weird nat/conntrack Problem with PASV FTP upload

[Thomas Bätzler]

Hi,

Jozsef Kadlecsik schrieb:
> In the first dump there is no dropped packet and the second one contains a 
> single packet. Neither of the dumps help. I need a full record of a TCP 
> session in which packets were marked as INVALID. If you can attach the log 
> record, that'd be even better.

Sorry, my fault.

Here's what I've done now:

- "tcpdump -s0" on the external interface
- I log invalid packets using this iptables rule:
   iptables -t mangle -A PREROUTING -m state --state INVALID -j LOG
- locate "invalid" dropped in kernel.log
- tcpdump -r -w on port identified above to create a session dump.

I've uploaded such a session dump and the corresponding log line to
http://baetzler.de/sandbox/dump.tar.bz2

I'm running a Debian flavour 2.6.25 kernel (nf_conntrack version 0.5.0 
(16384 buckets, 65536 max)).

If there's a better/different method to do this or to get additional 
debugging info, please let me know. I'm currently running a kernel 
compiled with debugging info for netfilter enabled, but this does not 
seem to produce any additional output in kernel.log.

TIA,
Thomas
-- 
BRINGE Informationstechnik GmbH
Zur Seeplatte 12
D-76228 Karlsruhe
Germany

Fon: +49 721 94246-0
Fon: +49 171 5438457
Fax: +49 721 94246-66
Web: http://www.bringe.de/

Geschäftsführer: Dipl.-Ing. (FH) Martin Bringe
Ust.Id: DE812936645, HRB 108943 Mannheim

Re: Weird nat/conntrack Problem with PASV FTP upload

[Jozsef Kadlecsik]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 3465 bytes --]

Hi,

On Wed, 11 Jun 2008, Thomas Bätzler wrote:

> Jozsef Kadlecsik schrieb:
> > In the first dump there is no dropped packet and the second one contains a
> > single packet. Neither of the dumps help. I need a full record of a TCP
> > session in which packets were marked as INVALID. If you can attach the log
> > record, that'd be even better.
> 
> I've uploaded such a session dump and the corresponding log line to
> http://baetzler.de/sandbox/dump.tar.bz2

That's a perfect dump file, thank you. Please try the patch below and 
please report me if it helps without any bad effect.

Checking the lower bound of valid ACK could lead to mark valid packets
as INVALID because:
 - We have got a "higher or equal" inequality, but the test checked
   the "higher" condition only; fixed.
 - If the packet contains a SACK option, it might occur that the ACK
   value is before the left edge of our (S)ACK "window": if a previous
   packet from the other party intersected the right edge of the window
   of the receiver, we could move forward the window parameters beyond
   accepting a valid ack. Therefore in this patch we check the rightmost
   SACK edge instead of the ACK value in the lower bound of valid (S)ACK
   test.

---
 net/netfilter/nf_conntrack_proto_tcp.c |   13 +++++++------
 1 files changed, 7 insertions(+), 6 deletions(-)

diff --git a/net/netfilter/nf_conntrack_proto_tcp.c b/net/netfilter/nf_conntrack_proto_tcp.c
index 6256795..fc43e22 100644
--- a/net/netfilter/nf_conntrack_proto_tcp.c
+++ b/net/netfilter/nf_conntrack_proto_tcp.c
@@ -332,12 +332,13 @@ static unsigned int get_conntrack_index(const struct tcphdr *tcph)
 
    I.   Upper bound for valid data:	seq <= sender.td_maxend
    II.  Lower bound for valid data:	seq + len >= sender.td_end - receiver.td_maxwin
-   III.	Upper bound for valid ack:      sack <= receiver.td_end
-   IV.	Lower bound for valid ack:	ack >= receiver.td_end - MAXACKWINDOW
+   III.	Upper bound for valid (s)ack:   sack <= receiver.td_end
+   IV.	Lower bound for valid (s)ack:	sack >= receiver.td_end - MAXACKWINDOW
 
-   where sack is the highest right edge of sack block found in the packet.
+   where sack is the highest right edge of sack block found in the packet
+   or ack in the case of packet without SACK option.
 
-   The upper bound limit for a valid ack is not ignored -
+   The upper bound limit for a valid (s)ack is not ignored -
    we doesn't have to deal with fragments.
 */
 
@@ -607,12 +608,12 @@ static int tcp_in_window(const struct nf_conn *ct,
 		 before(seq, sender->td_maxend + 1),
 		 after(end, sender->td_end - receiver->td_maxwin - 1),
 		 before(sack, receiver->td_end + 1),
-		 after(ack, receiver->td_end - MAXACKWINDOW(sender)));
+		 after(sack, receiver->td_end - MAXACKWINDOW(sender) - 1));
 
 	if (before(seq, sender->td_maxend + 1) &&
 	    after(end, sender->td_end - receiver->td_maxwin - 1) &&
 	    before(sack, receiver->td_end + 1) &&
-	    after(ack, receiver->td_end - MAXACKWINDOW(sender))) {
+	    after(sack, receiver->td_end - MAXACKWINDOW(sender) - 1)) {
 		/*
 		 * Take into account window scaling (RFC 1323).
 		 */
-- 
1.5.3.4

Best regards,
Jozsef
-
E-mail  : kadlec@blackhole.kfki.hu, kadlec@mail.kfki.hu
PGP key : http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address : KFKI Research Institute for Particle and Nuclear Physics
          H-1525 Budapest 114, POB. 49, Hungary

Re: Weird nat/conntrack Problem with PASV FTP upload

[Thomas Bätzler]

Jozsef Kadlecsik wrote:
> That's a perfect dump file, thank you. Please try the patch below and 
> please report me if it helps without any bad effect.

I'm now running the modified code. I should have some results
for you by the end of the week (or sooner, if it doesn't work ;-)).

Thanks a lot for your work on this!

Cheers,
Thomas
-- 
BRINGE Informationstechnik GmbH
Zur Seeplatte 12
D-76228 Karlsruhe
Germany

Fon: +49 721 94246-0
Fon: +49 171 5438457
Fax: +49 721 94246-66
Web: http://www.bringe.de/

Geschäftsführer: Dipl.-Ing. (FH) Martin Bringe
Ust.Id: DE812936645, HRB 108943 Mannheim

Re: Weird nat/conntrack Problem with PASV FTP upload

[Thomas Bätzler]

Jozsef Kadlecsik wrote:
> That's a perfect dump file, thank you. Please try the patch below and 
> please report me if it helps without any bad effect.

We've been running a Debian 2.6.25 kernel (2.6.25-4 to be precise) with
your patch for close to 2 days now. So far, it has worked perfectly:
We've transferred about 88GB of data without a single broken connection
and without a log message from netfilter.

Before we started tinkering with this, we'd see 2 to 4 lost connections
per day.

Thanks a lot for your help in this matter!

Thomas
-- 
BRINGE Informationstechnik GmbH
Zur Seeplatte 12
D-76228 Karlsruhe
Germany

Fon: +49 721 94246-0
Fon: +49 171 5438457
Fax: +49 721 94246-66
Web: http://www.bringe.de/

Geschäftsführer: Dipl.-Ing. (FH) Martin Bringe
Ust.Id: DE812936645, HRB 108943 Mannheim 

Re: Weird nat/conntrack Problem with PASV FTP upload

[Jozsef Kadlecsik]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 829 bytes --]

On Wed, 25 Jun 2008, Thomas Bätzler wrote:

> Jozsef Kadlecsik wrote:
> > That's a perfect dump file, thank you. Please try the patch below and 
> > please report me if it helps without any bad effect.
> 
> We've been running a Debian 2.6.25 kernel (2.6.25-4 to be precise) with
> your patch for close to 2 days now. So far, it has worked perfectly:
> We've transferred about 88GB of data without a single broken connection
> and without a log message from netfilter.

Good! Thank you the reports and the tcpdump recording - it helped a lot to 
find the bug.

Best regards,
Jozsef
-
E-mail  : kadlec@blackhole.kfki.hu, kadlec@mail.kfki.hu
PGP key : http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address : KFKI Research Institute for Particle and Nuclear Physics
          H-1525 Budapest 114, POB. 49, Hungary

Re: Weird nat/conntrack Problem with PASV FTP upload

[Thomas Bätzler]

Hi,

to finish up this matter and perhaps help people who are
in the same situation as me, here's a summary.

- From the end users PoV, data connections from a ftp
client to a ftp server would sometime spontaeously break
down.

- tcpdump on the client side nat gateway showed that
the nat gateway would inject RST packets in the connection.

- Further examination involved logging packets with a
conntrack state of INVALID and proved that the packets
causing the RST reply were considered to be INVALID by
conntrack.

- Upgrading client and NAT gateway from a 2.6.18 Debian
Etch stock kernel to 2.6.25 Debian testing kernel didn't
help.

At this point more info was requested, but I couldn't
provide it in any useful form.

By chance I happend across a posting by Vladislav Kurz
last week, where he suggested to activate conntrack
logging of invalid packets by setting
/proc/sys/net/ipv4/netfilter/ip_conntrack_log_invalid
to the protocol number that one was interested in.

Now that finally gave me some useful output, namely,
"nf_ct_tcp: ACK is under the lower bound (possible overly delayed ACK)".

 From looking at my dumps I think this is probably an
error, but then I'm still digesting the small parts
of TCP/IP Illustrated that I've read so for, so I
might aswell be wrong. If somebody feels like looking
into it, let me know what you need and I'll try and
supply it.

Anyways, the quick and dirty fix to my problem was to put
"inet.ipv4.netfilter.ip_conntrack_tcp_be_liberal=1" in
/etc/systcl.conf.

Cheers,
Thomas
-- 
BRINGE Informationstechnik GmbH
Zur Seeplatte 12
D-76228 Karlsruhe
Germany

Fon: +49 721 94246-0
Fon: +49 171 5438457
Fax: +49 721 94246-66
Web: http://www.bringe.de/

Geschäftsführer: Dipl.-Ing. (FH) Martin Bringe
Ust.Id: DE812936645, HRB 108943 Mannheim

Re: Weird nat/conntrack Problem with PASV FTP upload

[Jozsef Kadlecsik]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 492 bytes --]

On Mon, 23 Jun 2008, Thomas Bätzler wrote:

> to finish up this matter and perhaps help people who are
> in the same situation as me, here's a summary.
[...]

Hm, did you miss the patch I have sent you today (and to this list)?

Best regards,
Jozsef
-
E-mail  : kadlec@blackhole.kfki.hu, kadlec@mail.kfki.hu
PGP key : http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address : KFKI Research Institute for Particle and Nuclear Physics
          H-1525 Budapest 114, POB. 49, Hungary