1s Delay in HttpServer since Java 7

Question

We are using the internal HttpServer class in a project to exchange data between a client and a server over HTTP. As we switched to Java 7, we realized a delay in the delivery of the results. We could reduce the problem to the following sample:

Class EchoServer creates the context /echo which simply returns the current date and the request URI upon each request. This service is then invoked by a client in a loop.

import java.io.IOException;
import java.io.OutputStream;
import java.net.InetSocketAddress;
import java.util.Date;

import com.sun.net.httpserver.HttpExchange;
import com.sun.net.httpserver.HttpHandler;
import com.sun.net.httpserver.HttpServer;

public class EchoServer {

    public static void main(String[] args) throws IOException {
        HttpServer server = HttpServer.create(new InetSocketAddress(80), 0);
        server.createContext("/echo", new EchoHandler());
        server.start();
    }

    static class EchoHandler implements HttpHandler {
        public void handle(HttpExchange httpExchange) throws IOException {
            httpExchange.getResponseHeaders().add("Content-type", "text/html");
            String response = "<b>" + new Date() + "</b> for "  + httpExchange.getRequestURI();
            httpExchange.sendResponseHeaders(200, response.length());
            OutputStream os = httpExchange.getResponseBody();
            os.write(response.getBytes());
            os.close();
        }
    }
}

The following client invokes the service in an infinite loop using class URL and prints the first character from the returned stream (which will be the < sign). In addition, the client prints the current time.

import java.io.BufferedReader;
import java.io.InputStreamReader;
import java.net.URL;

public class EchoClient {

    public static void main(String[] args) throws Exception{
        while(true) {
            URL url = new URL("http://localhost:80/echo");

            BufferedReader rd = new BufferedReader(new InputStreamReader(url.openStream()));
            int res = rd.read();
            System.out.println((char)res);
            System.out.println(System.currentTimeMillis());
        }
    }
}

If this code is executed on Java6, everything works fine and a result is printed approx. every 5 ms.

% java -version
java version "1.6.0_24"
Java(TM) SE Runtime Environment (build 1.6.0_24-b07)
Java HotSpot(TM) 64-Bit Server VM (build 19.1-b02, mixed mode)

% java EchoClient
<
1362515635677
<
1362515635682
<
1362515635687
<
1362515635691

If the code is executed on Java7, then each request uses 1000ms approx.

% java -version
java version "1.7.0_17"
Java(TM) SE Runtime Environment (build 1.7.0_17-b02)
Java HotSpot(TM) 64-Bit Server VM (build 23.7-b01, mixed mode)

% java EchoClient
<
1362517297845
<
1362517298844
<
1362517299845
<
1362517300845

It seems that a timeout of 1000ms is hidden somewhere. If the character is read on the InputStreamReader instead over the BufferedReader, the same delay happens. If a byte is read from the input stream directly, then no delay can be seen. On the other hand, if the EchoClient program is run against a servlet, then everything works fine, independent of whether the BufferedReader or the InputStreamReader is used.

It seems, that class InputStreamReader is expecting something from the server which is no longer delivered by the Java 7 implementation of HttpServer. Do you have an idea what exactly happens here and how this problem could be resolved? A workaround? Or is this a bug?

Thanks!

---

I have added further timings to the client code:

public static void main(String[] args) throws Exception{
    while(true) {
        System.out.println("0: "+System.currentTimeMillis());
        URL url = new URL("http://localhost:80/echo");
        System.out.println("1: "+System.currentTimeMillis());
        InputStream in = url.openStream();
        System.out.println("2: "+System.currentTimeMillis());
        InputStreamReader isr = new InputStreamReader(in);
        System.out.println("3: "+System.currentTimeMillis());
        char res = (char)isr.read(); // character read is `<`
        System.out.println(res + ": "+System.currentTimeMillis());
    }
}

with the following result:

% java EchoClient
0: 1362532555535
1: 1362532555537
2: 1362532555608
3: 1362532555609
<: 1362532555611
0: 1362532555612
1: 1362532555613
2: 1362532556608
3: 1362532556609
<: 1362532556610
0: 1362532556611
1: 1362532556612
2: 1362532557609
3: 1362532557610
<: 1362532557611
0: 1362532557612
1: 1362532557613

The first invocation of openStream takes some time (70ms), but all further invocations of openStream take much longer (996ms approx).

Answer 1

I experienced the same issue, but the comment by user1050755 points out the bug filled and it has one solution:

...this is not a problem when the server uses a threadpool, but for a single threaded server, this timeout gives rise to a bottleneck..

So, make a multi-threaded server:

        final Executor multi = Executors.newFixedThreadPool(10);
        final HttpServer server = HttpServer.create(new InetSocketAddress(s_HTTP_PORT), 5);
        //... do your REST bindings here
        server.setExecutor(multi);
        server.start();

Worked like a charm for me.

PS. comments like "com.sun.net.httpserver is awful" don't give any help - it's the same as "use Apache instead"

Answer 2

You don't seem to be closing the BufferedReader or the InputStream returned by url.openStream(). Not closing the stream might lead to problems with being able to reuse the connection on subsequent iterations (and is buggy behavior in general).

Do you have different results with explicit calls to rd.close() and stream.close()?

Answer 3

Just filed a bug report with Oracle. I'm getting a 38 ms delay here for both Java releases (SE 6 or 7).

/**
 * @test
 * @bug 
 * @summary  pipelining delay on Ubuntu 12.04.01 LTS / amd64
 */

import com.sun.net.httpserver.*;

import java.util.*;
import java.util.concurrent.*;
import java.io.*;
import java.net.*;

public class Bug {

    static int iterations = 20;
    static long requiredMinimumDelay = 10L;

    public static void main (String[] args) throws Exception {
        Handler handler = new Handler();
        InetSocketAddress addr = new InetSocketAddress (0);
        HttpServer server = HttpServer.create (addr, 0);
        HttpContext ctx = server.createContext ("/test", handler);
        ExecutorService executor = Executors.newCachedThreadPool();
        server.setExecutor (executor);
        server.start ();

        long minDelay = requiredMinimumDelay * 1000L;

        try {
            for(int i = 0; i < iterations; i++) {
                URL url = new URL ("http://localhost:"+server.getAddress().getPort()+"/test/foo.html");
                HttpURLConnection urlc = (HttpURLConnection)url.openConnection ();
                InputStream is = urlc.getInputStream();
                InputStreamReader isr = new InputStreamReader(is);
                BufferedReader br = new BufferedReader(isr);
                String res = br.readLine();
                br.close();

                // skip first few
                if(i < iterations/2) {
                    continue;
                }

                long delay = System.currentTimeMillis() - Long.parseLong(res);
                System.out.println("delay: "+delay+" ms");
                if(delay < minDelay) {
                    minDelay = delay;
                }
            }
        } catch (Exception ex) {}

        server.stop(2);
        executor.shutdown();

        if(minDelay > requiredMinimumDelay) {
            throw new Exception("minimum delay too large: "+minDelay);
        }
    }

    static class Handler implements HttpHandler {
        public void handle (HttpExchange t)
            throws IOException
        {
            InputStream is = t.getRequestBody();
            Headers map = t.getRequestHeaders();
            Headers rmap = t.getResponseHeaders();
            while (is.read () != -1) ;
            is.close();
            String response = Long.toString(System.currentTimeMillis())+"\n";
            t.sendResponseHeaders (200, response.length());
            OutputStream os = t.getResponseBody();
            os.write (response.getBytes());
            t.close();
        }
    }    
}

http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=8009548

Update: turns out Oracle classified it as "two different bugs" one for the 38ms (which they punted on?) and one for the 1000ms one, which they resolved here:

http://bugs.java.com/bugdatabase/view_bug.do?bug_id=8014254

So the 1000ms one hopefully fixed in versions "8b91" and "7u85" based on the backports linked.