2

The following network trace was recorded on a Raspberry PI running Debian Linux. It seems the Raspberry is not seeing the data packet #36995 for some reason; it is just stupidly repeating his SYN,ACK until the tcp_synack_retries limit is reached.

Do you have any idea what could go wrong? This is a pattern we observe at most data transfers between these two devices.

We have already tried updating the kernel from 3.18.11 to 4.1.20+. The service behind port 44269 is a Java program (excerpt below) running on Oracle JRE 1.8.0-b132.

See on CloudShark: https://www.cloudshark.org/captures/9a562c79855a

No.     Time           Source                Destination           Protocol Length Info
  36988 0.000000000    192.168.1.150         192.168.1.200         TCP      66     62935 > 44269 [SYN] Seq=0 Win=65535 Len=0 MSS=1460 WS=2 SACK_PERM=1
  36989 0.000302000    192.168.1.200         192.168.1.150         TCP      66     44269 > 62935 [SYN, ACK] Seq=0 Ack=1 Win=29200 Len=0 MSS=1460 SACK_PERM=1 WS=64
  36991 0.001051000    192.168.1.150         192.168.1.200         TCP      60     62935 > 44269 [ACK] Seq=1 Ack=1 Win=65700 Len=0
  36995 0.046655000    192.168.1.150         192.168.1.200         TCP      425    62935 > 44269 [PSH, ACK] Seq=1 Ack=1 Win=65700 Len=371
  37051 0.942187000    192.168.1.200         192.168.1.150         TCP      66     44269 > 62935 [SYN, ACK] Seq=0 Ack=1 Win=29200 Len=0 MSS=1460 SACK_PERM=1 WS=64
  37052 0.001155000    192.168.1.150         192.168.1.200         TCP      60     [TCP Dup ACK 36995#1] 62935 > 44269 [ACK] Seq=372 Ack=1 Win=65700 Len=0
  37183 1.998841000    192.168.1.200         192.168.1.150         TCP      66     44269 > 62935 [SYN, ACK] Seq=0 Ack=1 Win=29200 Len=0 MSS=1460 SACK_PERM=1 WS=64
  37184 0.001005000    192.168.1.150         192.168.1.200         TCP      60     [TCP Dup ACK 36995#2] 62935 > 44269 [ACK] Seq=372 Ack=1 Win=65700 Len=0
  37188 0.054728000    192.168.1.150         192.168.1.200         TCP      425    [TCP Retransmission] 62935 > 44269 [PSH, ACK] Seq=1 Ack=1 Win=65700 Len=371
  37299 1.756498000    192.168.1.150         192.168.1.200         TCP      60     62935 > 44269 [FIN, ACK] Seq=372 Ack=1 Win=65700 Len=0
  37429 2.187771000    192.168.1.200         192.168.1.150         TCP      66     44269 > 62935 [SYN, ACK] Seq=0 Ack=1 Win=29200 Len=0 MSS=1460 SACK_PERM=1 WS=64
  37430 0.001090000    192.168.1.150         192.168.1.200         TCP      60     [TCP Dup ACK 37299#1] 62935 > 44269 [ACK] Seq=373 Ack=1 Win=65700 Len=0
  37579 2.062723000    192.168.1.150         192.168.1.200         TCP      425    [TCP Retransmission] 62935 > 44269 [FIN, PSH, ACK] Seq=1 Ack=1 Win=65700 Len=371
  37964 5.936190000    192.168.1.200         192.168.1.150         TCP      66     44269 > 62935 [SYN, ACK] Seq=0 Ack=1 Win=29200 Len=0 MSS=1460 SACK_PERM=1 WS=64
  37965 0.001178000    192.168.1.150         192.168.1.200         TCP      60     [TCP Dup ACK 37579#1] 62935 > 44269 [ACK] Seq=373 Ack=1 Win=65700 Len=0
  38357 6.184544000    192.168.1.150         192.168.1.200         TCP      425    [TCP Retransmission] 62935 > 44269 [FIN, PSH, ACK] Seq=1 Ack=1 Win=65700 Len=371
  39002 9.814283000    192.168.1.200         192.168.1.150         TCP      66     44269 > 62935 [SYN, ACK] Seq=0 Ack=1 Win=29200 Len=0 MSS=1460 SACK_PERM=1 WS=64
  39003 0.001056000    192.168.1.150         192.168.1.200         TCP      60     [TCP Dup ACK 38357#1] 62935 > 44269 [ACK] Seq=373 Ack=1 Win=65700 Len=0
  39935 14.424503000   192.168.1.150         192.168.1.200         TCP      425    [TCP Retransmission] 62935 > 44269 [FIN, PSH, ACK] Seq=1 Ack=1 Win=65700 Len=371
  43097 48.376598000   192.168.1.150         192.168.1.200         TCP      425    [TCP Retransmission] 62935 > 44269 [FIN, PSH, ACK] Seq=1 Ack=1 Win=65700 Len=371
  43098 0.000295000    192.168.1.200         192.168.1.150         TCP      54     44269 > 62935 [RST] Seq=1 Win=0 Len=0

Java server:

@Override
public void run()
{
    LOG.info("Opening listen socket on port " + port);
    try (ServerSocket serverSocket = new ServerSocket(port))
    {
        while (true)
        {
            Socket socket;
            try
            {
                LOG.debug("Listening on port {} for a client to connect...", port);
                socket = serverSocket.accept();
                LOG.debug("Client connected! Creating worker-thread for " + socket.getInetAddress().getHostName() + ":"
                        + socket.getPort());
                new WorkerThread(socket).start();
            }
            catch (IOException e)
            {
                LOG.error("Failed to listen for a connection", e);
                continue;
            }
        }
    }
    catch (IOException e)
    {
        LOG.error("Failed to open listen socket", e);
        LOG.info("----------SOFTWARE TERMINATED----------");
        System.exit(1);
    }
}

Edit 1: I noticed that netstat -s is showing a very high number of overflows of the listen queue:

netstat -s | grep -i list
    226094 times the listen queue of a socket overflowed
    226094 SYNs to LISTEN sockets dropped

This lead me to checking the size of the backlog, which was 128 (cat /proc/sys/net/ipv4/tcp_max_syn_backlog). I increased it to 2048 but this did not really solve the problem.

I found another post (#646604 on serverfault, can't link it due to too little reputation here) that describes a slightly different problem, but it helped me to locate the responsible section in the Linux kernel: lxr.free-electrons.com/source/net/ipv4/tcp_ipv4.c#L1274

1274         if (sk_acceptq_is_full(sk))
1275                 goto exit_overflow;

1346 exit_overflow:
1347         NET_INC_STATS_BH(sock_net(sk), LINUX_MIB_LISTENOVERFLOWS);
1348 exit_nonewsk:
1349         dst_release(dst);
1350 exit:
1351         NET_INC_STATS_BH(sock_net(sk), LINUX_MIB_LISTENDROPS);
1352         return NULL;

I see here that both counters will count up simultaneously when the application's accept queue overflows. So I will now turn my focus on the Java application to see if there are limits/bottlenecks.

Edit 2: Further investigation brought me to this post that explains this phenomenon pretty well: http://veithen.github.io/2014/01/01/how-tcp-backlog-works-in-linux.html

In short, Linux has two queues that hold new connections before the application takes them via accept() call:

  • the SYN queue, with its length defined by net.ipv4.tcp_max_syn_backlog
  • the accept queue, whose length is determined by the backlog argument in the listen() call

The latter is overflowing in my case. Java encapsulates the listen() call in its ServerSocket() implementation and sets the backlog to a fixed size of 50. This can be seen with ss -l:

State      Recv-Q Send-Q      Local Address:Port          Peer Address:Port
LISTEN     51     50                     :::44269                   :::*

The question is now, why is Java not emptying the accept queue fast enough?

  • Look, what if you try to reproduce this test using Linux Netcat (like here thegeekstuff.com/2012/04/nc-command-examples) (On a server nc -l 44269, on a client machine (or even on the same machine) echo "Test send" | nc localhost 44269? Get tcpdump for it and then add it here. – Sergei Kurenkov Mar 30 '16 at 10:50
  • It took me a while to get Netcat running (must use nc -l -p 44269) and to capture network traffic on localhost (tshark -i lo -w filename.pcap). What I feared happened: Everything was running fine, just as it should. I was running that test on the same machine, in parallel to the Java service (on another port of course). Can this behaviour have something to do with full buffers, max. number of parallel connections, etc.? – chrset Mar 30 '16 at 13:57
  • Look, the bug is in your app. Try to provide a small test program to the community to demonstrate the bug. – Sergei Kurenkov Mar 30 '16 at 14:16
  • Besides writing a small test program to demonstrate the bug, you can also use strace -e trace=network (linux.die.net/man/1/strace) to check difference in syscalls between netcat and your app. There is a chance you can see what your app is doing wrong. – Sergei Kurenkov Mar 31 '16 at 4:41

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.