【发布时间】:2011-12-06 14:04:16
【问题描述】:
我使用 Apache HttpClient 4.1.2 将压缩的二进制数据(序列化的 Java 对象)发布到服务器。
有时(20% 的时间)客户端在接收响应时会超时,即使在服务器正确响应之后并在其自己的日志中记录了“200”响应。
事件的顺序是:
- 客户端将数据 POST 到服务器 (T0)。
- 服务器记录数据接收(T2,即 T + 2 秒)。
- 服务器处理数据。
- 服务器记录成功完成处理 (T45)。
- 服务器访问日志显示完成的响应以“200”状态发出 (T46)。
- 客户端阻止读取响应标头。
- 客户端超时(T1800,即 POST 请求后 30 分钟,这是我使用的标准超时)。
服务器返回的响应正文是一个很小的,例如五个字节或更少的纯文本字符串,例如“好的”。
这里会发生什么?如果服务器没有响应,我可以理解超时;但是服务器已经响应,并且在客户端超时之前很久就及时记录了正确的响应。客户端似乎正在“尝试”读取响应,但会阻塞并最终超时。
客户端在 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]"
谢谢。
【问题讨论】:
标签: java apache timeout httpclient