Why doesn't Java see the incoming UDP packet that tcpdump shows?

Question

I see a problem (Java 6 on SLES11) where a UDP packet is sent back to the client machine (and tcpdump on the client machine shows that it has been received), but the packet is not viewed by Java.

The test works as follows:

The client side generates some random data, inserts it into a UDP packet, sends it to the server on a specific port and expects it to be recalled (with SO_TIMEOUT 180,000 ms). When he receives it back, he prints out that he received it and how long it was sent.

The server side is listening on the UDP packet on this port. When he receives it, he delays the bit, and then sends it back, unchanged. The delay starts at some initial value (3000 ms), and then doubles each time it receives a packet until it reaches a maximum (90,000 ms), after which the delay will simply remain maximum.

It works fine until the delay reaches 48000 ms. The tcpdump operation performed on the client shows the packet being sent and shows the response packet arriving after 48,000 ms. However, the Java program never sees this response packet and, after 180,000 ms, claims to receive timeout. Despite the fact that the client machine received the packet after 48000 ms, as tcpdump shows.

What can happen?

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

On the client machine, the output of the test program:

 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 

tcpdump output on client machine (with my comments):

 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 machine, the server output the test program:

 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 source client :

 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 source server :

 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 size. DatagramLength = 333 # Number of times to run the client. Loops = 8 # Client time out period in milliseconds. Timeout = 180000 

Finally, server.conf :

 # Server port number. Port=20000 # Length of the datagram. # It must match the client size. DatagramLength = 333 # Initial sleep time. MinSleepTime = 1000 # Maximu sleep time. Goes from the MinSleepTime to the # maximum sleep time. MaxSleepTime = 90000 

Answer 1

(Sorry to take so long to get back to this. I found the answer some time ago.)

I feel pretty stupid. It turns out that a firewall rule was created on incoming UDP packets. If the “response” packet arrived “soon enough” regarding the outgoing “request” packet, everything was fine. But as soon as the delay went too long, the firewall considered the response unconnected with the request and therefore considered it as a random incoming packet and thereby blocked it.

Answer 2

If possible, perhaps check the IPv4 TTL (lifetime) packet in tcpdump capture.

After 48 seconds, a packet can be received, but removed from the IP stack on the receiver side due to TTL.

Also see this TTL change answer (which says it is only for multicast sockets, but was accepted anyway): Java control IP TTL?

Answer 3

This can happen if the receiver socket receive buffer is full.

Slightly off topic, but this:

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

is obviously redundant. You can reuse an incoming datagram for a response simply by changing its data. It already has a return address and port, by construction.