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

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

[Gabriel Barazer]

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

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

[Willy Tarreau]

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

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

[Willy Tarreau]

[ 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

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

[Gabriel Barazer]

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 <w@1wt.eu> 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

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

[Willy Tarreau]

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 netdev@vger.kernel.org, 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 <w@1wt.eu> 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

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

[Gabriel Barazer]

Hi

On 03/15/2008 9:55:27 AM +0100, Willy Tarreau <w@1wt.eu> 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

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

[Willy Tarreau]

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 <w@1wt.eu> 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