Setting socket read timeout for HttpAsyncClient 4.0-beta4 but not getting exception

Allen Wang Thu, 19 Sep 2013 15:32:20 -0700

Hello,

I tried to set 2 seconds socket read timeout for HttpAsyncClient using the
following code:


RequestConfig requestConfig = RequestConfig.custom()

                .setConnectTimeout(2000)

                .setSocketTimeout(2000)

                .build();

        httpclient =
HttpAsyncClients.custom().setDefaultRequestConfig(requestConfig).build();

        httpclient.start();

Then I tried to hit a localhost REST point where it waits 10 seconds before
responding. However, I am not getting any exception on the FutureCallback
listener I passed into the HttpAsyncClient(HttpUriRequest,
FutureCallback<HttpResponse>) call.

Here is the http debug output:

2013-09-19 14:58:14,784 DEBUG
org.apache.http.impl.nio.client.MainClientExec:125 [main] [prepare]
[exchange: 1] start execution

2013-09-19 14:58:14,797 DEBUG
org.apache.http.client.protocol.RequestAddCookies:121 [main] [process]
CookieSpec selected: best-match

2013-09-19 14:58:14,805 DEBUG
org.apache.http.client.protocol.RequestAuthCache:75 [main] [process] Auth
cache not set in the context

2013-09-19 14:58:14,805 DEBUG
org.apache.http.impl.nio.client.DefaultClientExchangeHandlerImpl:320 [main]
[requestConnection] [exchange: 1] Request connection for {}->
http://localhost:4527

2013-09-19 14:58:14,806 DEBUG
org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager:224
[main] [requestConnection] Connection request: [route:
{}->http://localhost:4527][total kept alive: 0; route allocated: 0 of 2;
total allocated: 0 of 20]

2013-09-19 14:58:14,828 DEBUG
org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager$InternalPoolEntryCallback:436
[I/O dispatcher 1] [completed] Connection leased: [id:
http-outgoing-0][route: {}->http://localhost:4527][total kept alive: 0;
route allocated: 1 of 2; total allocated: 1 of 20]

2013-09-19 14:58:14,832 DEBUG
org.apache.http.impl.nio.client.DefaultClientExchangeHandlerImpl:267 [I/O
dispatcher 1] [connectionAllocated] [exchange: 1] Connection allocated:
Managed connection

2013-09-19 14:58:14,833 DEBUG
org.apache.http.impl.nio.conn.LoggingIOSession:164 [I/O dispatcher 1]
[setAttribute] http-outgoing-0 127.0.0.1:52789<->127.0.0.1:4527[ACTIVE][r:]:
Set attribute http.nio.exchange-handler

2013-09-19 14:58:14,833 DEBUG
org.apache.http.impl.nio.conn.LoggingIOSession:102 [I/O dispatcher 1]
[setEvent] http-outgoing-0 127.0.0.1:52789<->127.0.0.1:4527[ACTIVE][rw:]:
Event set [w]

2013-09-19 14:58:14,833 DEBUG
org.apache.http.impl.nio.client.LoggingAsyncRequestExecutor:58 [I/O
dispatcher 1] [connected] http-outgoing-0 [ACTIVE]: Connected

2013-09-19 14:58:14,834 DEBUG
org.apache.http.impl.nio.conn.LoggingIOSession:164 [I/O dispatcher 1]
[setAttribute] http-outgoing-0 127.0.0.1:52789<->127.0.0.1:4527[ACTIVE][rw:]:
Set attribute http.nio.http-exchange-state

2013-09-19 14:58:14,834 DEBUG
org.apache.http.impl.nio.client.LoggingAsyncRequestExecutor:75 [I/O
dispatcher 1] [requestReady] http-outgoing-0 [ACTIVE] Request ready

2013-09-19 14:58:14,834 DEBUG
org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl:96 [I/O
dispatcher 1] [bind] http-outgoing-0 Upgrade session 127.0.0.1:52789
<->127.0.0.1:4527[ACTIVE][rw:]

2013-09-19 14:58:14,834 DEBUG
org.apache.http.impl.nio.client.MainClientExec:211 [I/O dispatcher 1]
[generateRequest] [exchange: 1] Attempt 1 to execute request

2013-09-19 14:58:14,834 DEBUG
org.apache.http.impl.nio.client.MainClientExec:218 [I/O dispatcher 1]
[generateRequest] Target auth state: UNCHALLENGED

2013-09-19 14:58:14,835 DEBUG
org.apache.http.impl.nio.client.MainClientExec:225 [I/O dispatcher 1]
[generateRequest] Proxy auth state: UNCHALLENGED

2013-09-19 14:58:14,836 DEBUG
org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl:133 [I/O
dispatcher 1] [onRequestSubmitted] http-outgoing-0 >> GET /test/readTimeout
HTTP/1.1

2013-09-19 14:58:14,836 DEBUG
org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl:136 [I/O
dispatcher 1] [onRequestSubmitted] http-outgoing-0 >> Host: localhost:4527

2013-09-19 14:58:14,836 DEBUG
org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl:136 [I/O
dispatcher 1] [onRequestSubmitted] http-outgoing-0 >> Connection: Keep-Alive

2013-09-19 14:58:14,836 DEBUG
org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl:136 [I/O
dispatcher 1] [onRequestSubmitted] http-outgoing-0 >> User-Agent:
Apache-HttpAsyncClient/4.0-beta4 (java 1.5)

2013-09-19 14:58:14,837 DEBUG
org.apache.http.impl.nio.conn.LoggingIOSession:102 [I/O dispatcher 1]
[setEvent] http-outgoing-0 127.0.0.1:52789<->127.0.0.1:4527[ACTIVE][rw:]:
Event set [w]

2013-09-19 14:58:14,837 DEBUG
org.apache.http.impl.nio.client.MainClientExec:258 [I/O dispatcher 1]
[requestCompleted] [exchange: 1] Request completed

2013-09-19 14:58:14,837 DEBUG
org.apache.http.impl.nio.client.LoggingAsyncRequestExecutor:75 [I/O
dispatcher 1] [requestReady] http-outgoing-0 [ACTIVE] Request ready

2013-09-19 14:58:14,839 DEBUG
org.apache.http.impl.nio.conn.LoggingIOSession$LoggingByteChannel:201 [I/O
dispatcher 1] [write] http-outgoing-0
127.0.0.1:52789<->127.0.0.1:4527[ACTIVE][rw:w]:
142 bytes written

2013-09-19 14:58:14,840 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 >> "GET /test/readTimeout
HTTP/1.1[\r][\n]"

2013-09-19 14:58:14,840 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 >> "Host: localhost:4527[\r][\n]"

2013-09-19 14:58:14,840 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"

2013-09-19 14:58:14,840 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 >> "User-Agent:
Apache-HttpAsyncClient/4.0-beta4 (java 1.5)[\r][\n]"

2013-09-19 14:58:14,840 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 >> "[\r][\n]"

2013-09-19 14:58:14,840 DEBUG
org.apache.http.impl.nio.conn.LoggingIOSession:109 [I/O dispatcher 1]
[clearEvent] http-outgoing-0 127.0.0.1:52789<->127.0.0.1:4527[ACTIVE][r:w]:
Event cleared [w]

2013-09-19 14:58:24,891 DEBUG
org.apache.http.impl.nio.conn.LoggingIOSession$LoggingByteChannel:186 [I/O
dispatcher 1] [read] http-outgoing-0
127.0.0.1:52789<->127.0.0.1:4527[ACTIVE][r:r]:
110 bytes read

2013-09-19 14:58:24,891 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 << "HTTP/1.1 200 OK[\r][\n]"

2013-09-19 14:58:24,891 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 << "Transfer-encoding: chunked[\r][\n]"

2013-09-19 14:58:24,892 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 << "Content-type:
application/json[\r][\n]"

2013-09-19 14:58:24,892 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 << "[\r][\n]"

2013-09-19 14:58:24,892 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 << "19[\r][\n]"

2013-09-19 14:58:24,892 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 << "{"name":"ribbon","age":1}[\r][\n]"

2013-09-19 14:58:24,898 DEBUG
org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl:122 [I/O
dispatcher 1] [onResponseReceived] http-outgoing-0 << HTTP/1.1 200 OK

2013-09-19 14:58:24,898 DEBUG
org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl:125 [I/O
dispatcher 1] [onResponseReceived] http-outgoing-0 << Transfer-encoding:
chunked

2013-09-19 14:58:24,898 DEBUG
org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl:125 [I/O
dispatcher 1] [onResponseReceived] http-outgoing-0 << Content-type:
application/json

2013-09-19 14:58:24,898 DEBUG
org.apache.http.impl.nio.client.LoggingAsyncRequestExecutor:110 [I/O
dispatcher 1] [responseReceived] http-outgoing-0 [ACTIVE(31)] Response
received

2013-09-19 14:58:24,898 DEBUG
org.apache.http.impl.nio.client.MainClientExec:269 [I/O dispatcher 1]
[responseReceived] [exchange: 1] Response received HTTP/1.1 200 OK

2013-09-19 14:58:24,900 DEBUG
org.apache.http.impl.nio.client.LoggingAsyncRequestExecutor:85 [I/O
dispatcher 1] [inputReady] http-outgoing-0 [ACTIVE(31)] Input ready

2013-09-19 14:58:24,900 DEBUG
org.apache.http.impl.nio.client.MainClientExec:308 [I/O dispatcher 1]
[consumeContent] [exchange: 1] Consume content

2013-09-19 14:58:24,901 DEBUG
org.apache.http.impl.nio.conn.LoggingIOSession$LoggingByteChannel:186 [I/O
dispatcher 1] [read] http-outgoing-0
127.0.0.1:52789<->127.0.0.1:4527[ACTIVE][r:r]:
5 bytes read

2013-09-19 14:58:24,901 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 << "0[\r][\n]"

2013-09-19 14:58:24,901 DEBUG org.apache.http.impl.nio.conn.Wire:54 [I/O
dispatcher 1] [wire] http-outgoing-0 << "[\r][\n]"

2013-09-19 14:58:24,901 DEBUG
org.apache.http.impl.nio.conn.LoggingIOSession$LoggingByteChannel:186 [I/O
dispatcher 1] [read] http-outgoing-0
127.0.0.1:52789<->127.0.0.1:4527[ACTIVE][r:r]:
0 bytes read

2013-09-19 14:58:24,901 DEBUG
org.apache.http.impl.nio.conn.LoggingIOSession$LoggingByteChannel:186 [I/O
dispatcher 1] [read] http-outgoing-0
127.0.0.1:52789<->127.0.0.1:4527[ACTIVE][r:r]:
0 bytes read

2013-09-19 14:58:24,902 DEBUG
org.apache.http.impl.nio.client.MainClientExec:336 [I/O dispatcher 1]
[responseCompleted] [exchange: 1] Connection can be kept alive indefinitely

2013-09-19 14:58:24,902 DEBUG
org.apache.http.impl.nio.client.MainClientExec:376 [I/O dispatcher 1]
[responseCompleted] [exchange: 1] Response processed

2013-09-19 14:58:24,903 DEBUG
org.apache.http.impl.nio.client.DefaultClientExchangeHandlerImpl:192 [I/O
dispatcher 1] [releaseConnection] [exchange: 1] releasing connection

2013-09-19 14:58:24,903 DEBUG
org.apache.http.impl.nio.conn.LoggingIOSession:171 [I/O dispatcher 1]
[removeAttribute] http-outgoing-0
127.0.0.1:52789<->127.0.0.1:4527[ACTIVE][r:r]:
Remove attribute http.nio.exchange-handler

2013-09-19 14:58:24,903 DEBUG
org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager:268 [I/O
dispatcher 1] [releaseConnection] Connection [id: http-outgoing-0][route:
{}->http://localhost:4527] can be kept alive indefinitely

2013-09-19 14:58:24,903 DEBUG
org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager:274 [I/O
dispatcher 1] [releaseConnection] Connection released: [id:
http-outgoing-0][route: {}->http://localhost:4527][total kept alive: 1;
route allocated: 1 of 2; total allocated: 1 of 20]

2013-09-19 14:58:24,928 DEBUG
org.apache.http.impl.nio.client.LoggingAsyncRequestExecutor:89 [I/O
dispatcher 1] [inputReady] http-outgoing-0 [ACTIVE] [chunk-coded;
completed: true]

Thanks.

Setting socket read timeout for HttpAsyncClient 4.0-beta4 but not getting exception

Reply via email to