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



我使用Apache HttpClient 4.1.2将压缩的二进制数据(序列化的Java对象)POST到服务器。

有时(20%的时间)客户端在接收响应时会超时,甚至在服务器正确响应并在其自己的日志记录中记录"200"响应之后。

事件顺序为:

  • 客户端发送数据到服务器(T0)。
  • 服务器记录接收数据(T2,即T + 2秒)。
  • 服务器处理数据。
  • 服务器记录处理成功完成(T45)。
  • 服务器访问日志显示完成响应输出,状态为"200"(T46)。
  • client block read response headers.
  • 客户端超时(T1800,即post请求后30分钟,这是我使用的标准超时)

服务器返回的响应体是一个小的纯文本字符串,比如5个字节或更少。"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]" 

谢谢。

我注意到响应说

Content-Length: 2

但我没有看到[r][n]结束空白行后的任何内容,不应算作内容。我想那是你的问题。要么服务器应该说Content-Length: 0,要么它没有适当地刷新缓冲区或其他东西。

同时,在报头中服务器说:

Connection: close

服务器已关闭连接或客户端仍在连接?如果服务器没有关闭,那么它就被卡住了。

相关内容

  • 没有找到相关文章

最新更新