Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
Re: [jetty-users] Long processing time before HttpConnection.onFillable invoked

Thanks for the response Joakim.

I tried your config with 4 selectors, but there is no luck, same behavior. Any other ideas?

In the doc it says the onFillable "is called when this Connection is ready to read bytes from the EndPoint". What triggers this "is ready" signal? I am guess the trigger is getting delayed for some reason.

Thanks,
Jing

Date: Thu, 29 Jun 2017 16:53:11 -0700
From: Joakim Erdfelt <joakim@xxxxxxxxxxx>

>
> Server: 8 cores, 30 G memory
> Jetty: 9.2x
> Acceptor: 4 (default was 2, tried to increase to see difference but no
> help)
> Selector: 16 (default was 8, tried to increase to see difference but no
> help)
> Executor: 48


That seems backwards for your desired goal.

Go with.
Acceptors: 1
Selectors: 4
ThreadPool: QueuedThreadPool  (Don't use Executor for high load
configurations)

With your memory configuration you should be on Java 8 and Jetty 9.4.6.


Joakim Erdfelt / joakim@xxxxxxxxxxx

On Thu, Jun 29, 2017 at 3:59 PM, Jing Yang <jingisgood@xxxxxxxxx> wrote:

> Hi There,
>
> I noticed this issue during high load. A very simple example, I ran
>
> curl "http://localhost:8080/heath"
>
> it returned in 10+ seconds; however when I look at the request log, the
> latency is logged as tens of milli seconds. I profiled my server and qtp
> threads are not under heavy load.
>
> I turned on debug and found the following:
>
> 19:09:26.632:DBUG:oeji.SelectChannelEndPoint:qtp1963485345-43-selector-
> ServerConnectorManager@14a6d5e4/2: Key interests updated 1 -> 0 on
> SelectChannelEndPoint@199c8743{/127.0.0.1:46061<->8080,Open,
> in,out,R,-,7/30000,HttpConnection}{io=1,kio=0,kro=1}
> 19:09:26.633:DBUG:oeji.SelectChannelEndPoint:qtp1963485345-43-selector-
> ServerConnectorManager@14a6d5e4/2: Local interests updating 1 -> 0 for
> SelectChannelEndPoint@199c8743{/127.0.0.1:46061<->8080,Open,
> in,out,R,-,8/30000,HttpConnection}{io=0,kio=0,kro=1}
> 19:09:26.633:DBUG:oeji.SelectorManager:qtp1963485345-43-selector-
> ServerConnectorManager@14a6d5e4/2: Queued change org.eclipse.jetty.io.
> SelectChannelEndPoint$1@1712a18
> 19:09:26.633:DBUG:oeji.AbstractConnection:qtp1963485345-43-selector-
> ServerConnectorManager@14a6d5e4/2: FILL_INTERESTED-->FILLING
> HttpConnection@44ced19c{FILLING}
> 19:09:26.634:DBUG:oeji.SelectorManager:qtp1963485345-43-selector-
> ServerConnectorManager@14a6d5e4/2: Running change org.eclipse.jetty.io.
> SelectChannelEndPoint$1@1712a18
>
>
> but after this, the onfillable happens after 10 seconds:
>
> 19:09:37.006:DBUG:oeji.ChannelEndPoint:qtp1963485345-5349: filled 99
> SelectChannelEndPoint@199c8743{/127.0.0.1:46061<->8080,Open,
> in,out,-,-,10381/30000,HttpConnection}{io=0,kio=0,kro=1}
>
> Can any please help me fiture out what exactly happened after the
> HttpConnection turns into FILLING state and what caused the onfillable to
> be invoked after 10+ seconds?
>
> My environment:
> Server: 8 cores, 30 G memory
> Jetty: 9.2x
> Acceptor: 4 (default was 2, tried to increase to see difference but no
> help)
> Selector: 16 (default was 8, tried to increase to see difference but no
> help)
> Executor: 48
>
> Thanks,
> Jing

Back to the top