You are viewing a plain text version of this content. The canonical link for it is here.
Posted to httpclient-users@hc.apache.org by Farzad Mahdikhani <f....@dotin.ir> on 2017/02/28 13:11:34 UTC
Unexpected connection close in HttpClient
I am facing a problem with HttpClient (version 4.5.2) in a web application, I mean, in a multi-threaded way. In normal situation, when a connection request is arrived, a connection is leased from the pool, then used and finally released back to the pool again to be used in future requests again as the following part of log for connection with id 673890 states .
-------------------------------------------------------------
15 Feb 2017 018:25:54:115 p-1-thread-121 DEBUG PoolingHttpClientConnectionManager:249 - Connection request: [route: {}->http://127.0.0.1:8080][total kept alive: 51; route allocated: 4 of 100; total allocated: 92 of 500]
15 Feb 2017 018:25:54:116 p-1-thread-121 DEBUG PoolingHttpClientConnectionManager:282 - Connection leased: [id: 673890][route: {}->http://127.0.0.1:8080][total kept alive: 51; route allocated: 4 of 100; total allocated: 92 of 500]
15 Feb 2017 018:25:54:116 p-1-thread-121 DEBUG DefaultManagedHttpClientConnection:90 - http-outgoing-673890: set socket timeout to 9000
15 Feb 2017 018:25:54:120 p-1-thread-121 DEBUG PoolingHttpClientConnectionManager:314 - Connection [id: 673890][route: {}->http://127.0.0.1:8080] can be kept alive for 10.0 seconds
15 Feb 2017 018:25:54:121 p-1-thread-121 DEBUG PoolingHttpClientConnectionManager:320 - Connection released: [id: 673890][route: {}->http://127.0.0.1:8080][total kept alive: 55; route allocated: 4 of 100; total allocated: 92 of 500]
-------------------------------------------------------------
After using the mentioned connection (id 673890) several times in a normal way which I mentioned above, I notice the following happens in the code:
-------------------------------------------------------------
15 Feb 2017 018:25:54:130 p-1-thread-126 DEBUG PoolingHttpClientConnectionManager:249 - Connection request: [route: {}->http://127.0.0.1:8080][total kept alive: 55; route allocated: 4 of 100; total allocated: 92 of 500]
15 Feb 2017 018:25:54:130 p-1-thread-126 DEBUG PoolingHttpClientConnectionManager:282 - Connection leased: [id: 673890][route: {}->http://127.0.0.1:8080][total kept alive: 54; route allocated: 4 of 100; total allocated: 92 of 500]
15 Feb 2017 018:25:54:131 p-1-thread-126 DEBUG DefaultManagedHttpClientConnection:90 - http-outgoing-673890: set socket timeout to 9000
15 Feb 2017 018:25:54:133 p-1-thread-126 DEBUG DefaultManagedHttpClientConnection:81 - http-outgoing-673890: Close connection
15 Feb 2017 018:25:54:133 p-1-thread-126 DEBUG PoolingHttpClientConnectionManager:320 - Connection released: [id: 673890][route: {}->http://127.0.0.1:8080][total kept alive: 55; route allocated: 3 of 100; total allocated: 91 of 500]
-------------------------------------------------------------
The log says that the connection is requested, leased, used, closed and then released back to the pool. So, my question is that why the connection is closed? And why it is released to the pool after closing?
I know that the connection could be closed by the server, but that is a different situation. In that case, the connection is leased from the pool, determined as stale, so a new connection is established and used but the log I presented above shows a different behavior.
I am aware of two reasons for connection close in HttpClient. First, closed for being idle because their KeepAliveTime is expired. Second, closed by the server which makes the connection stale in the pool. Is there any other reason for connections to be closed?
Regards,
Ferez
---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org
Re: Unexpected connection close in HttpClient
Posted by Farzad Mahdikhani <f....@dotin.ir>.
Thank you very much Oleg, you are right and the problem was because of 'Connection: close' header sent by the other hand. I appraciate your help.
Ferez
From: Oleg Kalnichevski <ol...@apache.org>
Sent: Wednesday, March 1, 2017 12:22 AM
To: HttpClient User Discussion
Subject: Re: Unexpected connection close in HttpClient
On Tue, 2017-02-28 at 13:11 +0000, Farzad Mahdikhani wrote:
> I am facing a problem with HttpClient (version 4.5.2) in a web
> application, I mean, in a multi-threaded way. In normal situation,
> when a connection request is arrived, a connection is leased from the
> pool, then used and finally released back to the pool again to be
> used in future requests again as the following part of log for
> connection with id 673890 states .
> -------------------------------------------------------------
> 15 Feb 2017 018:25:54:115 p-1-thread-121 DEBUG
> PoolingHttpClientConnectionManager:249 - Connection request: [route:
> {}->http://127.0.0.1:8080][total kept alive: 51; route allocated: 4
> of 100; total allocated: 92 of 500]
> 15 Feb 2017 018:25:54:116 p-1-thread-121 DEBUG
> PoolingHttpClientConnectionManager:282 - Connection leased: [id:
> 673890][route: {}->http://127.0.0.1:8080][total kept alive: 51; route
> allocated: 4 of 100; total allocated: 92 of 500]
> 15 Feb 2017 018:25:54:116 p-1-thread-121 DEBUG
> DefaultManagedHttpClientConnection:90 - http-outgoing-673890: set
> socket timeout to 9000
> 15 Feb 2017 018:25:54:120 p-1-thread-121 DEBUG
> PoolingHttpClientConnectionManager:314 - Connection [id:
> 673890][route: {}->http://127.0.0.1:8080] can be kept alive for 10.0
> seconds
> 15 Feb 2017 018:25:54:121 p-1-thread-121 DEBUG
> PoolingHttpClientConnectionManager:320 - Connection released: [id:
> 673890][route: {}->http://127.0.0.1:8080][total kept alive: 55; route
> allocated: 4 of 100; total allocated: 92 of 500]
> -------------------------------------------------------------
> After using the mentioned connection (id 673890) several times in a
> normal way which I mentioned above, I notice the following happens in
> the code:
> -------------------------------------------------------------
> 15 Feb 2017 018:25:54:130 p-1-thread-126 DEBUG
> PoolingHttpClientConnectionManager:249 - Connection request: [route:
> {}->http://127.0.0.1:8080][total kept alive: 55; route allocated: 4
> of 100; total allocated: 92 of 500]
> 15 Feb 2017 018:25:54:130 p-1-thread-126 DEBUG
> PoolingHttpClientConnectionManager:282 - Connection leased: [id:
> 673890][route: {}->http://127.0.0.1:8080][total kept alive: 54; route
> allocated: 4 of 100; total allocated: 92 of 500]
> 15 Feb 2017 018:25:54:131 p-1-thread-126 DEBUG
> DefaultManagedHttpClientConnection:90 - http-outgoing-673890: set
> socket timeout to 9000
> 15 Feb 2017 018:25:54:133 p-1-thread-126 DEBUG
> DefaultManagedHttpClientConnection:81 - http-outgoing-673890: Close
> connection
> 15 Feb 2017 018:25:54:133 p-1-thread-126 DEBUG
> PoolingHttpClientConnectionManager:320 - Connection released: [id:
> 673890][route: {}->http://127.0.0.1:8080][total kept alive: 55; route
> allocated: 3 of 100; total allocated: 91 of 500]
> -------------------------------------------------------------
> The log says that the connection is requested, leased, used, closed
> and then released back to the pool. So, my question is that why the
> connection is closed? And why it is released to the pool after
> closing?
>
> I know that the connection could be closed by the server, but that is
> a different situation. In that case, the connection is leased from
> the pool, determined as stale, so a new connection is established and
> used but the log I presented above shows a different behavior.
>
> I am aware of two reasons for connection close in HttpClient. First,
> closed for being idle because their KeepAliveTime is expired. Second,
> closed by the server which makes the connection stale in the pool. Is
> there any other reason for connections to be closed?
>
'Connection: close' header or HTTP/1.0 non-persistent connections.
Oleg
---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org
Re: Unexpected connection close in HttpClient
Posted by Oleg Kalnichevski <ol...@apache.org>.
On Tue, 2017-02-28 at 13:11 +0000, Farzad Mahdikhani wrote:
> I am facing a problem with HttpClient (version 4.5.2) in a web
> application, I mean, in a multi-threaded way. In normal situation,
> when a connection request is arrived, a connection is leased from the
> pool, then used and finally released back to the pool again to be
> used in future requests again as the following part of log for
> connection with id 673890 states .
> -------------------------------------------------------------
> 15 Feb 2017 018:25:54:115 p-1-thread-121 DEBUG
> PoolingHttpClientConnectionManager:249 - Connection request: [route:
> {}->http://127.0.0.1:8080][total kept alive: 51; route allocated: 4
> of 100; total allocated: 92 of 500]
> 15 Feb 2017 018:25:54:116 p-1-thread-121 DEBUG
> PoolingHttpClientConnectionManager:282 - Connection leased: [id:
> 673890][route: {}->http://127.0.0.1:8080][total kept alive: 51; route
> allocated: 4 of 100; total allocated: 92 of 500]
> 15 Feb 2017 018:25:54:116 p-1-thread-121 DEBUG
> DefaultManagedHttpClientConnection:90 - http-outgoing-673890: set
> socket timeout to 9000
> 15 Feb 2017 018:25:54:120 p-1-thread-121 DEBUG
> PoolingHttpClientConnectionManager:314 - Connection [id:
> 673890][route: {}->http://127.0.0.1:8080] can be kept alive for 10.0
> seconds
> 15 Feb 2017 018:25:54:121 p-1-thread-121 DEBUG
> PoolingHttpClientConnectionManager:320 - Connection released: [id:
> 673890][route: {}->http://127.0.0.1:8080][total kept alive: 55; route
> allocated: 4 of 100; total allocated: 92 of 500]
> -------------------------------------------------------------
> After using the mentioned connection (id 673890) several times in a
> normal way which I mentioned above, I notice the following happens in
> the code:
> -------------------------------------------------------------
> 15 Feb 2017 018:25:54:130 p-1-thread-126 DEBUG
> PoolingHttpClientConnectionManager:249 - Connection request: [route:
> {}->http://127.0.0.1:8080][total kept alive: 55; route allocated: 4
> of 100; total allocated: 92 of 500]
> 15 Feb 2017 018:25:54:130 p-1-thread-126 DEBUG
> PoolingHttpClientConnectionManager:282 - Connection leased: [id:
> 673890][route: {}->http://127.0.0.1:8080][total kept alive: 54; route
> allocated: 4 of 100; total allocated: 92 of 500]
> 15 Feb 2017 018:25:54:131 p-1-thread-126 DEBUG
> DefaultManagedHttpClientConnection:90 - http-outgoing-673890: set
> socket timeout to 9000
> 15 Feb 2017 018:25:54:133 p-1-thread-126 DEBUG
> DefaultManagedHttpClientConnection:81 - http-outgoing-673890: Close
> connection
> 15 Feb 2017 018:25:54:133 p-1-thread-126 DEBUG
> PoolingHttpClientConnectionManager:320 - Connection released: [id:
> 673890][route: {}->http://127.0.0.1:8080][total kept alive: 55; route
> allocated: 3 of 100; total allocated: 91 of 500]
> -------------------------------------------------------------
> The log says that the connection is requested, leased, used, closed
> and then released back to the pool. So, my question is that why the
> connection is closed? And why it is released to the pool after
> closing?
>
> I know that the connection could be closed by the server, but that is
> a different situation. In that case, the connection is leased from
> the pool, determined as stale, so a new connection is established and
> used but the log I presented above shows a different behavior.
>
> I am aware of two reasons for connection close in HttpClient. First,
> closed for being idle because their KeepAliveTime is expired. Second,
> closed by the server which makes the connection stale in the pool. Is
> there any other reason for connections to be closed?
>
'Connection: close' header or HTTP/1.0 non-persistent connections.
Oleg
---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org