United StatesChange Country, Oracle Worldwide Web Sites Communities I am a... I want to...
JDK-4772077 : using defaultReadTimeout appear to retry request upon timeout

Details
Type:
Bug
Submit Date:
2002-10-31
Status:
Resolved
Updated Date:
2004-09-16
Project Name:
JDK
Resolved Date:
2003-11-03
Component:
core-libs
OS:
windows_2000
Sub-Component:
java.net
CPU:
x86
Priority:
P3
Resolution:
Fixed
Affected Versions:
1.4.1
Fixed Versions:
5.0 (b28)

Related Reports
Backport:

Sub Tasks

Description

Name: nt126004			Date: 10/31/2002


FULL PRODUCT VERSION :
java version "1.4.1"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.1-b21)
Java HotSpot(TM) Client VM (build 1.4.1-b21, mixed mode)

FULL OPERATING SYSTEM VERSION : Microsoft Windows 2000
[Version 5.00.2195]


A DESCRIPTION OF THE PROBLEM :
I'm using System.setProperty
("sun.net.client.defaultReadTimeout", "10000"); to set the
read timeout on my http request.

I have a simple demo program where it sends out an http
request.  The server receives the request and then sleeps
for 20000 msec.  Just before the client receives the
SocketTimeoutException, I see that the server reads in the
exact same request.  Where is this duplicate request coming
from?  Is the jre resending it for me?  Is this
configurable?


STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :

Below is a my sample test driver that can be used as both
the client and the server:

1.  start a server: java -cp . HttpCommTest -p 5555
2.  start a client: java -cp . HttpCommTest -p 7777 -
u "http://127.0.0.1:5555"
3.  at the client's enter prompt, press the enter key
4.  watch the timestamps for
   a.  the original message received
   b.  the exception received by the client
   c.  the duplicate message received by the server

It looks like the server receives the duplicate before the
client receives the exception




EXPECTED VERSUS ACTUAL BEHAVIOR :
ACTUAL
-------
Watch the timestamps for
   a.  the original message received
   b.  the exception received by the client
   c.  the duplicate message received by the server

It looks like the server receives the duplicate before the
client receives the exception

EXPECTED
--------
I did not expect for the server to receive a duplicate
message after the socket read timeout exception was
received by the client.

REPRODUCIBILITY :
This bug can be reproduced always.

---------- BEGIN SOURCE ----------

/**
 * This class can take a variable number of parameters on the command
 * line. Program execution begins with the main() method. The class
 * constructor is not invoked unless an object of type 'Class1'
 * created in the main() method.
 */

//  for server -->  -cp . HttpCommTest -p 5555
//  for client -->  -cp . HttpCommTest -p 7777 -u "http://127.0.0.1:5555"



import java.net.*;
import java.util.*;
import java.io.*;
import java.text.SimpleDateFormat;

public class HttpCommTest implements Runnable
{
	private static int m_port = 80;
    private static String m_sendToUrl = "http://127.0.0.1:5555";
	
	/**
	 * The main entry point for the application.
	 *
	 * @param args Array of parameters passed to the application
	 * via the command line.
	 */
	public static void main (String[] args)
	{
		System.setProperty
("sun.net.client.defaultReadTimeout", "10000");
		
       //must have an even number of args
		if( (args.length % 2) != 0 )
		{
			outputUsage();
			return;
		}
		
		//get command line args
		for( int i = 0; i < args.length; i++ )
		{
			if( args[i].equalsIgnoreCase( "-p" ) )
				m_port = Integer.valueOf(args[++i]).intValue();
			else
			if( args[i].equalsIgnoreCase( "-u" ) )
				m_sendToUrl = args[++i];
			else
			{
				outputUsage();
				//return;
			}
		}
		
		HttpCommTest httpCommTest = new HttpCommTest();
		
		//start a thread to for incoming http requests
		Thread t = new Thread( httpCommTest );
		t.setDaemon( true );
		t.start();
						
		httpCommTest.doInput();
		
	}
	
	private void doInput()
	{
		//listen for command line input to do a send on main thread
		try
		{
			String dataToSend = "";
			System.out.print( "<Enter>" );
			while( true )
			{
				byte[] buf = new byte[1];
				int len = System.in.read( buf );
				if( len == -1 )
					break;
				
				if( buf[0] == '\r' )
					continue;
				
				if( buf[0] == '\n' )
				{
					
					
					try
					{
						URL url = new URL(m_sendToUrl);
			
	
						
					    HttpURLConnection urlConn =
(HttpURLConnection)url.openConnection();
					    urlConn.setRequestMethod("GET");
					    urlConn.setDoOutput(false);
			    		urlConn.setDoInput(true);
					    urlConn.setAllowUserInteraction
(false);
					    urlConn.setRequestProperty("Content-
type", "application/x-www-form-urlencoded");
	        
	        		    urlConn.setRequestProperty("Content-
length", "0" );

						logTimestampedMsg("Sending
Request---" );
				
					    urlConn.connect();
				    

						logTimestampedMsg("Waiting for
response ---" );
					

				        // Check the response code
				        int responseCode =
urlConn.getResponseCode();
				        String responseMessage =
urlConn.getResponseMessage();
				        if (responseCode != 200) {
				            System.out.println( "got bad http
response code " + responseCode + ":" + responseMessage );
				            throw new IOException("HTTP " +
responseCode + " " + responseMessage);
				        }
				       	logTimestampedMsg("Got response code
= " + responseCode );
					
					}
					catch( Throwable t )
					{
						logTimestampedMsg("Unexpected
Exception:" );
						t.printStackTrace();
						System.out.println
( "==================================================" );
						System.out.println( "" );
					}
					
					dataToSend = "";
					System.out.print( "<Enter>" );
				}
				else
				{
					String bufVal = new String( buf );
					dataToSend += bufVal;
				}
			}
		}
		catch( Exception e )
		{
			System.out.println( "INPUT FAILURE:" );
			e.printStackTrace();
		}
	}
	
	public static void outputUsage()
	{
		System.out.println( "java
com.sentillion.test.httpCommunications -p <port> -u <url>" );
		System.out.println( "-p = port to listen for incoming requests,
defaults to " + m_port );
		System.out.println( "-u = url to send a request to, defaults
to " + m_sendToUrl );
		System.out.println( "Enter 'post' to send the request as a
post" );
	}
	
	public void run()
	{
		ServerSocket connectSocket = null;
		try
		{
			connectSocket = new ServerSocket( m_port );
			connectSocket.setSoTimeout(5000);

			while( true )
			{
				Socket requestSocket = null;
				// Wait for a connection, then open a socket to
receive the request
				try
				{
					requestSocket = connectSocket.accept();
					dispatchRequest( requestSocket );
				}
				catch (InterruptedIOException ex)
				{
					// System.out.println("CP Thread:
timeout on connection - retrying");
					continue;  // timeout on accept
				}
				catch (IOException e)
				{
					System.out.println("CP Thread: " +
e.toString());
					break;
				}
			}
			
			connectSocket.close();
			connectSocket = null;
			System.out.println("CP Thread: exiting.");
		}
		catch( Exception e )
		{
			System.out.println( "LISTENING SOCKET FAILURE:" );
			e.printStackTrace();
			return;
		}

	}
	
	private void dispatchRequest( Socket socket )
	{
		String argContent = null;
		try
		{
			System.out.println("Reading request InputStream---");
			java.io.DataInputStream dataIn = new
java.io.DataInputStream(socket.getInputStream());

			// Get first line of request, verify it's a POST
			//String line = dataIn.readLine();
			//System.out.println("Receiving Request---");
			//System.out.println(line);

			logTimestampedMsg("Receiving Request---");
			String firstLine = dataIn.readLine();
            String line = firstLine;
            while (line.length() != 0)
            {
                System.out.println(line);
                line = dataIn.readLine();
            }
			System.out.println( "" );
			
           try
           {
           		long sleepTime = 20000;
           		logTimestampedMsg("Sleeping for " + sleepTime + "
Msec.");
           		Thread.currentThread().sleep(sleepTime);
           }
           catch(InterruptedException ex) {}
            
            
			System.out.println( "" );
		}
		catch (IOException e)
		{
			logTimestampedMsg("Request Handler: " + e.toString());
			e.printStackTrace();
		}
		finally
		{
			System.out.println("");
			System.out.println
( "==================================================" );
			System.out.println("");
			System.out.print("<Enter>");
		}
		
	}
	
	/**
	 *
	 */
	
	private void logTimestampedMsg(String msg)
	{
		String timeStamp = (new SimpleDateFormat("yyyy.MM.dd
HH:mm:ss:SSS")).format(new Date());
		System.out.println(timeStamp + "  " + msg);
	}
}
---------- END SOURCE ----------
(Review ID: 165851) 
======================================================================

Name: nt126004			Date: 10/31/2002


FULL PRODUCT VERSION :
java version "1.4.1"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.1-b21)
Java HotSpot(TM) Client VM (build 1.4.1-b21, mixed mode)

FULL OPERATING SYSTEM VERSION :
Microsoft Windows 2000 [Version 5.00.2195]
ServicePack 3

A DESCRIPTION OF THE PROBLEM :
When HttpURLConnection makes a POST request to a web
server, a separate timeout thread is used to call
HttpURLConnection.disconnect() to break the connection to
the web server.  However, when HtppURLConnection.disconnect
() is called, the connection is broken AND
HttpURLConnection establishes a new connection, resending
the request a second time.  There is no way to timeout this
second request, because at the higher application level
(i.e. my program) I have already successfully called
HttpUrlConnection.disconnect().

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
1. start a thread to timeout in 30 sec. to call disconnect()
2. make a request to a server that will NOT send anything
back (i.e. no HTTP Response Header).
3. check logging on both sides and you will see that
HttpURLConnection made 2 requests to the webserver.

EXPECTED VERSUS ACTUAL BEHAVIOR :
Only one POST should have been made and the
HttpURLConnection.disconnect() should have broken its
connection to the server.

REPRODUCIBILITY :
This bug can be reproduced always.
(Review ID: 166180)
======================================================================

                                    

Comments
EVALUATION

In sun's implementation of Http protocol, we do try ONE more time (automatically send the request a second time) if the first attempt results in an IOException. Since in this case, we encountered a SocketTimeoutException which is an IOException, we send the same request again, hoping that the server would wake up, when this again failed, we throw that exception out to the application.

So what happens is the following:

client send request;
read timeout on receiving response (because the server never respond);
catch the exception, retry by sending the request to server again;
read timeout again;
catch the exception. Since we already failed once, throw this exception.

(Calling disconnect() won't make a difference because that will only result in an IOException on receiving server response.)

The retry ONCE was put there mainly as a backup measure to resend the request to the server again hoping that the server was temporarily out of order. We will investigate whether we should always do this automatically and whether we should provide a means to disable it. Probably too late for Mantis to change such behaviour. 

###@###.### 2002-10-31

We won't have time in Tiger to add a new API to disable automatic retry.

###@###.### 2003-07-09

Will fix in Tiger by disable automatic retry upon a SocketTimeoutException when timeout is set.

###@###.### 2003-10-27
                                     
2003-07-09
CONVERTED DATA

BugTraq+ Release Management Values

COMMIT TO FIX:
1.4.2_07
tiger-b28
tiger-beta

FIXED IN:
tiger-b28
tiger-beta

INTEGRATED IN:
tiger-b28
tiger-beta


                                     
2004-09-17



Hardware and Software, Engineered to Work Together