Re: [jetty-users] [jetty-9.1.1.v20140108] Jetty client idle timeout

[Simone Bordet <sbordet@xxxxxxxxxxx>]

Hi,

On Sat, Jan 25, 2014 at 1:36 AM, Vijay Panghal <vijay.panghal@xxxxxxxxx> wrote:
> Hi,
>
>
>
> In our system, jetty http client [jetty-9.1.1.v20140108] maintain single
> persistence connection to the jetty server. The same http client connection
> is being used to send message from multiple threads. We observing that after
> some time (sometime 30 second and sometime few minutes), client socket goes
> to CLOSED_WAIT state and client is not sending any message. We do not see
> any activity on the wire.
>
>
> Client is configured with these configuration:
> 1) Http basic authentication
> 2) Idle timeout 10 seconds. T
> 3) Connection timeout 10 seconds
> 4) Read timeout 5 second
> 5) SSL
> From the debug traces, it looks like jetty is repeatedly hitting 10 seconds
> idle timeout. I am not aware of the internal of jetty client implementation.
> Can anyone look at the traces and point out any obvious thing that I may be
> missing.
>
>
> I see same kind of issue in this message:
> http://dev.eclipse.org/mhonarc/lists/jetty-users/msg04291.html
>
>
> D 01-23 15:17:10.040 hippo-task-4 o.e.j.client.HttpDestination:178] Queued
> HttpRequest[POST /services/xxxxx HTTP/1.1]@3a0a4e33
> D 01-23 15:17:10.041 hippo-task-4 o.e.j.client.ConnectionPool:84] Max
> connections 1/1 reached
> D 01-23 15:17:11.758 HttpClient@740141492-scheduler
> o.eclipse.jetty.io.IdleTimeout:145]
> SelectChannelEndPoint@6a628568{xxxxxxx.com/10.50.1.181:19500<->64560,Open,in,out,-,-,10000,SslConnection}{io=0,kio=0,kro=1}
> idle timeout check, elapsed: 6633 ms, remaining: 3367 ms
> D 01-23 15:17:15.126 HttpClient@740141492-scheduler
> o.eclipse.jetty.io.IdleTimeout:145]
> SelectChannelEndPoint@6a628568{xxxxxxx.com/10.50.1.181:19500<->64560,Open,in,out,-,-,10000,SslConnection}{io=0,kio=0,kro=1}
> idle timeout check, elapsed: 10001 ms, remaining: -1 ms
>
>
> All subsequent jetty request timeout
>
>
> D 01-23 15:17:03.523 HttpClient@740141492-scheduler
> o.eclipse.jetty.io.IdleTimeout:145]
> SelectChannelEndPoint@6a628568{hippofood1.maginatics.com/10.50.1.181:19500<->64560,Open,in,out,R,-,10000,SslConnection}{io=1,kio=1,kro=1}
> idle timeout check, elapsed: 1766 ms, remaining: 8234 ms
> D 01-23 15:17:11.758 HttpClient@740141492-scheduler
> o.eclipse.jetty.io.IdleTimeout:145]
> SelectChannelEndPoint@6a628568{hippofood1.maginatics.com/10.50.1.181:19500<->64560,Open,in,out,-,-,10000,SslConnection}{io=0,kio=0,kro=1}
> idle timeout check, elapsed: 6633 ms, remaining: 3367 ms
> D 01-23 15:17:15.126 HttpClient@740141492-scheduler
> o.eclipse.jetty.io.IdleTimeout:145]
> SelectChannelEndPoint@6a628568{hippofood1.maginatics.com/10.50.1.181:19500<->64560,Open,in,out,-,-,10000,SslConnection}{io=0,kio=0,kro=1}
> idle timeout check, elapsed: 10001 ms, remaining: -1 ms
> D 01-23 15:17:25.128 HttpClient@740141492-scheduler
> o.eclipse.jetty.io.IdleTimeout:145]
> SelectChannelEndPoint@6a628568{hippofood1.maginatics.com/10.50.1.181:19500<->64560,Open,in,out,-,-,10000,SslConnection}{io=0,kio=0,kro=1}
> idle timeout check, elapsed: 10001 ms, remaining: -1 ms
> D 01-23 15:17:35.129 HttpClient@740141492-scheduler
> o.eclipse.jetty.io.IdleTimeout:145]
> SelectChannelEndPoint@6a628568{hippofood1.maginatics.com/10.50.1.181:19500<->64560,Open,in,out,-,-,10000,SslConnection}{io=0,kio=0,kro=1}
> idle timeout check, elapsed: 10001 ms, remaining: -1 ms
> D 01-23 15:17:45.131 HttpClient@740141492-scheduler
> o.eclipse.jetty.io.IdleTimeout:145]
> SelectChannelEndPoint@6a628568{hippofood1.maginatics.com/10.50.1.181:19500<->64560,Open,in,out,-,-,10000,SslConnection}{io=0,kio=0,kro=1}
> idle timeout check, elapsed: 10000 ms, remaining: 0 ms
> D 01-23 15:17:55.131 HttpClient@740141492-scheduler
> o.eclipse.jetty.io.IdleTimeout:145]
> SelectChannelEndPoint@6a628568{hippofood1.maginatics.com/10.50.1.181:19500<->64560,Open,in,out,-,-,10000,SslConnection}{io=0,kio=0,kro=1}
> idle timeout check, elapsed: 10000 ms, remaining: 0 ms

Your logs are only partial, and not ordered.
Can you please record one such failure with "org.eclipse.jetty.client"
log level set to DEBUG, and attach the logs ?
Seems like a bug, but I need the full logs to understand more.

Thanks !

-- 
Simone Bordet
----
http://cometd.org
http://webtide.com
http://intalio.com
Developer advice, training, services and support
from the Jetty & CometD experts.
Intalio, the modern way to build business applications.