2

As far as I konw, tcp delay ack always 200ms, but now in my production environment it delay almost 600ms, my environment is below: ubuntu 11.04 48G memory 16 core, load not heavy; I catch packet in the server(6380 is server port), the packet is below, as we can see at time 16:29:24.036999 the server receive a packet from the client, but the not reply ack until 16:29:24.634244, it last almost 600ms, and the client timeout set is 500ms,so it close the connection.

600ms+ delay ack packet
16:29:12.458770 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [.], ack 11504, win 1107, length 0
16:29:15.070423 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [P.], seq 9756:9790, ack 11504, win 1107, length 34
16:29:15.070497 IP 192.168.70.134.6380 > 192.168.60.71.22142: Flags [P.], seq 11504:11514, ack 9790, win 848, length 10
16:29:15.070568 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [.], ack 11514, win 1107, length 0
16:29:16.951893 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [P.], seq 9790:9842, ack 11514, win 1107, length 52
16:29:16.951983 IP 192.168.70.134.6380 > 192.168.60.71.22142: Flags [P.], seq 11514:11620, ack 9842, win 848, length 106
16:29:16.952100 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [.], ack 11620, win 1107, length 0
16:29:18.469622 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [P.], seq 9842:9894, ack 11620, win 1107, length 52
16:29:18.469761 IP 192.168.70.134.6380 > 192.168.60.71.22142: Flags [P.], seq 11620:11721, ack 9894, win 848, length 101
16:29:18.469839 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [.], ack 11721, win 1107, length 0
16:29:20.202913 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [P.], seq 9894:10710, ack 11721, win 1107, length 816
16:29:20.203026 IP 192.168.70.134.6380 > 192.168.60.71.22142: Flags [P.], seq 11721:11726, ack 10710, win 863, length 5
16:29:20.203157 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [.], ack 11726, win 1107, length 0
16:29:21.893243 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [P.], seq 10710:10744, ack 11726, win 1107, length 34
16:29:21.893354 IP 192.168.70.134.6380 > 192.168.60.71.22142: Flags [P.], seq 11726:11736, ack 10744, win 863, length 10
16:29:21.893487 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [.], ack 11736, win 1107, length 0
16:29:24.036999 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [P.], seq 10744:10796, ack 11736, win 1107, length 52
16:29:24.240657 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [P.], seq 10744:10796, ack 11736, win 1107, length 52
16:29:24.536929 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [F.], seq 10796, ack 11736, win 1107, length 0
16:29:24.634244 IP 192.168.70.134.6380 > 192.168.60.71.22142: Flags [P.], seq 11736:12057, ack 10796, win 863, length 321
16:29:24.634410 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [F.], seq 10796, ack 11736, win 1107, length 0
16:29:24.634470 IP 192.168.60.71.22142 > 192.168.70.134.6380: Flags [R], seq 554218496, win 0, length 0

800ms delay ack packet
16:37:01.921951 IP 192.168.60.72.23935 > 192.168.70.135.6380: Flags [P.], seq 40135:40187, ack 42430, win 1081, length 52
16:37:01.922029 IP 192.168.70.135.6380 > 192.168.60.72.23935: Flags [P.], seq 42430:42655, ack 40187, win 1345, length 225
16:37:01.922097 IP 192.168.60.72.23935 > 192.168.70.135.6380: Flags [.], ack 42655, win 1081, length 0
16:37:04.569001 IP 192.168.60.72.23935 > 192.168.70.135.6380: Flags [P.], seq 40187:40239, ack 42655, win 1081, length 52
16:37:04.770636 IP 192.168.60.72.23935 > 192.168.70.135.6380: Flags [P.], seq 40187:40239, ack 42655, win 1081, length 52
16:37:05.069588 IP 192.168.60.72.23935 > 192.168.70.135.6380: Flags [F.], seq 40239, ack 42655, win 1081, length 0
16:37:05.178638 IP 192.168.60.72.23935 > 192.168.70.135.6380: Flags [P.], seq 40187:40239, ack 42655, win 1081, length 52
16:37:05.442263 IP 192.168.70.135.6380 > 192.168.60.72.23935: Flags [P.], seq 42655:42832, ack 40239, win 1345, length 177
16:37:05.443329 IP 192.168.70.135.6380 > 192.168.60.72.23935: Flags [.], ack 40239, win 1345, options [nop,nop,sack 1 {40187:40239}], length 0
16:37:05.443484 IP 192.168.60.72.23935 > 192.168.70.135.6380: Flags [F.], seq 40239, ack 42655, win 1081, length 0
16:37:05.445463 IP 192.168.70.135.6380 > 192.168.60.72.23935: Flags [F.], seq 42832, ack 40240, win 1345, options [nop,nop,sack 1 {40239:40240}], length 0
16:37:05.448999 IP 192.168.60.72.23935 > 192.168.70.135.6380: Flags [R], seq 4279187611, win 0, length 0
4
  • What client timeout are you talking about? Sep 11, 2014 at 1:01
  • @DavidSchwartz now my doubt is why the ack delay 600ms?(as i know tcp delay Maximum is 200ms, am i wrong?) not the client timeout, the client set the SO_RCVTIMEO 500ms, so it timeout.
    – good90
    Sep 11, 2014 at 1:11
  • It looks like a packet was lost and retransmitted. The recipient didn't know the packet was lost and retransmitted, and so started a 200ms timer when it received the retransmit. A 500ms timeout over TCP is idiotic. Sep 11, 2014 at 1:15
  • @DavidSchwartz no, this packet is captured in the server side, so we can see the server recv the packet but not response ack to the client, so after 200ms the client retransmitted the packet.
    – good90
    Sep 11, 2014 at 1:19

2 Answers 2

1

RFC 1122 section 4.2.3.2 specifies that an ACK can be delayed as much as 500 milliseconds:

        A TCP SHOULD implement a delayed ACK, but an ACK should not
        be excessively delayed; in particular, the delay MUST be
        less than 0.5 seconds, and in a stream of full-sized
        segments there SHOULD be an ACK for at least every second
        segment.

There is no rush to send an ACK. Something is odd here though, the retransmission seems awfully quick.

3
  • but my packet delay 600ms, and i also capture a packet in the server side delay almost 900ms.
    – good90
    Sep 11, 2014 at 1:35
  • You seem to be expecting some unreasonable level of precision from TCP timers. It's not intended to be a real-time, low-latency service. Sep 11, 2014 at 1:39
  • when i test the delay ack in this machine, it's ok, 200ms
    – good90
    Sep 11, 2014 at 1:42
0

If you see a packet in tcpdump it only says, that the packet arrived at the machine. But, the ACK gets only created by the kernel if it could deliver the packet into the socket buffer of the application. This could fail because the packet was blocked by the packet filter or because the system has not enough memory, but the most likely case is that the socket buffer of the application is full because it got a bulk of data in a short time and was not able to process all of them yet.

In this case the packet is lost even if it arrived at the system, so no ACK will be generated and the packet has to be retransmitted by the sender. If the application is ready and has room in the socket buffer it can now be delivered, otherwise it will be lost and again no ACK will be sent.

5
  • my server load is not heavy, and the connection is a persistent connection, you can see the packet at time 16:37:01.921951 is response ok, so the data in the socket buff must already delivered to the application, it cannot be socket buff full.
    – good90
    Sep 11, 2014 at 12:46
  • I only see that there is an ACK to this packet and that the packet from the server contains data. That only means that the packet was successfully put into the socket buffer and that the server send some data back (together with the ACK). It does not say that the data the server sent are in response to the packet it just got, they might be a response to earlier data. You can only be sure if you could match directly match request and response by looking at the content of the data or similar techniques. Sep 11, 2014 at 12:55
  • from the packet at time 16:37:01.922029 we can see the tcp windows size is 1345, so the tcp socket buff must not full, is't it?
    – good90
    Sep 12, 2014 at 7:13
  • Yes, I think you are right. The traffic looks indeed strange, as if the server waits for sending out acks until it has own data to send. It looks like there is a tcp_delack_min parameter on some versions of RedHat, maybe this was used on the server? Or any patches proposed in lwn.net/Articles/502585 to tune the TCP stack? Sep 12, 2014 at 7:57
  • my server system is ubuntu11.04, and the server application is redis, i see redis slow log, no command execute more than 10ms, so i think is may system reason
    – good90
    Sep 12, 2014 at 14:05

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .