Why doesn't Java see an incoming UDP packet that tcpdump shows is received?

Question

I am seeing an issue (Java 6 on SLES11) where a UDP packet is being sent back to the client machine (and tcpdump on the client machine shows it being received), but the packet isn't being seen by Java.

The test works like this:

The client side generates some random data, sticks it in a UDP packet, sends it to the server on a particular port and waits for it to be echoed back (with a SO_TIMEOUT of 180000 ms). When it receives it back it prints out that it has received it and how long since it's been sent.

The server side listens for a UDP packet on a that port. When it receives it, it delays a bit then sends it right back, unchanged. The delay starts at some initial value (3000 ms) then doubles each time it receives a packet until it reaches a maximum (90000 ms) after which the delay just stays at the maximum.

It works fine until the delay hits 48000 ms. The tcpdump running on the client shows the packet being sent and shows the reply packet arriving 48000 ms later. However, the Java program never sees that reply packet and after 180000 ms claims the receive timed out. Even though the client machine got the packet after only 48000 ms as tcpdump shows.

What could be happening?

Below is the output of the programs and tcpdump and after that is the source of the client and server programs.

On the client machine the test program output is:

rich-ova3:~/UDPTest2 # java -cp . Client
Properties:
-- listing properties --
ServerPort=20000
Timeout=180000
Server=rich-ova5.teak.eng
Loops=8
DatagramLength=333

UDP socket timeout is 180000 ms
Sending packet 1 of 8
Received packet 1 of 8
Round-trip time: 3001 ms

Sending packet 2 of 8
Received packet 2 of 8
Round-trip time: 6001 ms

Sending packet 3 of 8
Received packet 3 of 8
Round-trip time: 12001 ms

Sending packet 4 of 8
Received packet 4 of 8
Round-trip time: 24000 ms

Sending packet 5 of 8
Error receiving: Receive timed out
java.net.SocketTimeoutException: Receive timed out
        at java.net.PlainDatagramSocketImpl.receive0(Native Method)
        at java.net.PlainDatagramSocketImpl.receive(Unknown Source)
        at java.net.DatagramSocket.receive(Unknown Source)
        at Client.go(Client.java:80)
        at Client.main(Client.java:39)
Round-trip time: 180096 ms

Sending packet 6 of 8
Error receiving: Receive timed out
java.net.SocketTimeoutException: Receive timed out
        at java.net.PlainDatagramSocketImpl.receive0(Native Method)
        at java.net.PlainDatagramSocketImpl.receive(Unknown Source)
        at java.net.DatagramSocket.receive(Unknown Source)
        at Client.go(Client.java:80)
        at Client.main(Client.java:39)
Round-trip time: 180087 ms

Sending packet 7 of 8
Error receiving: Receive timed out
java.net.SocketTimeoutException: Receive timed out
        at java.net.PlainDatagramSocketImpl.receive0(Native Method)
        at java.net.PlainDatagramSocketImpl.receive(Unknown Source)
        at java.net.DatagramSocket.receive(Unknown Source)
        at Client.go(Client.java:80)
        at Client.main(Client.java:39)
Round-trip time: 180093 ms

Sending packet 8 of 8
Error receiving: Receive timed out
java.net.SocketTimeoutException: Receive timed out
        at java.net.PlainDatagramSocketImpl.receive0(Native Method)
        at java.net.PlainDatagramSocketImpl.receive(Unknown Source)
        at java.net.DatagramSocket.receive(Unknown Source)
        at Client.go(Client.java:80)
        at Client.main(Client.java:39)
Round-trip time: 180078 ms

Send successes: 8
Send errors: 0

Receive successes: 4
Receive errors: 4

The tcpdump output on the client machine (with my comments interlined) is:

16:03:42.438252 IP 172.16.20.113.16362 > 172.16.20.115.20000: UDP, length 333
16:03:45.439322 IP 172.16.20.115.20000 > 172.16.20.113.16362: UDP, length 333
(a 3011 ms delay)

16:03:45.440315 IP 172.16.20.113.25559 > 172.16.20.115.20000: UDP, length 333
16:03:51.441394 IP 172.16.20.115.20000 > 172.16.20.113.25559: UDP, length 333
(a 6001 ms delay)

16:03:51.441938 IP 172.16.20.113.30457 > 172.16.20.115.20000: UDP, length 333
16:04:03.442564 IP 172.16.20.115.20000 > 172.16.20.113.30457: UDP, length 333
(a 12000 ms delay)

16:04:03.443095 IP 172.16.20.113.46143 > 172.16.20.115.20000: UDP, length 333
16:04:27.443572 IP 172.16.20.115.20000 > 172.16.20.113.46143: UDP, length 333
(a 24001ms delay)

16:04:27.444109 IP 172.16.20.113.31747 > 172.16.20.115.20000: UDP, length 333
16:05:15.444688 IP 172.16.20.115.20000 > 172.16.20.113.31747: UDP, length 333
(a 48001 ms delay)

16:07:27.540689 IP 172.16.20.113.38357 > 172.16.20.115.20000: UDP, length 333
16:08:57.541312 IP 172.16.20.115.20000 > 172.16.20.113.38357: UDP, length 333
(a 90000 ms delay)

16:10:27.627411 IP 172.16.20.113.33915 > 172.16.20.115.20000: UDP, length 333
16:11:57.631436 IP 172.16.20.115.20000 > 172.16.20.113.33915: UDP, length 333
(a 90004 ms delay)

16:13:27.720668 IP 172.16.20.113.36494 > 172.16.20.115.20000: UDP, length 333
16:14:57.722353 IP 172.16.20.115.20000 > 172.16.20.113.36494: UDP, length 333
(a 90001 ms delay)

On the server machine the test program output is:

rich-ova5:~/UDPTest2 # java -cp . Server
Properties:
-- listing properties --
MinSleepTime=1000
DatagramLength=333
MaxSleepTime=90000
Port=20000

Received packet.
Delaying for 3000 ms
Sending packet.

Received packet.
Delaying for 6000 ms
Sending packet.

Received packet.
Delaying for 12000 ms
Sending packet.

Received packet.
Delaying for 24000 ms
Sending packet.

Received packet.
Delaying for 48000 ms
Sending packet.

Received packet.
Delaying for 90000 ms
Sending packet.

Received packet.
Delaying for 90000 ms
Sending packet.

Received packet.
Delaying for 90000 ms
Sending packet.

And here is the client source:

import java.io.FileInputStream;
import java.io.IOException;
import java.net.DatagramPacket;
import java.net.DatagramSocket;
import java.net.InetAddress;
import java.net.UnknownHostException;
import java.util.Properties;
import java.util.Random;

public class Client {
    private static final String CONFIG_FILE = "client.conf";

    private int datagramLength;
    private boolean debug;
    private InetAddress server;
    private int serverPort;
    private int timeout;
    private int loops;

    public static void main(String[] arg) throws Exception {
        Client c = new Client();
        c.go();
    }

    private void go() throws Exception {
        readClientConfig();
        Random rand = new Random(System.currentTimeMillis());

        System.out.println("UDP socket timeout is " + timeout + " ms");

        byte[] referenceData = new byte[datagramLength];
        byte[] sentData = new byte[referenceData.length];

        int receiveErrors = 0;
        int receiveSuccess = 0;
        int sendErrors = 0;
        int sendSuccess = 0;

        for (int i = 0; i < loops; i++) {
            long sendTime = 0;
            long receiveTime = 0;

            rand.nextBytes(referenceData);
            System.arraycopy(referenceData, 0, sentData, 0, referenceData.length);

            DatagramSocket serverSock = new DatagramSocket();
            serverSock.setSoTimeout(timeout);

            DatagramPacket datagram = new DatagramPacket(sentData, sentData.length, server, serverPort);
            try {
                System.out.println("Sending packet " + (i + 1) + " of " + loops);
                serverSock.send(datagram);
                sendSuccess++;
            } catch (Exception e) {
                System.out.println("Error sending: " + e.getMessage());
                e.printStackTrace();
                sendErrors++;
                continue;
            }
            sendTime = System.currentTimeMillis();

            try {
                serverSock.receive(datagram);
                System.out.println("Received packet " + (i + 1) + " of " + loops);
                receiveSuccess++;
            } catch (Exception e) {
                receiveErrors++;
                System.out.println("Error receiving: " + e.getMessage());
                e.printStackTrace();
            }
            serverSock.close();

            receiveTime = System.currentTimeMillis();
            System.out.println("Round-trip time: " + (receiveTime - sendTime) + " ms");

            byte[] receivedData = datagram.getData();
            if (receivedData.length != referenceData.length) {
                System.out.println("Mismatched packet length.");
                sendErrors++;
            }

            for (int j = 0; j < datagramLength; j++) {
                if (referenceData[j] != receivedData[j]) {
                    System.out.println("Mismatched packet contents.");
                    sendErrors++;
                }
            }

            System.out.println();
        }

        System.out.println("Send successes: " + sendSuccess);
        System.out.println("Send errors: " + sendErrors);
        System.out.println();
        System.out.println("Receive successes: " + receiveSuccess);
        System.out.println("Receive errors: " + receiveErrors);
    }

    private void readClientConfig() throws IOException {
        boolean hasError = false;
        String val;
        Properties prop = new Properties();

        FileInputStream fis = new FileInputStream(CONFIG_FILE);
        prop.load(fis);

        val = prop.getProperty("Server");
        if (val == null) {
            System.out.println("Error reading 'Server': missing value");
            hasError = true;
        } else {
            try {
                server = InetAddress.getByName(val);
            } catch (UnknownHostException e) {
                System.out.println("Error reading 'Server': " + e.getMessage());
                hasError = true;
            }
        }

        val = prop.getProperty("ServerPort", "3000");
        try {
            serverPort = Integer.parseInt(val);
        } catch (NumberFormatException e) {
            System.out.println("Error reading 'ServerPort': " + e.getMessage());
            hasError = true;
        }

        val = prop.getProperty("DatagramLength", "200");
        try {
            datagramLength = Integer.parseInt(val);
        } catch (NumberFormatException e) {
            System.out.println("Error reading 'DatagramLength': " + e.getMessage());
            hasError = true;
        }

        // Time out in milliseconds.
        val = prop.getProperty("Timeout", "3000");
        try {
            timeout = Integer.parseInt(val);
        } catch (NumberFormatException e) {
            System.out.println("Error reading 'Timeout' value.");
            hasError = true;
        }

        // Number of loops to perform.
        val = prop.getProperty("Loops", "1");
        try {
            loops = Integer.parseInt(val);
        } catch (NumberFormatException nfe) {
            System.out.println("Error reading 'Loops' value.");
            hasError = true;
        }
        val = prop.getProperty("EnableDebug", "yes");
        debug = val.equalsIgnoreCase("yes");

        System.out.println("Properties:");
        prop.list(System.out);
        System.out.println();

        if (hasError) {
            System.out.println("There are errors - fix them and restart the server.");
            System.exit(1);
        }
    }

}

And the server source:

import java.io.FileInputStream;
import java.io.IOException;
import java.net.DatagramPacket;
import java.net.DatagramSocket;
import java.util.Properties;

public class Server {
    private static final String CONFIG_FILE = "server.conf";

    private int datagramLength;
    private boolean debug;
    private int port;
    private long initialDelay;
    private long maxDelay;

    public static void main(String[] arg) throws Exception {
        Server s = new Server();
        s.go();
    }

    private void go() throws Exception {
        readServerConfig();

        DatagramSocket sock = new DatagramSocket(port);

        sock.setSoTimeout(0);

        byte[] in = new byte[datagramLength];
        DatagramPacket datagram = new DatagramPacket(in, datagramLength);

        // Loop with exponentially-increasing delays between receive
        // and reply (up to the specified maximum delay).
        long delay = initialDelay;
        while (true) {
            sock.receive(datagram);
            System.out.println("Received packet.");

            System.out.println("Delaying for " + delay + " ms");
            Thread.sleep(delay);

            System.out.println("Sending packet.");

            datagram.setSocketAddress(datagram.getSocketAddress());
            datagram.setPort(datagram.getPort());
            sock.send(datagram);

            System.out.println();

            delay *= 2;
            if (delay > maxDelay) {
                delay = maxDelay;
            }
        }
    }

    private void readServerConfig() throws IOException {
        boolean hasError = false;
        String val;
        Properties prop = new Properties();

        FileInputStream fis = new FileInputStream(CONFIG_FILE);
        prop.load(fis);

        val = prop.getProperty("Port", "3000");
        try {
            port = Integer.parseInt(val);
        } catch (NumberFormatException e) {
            System.out.println("Error reading 'Port' value: " + e.getMessage());
            hasError = true;
        }

        val = prop.getProperty("DatagramLength", "200");
        try {
            datagramLength = Integer.parseInt(val);
        } catch (NumberFormatException e) {
            System.out.println("Error reading 'DatagramLength' value: " + e.getMessage());
            hasError = true;
        }

        val = prop.getProperty("StartSleepTime", "3000");
        try {
            initialDelay = Long.parseLong(val);
        } catch (NumberFormatException e) {
            System.out.println("Error reading 'StartSleepTime' value: " + e.getMessage());
            hasError = true;
        }

        val = prop.getProperty("MaxSleepTime", "60000");
        try {
            maxDelay = Long.parseLong(val);
        } catch (NumberFormatException e) {
            System.out.println("Error reading 'MaxSleepTime' value: " + e.getMessage());
            hasError = true;
        }

        val = prop.getProperty("EnableDebug", "yes");
        debug = val.equalsIgnoreCase("yes");

        System.out.println("Properties:");
        prop.list(System.out);
        System.out.println();

        if (hasError) {
            System.out.println("There are errors - fix them and restart the server.");
            System.exit(1);
        }
    }

}

And client.conf:

# Server address
Server = rich-ova5.teak.eng

# Server port number.
ServerPort = 20000

# This is the length of the data to send.
# It must match the server's size.
DatagramLength = 333

# Number of times to run the client.
Loops = 8

# Client time out period in milliseconds.
Timeout = 180000

And finally, server.conf:

# Server port number.
Port=20000

# Length of the datagram.
# It must match the client's size.
DatagramLength = 333

# Initial sleep time.
MinSleepTime = 1000

# Maximu sleep time. Goes from the MinSleepTime to the
# maximum sleep time.
MaxSleepTime = 90000

That's a typo (which I've fixed). As you can see from the actual client and server output in the question, both programs are using port 20000. — QuantumMechanic, Dec 15 '11 at 22:06
Running the Client and Server on `localhost` works just fine -- no errors at all. — sarnold, Dec 15 '11 at 22:09
Are the two machines on different sides of a NAT box? If so, there may be a timeout occurring at the translation point where it "forgets" the pseudo-connection. — Jim Garrison, Dec 15 '11 at 22:12
No, they aren't. Both are on the same subnet. And there are no routers of any sort between them. — QuantumMechanic, Dec 15 '11 at 22:14
What do you get if you call getSoTimeout() after setting it? — Jim Garrison, Dec 15 '11 at 22:22
sarnold -- same for me. No problems when both server and client are on `localhost` — QuantumMechanic, Dec 15 '11 at 22:31
Jim - I reran, printing `serverSock.getSoTimeout()` right after the call to `serverSock.send()` and it remains at 180000. — QuantumMechanic, Dec 15 '11 at 22:33
Fire up the client and server, and when it gets to the 48-second case, the one where it times out, do `cat /proc/net/udp`. You should be able to see the actual timeout value in use on the socket. — Jim Garrison, Dec 15 '11 at 22:40

score 0 · Answer 1 · edited May 23 '17 at 12:27

0

If possible, perhaps check the IPv4 TTL (Time to Live) of the packet in the tcpdump capture.

After the 48 seconds, the packet might be received but dropped by the IP stack on the receiver side because of the TTL.

Also see this answer about changing the TTL (which says it is only for Multicast sockets but was accepted anyways): Java control IP TTL?

edited May 23 '17 at 12:27

Community

1
1

answered Dec 15 '11 at 22:06

Christian

1,900
14
19

5

TTL refers to the number of hops, not a time value. – Jim Garrison Dec 15 '11 at 22:11
Note that [TTL](http://en.wikipedia.org/wiki/Time_to_live) hasn't meant "time" in decades -- it's really a _hop count_. The delay between sending packets won't influence the TTL set on the packet when it is initially sent. The default in `/proc/sys/net/ipv4/ip_default_ttl` (`64` on my system) really should be suitable for most networks. – sarnold Dec 15 '11 at 22:12
My TTL is 64. And that's not an issue since there are no hops between the machines (on same subnet with no routers between them). – QuantumMechanic Dec 15 '11 at 22:15

score 0 · Answer 2 · answered Dec 15 '11 at 22:53

That could happen if the receiver's socket receive buffer is full.

Slightly off topic, but this:

datagram.setSocketAddress(datagram.getSocketAddress());
datagram.setPort(datagram.getPort());

is self-evidently redundant. You can reuse the incoming datagram for the reply just by changing its data. It already has the return address and port, by construction.

score 0 · Accepted Answer · answered Feb 16 '12 at 19:44

(Sorry to take so long to get back to this. I found the answer out a while ago.)

I feel rather foolish. It turns out there was a firewall rule in place on incoming UDP packets. If the "reply" packet came in "soon enough" with respect to the outbound "request" packet, all was well. But once the delay got too long, the firewall considered the reply to be unrelated to the request and therefore viewed it as some random incoming packet and thus blocked it.

Why doesn't Java see an incoming UDP packet that tcpdump shows is received?

3 Answers3