服务器响应后Apache HttpClient超时异常

Question

服务器响应后Apache HttpClient超时异常

5

我使用Apache HttpClient 4.1.2向服务器POST压缩的二进制数据（序列化的Java对象）。有时（20%的时间），即使服务器正确响应并在其日志中记录了“200”响应，客户端仍会在接收响应时超时。事件序列如下：

- 客户端将数据POST到服务器（T0）。 - 服务器记录数据的接收时间（T2，即T + 2秒）。 - 服务器处理数据。 - 服务器记录成功完成处理的时间（T45）。 - 服务器访问日志显示带有“200”状态的完成响应已发出（T46）。 - 客户端阻止读取响应标头。 - 客户端超时（T1800，即请求POST后30分钟，这是我使用的标准超时）。

服务器返回的响应体是一个小型纯文本字符串，例如“OK”，长度不超过五个字节。

这里可能发生了什么？如果服务器未响应，则可以理解为超时；但是，服务器已经及时以正确的方式响应并记录了响应，远在客户端超时之前。客户端似乎正在“尝试”读取响应但被阻塞并最终超时。

客户端运行在Windows XP机器上；服务器是Ubuntu。两者都运行Java 6（现在是1.6.29）。

每次请求时我都创建一个新的DefaultHttpClient对象，并在每次请求后关闭它（并适当释放其他资源）。

客户端在请求成功完成后消耗和处理响应实体体，但我们还没有到达这个点-超时发生在httpclient.execute（方法）调用的上下文中。

堆栈跟踪：

java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(Unknown Source)
    at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:149)
    at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:110)
    at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:264)
    at org.apache.http.impl.conn.LoggingSessionInputBuffer.readLine(LoggingSessionInputBuffer.java:115)
    at org.apache.http.impl.conn.DefaultResponseParser.parseHead(DefaultResponseParser.java:98)
    at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:252)
    at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:281)
    at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:247)
    at org.apache.http.impl.conn.AbstractClientConnAdapter.receiveResponseHeader(AbstractClientConnAdapter.java:219)
    at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:298)
    at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
    at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:645)
    at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:464)
    at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
    at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
    at foo.StreamerClient.sendRequest(StreamerClient.java:312)
    at foo.StreamerClient.compressAndPostBinaryDataToFooServer(StreamerClient.java:287)
    at foo.StreamerClient.compressAndPostObjectsToFooServer(StreamerClient.java:238)

这是一次成功请求的线路日志记录。与不成功的请求唯一的区别在于，不成功的请求在记录二进制数据后停止，并在半小时后再次弹出并记录超时。

[12-06 14:07:22.359][scheduler-3] D DefaultClientConnection   Sending request: POST /foo/bar HTTP/1.1 
[12-06 14:07:22.359][scheduler-3] D wire                      >> "POST /foo/bar HTTP/1.1[\r][\n]" 
[12-06 14:07:22.359][scheduler-3] D wire                      >> "Accept-Encoding: gzip,deflate[\r][\n]" 
[12-06 14:07:22.359][scheduler-3] D wire                      >> "Content-Type: application/octet-stream[\r][\n]" 
[12-06 14:07:22.359][scheduler-3] D wire                      >> "Content-Length: 401[\r][\n]" 
[12-06 14:07:22.359][scheduler-3] D wire                      >> "Host: foo.com[\r][\n]" 
[12-06 14:07:22.359][scheduler-3] D wire                      >> "Connection: Keep-Alive[\r][\n]" 
[12-06 14:07:22.359][scheduler-3] D wire                      >> "User-Agent: Apache-HttpClient/4.1.2 (java 1.5)[\r][\n]" 
[12-06 14:07:22.359][scheduler-3] D wire                      >> "Authorization: Basic fobar[\r][\n]" 
[12-06 14:07:22.359][scheduler-3] D wire                      >> "[\r][\n]" 
[12-06 14:07:22.359][scheduler-3] D wire                      >> "[several lines of binary data]" 
[12-06 14:07:24.265][scheduler-3] D wire                      << "HTTP/1.1 200 OK[\r][\n]" 
[12-06 14:07:24.265][scheduler-3] D wire                      << "Date: Tue, 06 Dec 2011 03:07:23 GMT[\r][\n]" 
[12-06 14:07:24.265][scheduler-3] D wire                      << "Content-Type: text/plain;charset=ISO-8859-1[\r][\n]" 
[12-06 14:07:24.265][scheduler-3] D wire                      << "Content-Length: 2[\r][\n]"
[12-06 14:07:24.265][scheduler-3] D wire                      << "Connection: close[\r][\n]"
[12-06 14:07:24.265][scheduler-3] D wire                      << "[\r][\n]"

感谢您的选择。

- user1082373

1个回答

网页内容由stack overflow 提供, 点击上面的

可以查看英文原文，
原文链接

- Gray · Accepted Answer

我注意到响应中说：

Content-Length: 2

但是我没有看到任何内容在[\r][\n]之后的空白行，这个空白行不应该被计算为内容。我认为这就是你的问题所在。服务器要么应该说Content-Length: 0，要么它没有适当地刷新其缓冲区或其他原因。

另外，在头部中，服务器正在说：

Connection: close

服务器是否关闭了连接还是客户端仍然连接在上面？如果服务器没有关闭，则可能卡住了。希望这能有所帮助。