On Fri, 2019-06-07 at 19:06 +0200, Joan grupoventus wrote:
> Hi Oleg,
>
> Ok, let me explain a bit more. This comes from a previous mistake in
> our AsyncResponseConsumer.
>
> Some weeks ago I wrote you an email because we were having an issue
> where threads got stuck, streamEnd and failed methods were never
> called, and the thread was released when the container asynchronous
> timeout was reached. As you notice, the issue was in our
> updateCapacity method because we were doing nothing on it, instead of
> extending the capacity of the buffer. This was fixed.
>
> Now the current issue. Something similar is happening. After several
> days of execution, requests start to throw an exception because the
> container asynchronous timeout is reached. Tracing http, we saw the
> pool exhausted ... so it's a behavior similar to issue nr. 1.
> 08:14:03.054 Connection request: [route: {}->
> http://10.15.15.53:8083][total kept alive: 0; route allocated: 107 of
> 1500; total allocated: 1500 of 1500]
>
I could not find it anywhere in the logs that you have provided.
> That's why I asked you if it's possible the 'updateCapacity' method
> to be called but without previously calling the 'consumeResponse'
> method with a non-null entity.
No, I do not think it is possible.
> In this case the variable 'this.capacityToPerform' we use to extend
> the buffer will be 0 and we will be again in the first issue.
>
> So I think the pool exhausted is a consequence the thread that is
> managing the 'AsyncResponseConsumer' is not ending for some reason
> (like in the first issue).
>
Again, I need to see a _complete_ wire / context log of such message
exchange.
Is there something else (like updating the capacity) I have to take
> into account in the ' AsyncResponseConsumer ' to avoid hanging the
> execution?
>
I need to see a log of such 'hanging' message exchnage.
Oleg
> Thanks,
>
> Joan.
>
> -----Original Message-----
> From: Oleg Kalnichevski <ol...@apache.org>
> Sent: Friday, June 7, 2019 4:00 PM
> To: HttpClient User Discussion <httpclient-users@hc.apache.org>
> Subject: Re: Response timeout issue
>
> On Thu, 2019-06-06 at 18:56 +0200, Joan grupoventus wrote:
> > Hi again,
> >
> > Not sure if we have seen something strange in the current test
> > with
> > the keep alive connections. It's just a GET method to get a gif
> > (this
> > pool has no keep-alive, that means a 100ms keep-alive). Here the
> > complete http log: https://github.com/joanbalaguero/HttpClient.git
> > (it's the "http_get.log")
>
> Joan
>
> I am confused. I looked at http_get.log and I can see the exact same
> number of connection lease requests and that of released connections.
> There are two 253 message exchanges and the same number of connection
> lease / release operations.
>
> I am not seeing any evidence of connections being leaked. I am lost
> now. What is exactly the issue you are having?
>
> Oleg
>
>
> > Previously to this test, this pool received 4 requests today
> > 06/06/2019 around 11:15:00 (so 6 hours before the test), these 4
> > requests ended up with a 4xx status code.
> >
> > This is the first request we sent to this pool using this route.
> > Should not keep-alive be 0 and total allocated 1 of 1000?
> > -------------------------------------------------------------------
> > ------------
> > 17:23:02.692 ex-0105B9B8: preparing request execution
> > 17:23:02.692 Target auth state: UNCHALLENGED
> > 17:23:02.692 Proxy auth state: UNCHALLENGED
> > 17:23:02.692 ex-0105B9B8: acquiring connection with route {}->
> > http://andalucia.viajesolympia.com:80
> > 17:23:02.692 Connection request: [route: {}->
> > http://andalucia.viajesolympia.com:80][total kept alive: 1; route
> > allocated: 0 of 1000; total allocated: 1 of 1000]
> > 17:23:02.692 Connection leased: [route: {}->
> > http://andalucia.viajesolympia.com:80][total kept alive: 1; route
> > allocated: 1 of 1000; total allocated: 2 of 1000]
> > 17:23:02.692 ep-010526BF: acquired null
> > 17:23:02.692 ex-0105B9B8: connection acquired
> >
> > This is the second:
> > ------------------------
> > 17:23:02.954 ex-0105B9B9: preparing request execution
> > 17:23:02.955 Target auth state: UNCHALLENGED
> > 17:23:02.955 Proxy auth state: UNCHALLENGED
> > 17:23:02.955 ex-0105B9B9: acquiring connection with route {}->
> > http://andalucia.viajesolympia.com:80
> > 17:23:02.955 Connection request: [route: {}->
> > http://andalucia.viajesolympia.com:80][total kept alive: 2; route
> > allocated: 1 of 1000; total allocated: 2 of 1000]
> > 17:23:02.955 Connection leased: [route: {}->
> > http://andalucia.viajesolympia.com:80][total kept alive: 1; route
> > allocated: 1 of 1000; total allocated: 2 of 1000]
> > 17:23:02.955 ep-010526C0: acquired null
> > 17:23:02.955 ex-0105B9B9: connection acquired
> > 17:23:02.976 ep-010526C0: connected i/o-0000434A
> > 17:23:02.976 Connected to target
> > 17:23:02.976 Route fully established
> >
> > ( . . . )
> >
> > Now a pool reboot
> > -------------------------
> > 17:27:29.996 Shutdown connection pool GRACEFUL
> > 17:27:29.996 i/o-000043AF: Shutdown connection GRACEFUL
> > 17:27:29.996 i/o-00002D9A: Shutdown connection GRACEFUL
> > 17:27:29.996 Connection pool shut down
> > 17:27:29.997 Shutdown GRACEFUL
> >
> > 1st. request after rebooting. Here keep-alive = 0 and
> > total_allocated
> > = 1
> > -------------------------------------
> > 17:27:53.585 ex-0105BA49: preparing request execution
> > 17:27:53.585 Target auth state: UNCHALLENGED
> > 17:27:53.585 Proxy auth state: UNCHALLENGED
> > 17:27:53.585 ex-0105BA49: acquiring connection with route {}->
> > http://andalucia.viajesolympia.com:80
> > 17:27:53.585 Connection request: [route: {}->
> > http://andalucia.viajesolympia.com:80][total kept alive: 0; route
> > allocated: 0 of 1000; total allocated: 0 of 1000]
> > 17:27:53.585 Connection leased: [route: {}->
> > http://andalucia.viajesolympia.com:80][total kept alive: 0; route
> > allocated: 1 of 1000; total allocated: 1 of 1000]
> > 17:27:53.585 ep-01052750: acquired null
> > 17:27:53.585 ex-0105BA49: connection acquired
> > 17:27:53.609 ep-01052750: connected i/o-000043B0
> > 17:27:53.609 Connected to target
> > 17:27:53.609 Route fully established
> >
> >
> > Thanks,
> > Joan.
> >
> >
> >
> > -----------------------------------------------------------------
> > ----
> > To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
> > For additional commands, e-mail:
> > httpclient-users-h...@hc.apache.org
> >
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
> For additional commands, e-mail: httpclient-users-h...@hc.apache.org
>
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
> For additional commands, e-mail: httpclient-users-h...@hc.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org
