On Fri, 2019-06-07 at 19:43 +0200, Joan grupoventus wrote:
> Hi,
>
> > 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.
> --> It's here, https://github.com/joanbalaguero/HttpClient , in the
> http.log I uploaded.
>
But the pool is already been completely exhausted at the beginning of
the log
---
Connection request: [route: {}->http://10.15.15.22:8081][total kept
alive: 0; route allocated: 9 of 1500; total allocated: 1500 of 1500]
---
The log contains no information as to what has caused the pool
exhaustion in the first place. It is useless.
> >
> I need to see a log of such 'hanging' message exchnage.
> --> Ok, to do this I need to enable the http traces for days waiting
> the "hang" to happen. But with the log I have enabled now there is a
> significant increase in cpu and io (because the responses are usually
> quite big). Is there any way to enable a kind of logging useful for
> you but avoiding trace the request and response messages?
>
Try disabling I/O session and wire logging. That should massively
reduce the amount of chatter in the log.
---
<Configuration status="WARN" name="XMLConfigTest">
<Appenders>
<Console name="STDOUT">
<!--<PatternLayout pattern="%msg%n%xThrowable"/>-->
<PatternLayout pattern="%d %-5level
[%t][%logger]%notEmpty{[%markerSimpleName]} %msg%n%xThrowable"/>
</Console>
</Appenders>
<Loggers>
<Root level="warn">
<AppenderRef ref="STDOUT"/>
</Root>
<Logger name="org.apache.hc.client5" level="debug"/>
<Logger name="org.apache.hc.client5.http.impl" level="debug"/>
<Logger name="org.apache.hc.client5.http.headers" level="debug"/>
<Logger name="org.apache.hc.client5.http.impl.io" level="debug"/>
<Logger name="org.apache.hc.client5.http.impl.nio" level="debug"/>
<Logger name="org.apache.hc.client5.http.impl.cache" level="debug"/>
<Logger name="org.apache.hc.client5.http.wire" level="error"/>
<Logger name="org.apache.hc.client5.http2" level="debug"/>
<Logger name="org.apache.hc.client5.http2.frame" level="debug"/>
<Logger name="org.apache.hc.client5.http2.frame.payload" level="error"/>
<Logger name="org.apache.hc.client5.http2.flow" level="debug"/>
</Loggers>
</Configuration>
---
Oleg
> Joan.
>
>
> > 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
>
>
>
>
> ---------------------------------------------------------------------
> 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
