hc-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Ashim Kumar Rana (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (HTTPASYNC-120) Client is NOT handling 100 Continue correctly
Date Fri, 05 May 2017 14:29:04 GMT

    [ https://issues.apache.org/jira/browse/HTTPASYNC-120?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15998405#comment-15998405
] 

Ashim Kumar Rana commented on HTTPASYNC-120:
--------------------------------------------

I have attached the complete failure log. The case could be that either sever delayed sending
"100 continue" or because of slow network or client workload, the client read "100 continue"
as well "actual status code" at the same time and into the same buffer.

> Client is NOT handling 100 Continue correctly
> ---------------------------------------------
>
>                 Key: HTTPASYNC-120
>                 URL: https://issues.apache.org/jira/browse/HTTPASYNC-120
>             Project: HttpComponents HttpAsyncClient
>          Issue Type: Bug
>    Affects Versions: 4.1.3
>         Environment: HttpAsyncClient-------------Apache
>            Reporter: Ashim Kumar Rana
>            Priority: Blocker
>             Fix For: 4.1.3
>
>         Attachments: httpFailedLog
>
>
> When the 100 Continue and 200 OK(for that matter any other also) response is received
followed by connection close; the client reads all bytes, but treats the status code as 100.
In the next iteration the read would return -1 as expected and endOfInput would be called.
The 200 OK response is lost in transition!!! 
> InternalRequestExecutor.java:71 05/05/17 01:17:51.012 IST I/O dispatcher 10 [DEBUG] http-outgoing-4
[ACTIVE] Request ready
> LoggingIOSession.java:116 05/05/17 01:17:51.013 IST I/O dispatcher 10 [DEBUG] http-outgoing-4
172.30.230.36:62563<->10.212.24.158:443[ACTIVE][r:w][ACTIVE][r][NOT_HANDSHAKING][0][0][0][0]:
Event cleared [w
> ]
> LoggingIOSession.java:206 05/05/17 01:17:51.058 IST I/O dispatcher 10 [DEBUG] http-outgoing-4
172.30.230.36:62563<->10.212.24.158:443[ACTIVE][r:r][ACTIVE][r][NOT_HANDSHAKING][0][0][0][0]:
222 bytes read
> Wire.java:54 05/05/17 01:17:51.059 IST I/O dispatcher 10 [DEBUG] http-outgoing-4 <<
"HTTP/1.1 100 Continue[\r][\n]"
> Wire.java:54 05/05/17 01:17:51.059 IST I/O dispatcher 10 [DEBUG] http-outgoing-4 <<
"[\r][\n]"
> Wire.java:54 05/05/17 01:17:51.059 IST I/O dispatcher 10 [DEBUG] http-outgoing-4 <<
"HTTP/1.1 202 Accepted[\r][\n]"
> Wire.java:54 05/05/17 01:17:51.059 IST I/O dispatcher 10 [DEBUG] http-outgoing-4 <<
"Date: Thu, 04 May 2017 19:47:43 GMT[\r][\n]"
> Wire.java:54 05/05/17 01:17:51.059 IST I/O dispatcher 10 [DEBUG] http-outgoing-4 <<
"Server: Apache/2.4.6 (CentOS) OpenSSL/1.0.1e-fips mod_jk/1.2.40[\r][\n]"
> Wire.java:54 05/05/17 01:17:51.059 IST I/O dispatcher 10 [DEBUG] http-outgoing-4 <<
"Content-Length: 0[\r][\n]"
> Wire.java:54 05/05/17 01:17:51.059 IST I/O dispatcher 10 [DEBUG] http-outgoing-4 <<
"Connection: close[\r][\n]"
> Wire.java:54 05/05/17 01:17:51.059 IST I/O dispatcher 10 [DEBUG] http-outgoing-4 <<
"Content-Type: application/json[\r][\n]"
> Wire.java:54 05/05/17 01:17:51.059 IST I/O dispatcher 10 [DEBUG] http-outgoing-4 <<
"[\r][\n]"
> ManagedNHttpClientConnectionImpl.java:125 05/05/17 01:17:51.059 IST I/O dispatcher 10
[DEBUG] http-outgoing-4 << HTTP/1.1 100 Continue
> InternalRequestExecutor.java:106 05/05/17 01:17:51.059 IST I/O dispatcher 10 [DEBUG]
http-outgoing-4 [ACTIVE(197)] Response received
> LoggingIOSession.java:206 05/05/17 01:17:51.059 IST I/O dispatcher 10 [DEBUG] http-outgoing-4
172.30.230.36:62563<->10.212.24.158:443[ACTIVE][r:r][ACTIVE][r][NOT_HANDSHAKING][EOF][][0][0][0][0]:
-1 bytes read
> ManagedNHttpClientConnectionImpl.java:125 05/05/17 01:17:51.060 IST I/O dispatcher 10
[DEBUG] http-outgoing-4 << HTTP/1.1 202 Accepted
> ManagedNHttpClientConnectionImpl.java:128 05/05/17 01:17:51.060 IST I/O dispatcher 10
[DEBUG] http-outgoing-4 << Date: Thu, 04 May 2017 19:47:43 GMT
> ManagedNHttpClientConnectionImpl.java:128 05/05/17 01:17:51.060 IST I/O dispatcher 10
[DEBUG] http-outgoing-4 << Server: Apache/2.4.6 (CentOS) OpenSSL/1.0.1e-fips mod_jk/1.2.40
> ManagedNHttpClientConnectionImpl.java:128 05/05/17 01:17:51.060 IST I/O dispatcher 10
[DEBUG] http-outgoing-4 << Content-Length: 0
> ManagedNHttpClientConnectionImpl.java:128 05/05/17 01:17:51.060 IST I/O dispatcher 10
[DEBUG] http-outgoing-4 << Connection: close
> ManagedNHttpClientConnectionImpl.java:128 05/05/17 01:17:51.060 IST I/O dispatcher 10
[DEBUG] http-outgoing-4 << Content-Type: application/json
> InternalRequestExecutor.java:106 05/05/17 01:17:51.060 IST I/O dispatcher 10 [DEBUG]
http-outgoing-4 [ACTIVE] Response received
> MainClientExec.java:286 05/05/17 01:17:51.060 IST I/O dispatcher 10 [DEBUG] [exchange:
5] Response received HTTP/1.1 202 Accepted
> InternalRequestExecutor.java:130 05/05/17 01:17:51.060 IST I/O dispatcher 10 [DEBUG]
http-outgoing-4 [ACTIVE] End of input
> LoggingIOSession.java:141 05/05/17 01:17:51.060 IST I/O dispatcher 10 [DEBUG] http-outgoing-4
172.30.230.36:62563<->10.212.24.158:443[ACTIVE][r:r][ACTIVE][r][NOT_HANDSHAKING][EOF][][0][0][0][0]:
Shutdown
> AbstractClientExchangeHandler.java:263 05/05/17 01:17:51.060 IST I/O dispatcher 10 [DEBUG]
[exchange: 5] connection aborted
> PoolingNHttpClientConnectionManager.java:285 05/05/17 01:17:51.061 IST I/O dispatcher
10 [DEBUG] Releasing connection: [id: http-outgoing-4][route: {s}->https://10.212.24.158:443][total
kept alive: 0; route allocated: 4 of 10; total allocated: 4 of 10]
> PoolingNHttpClientConnectionManager.java:305 05/05/17 01:17:51.061 IST I/O dispatcher
10 [DEBUG] Connection released: [id: http-outgoing-4][route: {s}->https://10.212.24.158:443][total
kept alive: 0; route allocated: 3 of 10; total allocated: 3 of 10]
> LiveResponseCallback.java:122 05/05/17 01:17:51.062 IST I/O dispatcher 10 [ERROR] Live
Response Request failed for DeviceDetail [ip=192.1.37.3, deviceId=0c1818e5-9c10-45e4-bdbc-b103550a02c2]
with:
> org.apache.http.ConnectionClosedException: Connection closed
>         at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.endOfInput(HttpAsyncRequestExecutor.java:344)
>         at org.apache.http.impl.nio.client.InternalRequestExecutor.endOfInput(InternalRequestExecutor.java:132)
>         at org.apache.http.impl.nio.DefaultNHttpClientConnection.consumeInput(DefaultNHttpClientConnection.java:261)
>         at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:81)
>         at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:39)
>         at org.apache.http.impl.nio.reactor.AbstractIODispatch.inputReady(AbstractIODispatch.java:121)
>         at org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:162)
>         at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:337)
>         at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:315)
>         at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:276)
>         at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
>         at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:588)
>         at java.lang.Thread.run(Thread.java:745)
> LoggingIOSession.java:154 05/05/17 01:17:51.063 IST I/O dispatcher 10 [DEBUG] http-outgoing-4
0.0.0.0:62563<->10.212.24.158:443[CLOSED][][CLOSED][r][NOT_HANDSHAKING][EOF][][0][0][0][0]:
Set timeout 1000
> InternalRequestExecutor.java:81 05/05/17 01:17:51.063 IST I/O dispatcher 10 [DEBUG] http-outgoing-4
[CLOSED] Input ready
> MainClientExec.java:325 05/05/17 01:17:51.063 IST I/O dispatcher 10 [DEBUG] [exchange:
5] Consume content
> InternalRequestExecutor.java:122 05/05/17 01:17:51.063 IST I/O dispatcher 10 [DEBUG]
http-outgoing-4 [CLOSED] Exception
> java.lang.IllegalStateException: Content buffer is null
>         at org.apache.http.util.Asserts.notNull(Asserts.java:52)
>         at org.apache.http.nio.protocol.BasicAsyncResponseConsumer.onContentReceived(BasicAsyncResponseConsumer.java:81)
>         at org.apache.http.nio.protocol.AbstractAsyncResponseConsumer.consumeContent(AbstractAsyncResponseConsumer.java:141)
>         at org.apache.http.impl.nio.client.MainClientExec.consumeContent(MainClientExec.java:329)
>         at org.apache.http.impl.nio.client.DefaultClientExchangeHandlerImpl.consumeContent(DefaultClientExchangeHandlerImpl.java:153)
>         at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.inputReady(HttpAsyncRequestExecutor.java:324)
>         at org.apache.http.impl.nio.client.InternalRequestExecutor.inputReady(InternalRequestExecutor.java:83)
>         at org.apache.http.impl.nio.DefaultNHttpClientConnection.consumeInput(DefaultNHttpClientConnection.java:265)
>         at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:81)
>       at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:39)
>         at org.apache.http.impl.nio.reactor.AbstractIODispatch.inputReady(AbstractIODispatch.java:121)
>         at org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:162)
>         at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:337)
>         at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:315)
>         at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:276)
>         at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
>         at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:588)
>         at java.lang.Thread.run(Thread.java:745)
> LoggingIOSession.java:141 05/05/17 01:17:51.064 IST I/O dispatcher 10 [DEBUG] http-outgoing-4
0.0.0.0:62563<->10.212.24.158:443[CLOSED][][CLOSED][r][NOT_HANDSHAKING][EOF][][0][0][0][0]:
Shutdown
> InternalRequestExecutor.java:62 05/05/17 01:17:51.064 IST I/O dispatcher 10 [DEBUG] http-outgoing-4
[CLOSED]: Disconnected



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@hc.apache.org
For additional commands, e-mail: dev-help@hc.apache.org


Mime
View raw message