Posts tagged Java

问题描述

昨天晚上碰到一个比较奇怪的问题，用HttpClient 4.0.1向一个服务器发送请求，非常慢，请求的时间超过2秒，但是采用HttpClient 3.1或者HttpClient4.1.2速度都非常快，请求的时间在2毫秒左右，非常奇怪，我采用的代码如下：

    public static void main(String[] args) throws Exception {
        HttpClient client = new DefaultHttpClient();
        HttpPost httppost = new HttpPost("http://127.0.0.1:8080/qstore");
        Map<String, Object> requestMap = new HashMap<String, Object>();
        requestMap.put("method", "get");
        requestMap.put("chunkName", "bbt_chunk");
        requestMap.put("key", "liushunnian1");
        String data = JSONObject.fromObject(requestMap).toString();
        StringEntity reqEntity = new StringEntity(data);
        httppost.setEntity(reqEntity);

        while (true) {
            long start = System.currentTimeMillis();
            HttpResponse response = client.execute(httppost);
            long end = System.currentTimeMillis();
            System.out.println("Time:" + (end - start) + "ms");
            HttpEntity entity = response.getEntity();
            BufferedReader reader = new BufferedReader(new InputStreamReader(entity.getContent(), "UTF-8"));
            System.out.println(reader.readLine());
        }
    }

原因分析

为了找出原因，我打开了HttpClient的Debug日志：

    System.setProperty("org.apache.commons.logging.Log", "org.apache.commons.logging.impl.SimpleLog");
    System.setProperty("org.apache.commons.logging.simplelog.showdatetime", "true");
    System.setProperty("org.apache.commons.logging.simplelog.log.org.apache.http", "debug");

打出的部分日志如下：

2011/10/20 14:01:12:329 CST [DEBUG] headers - >> POST /qstore HTTP/1.1
2011/10/20 14:01:12:329 CST [DEBUG] headers - >> Content-Length: 61
2011/10/20 14:01:12:329 CST [DEBUG] headers - >> Content-Type: text/plain; charset=ISO-8859-1
2011/10/20 14:01:12:329 CST [DEBUG] headers - >> Host: 10.20.150.29:8080
2011/10/20 14:01:12:329 CST [DEBUG] headers - >> Connection: Keep-Alive
2011/10/20 14:01:12:329 CST [DEBUG] headers - >> User-Agent: Apache-HttpClient/4.1.2 (java 1.5)
2011/10/20 14:01:12:329 CST [DEBUG] headers - >> Expect: 100-continue
2011/10/20 14:01:14:331 CST [DEBUG] wire - >> "{"chunkName":"bbt_chunk","method":"get","key":"liushunnian1"}"
2011/10/20 14:01:14:333 CST [DEBUG] wire - << "HTTP/1.1 200 OK[\r][\n]"

可以看到客户端与服务端数据交互的过程：

1. HttpClient首先向服务器端发送了一个头信息，并且期望返回一个100-Continue
2. 过了大约两秒钟后，HttpClient又向服务器发送了请求中请求体

从上面的这个过程可以看出，HttpClient向服务器端发送100-Continue以后一直在等待服务端的返回，在等待超时之后才将请求体发送给服务器端，那么什么是100-Continue呢？看看Http规范里面的说明：

The client SHOULD continue with its request. This interim response is used to inform the client that the initial part of the request has been received and has not yet been rejected by the server. The client SHOULD continue by sending the remainder of the request or, if the request has already been completed, ignore this response. The server MUST send a final response after the request has been completed. See section 8.2.3 for detailed discussion of the use and handling of this status code.

也就是说当客户端要向服务器端发送大数据的时候，客户端可以先向服务器端发送一个请求，如果服务器端返回的是状态码100，那么客户端就可以继续把请求体的数据发送给服务器端。这样在某些情况下可以减少网络开销。

再看看HttpClient里面对100-Continue的说明：

The purpose of the Expect: 100-Continue handshake is to allow the client that is sending a request message with a request body to determine if the origin server is willing to accept the request (based on the request headers) before the client sends the request body. The use of the Expect: 100-continue handshake can result in a noticeable performance improvement for entity enclosing requests (such as POST and PUT) that require the target server’s authentication. The Expect: 100-continue handshake should be used with caution, as it may cause problems with HTTP servers and proxies that do not support HTTP/1.1 protocol.

里面提到的一句话是100-Continue应该谨慎使用，因为有些服务器不支持，可能会造成一些问题。那么我这次遇到的原因就是因为服务器端不支持，导致客户端一直要等到100-Continue请求超时以后才把请求体发送给服务器端。

而至于版本的问题是因为HttpClient 3.1和HttpClient 4.1.2都已经把100-Continue默认关闭掉了，只有在HttpClient 4.0.1下才是默认打开的，我奇怪的是HttpClient的文档里面都说了这个应该谨慎使用，为什么还要默认打开？

解决方法

解决方法一：当然，最简单的解决方法当然是更换HttpClient的版本，根据HttpClient的ReleaseNotes，4.1以后的版本都已经将100-Continue默认关闭掉了。

解决方法二：另一个解决方法就是在4.0.1中将100-Continue给关闭掉：

httppost.getParams().setBooleanParameter(CoreProtocolPNames.USE_EXPECT_CONTINUE, false);

解决方法三：如果你一定想要让100-Continue开着，那么可以减短100-Continue的超时时间，默认的超时时间是最大3秒钟，可以通过以下方法设置：

httppost.getParams().setIntParameter(CoreProtocolPNames.WAIT_FOR_CONTINUE, 100);