2008-03-15 01:46:51

by Gabriel Barazer

[permalink] [raw]
Subject: [2.6.24.3][net] bug: TCP 3rd handshake abnormal timeouts

Hi,

I am experiencing a very annoying bug which I think is a kernel bug,
related to how a client establishes a TCP connection to a server (both
linux, same vanilla 2.6.24.3 kernels but the problem happened also in
the previous 2.6.23.14 and kernel installed).

The case is about a bunch of web servers accessing a MySQL database
server via TCP and non-persistent connections and all application level
errors have been excluded.
"Sometimes" when establishing a TCP connection to the server, we are
seeing a 3000ms delay before the connection if effectively made. This
has been confirmed first by some strace-d telnet tests, then by tcpdump
captures on both side at the same time.

Here is a simplified version of what _both_ the server and the client
see (it's important because this means the packets are not lost and the
bug not caused by a lossy network). I can send the original pcap file if
necessary.

- The client send a TCP packet with the SYN bit
- The server replies by a TCP packet with the SYN,ACK bits (connection
appears in netstat -a as in the SYN_RECV state)
- Here the client should have replied with a TCP ACK packet, but for
some reason wait for exactly 3 seconds instead (the delay for
retransmitting a SYN packet).
- The client re-send a TCP SYN packet
- The server replies by its TCP SYN,ACK packet
- And finally the client send its TCP ACK packet, completing the 3-way
handshake and beginning communication with the MySQL server.

During the time when the bug happens (~1 minute), I can log into the
server, and confirm this 3 second delay when strace-ing a telnet session
to the mysql port.

I believe the problem is on the client side because when this abnormal
delay happens, all the other mysql connections from the other web
servers are doing fine (the MySQL server serves other host's queries
without any connection delay), and I think I can rule out the userland
processes as well because they are not aware of this TCP handshake
failing and retrying, only the connect() syscall does.

I have reports of other people having this problem on other networks
with different hardware specs, and on different networks (I run this on
a local network).

I have no syncookies enabled, and have the netfilter connection tracking
enabled but the tracked connections count is very stable, not
overflowing and not even increasing when the problem happens.

Obviously, no message in the syslog or the kernel buffer ring.

Has anyone any idea on where to start to find and fix this bug? the
situation is becoming critical as this affects all of our installations
and I can't find a way to solve or even workaround this.

Any comment or idea would be very appreciated.

Gabriel


2008-03-15 07:02:59

by Willy Tarreau

[permalink] [raw]
Subject: Re: [2.6.24.3][net] bug: TCP 3rd handshake abnormal timeouts

Hi Gabriel,

On Sat, Mar 15, 2008 at 02:39:53AM +0100, Gabriel Barazer wrote:
> Hi,

[cc'd netdev]

> I am experiencing a very annoying bug which I think is a kernel bug,
> related to how a client establishes a TCP connection to a server (both
> linux, same vanilla 2.6.24.3 kernels but the problem happened also in
> the previous 2.6.23.14 and kernel installed).
>
> The case is about a bunch of web servers accessing a MySQL database
> server via TCP and non-persistent connections and all application level
> errors have been excluded.
> "Sometimes" when establishing a TCP connection to the server, we are
> seeing a 3000ms delay before the connection if effectively made. This
> has been confirmed first by some strace-d telnet tests, then by tcpdump
> captures on both side at the same time.
>
> Here is a simplified version of what _both_ the server and the client
> see (it's important because this means the packets are not lost and the
> bug not caused by a lossy network). I can send the original pcap file if
> necessary.
>
> - The client send a TCP packet with the SYN bit
> - The server replies by a TCP packet with the SYN,ACK bits (connection
> appears in netstat -a as in the SYN_RECV state)
> - Here the client should have replied with a TCP ACK packet, but for
> some reason wait for exactly 3 seconds instead (the delay for
> retransmitting a SYN packet).
> - The client re-send a TCP SYN packet
> - The server replies by its TCP SYN,ACK packet
> - And finally the client send its TCP ACK packet, completing the 3-way
> handshake and beginning communication with the MySQL server.
>
> During the time when the bug happens (~1 minute), I can log into the
> server, and confirm this 3 second delay when strace-ing a telnet session
> to the mysql port.
>
> I believe the problem is on the client side because when this abnormal
> delay happens, all the other mysql connections from the other web
> servers are doing fine (the MySQL server serves other host's queries
> without any connection delay), and I think I can rule out the userland
> processes as well because they are not aware of this TCP handshake
> failing and retrying, only the connect() syscall does.
>
> I have reports of other people having this problem on other networks
> with different hardware specs, and on different networks (I run this on
> a local network).
>
> I have no syncookies enabled, and have the netfilter connection tracking
> enabled but the tracked connections count is very stable, not
> overflowing and not even increasing when the problem happens.
>
> Obviously, no message in the syslog or the kernel buffer ring.
>
> Has anyone any idea on where to start to find and fix this bug? the
> situation is becoming critical as this affects all of our installations
> and I can't find a way to solve or even workaround this.
>
> Any comment or idea would be very appreciated.

You should carefully check the the SYN-ACK received by the client has a
correct checksum ("cksum OK" in tcpdump output). It would be possible
that for some reason, something on the network randomly corrupts it.

Also, you say you have netfilter with conntrack. Is this on the client ?
If so, you should try disabling it to rule out any possible bug in the
connection tracking.

Regards,
Willy

2008-03-15 07:04:15

by Willy Tarreau

[permalink] [raw]
Subject: Re: [2.6.24.3][net] bug: TCP 3rd handshake abnormal timeouts


[ forgot to CC netdev ]

Hi Gabriel,

On Sat, Mar 15, 2008 at 02:39:53AM +0100, Gabriel Barazer wrote:
> Hi,

[cc'd netdev]

> I am experiencing a very annoying bug which I think is a kernel bug,
> related to how a client establishes a TCP connection to a server (both
> linux, same vanilla 2.6.24.3 kernels but the problem happened also in
> the previous 2.6.23.14 and kernel installed).
>
> The case is about a bunch of web servers accessing a MySQL database
> server via TCP and non-persistent connections and all application level
> errors have been excluded.
> "Sometimes" when establishing a TCP connection to the server, we are
> seeing a 3000ms delay before the connection if effectively made. This
> has been confirmed first by some strace-d telnet tests, then by tcpdump
> captures on both side at the same time.
>
> Here is a simplified version of what _both_ the server and the client
> see (it's important because this means the packets are not lost and the
> bug not caused by a lossy network). I can send the original pcap file if
> necessary.
>
> - The client send a TCP packet with the SYN bit
> - The server replies by a TCP packet with the SYN,ACK bits (connection
> appears in netstat -a as in the SYN_RECV state)
> - Here the client should have replied with a TCP ACK packet, but for
> some reason wait for exactly 3 seconds instead (the delay for
> retransmitting a SYN packet).
> - The client re-send a TCP SYN packet
> - The server replies by its TCP SYN,ACK packet
> - And finally the client send its TCP ACK packet, completing the 3-way
> handshake and beginning communication with the MySQL server.
>
> During the time when the bug happens (~1 minute), I can log into the
> server, and confirm this 3 second delay when strace-ing a telnet session
> to the mysql port.
>
> I believe the problem is on the client side because when this abnormal
> delay happens, all the other mysql connections from the other web
> servers are doing fine (the MySQL server serves other host's queries
> without any connection delay), and I think I can rule out the userland
> processes as well because they are not aware of this TCP handshake
> failing and retrying, only the connect() syscall does.
>
> I have reports of other people having this problem on other networks
> with different hardware specs, and on different networks (I run this on
> a local network).
>
> I have no syncookies enabled, and have the netfilter connection tracking
> enabled but the tracked connections count is very stable, not
> overflowing and not even increasing when the problem happens.
>
> Obviously, no message in the syslog or the kernel buffer ring.
>
> Has anyone any idea on where to start to find and fix this bug? the
> situation is becoming critical as this affects all of our installations
> and I can't find a way to solve or even workaround this.
>
> Any comment or idea would be very appreciated.

You should carefully check the the SYN-ACK received by the client has a
correct checksum ("cksum OK" in tcpdump output). It would be possible
that for some reason, something on the network randomly corrupts it.

Also, you say you have netfilter with conntrack. Is this on the client ?
If so, you should try disabling it to rule out any possible bug in the
connection tracking.

Regards,
Willy

2008-03-15 08:47:41

by Gabriel Barazer

[permalink] [raw]
Subject: Re: [2.6.24.3][net] bug: TCP 3rd handshake abnormal timeouts

Hi

Thanks for the netdev Cc, I didn't know where to write to the "network
guys".

By the way thanks for replying. It's hard to explain and describe a
problem when you know people will ask you hundreds of questions related
to application-level problems, or not reply because web/mysql problems
are so common and generally not related to any kernel issue.

On 03/15/2008 7:58:49 AM +0100, Willy Tarreau <[email protected]> wrote:
>
> You should carefully check the the SYN-ACK received by the client has a
> correct checksum ("cksum OK" in tcpdump output). It would be possible
> that for some reason, something on the network randomly corrupts it.

I used to use TCP offloading one time, and by the way never had a
problem with it. Besides just to be sure, I have been able to reproduce
the problem without any offload engine enabled (= not compiled into the
kernel, mainly because it seems to hang the kernel at boot in 2.6.24.3).
So I assume that is not the problem

I use wireshark to analyse my pcap files and it says the checksum is
correct on all packets.

> Also, you say you have netfilter with conntrack. Is this on the client ?
> If so, you should try disabling it to rule out any possible bug in the
> connection tracking.

I have the conntrack on both the client and server, and unfortunately
can't disable it now on the client (I use it only for the REDIRECT
target on a precise destination address and port, not MySQL related),
however I will test today and disable it on the server, after I get some
sleep (although I think the issue is on the client).

Gabriel

2008-03-15 08:55:42

by Willy Tarreau

[permalink] [raw]
Subject: Re: [2.6.24.3][net] bug: TCP 3rd handshake abnormal timeouts

On Sat, Mar 15, 2008 at 09:47:24AM +0100, Gabriel Barazer wrote:
> Hi
>
> Thanks for the netdev Cc, I didn't know where to write to the "network
> guys".

except I just noticed I got it wrong: it's [email protected], and
I omitted the "vger" part. That's what is expected when posting before
caffeine :-)

Feel free to repost the whole issue overthere (along with your new tests)
if you don't get useful replies in a few days.

> By the way thanks for replying. It's hard to explain and describe a
> problem when you know people will ask you hundreds of questions related
> to application-level problems, or not reply because web/mysql problems
> are so common and generally not related to any kernel issue.

What caught my attention was the usual "3s delay", which is purely TCP
and application-independant.

> On 03/15/2008 7:58:49 AM +0100, Willy Tarreau <[email protected]> wrote:
> >
> >You should carefully check the the SYN-ACK received by the client has a
> >correct checksum ("cksum OK" in tcpdump output). It would be possible
> >that for some reason, something on the network randomly corrupts it.
>
> I used to use TCP offloading one time, and by the way never had a
> problem with it. Besides just to be sure, I have been able to reproduce
> the problem without any offload engine enabled (= not compiled into the
> kernel, mainly because it seems to hang the kernel at boot in 2.6.24.3).
> So I assume that is not the problem

OK

> I use wireshark to analyse my pcap files and it says the checksum is
> correct on all packets.

OK

> >Also, you say you have netfilter with conntrack. Is this on the client ?
> >If so, you should try disabling it to rule out any possible bug in the
> >connection tracking.
>
> I have the conntrack on both the client and server, and unfortunately
> can't disable it now on the client (I use it only for the REDIRECT
> target on a precise destination address and port, not MySQL related),
> however I will test today and disable it on the server, after I get some
> sleep (although I think the issue is on the client).

I'm sure it's a client issue too, that's why it would be reasonable to
be able to try without conntrack. Can't you use a TCP proxy instead of
REDIRECT ? Also, you said that you also noticed the same behaviour in
other environments, maybe there you can disable conntrack ?

Willy

2008-03-16 16:25:23

by Gabriel Barazer

[permalink] [raw]
Subject: Re: [2.6.24.3][net] bug: TCP 3rd handshake abnormal timeouts

Hi

On 03/15/2008 9:55:27 AM +0100, Willy Tarreau <[email protected]> wrote:
> On Sat, Mar 15, 2008 at 09:47:24AM +0100, Gabriel Barazer wrote:
>
> Feel free to repost the whole issue overthere (along with your new tests)
> if you don't get useful replies in a few days.
>
>> By the way thanks for replying. It's hard to explain and describe a
>> problem when you know people will ask you hundreds of questions related
>> to application-level problems, or not reply because web/mysql problems
>> are so common and generally not related to any kernel issue.
>
> What caught my attention was the usual "3s delay", which is purely TCP
> and application-independant.
>
>
>>> Also, you say you have netfilter with conntrack. Is this on the client ?
>>> If so, you should try disabling it to rule out any possible bug in the
>>> connection tracking.
>> I have the conntrack on both the client and server, and unfortunately
>> can't disable it now on the client (I use it only for the REDIRECT
>> target on a precise destination address and port, not MySQL related),
>> however I will test today and disable it on the server, after I get some
>> sleep (although I think the issue is on the client).
>
> I'm sure it's a client issue too, that's why it would be reasonable to
> be able to try without conntrack. Can't you use a TCP proxy instead of
> REDIRECT ? Also, you said that you also noticed the same behaviour in
> other environments, maybe there you can disable conntrack ?

I was able to reproduce the bug multiple times without conntrack nor
netfilter on the client and the server(I recompiled the kernel disabling
the entire netfilter subsystem). The 3-second problem still occurs so we
can completely rule out contrack-related bugs.

What can we do and test next?

Gabriel

2008-03-20 04:40:23

by Willy Tarreau

[permalink] [raw]
Subject: Re: [2.6.24.3][net] bug: TCP 3rd handshake abnormal timeouts

On Sun, Mar 16, 2008 at 05:24:38PM +0100, Gabriel Barazer wrote:
> Hi
>
> On 03/15/2008 9:55:27 AM +0100, Willy Tarreau <[email protected]> wrote:
> >On Sat, Mar 15, 2008 at 09:47:24AM +0100, Gabriel Barazer wrote:
> >
> >Feel free to repost the whole issue overthere (along with your new tests)
> >if you don't get useful replies in a few days.
> >
> >>By the way thanks for replying. It's hard to explain and describe a
> >>problem when you know people will ask you hundreds of questions related
> >>to application-level problems, or not reply because web/mysql problems
> >>are so common and generally not related to any kernel issue.
> >
> >What caught my attention was the usual "3s delay", which is purely TCP
> >and application-independant.
> >
> >
> >>>Also, you say you have netfilter with conntrack. Is this on the client ?
> >>>If so, you should try disabling it to rule out any possible bug in the
> >>>connection tracking.
> >>I have the conntrack on both the client and server, and unfortunately
> >>can't disable it now on the client (I use it only for the REDIRECT
> >>target on a precise destination address and port, not MySQL related),
> >>however I will test today and disable it on the server, after I get some
> >>sleep (although I think the issue is on the client).
> >
> >I'm sure it's a client issue too, that's why it would be reasonable to
> >be able to try without conntrack. Can't you use a TCP proxy instead of
> >REDIRECT ? Also, you said that you also noticed the same behaviour in
> >other environments, maybe there you can disable conntrack ?
>
> I was able to reproduce the bug multiple times without conntrack nor
> netfilter on the client and the server(I recompiled the kernel disabling
> the entire netfilter subsystem). The 3-second problem still occurs so we
> can completely rule out contrack-related bugs.

ah, that's excellent. Now we're pretty sure that either :
a) the packets are corrupted somewhere (but I believe you told that the
checksums were indicated OK)
b) there is something wrong on the client side, either a major tuning
issue (but I don't see what may cause this) or a bug (more likely)

Do you know how many sessions/s you have between the client and the server ?
Is it in the order of 10, 100, 1000, 10000 ? Also, I think that a full
capture of the same session on both ends will help (either join the pcap
file, or decode it with tcpdump -Snevvvs0). For instance, it would be
possible (though strange) that for an unknown reason, sometimes the ARP
entry for the client in the server table is wrong, so that the client does
not accept the SYN-ACK. However, sniffing it in promiscuous mode still shows
it.

Regards,
Willy