[
Date Prev][
Date Next][
Thread Prev][
Thread Next][
Date Index][
Thread Index]
[
List Home]
Re: [jetty-dev] Help explaining why FutureCallback.get would be showing up as a hotspot in profiling?
|
Aaron,
On Thu, Oct 4, 2012 at 12:52 PM, Aaron Daubman <daubman@xxxxxxxxx> wrote:
> Greetings,
>
> After moving from Jetty 7.6.5 to 9.0M0 we've seen a degradation in
> performance and I am attempting to troubleshoot.
>
> The hotspot I am seeing is that several seconds may be spent in
> FutureCallback.get (line 115), which is just: a _done.await()
>
> Would somebody please educate me on if this is a red flag or typically
> symptomatic of some issue I might be able to focus on (or any other
> possible indicators)?
>
> From jetty/util/FutureCallback.java:
> ---snip---
> 113 public C get() throws InterruptedException, ExecutionException
> 114 {
> *115 _done.await();
> 116 if (_completed)
> 117 return _context;
> 118 if (_cause instanceof CancellationException)
> 119 throw (CancellationException) new
> CancellationException().initCause(_cause);
> 120 throw new ExecutionException(_cause);
> 121 }
>
> ---snip---
>
> Here's the partial call graph I am looking at:
> ---snip---
> org.eclipse.jetty.server.HttpOutput:write:174 (method time = 0 ms,
> total time = 4885 ms)
> org.eclipse.jetty.server.HttpChannel:write:608 (method time = 0 ms,
> total time = 4885 ms)
> org.eclipse.jetty.server.HttpConnection:send:410 (method time = 0
> ms, total time = 4885 ms)
> org.eclipse.jetty.server.HttpConnection:send:372 (method time = 0
> ms, total time = 4885 ms)
> org.eclipse.jetty.server.HttpConnection:blockingWrite:419 (method
> time = 0 ms, total time = 4885 ms)
> org.eclipse.jetty.util.FutureCallback:get:115 (method time = 4885
> ms, total time = 4885 ms)
> ---snip---
>
> If background is helpful, this jetty instance is running a single Solr
> war, has a 50G heap, typically uses 12-20Gig, and is being hit with
> only around 50-100 requests per Minute. (each request does need to
> scan a 70Gig solr index, however, before the upgrade we were seeing
> average and pretty tight response times around 100-200 ms. Now they
> vary a lot more wildly (regularly spiking to 9000ms) and average
> 400-600ms.
This spot is already on our TODO list, because HttpChannel should be
completely asynchronous.
In your particular case it seems there is a slow client and Jetty is
waiting for this client to read the content.
As I said, Jetty should not blocking wait.
Will soon be fixed, bear with us :)
Simon
--
http://cometd.org
http://webtide.com
Developer advice, services and support
from the Jetty & CometD experts.
----
Finally, no matter how good the architecture and design are,
to deliver bug-free software with optimal performance and reliability,
the implementation technique must be flawless. Victoria Livschitz