Grizzly provider TimeoutException making async requests

[jbrittain]

When making async requests using the Grizzly provider (from AHC 2.0.0-SNAPSHOT), I get some TimeoutExceptions that should not occur. The server is serving these requests very rapidly, and the JVM isn't GCing very much. The requests serve in a fraction of a second, but the Grizzly provider says they timed out after 9 seconds. If I set the Grizzly provider's timeout to a higher number of seconds then it times out after that many seconds instead..

Some stack trace examples:

java.util.concurrent.TimeoutException: Timeout exceeded at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider.timeout(GrizzlyAsyncHttpProvider.java:485) at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider$3.onTimeout(GrizzlyAsyncHttpProvider.java:276) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:382) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:362) at org.glassfish.grizzly.utils.DelayedExecutor$DelayedRunnable.run(DelayedExecutor.java:158) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722)

---

another stack trace:

java.util.concurrent.ExecutionException: java.util.concurrent.TimeoutException: Timeout exceeded at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:252) at java.util.concurrent.FutureTask.get(FutureTask.java:111) at org.asynchttpclient.providers.grizzly.GrizzlyResponseFuture.get(GrizzlyResponseFuture.java:165) at org.ebaysf.webclient.benchmark.NingAhcGrizzlyBenchmarkTest.asyncWarmup(NingAhcGrizzlyBenchmarkTest.java:105) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:601) at org.ebaysf.webclient.benchmark.AbstractBenchmarkTest.doBenchmark(AbstractBenchmarkTest.java:168) at org.ebaysf.webclient.benchmark.NingAhcGrizzlyBenchmarkTest.testAsyncLargeResponses(NingAhcGrizzlyBenchmarkTest.java:84) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:601) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55) at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55) at org.junit.rules.RunRules.evaluate(RunRules.java:20) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) at org.junit.runners.ParentRunner.run(ParentRunner.java:309) at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:45) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:119) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:101) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:601) at org.apache.maven.surefire.booter.ProviderFactory$ClassLoaderProxy.invoke(ProviderFactory.java:103) at com.sun.proxy.$Proxy0.invoke(Unknown Source) at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:150) at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcess(SurefireStarter.java:91) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:69) Caused by: java.util.concurrent.TimeoutException: Timeout exceeded at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider.timeout(GrizzlyAsyncHttpProvider.java:485) at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider$3.onTimeout(GrizzlyAsyncHttpProvider.java:276) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:382) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:362) at org.glassfish.grizzly.utils.DelayedExecutor$DelayedRunnable.run(DelayedExecutor.java:158) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722)

Here's what my asyncWarmup() method looks like:

public void asyncWarmup(final String testUrl) {
    List<Future<Response>> futures = new ArrayList<Future<Response>>(warmupRequests);
    for (int i = 0; i < warmupRequests; i++) {
        try {
            futures.add(this.client.prepareGet(testUrl).execute());
        } catch (IOException e) {
            System.err.println("Failed to execute get at iteration #" + i);
        }
    }

    for (Future<Response> future : futures) {
        try {
            future.get();
        } catch (InterruptedException e) {
            e.printStackTrace();
        } catch (ExecutionException e) {
            e.printStackTrace();
        }
    }
}

And here's how the client is initialized:

@Override
protected void setup() {
    super.setup();

    GrizzlyAsyncHttpProviderConfig providerConfig = new GrizzlyAsyncHttpProviderConfig();
    AsyncHttpClientConfig config = new AsyncHttpClientConfig.Builder()
            .setAsyncHttpClientProviderConfig(providerConfig)
            .setMaximumConnectionsTotal(-1)
            .setMaximumConnectionsPerHost(4500)
            .setCompressionEnabled(false)
            .setAllowPoolingConnection(true /* keep-alive connection */)
            // .setAllowPoolingConnection(false /* no keep-alive connection */)
            .setConnectionTimeoutInMs(9000).setRequestTimeoutInMs(9000)
            .setIdleConnectionInPoolTimeoutInMs(3000).build();

    this.client = new AsyncHttpClient(new GrizzlyAsyncHttpProvider(config), config);

}

[rlubke]

Investigating now...

[rlubke]

Root cause is the request-in-flight idle timeout is being triggered when a connection is idle within the pool.

Good catch and thanks for logging the issue.

[jbrittain]

Interesting. Just so it's clear: when the connection is currently not being used for a request (so it's sitting in a pool of available connections), that's when the idle timeout is getting called?

Thanks for looking into it. I believe the Netty provider may have the same problem.

[rlubke]

Well, that's one part of it. The wrong timeout is being called, but digging more, it's actually not the root cause. Will be getting back to investigating this morning,

[rlubke]

Okay cleaned the code that would yield some false positives. That said, the issue persisted however, I believe I've finally narrowed the problem down.

The same test case doesn't fail with the Netty provider and this appears to be due to the fact that, by default, netty doesn't do async connections where as Grizzly does. If I enable async connections on the Netty provider, then I see the same result as with the Grizzly provider.

I'll be making some changes shortly to support configurable connection behavior.

[rlubke]

Mind pulling the latest updates from Master and verifying resolution on your end?

[jbrittain]

Sure, I'm trying it now..

[jbrittain]

It doesn't build.. looks like you need to change:

providers/netty/src/test/java/org/asynchttpclient/providers/netty/RetryNonBlockingIssue.java

from: config.setAsyncConnect(true);

to: bc.setAsyncConnectMode(true);

[rlubke]

Fixed, thanks.

[jbrittain]

Beginning warmup... Warmup complete, running 10 batches... [GC 393216K->10281K(1507328K), 0.0156740 secs] [GC 403497K->272007K(1507328K), 0.2038330 secs] [GC 665223K->598921K(1507328K), 0.3592890 secs] [GC 992137K->908443K(1507328K), 0.3317680 secs] [Full GC 908443K->908381K(1507328K), 0.4318490 secs] [Full GC 1301597K->1247980K(1507328K), 0.5528620 secs] [Full GC 1441776K->1441776K(1507328K), 0.4483640 secs] [Full GC 1441776K->1408907K(1507328K), 0.9497030 secs] [Full GC 1441751K->1427304K(1507328K), 0.3811410 secs] [Full GC 1441751K->1423491K(1507328K), 0.3201330 secs] [Full GC 1441751K->1438569K(1507328K), 0.3210360 secs] [Full GC 1441751K->1398285K(1507328K), 0.9203450 secs] [Full GC 1441777K->1441777K(1507328K), 0.3710460 secs] [Full GC 1441777K->1434563K(1507328K), 0.6901430 secs] [Full GC 1441780K->1441780K(1507328K), 0.3390280 secs] [Full GC 1441780K->1439493K(1507328K), 0.6746920 secs] [Full GC 1441779K->1441779K(1507328K), 0.3392970 secs] [Full GC 1441779K->1440184K(1507328K), 0.5791560 secs] [Full GC 1441779K->1441779K(1507328K), 0.3886020 secs] [Full GC 1441779K->1439068K(1507328K), 0.7152100 secs] [Full GC 1441791K->1441791K(1507328K), 0.3444070 secs] [Full GC 1441791K->1438696K(1507328K), 0.6960140 secs] java.util.concurrent.TimeoutException: Timeout exceeded at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider.timeout(GrizzlyAsyncHttpProvider.java:490) at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider$3.onTimeout(GrizzlyAsyncHttpProvider.java:280) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:383) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:362) at org.glassfish.grizzly.utils.DelayedExecutor$DelayedRunnable.run(DelayedExecutor.java:158) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

.. then, in another benchmark run, I saw:

java.io.IOException: Remotely Closed at org.asynchttpclient.providers.grizzly.filters.AsyncHttpClientTransportFilter$1.failed(AsyncHttpClientTransportFilter.java:47) at org.glassfish.grizzly.filterchain.DefaultFilterChain.notifyFailure(DefaultFilterChain.java:606) at org.glassfish.grizzly.filterchain.DefaultFilterChain.throwChain(DefaultFilterChain.java:490) at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:164) at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114) at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:837) at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722) [GC 1037110K->950621K(1507328K), 0.5892260 secs] [Full GC 950621K->179713K(1507328K), 0.5322360 secs] [GC 572917K->567085K(1288960K), 0.2565390 secs] [GC 741917K->739998K(1398144K), 0.1607890 secs] [Full GC 739998K->738869K(1398144K), 0.5721380 secs] [GC 913678K->911679K(1398144K), 0.0933440 secs] [Full GC 911679K->858771K(1398144K), 0.7667500 secs] [GC 1033611K->1031318K(1398144K), 0.1277300 secs] [Full GC 1031318K->1031139K(1398144K), 0.4910620 secs] [Full GC 1205979K->1204065K(1398144K), 0.4756350 secs] [Full GC 1223405K->1223405K(1398144K), 0.3783900 secs] [Full GC 1223421K->1221695K(1398144K), 0.5907000 secs] [Full GC 1223412K->1223412K(1398144K), 0.2848630 secs] [Full GC 1223412K->1223115K(1398144K), 0.5960710 secs] [Full GC 1223407K->1223407K(1398144K), 0.2564760 secs] [Full GC 1223407K->1223360K(1398144K), 0.4837830 secs] java.lang.OutOfMemoryError: Java heap space Dumping heap to ./oome-heap-dump.hprof ... [Full GC 1223393K->1223393K(1398144K), 0.2817790 secs] [Full GC 1223393K->1223360K(1398144K), 0.4946650 secs] Heap dump file created [1294088705 bytes in 7.241 secs] [Full GC 1223393K->1223393K(1398144K), 0.3364600 secs] [Full GC 1223393K->1223376K(1398144K), 0.5257860 secs] java.util.concurrent.TimeoutException: Timeout exceeded at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider.timeout(GrizzlyAsyncHttpProvider.java:490) at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider$3.onTimeout(GrizzlyAsyncHttpProvider.java:280) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:383) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:362) [Full GC 1223392K->1223392K(1398144K), 0.2875270 secs] [Full GC 1223392K->1223378K(1398144K), 0.2828440 secs] [Full GC 1223411K->1223411K(1398144K), 0.2462770 secs] [Full GC 1223411K->1223411K(1398144K), 0.2476880 secs] [Full GC 1223411K->1223411K(1398144K), 0.2477750 secs] [Full GC 1223411K->1223411K(1398144K), 0.2496550 secs] [Full GC 1223411K->1223411K(1398144K), 0.2465580 secs] [Full GC 1223411K->1223411K(1398144K), 0.2488180 secs] [Full GC 1223411K->1223411K(1398144K), 0.2462770 secs] [Full GC 1223411K->1223411K(1398144K), 0.2480820 secs] [Full GC 1223411K->1223411K(1398144K), 0.2484750 secs] [Full GC 1223411K->1223411K(1398144K), 0.2482530 secs] at org.glassfish.grizzly.utils.DelayedExecutor$DelayedRunnable.run(DelayedExecutor.java:158) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722) [Full GC 1223415K->1223415K(1398144K), 0.2491630 secs] [Full GC 1223415K->1223415K(1398144K), 0.2490010 secs] [Full GC 1223415K->1223415K(1398144K), 0.2486760 secs] [Full GC 1223416K->1223176K(1398144K), 0.4876010 secs] Exception in thread "Grizzly-IdleTimeoutFilter-IdleCheck" java.lang.OutOfMemoryError: GC overhead limit exceeded [Full GC 1223396K->1223396K(1398144K), 0.2476110 secs] [Full GC 1223396K->1223396K(1398144K), 0.2465310 secs] [Full GC 1223384K->1223384K(1398144K), 0.2487420 secs] [Full GC 1223384K->1223384K(1398144K), 0.2488750 secs] [Full GC 1223384K->1223384K(1398144K), 0.2474140 secs] [Full GC 1223384K->1223384K(1398144K), 0.2491090 secs] [Full GC 1223384K->1223384K(1398144K), 0.2459780 secs] [Full GC 1223384K->1223384K(1398144K), 0.2497880 secs] [Full GC 1223384K->1223384K(1398144K), 0.2560070 secs] [Full GC 1223384K->1223384K(1398144K), 0.2551230 secs] [Full GC 1223384K->1223384K(1398144K), 0.2465750 secs] [Full GC 1223384K->1223384K(1398144K), 0.2496110 secs] [Full GC 1223384K->1223384K(1398144K), 0.2469400 secs] [Full GC 1223384K->1223384K(1398144K), 0.2479750 secs] [Full GC 1223384K->1223384K(1398144K), 0.2463250 secs] [Full GC 1223384K->1223384K(1398144K), 0.2488260 secs]

Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "AsyncHttpClient-Callback"

...

I can give you a copy of the oome-heap-dump.hprof file if you'd like (if so, how?). I'm going to inspect it as well..

[rlubke]

Interesting. I'd recommend using something like dropbox to share the dump.

[jbrittain]

It's possible there are memory leak(s), having to do with Grizzly BufferChunk, ByteChunk, CharChunk, and/or DataChunk..

Instance Counts for All Classes (excluding platform):

156126 instances of class org.glassfish.grizzly.http.util.BufferChunk 156126 instances of class org.glassfish.grizzly.http.util.ByteChunk 156126 instances of class org.glassfish.grizzly.http.util.CharChunk 151924 instances of class org.glassfish.grizzly.http.util.DataChunk 43978 instances of class org.glassfish.grizzly.http.util.MimeHeaderField 32564 instances of class org.glassfish.grizzly.memory.HeapMemoryManager$TrimmableHeapBuffer 28565 instances of class org.glassfish.grizzly.http.HttpContent 28463 instances of class org.asynchttpclient.providers.grizzly.GrizzlyResponseBodyPart 27993 instances of class [Lorg.glassfish.grizzly.filterchain.DefaultFilterChain$FilterStateElement; 16419 instances of class org.glassfish.grizzly.attributes.IndexedAttributeHolder 16419 instances of class org.glassfish.grizzly.attributes.IndexedAttributeHolder$IndexedAttributeAccessorImpl 11994 instances of class org.glassfish.grizzly.http.util.MimeHeaders 11994 instances of class org.glassfish.grizzly.http.util.MimeHeaders$1 11994 instances of class [Lorg.glassfish.grizzly.http.util.MimeHeaderField; 7998 instances of class org.glassfish.grizzly.asyncqueue.TaskQueue 7998 instances of class org.glassfish.grizzly.utils.Holder$3 7996 instances of class org.asynchttpclient.FluentCaseInsensitiveStringsMap 4011 instances of class org.glassfish.grizzly.utils.ArraySet 4005 instances of class org.glassfish.grizzly.monitoring.DefaultMonitoringConfig 3999 instances of class org.glassfish.grizzly.filterchain.DefaultFilterChain$FiltersState 3999 instances of class org.glassfish.grizzly.impl.SafeFutureImpl 3999 instances of class org.glassfish.grizzly.nio.NIOConnection$1 3999 instances of class org.glassfish.grizzly.nio.NIOConnection$4 3999 instances of class org.glassfish.grizzly.nio.NIOConnection$5 3999 instances of class org.glassfish.grizzly.nio.NIOConnection$ProcessorStatesMap 3999 instances of class org.glassfish.grizzly.nio.NIOConnection$ProcessorStatesMap$ProcessorState 3999 instances of class org.glassfish.grizzly.nio.transport.TCPNIOConnection 3999 instances of class org.glassfish.grizzly.nio.transport.TCPNIOConnection$1 3999 instances of class org.glassfish.grizzly.nio.transport.TCPNIOConnection$2 3999 instances of class org.glassfish.grizzly.utils.IdleTimeoutFilter$IdleRecord 3999 instances of class [[Lorg.glassfish.grizzly.filterchain.DefaultFilterChain$FilterStateElement; 3998 instances of class org.asynchttpclient.RequestBuilderBase$RequestImpl 3998 instances of class org.asynchttpclient.Response$ResponseBuilder 3998 instances of class org.asynchttpclient.listenable.ExecutionList 3998 instances of class org.asynchttpclient.providers.grizzly.GrizzlyResponseFuture 3998 instances of class org.asynchttpclient.providers.grizzly.GrizzlyResponseHeaders 3998 instances of class org.asynchttpclient.providers.grizzly.GrizzlyResponseStatus 3998 instances of class org.asynchttpclient.providers.grizzly.HttpTransactionContext 3998 instances of class org.ebaysf.webclient.benchmark.NingAhcGrizzlyBenchmarkTest$1$1 3998 instances of class org.glassfish.grizzly.http.HttpClientFilter$ClientHttpResponseImpl 3998 instances of class org.glassfish.grizzly.http.HttpCodecFilter$ContentParsingState 3998 instances of class org.glassfish.grizzly.http.HttpCodecFilter$HeaderParsingState 3998 instances of class org.glassfish.grizzly.http.HttpRequestPacketImpl$1 3998 instances of class org.glassfish.grizzly.http.ProcessingState 3998 instances of class org.glassfish.grizzly.http.util.RequestURIRef 3998 instances of class org.glassfish.grizzly.http.util.RequestURIRef$1 3998 instances of class [Lorg.glassfish.grizzly.Buffer; 3281 instances of class org.asynchttpclient.providers.grizzly.ConnectionManager$Pool$DelayedExecutor$TimeoutResolver$IdleRecord 1786 instances of class org.glassfish.grizzly.ThreadCache$ObjectCacheElement 915 instances of class org.glassfish.grizzly.nio.DefaultSelectorHandler$RegisterKeyTask 423 instances of class org.glassfish.grizzly.filterchain.InvokeAction 423 instances of class org.glassfish.grizzly.filterchain.StopAction 422 instances of class org.glassfish.grizzly.filterchain.FilterChainContext 422 instances of class org.glassfish.grizzly.filterchain.FilterChainContext$1 422 instances of class org.glassfish.grizzly.filterchain.FilterChainContext$TransportContext 422 instances of class org.glassfish.grizzly.filterchain.InternalContextImpl 328 instances of class org.glassfish.grizzly.asyncqueue.AsyncWriteQueueRecord 319 instances of class [Lorg.glassfish.grizzly.ThreadCache$ObjectCacheElement; 318 instances of class org.glassfish.grizzly.ThreadCache$ObjectCache 317 instances of class org.glassfish.grizzly.nio.DirectByteBufferRecord 314 instances of class org.glassfish.grizzly.http.HttpContent$Builder 227 instances of class org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable 212 instances of class org.glassfish.grizzly.http.ParsingResult 209 instances of class org.asynchttpclient.providers.grizzly.filters.AsyncHttpClientTransportFilter$1 204 instances of class org.glassfish.grizzly.http.util.CacheableDataChunk 102 instances of class org.glassfish.grizzly.Writer$Reentrant 100 instances of class org.ebaysf.webclient.benchmark.NingAhcGrizzlyBenchmarkTest$1 52 instances of class org.glassfish.grizzly.http.util.Header 41 instances of class org.glassfish.grizzly.http.util.HttpStatus 34 instances of class [Lorg.glassfish.grizzly.IOEvent; 20 instances of class org.glassfish.grizzly.attributes.Attribute 18 instances of class org.glassfish.grizzly.ThreadCache$CachedTypeIndex 9 instances of class org.glassfish.grizzly.http.Method 8 instances of class org.glassfish.grizzly.IOEvent 7 instances of class org.glassfish.grizzly.ProcessorResult 7 instances of class org.glassfish.grizzly.ProcessorResult$Status 7 instances of class org.glassfish.grizzly.filterchain.FilterChainContext$Operation 6 instances of class org.glassfish.grizzly.Transport$State 6 instances of class org.junit.runner.Description 5 instances of class org.glassfish.grizzly.http.util.DataChunk$Type 5 instances of class org.slf4j.impl.SimpleLogger 4 instances of class $Proxy4 4 instances of class org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProviderConfig$Property 4 instances of class org.glassfish.grizzly.asyncqueue.AsyncQueue$AsyncResult 4 instances of class org.glassfish.grizzly.threadpool.ThreadPoolConfig 4 instances of class org.junit.internal.runners.rules.RuleFieldValidator 4 instances of class org.junit.runners.model.FrameworkMethod 3 instances of class org.asynchttpclient.AsyncHandler$STATE 3 instances of class org.glassfish.grizzly.http.Method$PayloadExpectation 3 instances of class org.glassfish.grizzly.http.Protocol 2 instances of class $Proxy5 2 instances of class org.apache.maven.surefire.NonAbstractClassFilter 2 instances of class org.apache.maven.surefire.booter.Classpath 2 instances of class org.apache.maven.surefire.report.ReporterConfiguration 2 instances of class org.apache.maven.surefire.report.RunStatistics$Sources 2 instances of class org.apache.maven.surefire.testset.DirectoryScannerParameters 2 instances of class org.apache.maven.surefire.testset.TestArtifactInfo 2 instances of class org.apache.maven.surefire.testset.TestRequest 2 instances of class org.apache.maven.surefire.util.TeeStream 2 instances of class org.asynchttpclient.providers.grizzly.statushandler.StatusHandler$InvocationStatus 2 instances of class org.glassfish.grizzly.CloseType 2 instances of class org.glassfish.grizzly.Context 2 instances of class org.glassfish.grizzly.StandaloneProcessor 2 instances of class org.glassfish.grizzly.attributes.DefaultAttributeBuilder 2 instances of class org.glassfish.grizzly.filterchain.DefaultFilterChain 2 instances of class org.glassfish.grizzly.filterchain.DefaultFilterChain$FILTER_STATE_TYPE 2 instances of class org.glassfish.grizzly.filterchain.DefaultFilterChain$FilterExecution 2 instances of class org.glassfish.grizzly.filterchain.DefaultFilterChain$FiltersStateFactory 2 instances of class org.glassfish.grizzly.filterchain.FilterChainBuilder$StatelessFilterChainBuilder 2 instances of class org.glassfish.grizzly.filterchain.FilterChainContext$State 2 instances of class org.glassfish.grizzly.memory.Buffers$BuffersAppender 2 instances of class org.glassfish.grizzly.memory.CompositeBuffer$DisposeOrder 2 instances of class org.glassfish.grizzly.memory.HeapMemoryManager$HeapBufferThreadLocalPool 2 instances of class org.glassfish.grizzly.nio.SelectorRunner 2 instances of class org.glassfish.grizzly.nio.transport.TCPNIOConnectorHandler$InstantConnectHandler 2 instances of class org.glassfish.grizzly.ssl.SSLEngineConfigurator 2 instances of class org.glassfish.grizzly.threadpool.DefaultWorkerThread 2 instances of class org.glassfish.grizzly.threadpool.FixedThreadPool$BasicWorker 2 instances of class org.glassfish.grizzly.utils.JdkVersion 2 instances of class org.junit.internal.runners.model.EachTestNotifier 2 instances of class org.junit.rules.TestWatcher$1 2 instances of class org.junit.runners.model.FrameworkField 2 instances of class org.slf4j.impl.SimpleLoggerFactory 1 instance of class $Proxy0 1 instance of class com.sun.crypto.provider.SunJCE 1 instance of class org.apache.maven.surefire.booter.BaseProviderFactory 1 instance of class org.apache.maven.surefire.booter.BooterDeserializer 1 instance of class org.apache.maven.surefire.booter.ClassLoaderConfiguration 1 instance of class org.apache.maven.surefire.booter.ClasspathConfiguration 1 instance of class org.apache.maven.surefire.booter.IsolatedClassLoader 1 instance of class org.apache.maven.surefire.booter.PropertiesWrapper 1 instance of class org.apache.maven.surefire.booter.ProviderConfiguration 1 instance of class org.apache.maven.surefire.booter.ProviderFactory 1 instance of class org.apache.maven.surefire.booter.ProviderFactory$ClassLoaderProxy 1 instance of class org.apache.maven.surefire.booter.StartupConfiguration 1 instance of class org.apache.maven.surefire.booter.SurefireReflector 1 instance of class org.apache.maven.surefire.booter.SurefireStarter 1 instance of class org.apache.maven.surefire.common.junit3.JUnit3TestChecker 1 instance of class org.apache.maven.surefire.common.junit4.JUnit4RunListener 1 instance of class org.apache.maven.surefire.common.junit4.JUnit4TestChecker 1 instance of class org.apache.maven.surefire.junit4.JUnit4Provider 1 instance of class org.apache.maven.surefire.report.BriefFileReporter 1 instance of class org.apache.maven.surefire.report.ForkingConsoleReporter 1 instance of class org.apache.maven.surefire.report.MulticastingReporter 1 instance of class org.apache.maven.surefire.report.ReporterManager 1 instance of class org.apache.maven.surefire.report.ReporterManagerFactory 1 instance of class org.apache.maven.surefire.report.RunStatistics 1 instance of class org.apache.maven.surefire.report.SimpleReportEntry 1 instance of class org.apache.maven.surefire.report.SystemStreamCapturer 1 instance of class org.apache.maven.surefire.report.XMLReporter 1 instance of class org.apache.maven.surefire.shade.org.codehaus.plexus.util.SelectorUtils 1 instance of class org.apache.maven.surefire.util.DefaultDirectoryScanner 1 instance of class org.apache.maven.surefire.util.TestsToRun 1 instance of class org.asynchttpclient.AsyncHttpClient 1 instance of class org.asynchttpclient.AsyncHttpClientConfig 1 instance of class org.asynchttpclient.AsyncHttpClientConfig$Builder 1 instance of class org.asynchttpclient.AsyncHttpClientConfig$Builder$2 1 instance of class org.asynchttpclient.AsyncHttpClientConfig$Builder$3 1 instance of class org.asynchttpclient.DefaultConnectionPoolStrategy 1 instance of class org.asynchttpclient.ntlm.NTLMEngine 1 instance of class org.asynchttpclient.providers.grizzly.ConnectionManager 1 instance of class org.asynchttpclient.providers.grizzly.ConnectionManager$ConnectionMonitor 1 instance of class org.asynchttpclient.providers.grizzly.ConnectionManager$Pool 1 instance of class org.asynchttpclient.providers.grizzly.ConnectionManager$Pool$1 1 instance of class org.asynchttpclient.providers.grizzly.ConnectionManager$Pool$DelayedExecutor 1 instance of class org.asynchttpclient.providers.grizzly.ConnectionManager$Pool$DelayedExecutor$DelayedRunnable 1 instance of class org.asynchttpclient.providers.grizzly.ConnectionManager$Pool$DelayedExecutor$IdleConnectionQueue 1 instance of class org.asynchttpclient.providers.grizzly.ConnectionManager$Pool$DelayedExecutor$TimeoutResolver 1 instance of class org.asynchttpclient.providers.grizzly.ConnectionManager$Pool$DelayedExecutor$TimeoutResolver$1 1 instance of class org.asynchttpclient.providers.grizzly.EventHandler 1 instance of class org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider 1 instance of class org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider$2 1 instance of class org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider$3 1 instance of class org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProviderConfig 1 instance of class org.asynchttpclient.providers.grizzly.ProxyAwareConnectorHandler 1 instance of class org.asynchttpclient.providers.grizzly.bodyhandler.BodyGeneratorBodyHandler 1 instance of class org.asynchttpclient.providers.grizzly.bodyhandler.BodyHandlerFactory 1 instance of class org.asynchttpclient.providers.grizzly.bodyhandler.ByteArrayBodyHandler 1 instance of class org.asynchttpclient.providers.grizzly.bodyhandler.EntityWriterBodyHandler 1 instance of class org.asynchttpclient.providers.grizzly.bodyhandler.FileBodyHandler 1 instance of class org.asynchttpclient.providers.grizzly.bodyhandler.ParamsBodyHandler 1 instance of class org.asynchttpclient.providers.grizzly.bodyhandler.PartsBodyHandler 1 instance of class org.asynchttpclient.providers.grizzly.bodyhandler.StreamDataBodyHandler 1 instance of class org.asynchttpclient.providers.grizzly.bodyhandler.StringBodyHandler 1 instance of class org.asynchttpclient.providers.grizzly.filters.AsyncHttpClientEventFilter 1 instance of class org.asynchttpclient.providers.grizzly.filters.AsyncHttpClientFilter 1 instance of class org.asynchttpclient.providers.grizzly.filters.AsyncHttpClientTransportFilter 1 instance of class org.asynchttpclient.providers.grizzly.filters.SwitchingSSLFilter 1 instance of class org.asynchttpclient.providers.grizzly.filters.SwitchingSSLFilter$ProtocolHandshakeListener 1 instance of class org.asynchttpclient.providers.grizzly.statushandler.AuthorizationHandler 1 instance of class org.asynchttpclient.providers.grizzly.statushandler.ProxyAuthorizationHandler 1 instance of class org.asynchttpclient.providers.grizzly.statushandler.RedirectHandler 1 instance of class org.asynchttpclient.util.AllowAllHostnameVerifier 1 instance of class org.asynchttpclient.util.AsyncHttpProviderUtils$1 1 instance of class org.asynchttpclient.util.SslUtils$LooseTrustManager 1 instance of class org.ebaysf.webclient.benchmark.AbstractBenchmarkTest$1 1 instance of class org.ebaysf.webclient.benchmark.BatchResult 1 instance of class org.ebaysf.webclient.benchmark.NingAhcGrizzlyBenchmarkTest 1 instance of class org.glassfish.grizzly.AbstractTransport$1 1 instance of class org.glassfish.grizzly.Context$NullProcessor 1 instance of class org.glassfish.grizzly.Writer$Reentrant$1 1 instance of class org.glassfish.grizzly.asyncqueue.AsyncQueueIO$ImmutableAsyncQueueIO 1 instance of class org.glassfish.grizzly.filterchain.ExecutorResolver$1 1 instance of class org.glassfish.grizzly.filterchain.ExecutorResolver$2 1 instance of class org.glassfish.grizzly.filterchain.ExecutorResolver$3 1 instance of class org.glassfish.grizzly.filterchain.ExecutorResolver$4 1 instance of class org.glassfish.grizzly.filterchain.ExecutorResolver$5 1 instance of class org.glassfish.grizzly.filterchain.ExecutorResolver$6 1 instance of class org.glassfish.grizzly.filterchain.ExecutorResolver$7 1 instance of class org.glassfish.grizzly.filterchain.ExecutorResolver$8 1 instance of class org.glassfish.grizzly.filterchain.ExecutorResolver$9 1 instance of class org.glassfish.grizzly.filterchain.RerunFilterAction 1 instance of class org.glassfish.grizzly.filterchain.SuspendAction 1 instance of class org.glassfish.grizzly.filterchain.TransportFilter$FlushEvent 1 instance of class org.glassfish.grizzly.http.ChunkedTransferEncoding 1 instance of class org.glassfish.grizzly.http.FixedLengthTransferEncoding 1 instance of class org.glassfish.grizzly.http.HttpCodecFilter$1 1 instance of class org.glassfish.grizzly.http.HttpCodecFilter$FlushAndCloseHandler 1 instance of class org.glassfish.grizzly.http.util.UTF8Decoder 1 instance of class org.glassfish.grizzly.impl.SafeFutureImpl$1 1 instance of class org.glassfish.grizzly.memory.AbstractMemoryManager$1 1 instance of class org.glassfish.grizzly.memory.Buffers$1 1 instance of class org.glassfish.grizzly.memory.HeapMemoryManager 1 instance of class org.glassfish.grizzly.nio.DefaultSelectionKeyHandler 1 instance of class org.glassfish.grizzly.nio.DefaultSelectorHandler 1 instance of class org.glassfish.grizzly.nio.DefaultSelectorHandler$RunnableTask 1 instance of class org.glassfish.grizzly.nio.NIOConnection$2 1 instance of class org.glassfish.grizzly.nio.NIOConnection$3 1 instance of class org.glassfish.grizzly.nio.RoundRobinConnectionDistributor 1 instance of class org.glassfish.grizzly.nio.RoundRobinConnectionDistributor$SharedIterator 1 instance of class org.glassfish.grizzly.nio.tmpselectors.TemporarySelectorIO 1 instance of class org.glassfish.grizzly.nio.tmpselectors.TemporarySelectorPool 1 instance of class org.glassfish.grizzly.nio.transport.TCPNIOAsyncQueueReader 1 instance of class org.glassfish.grizzly.nio.transport.TCPNIOAsyncQueueWriter 1 instance of class org.glassfish.grizzly.nio.transport.TCPNIOBindingHandler 1 instance of class org.glassfish.grizzly.nio.transport.TCPNIOTemporarySelectorReader 1 instance of class org.glassfish.grizzly.nio.transport.TCPNIOTemporarySelectorWriter 1 instance of class org.glassfish.grizzly.nio.transport.TCPNIOTransport 1 instance of class org.glassfish.grizzly.nio.transport.TCPNIOTransport$RegisterChannelCompletionHandler 1 instance of class org.glassfish.grizzly.nio.transport.TCPNIOTransport$TransportConnectorHandler 1 instance of class org.glassfish.grizzly.nio.transport.TCPNIOTransportFilter 1 instance of class org.glassfish.grizzly.ssl.SSLBaseFilter$1 1 instance of class org.glassfish.grizzly.ssl.SSLBaseFilter$2 1 instance of class org.glassfish.grizzly.ssl.SSLBaseFilter$OnWriteCopyCloner 1 instance of class org.glassfish.grizzly.ssl.SSLContextConfigurator 1 instance of class org.glassfish.grizzly.ssl.SSLFilter$ConnectionCloseListener 1 instance of class org.glassfish.grizzly.ssl.SSLUtils$1 1 instance of class org.glassfish.grizzly.ssl.SSLUtils$2 1 instance of class org.glassfish.grizzly.strategies.AbstractIOStrategy$EnableInterestProcessingHandler 1 instance of class org.glassfish.grizzly.strategies.WorkerThreadIOStrategy 1 instance of class org.glassfish.grizzly.threadpool.AbstractThreadPool$1 1 instance of class org.glassfish.grizzly.threadpool.AbstractThreadPool$2 1 instance of class org.glassfish.grizzly.threadpool.AbstractThreadPool$3 1 instance of class org.glassfish.grizzly.threadpool.AbstractThreadPool$5 1 instance of class org.glassfish.grizzly.threadpool.FixedThreadPool 1 instance of class org.glassfish.grizzly.threadpool.GrizzlyExecutorService 1 instance of class org.glassfish.grizzly.utils.Charsets$DecoderResolver 1 instance of class org.glassfish.grizzly.utils.Charsets$EncoderResolver 1 instance of class org.glassfish.grizzly.utils.CompletionHandlerAdapter$1 1 instance of class org.glassfish.grizzly.utils.DelayedExecutor 1 instance of class org.glassfish.grizzly.utils.DelayedExecutor$DelayQueue 1 instance of class org.glassfish.grizzly.utils.DelayedExecutor$DelayedRunnable 1 instance of class org.glassfish.grizzly.utils.Futures$FutureToCompletionHandler 1 instance of class org.glassfish.grizzly.utils.IdleTimeoutFilter 1 instance of class org.glassfish.grizzly.utils.IdleTimeoutFilter$1 1 instance of class org.glassfish.grizzly.utils.IdleTimeoutFilter$2 1 instance of class org.glassfish.grizzly.utils.IdleTimeoutFilter$ContextCompletionListener 1 instance of class org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker 1 instance of class org.glassfish.grizzly.utils.IdleTimeoutFilter$Resolver 1 instance of class org.glassfish.grizzly.utils.StateHolder 1 instance of class org.glassfish.grizzly.websockets.WebSocketClientFilter 1 instance of class org.junit.internal.MethodSorter$1 1 instance of class org.junit.internal.MethodSorter$2 1 instance of class org.junit.internal.runners.statements.InvokeMethod 1 instance of class org.junit.rules.RunRules 1 instance of class org.junit.rules.TestName 1 instance of class org.junit.runner.manipulation.Filter$1 1 instance of class org.junit.runner.manipulation.Sorter 1 instance of class org.junit.runner.manipulation.Sorter$1 1 instance of class org.junit.runner.notification.RunNotifier 1 instance of class org.junit.runners.BlockJUnit4ClassRunner 1 instance of class org.junit.runners.ParentRunner$1 1 instance of class org.junit.runners.ParentRunner$2 1 instance of class org.junit.runners.ParentRunner$3 1 instance of class org.junit.runners.model.FrameworkMethod$1 1 instance of class org.junit.runners.model.TestClass 1 instance of class org.slf4j.helpers.NOPLoggerFactory 1 instance of class org.slf4j.helpers.SubstituteLoggerFactory 1 instance of class org.slf4j.impl.StaticLoggerBinder 1 instance of class [Lorg.asynchttpclient.AsyncHandler$STATE; 1 instance of class [Lorg.asynchttpclient.DefaultConnectionPoolStrategy; 1 instance of class [Lorg.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProviderConfig$Property; 1 instance of class [Lorg.asynchttpclient.providers.grizzly.bodyhandler.BodyHandler; 1 instance of class [Lorg.asynchttpclient.providers.grizzly.statushandler.StatusHandler$InvocationStatus; 1 instance of class [Lorg.glassfish.grizzly.CloseType; 1 instance of class [Lorg.glassfish.grizzly.ProcessorResult$Status; 1 instance of class [Lorg.glassfish.grizzly.Transport$State; 1 instance of class [Lorg.glassfish.grizzly.asyncqueue.AsyncQueue$AsyncResult; 1 instance of class [Lorg.glassfish.grizzly.filterchain.DefaultFilterChain$FILTER_STATE_TYPE; 1 instance of class [Lorg.glassfish.grizzly.filterchain.FilterChainContext$Operation; 1 instance of class [Lorg.glassfish.grizzly.filterchain.FilterChainContext$State; 1 instance of class [Lorg.glassfish.grizzly.http.Method$PayloadExpectation; 1 instance of class [Lorg.glassfish.grizzly.http.Protocol; 1 instance of class [Lorg.glassfish.grizzly.http.TransferEncoding; 1 instance of class [Lorg.glassfish.grizzly.http.util.DataChunk$Type; 1 instance of class [Lorg.glassfish.grizzly.http.util.Header; 1 instance of class [Lorg.glassfish.grizzly.memory.CompositeBuffer$DisposeOrder; 1 instance of class [Lorg.glassfish.grizzly.nio.SelectorRunner; 1 instance of class [Lorg.junit.internal.runners.rules.RuleFieldValidator; 1 instance of class [[Lorg.glassfish.grizzly.IOEvent;

Heap Histogram: All Classes (excluding platform)

Class Instance Count Total Size class [B 52006 1192754407 class org.glassfish.grizzly.http.util.ByteChunk 156126 9679812 class org.glassfish.grizzly.http.util.CharChunk 156126 7181796 class org.glassfish.grizzly.http.util.DataChunk 151924 6076960 class org.glassfish.grizzly.http.util.BufferChunk 156126 5620536 class [Ljava.util.HashMap$Entry; 20287 3221296 class [Ljava.lang.Object; 35807 2129512 class org.glassfish.grizzly.memory.HeapMemoryManager$TrimmableHeapBuffer 32564 2051532 class [Lorg.glassfish.grizzly.filterchain.DefaultFilterChain$FilterStateElement; 27993 1567608 class org.asynchttpclient.providers.grizzly.GrizzlyResponseBodyPart 28463 1138520 class org.glassfish.grizzly.http.HttpRequestPacketImpl$1 3998 1111444 class [C 14176 1086814 class java.lang.String 54276 1085520 class [I 18900 1040132 class java.net.URI 8039 1028992 class [Lorg.glassfish.grizzly.http.util.MimeHeaderField; 11994 959520 class java.util.LinkedHashMap 16075 916275 class org.asynchttpclient.RequestBuilderBase$RequestImpl 3998 819590 class org.glassfish.grizzly.http.HttpClientFilter$ClientHttpResponseImpl 3998 763618 class java.util.LinkedHashMap$Entry 17066 750904 class org.glassfish.grizzly.http.util.MimeHeaderField 43978 747626 class org.glassfish.grizzly.nio.transport.TCPNIOConnection 3999 735816 class org.glassfish.grizzly.attributes.IndexedAttributeHolder 16419 656760 class sun.nio.ch.SocketChannelImpl 3999 579855 class org.asynchttpclient.providers.grizzly.HttpTransactionContext 3998 571714 class java.net.SocksSocketImpl 3999 567858 class org.glassfish.grizzly.http.HttpContent 28565 485605 class java.util.concurrent.ConcurrentLinkedQueue$Node 29670 474720 class org.glassfish.grizzly.asyncqueue.TaskQueue 7998 391902 class java.util.concurrent.atomic.AtomicReference 48460 387680 class java.util.concurrent.ConcurrentLinkedQueue 24001 384016 class java.util.HashMap$Entry 13431 376068 class java.lang.Class 2001 288144 class [[Lorg.glassfish.grizzly.filterchain.DefaultFilterChain$FilterStateElement; 3999 287928 class org.asynchttpclient.providers.grizzly.GrizzlyResponseFuture 3998 287856 class org.glassfish.grizzly.http.util.MimeHeaders 11994 287856 class java.util.concurrent.FutureTask$Sync 4099 278732 class java.util.ArrayList 17179 274864 class org.glassfish.grizzly.http.HttpCodecFilter$HeaderParsingState 3998 255872 class java.util.concurrent.LinkedBlockingQueue 4001 240060 class java.util.concurrent.locks.ReentrantLock$NonfairSync 8167 228676 class java.util.HashMap 4210 202080 class org.glassfish.grizzly.http.util.RequestURIRef 3998 199900 class java.lang.ref.Finalizer 4127 198096 class java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject 8008 192192 class java.net.Inet4Address 7998 191952 class org.glassfish.grizzly.http.util.RequestURIRef$1 3998 191904 class sun.nio.ch.SocketAdaptor 3999 171957 class java.util.concurrent.ConcurrentHashMap$HashEntry 5972 167216 class [S 2806 163782 class [Ljava.nio.channels.SelectionKey; 3999 159960 class java.net.InetSocketAddress 7998 159960 class org.ebaysf.webclient.benchmark.NingAhcGrizzlyBenchmarkTest$1$1 3998 159920 class sun.nio.ch.SelectionKeyImpl 3999 147963 class org.glassfish.grizzly.http.HttpCodecFilter$ContentParsingState 3998 147926 class java.util.concurrent.atomic.AtomicInteger 36117 144468 class org.glassfish.grizzly.utils.Holder$3 7998 135966 class org.asynchttpclient.providers.grizzly.GrizzlyResponseHeaders 3998 135932 class org.glassfish.grizzly.attributes.IndexedAttributeHolder$IndexedAttributeAccessorImpl 16419 131352 class org.asynchttpclient.FluentCaseInsensitiveStringsMap 7996 127936 class [Ljava.util.concurrent.ConcurrentHashMap$HashEntry; 125 101440 class org.glassfish.grizzly.utils.ArraySet 4011 100275 class org.glassfish.grizzly.utils.IdleTimeoutFilter$IdleRecord 3999 99975 class java.util.Collections$SynchronizedRandomAccessList 4000 96000 class [Lorg.glassfish.grizzly.Buffer; 3998 95952 class org.asynchttpclient.Response$ResponseBuilder 3998 95952 class org.asynchttpclient.providers.grizzly.GrizzlyResponseStatus 3998 95952 class org.glassfish.grizzly.http.util.MimeHeaders$1 11994 95952 class org.glassfish.grizzly.nio.NIOConnection$ProcessorStatesMap 3999 79980 class [Lorg.glassfish.grizzly.ThreadCache$ObjectCacheElement; 319 68832 class java.util.concurrent.locks.ReentrantLock 8042 64336 class java.util.concurrent.atomic.AtomicLong 8007 64056 class java.util.concurrent.LinkedBlockingQueue$Node 4001 64016 class org.glassfish.grizzly.nio.NIOConnection$ProcessorStatesMap$ProcessorState 3999 63984 class org.glassfish.grizzly.filterchain.FilterChainContext 422 55704 class java.io.FileDescriptor 4006 48072 class java.lang.Thread 340 47260

[rlubke]

Okay, thanks. I'll be looking into it shortly.

[rlubke]

Committed some changes that should improve memory profile.

[rlubke]

Unfortunately, there's still some thrash with the HttpRequestPacketImpl. The ThreadCache it uses to reduce the overhead creating these instances doesn't work with AHC as the thread that it's created on is different from the one it's returned to the cache on, so when the main thread goes to create a new one, it's always a cache miss. Need to look into a workaround.

[rlubke]

So, thinking about this more, this did find a problem with the underlying objects not being recycled properly, however, I think the test case could be re-written to provide a more realistic memory/GC profile. Maybe I'm wrong, but I don't think any application is going to execute thousands of requests, stash them in a list, and then later loop through the list. Example, if I use your test code and try to execute 200,000 requests, the test will OOM.

However, if I re-write the test like so:

            public static void main(String[] args) {
                    AsyncHttpClientConfig config = new AsyncHttpClientConfig.Builder()
                            .setMaximumConnectionsTotal(-1)
                            .setMaximumConnectionsPerHost(4500)
                            .setCompressionEnabled(false)
                            .setAllowPoolingConnection(true /* keep-alive connection */)
                                    // .setAllowPoolingConnection(false /* no keep-alive connection */)
                            .setConnectionTimeoutInMs(9000).setRequestTimeoutInMs(9000)
                            .setIdleConnectionInPoolTimeoutInMs(3000).build();

                    final AsyncHttpClient client =
                            new AsyncHttpClient(new GrizzlyAsyncHttpProvider(config), config);
                    final BlockingQueue<Future<Response>> requestQueue =
                            new LinkedBlockingQueue<Future<Response>>();

                    final int warmupRequests = 200000;
                    final CountDownLatch latch = new CountDownLatch(2);
                    final Runnable producer = new Runnable() {
                        @Override
                        public void run() {
                            final String testUrl = "http://localhost:8080";

                            for (int i = 0; i < warmupRequests; i++) {
                                try {
                                    requestQueue.add(client.prepareGet(testUrl).execute());
                                } catch (IOException e) {
                                    System.err
                                            .println(
                                                    "Failed to execute get at iteration #" + i);
                                }
                            }
                            latch.countDown();
                        }
                    };
                    final Runnable consumer = new Runnable() {
                        @Override
                        public void run() {
                            int counter = 0;
                            while (counter < warmupRequests) {
                                try {
                                    Future<Response> responseFuture =
                                                            requestQueue.take();
                                    counter++;
                                    responseFuture.get();
                                } catch (Exception e) {
                                    System.err
                                            .println(
                                                    "Failed to execute get at iteration #" + counter);
                                    e.printStackTrace();
                                    client.close();
                                    System.exit(1);
                                }
                            }
                            latch.countDown();
                        }
                    };

                    Thread t1 = new Thread(producer);
                    Thread t2 = new Thread(consumer);
                    t1.start();
                    t2.start();

                    try {
                        latch.await();
                    } catch (InterruptedException e) {
                        e.printStackTrace();
                    }

                    System.out.println("Test complete...");
                    client.close();
                }

I'm able to execute all of the requests without issue, no major GCs, and the heap profile over time looks much better.

[rlubke]

Just checking back if we're good on this or not.

[jbrittain]

I didn't have time to try this today, so I'll try it in the morning. But, it appears like it is another potential way to benchmark it, and if it works, it should probably get documented somewhere. I will let you know as soon as I try it (thanks!).

[jbrittain]

Sorry this took me a while to thoroughly try and get back to you, but here's what it's doing now, with your new test client code..

Using 100 threads, 10 requests per thread, 10 batches, all of the requests consistently complete with zero errors. BenchmarkResult: successful=10000, failed=0, average=0.48ms, requestsPerSecond=2072.03, averageBatchTime=482.61ms, totalBenchmarkTime=4826.17ms, targetRequests=10000 Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 5.555 sec

Using 100 threads, 40 requests per thread, 10 batches, I first get lots of these:

java.util.concurrent.ExecutionException: java.net.ConnectException: Cannot assign requested address at org.asynchttpclient.providers.jdk.JDKFuture.get(JDKFuture.java:143) at org.asynchttpclient.providers.jdk.JDKFuture.get(JDKFuture.java:118) at org.ebaysf.webclient.benchmark.NingAhcNettyBenchmarkTest$2.run(NingAhcNettyBenchmarkTest.java:204) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722) Caused by: java.net.ConnectException: Cannot assign requested address at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:579) at sun.net.NetworkClient.doConnect(NetworkClient.java:175) at sun.net.www.http.HttpClient.openServer(HttpClient.java:388) at sun.net.www.http.HttpClient.openServer(HttpClient.java:483) at sun.net.www.http.HttpClient.(HttpClient.java:213) at sun.net.www.http.HttpClient.New(HttpClient.java:300) at sun.net.www.http.HttpClient.New(HttpClient.java:316) at sun.net.www.protocol.http.HttpURLConnection.getNewHttpClient(HttpURLConnection.java:992) at sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:971) at sun.net.www.protocol.http.HttpURLConnection.connect(HttpURLConnection.java:846) at org.asynchttpclient.providers.jdk.JDKAsyncHttpProvider$AsyncHttpUrlConnection.call(JDKAsyncHttpProvider.java:241) ... 5 more

.. then I get lots of these:

java.net.ConnectException: Connection refused at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:701) at org.glassfish.grizzly.nio.transport.TCPNIOConnectorHandler.onConnectedAsync(TCPNIOConnectorHandler.java:206) at org.glassfish.grizzly.nio.transport.TCPNIOConnectorHandler$1.connected(TCPNIOConnectorHandler.java:154) at org.glassfish.grizzly.nio.transport.TCPNIOConnection.onConnect(TCPNIOConnection.java:258) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:826) at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.executeIoEvent(WorkerThreadIOStrategy.java:101) at org.glassfish.grizzly.strategies.AbstractIOStrategy.executeIoEvent(AbstractIOStrategy.java:89) at org.glassfish.grizzly.nio.SelectorRunner.iterateKeyEvents(SelectorRunner.java:406) at org.glassfish.grizzly.nio.SelectorRunner.iterateKeys(SelectorRunner.java:375) at org.glassfish.grizzly.nio.SelectorRunner.doSelect(SelectorRunner.java:339) at org.glassfish.grizzly.nio.SelectorRunner.run(SelectorRunner.java:271) at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:565) at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:545) at java.lang.Thread.run(Thread.java:722)

.. then a bunch of these:

java.io.IOException: Remotely Closed at org.asynchttpclient.providers.grizzly.filters.AsyncHttpClientTransportFilter$1.failed(AsyncHttpClientTransportFilter.java:47) at org.glassfish.grizzly.filterchain.DefaultFilterChain.notifyFailure(DefaultFilterChain.java:606) at org.glassfish.grizzly.filterchain.DefaultFilterChain.throwChain(DefaultFilterChain.java:490) at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:164) at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114) at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:837) at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

.. then, the benchmark test does not complete, it just hangs. Then when I do a full JVM stack dump, I find lots of these:

"pool-1-thread-3" prio=10 tid=0x00007fdbd0005000 nid=0x5815 waiting on condition [0x00007fdbd4da9000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method)

• parking to wait for <0x00000000f8383560> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1043) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1103) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

"pool-1-thread-2" prio=10 tid=0x00007fdbd0003000 nid=0x5814 waiting on condition [0x00007fdbd4eaa000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method)

• parking to wait for <0x00000000f8383560> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1043) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1103) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

"pool-1-thread-1" prio=10 tid=0x00007fdbd0002000 nid=0x5813 waiting on condition [0x00007fdbd4fab000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method)

• parking to wait for <0x00000000f8383560> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1043) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1103) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

Just for comparison, I tried the same kind of a test client using the Netty provider, and it also has trouble with the same number of threads and requests, hanging all of its threads like this:

"New I/O worker #1" daemon prio=10 tid=0x00007fc514371800 nid=0x7162 runnable [0x00007fc50ad64000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)

• locked <0x00000000f8182360> (a sun.nio.ch.Util$2)
• locked <0x00000000f8182350> (a java.util.Collections$UnmodifiableSet)
• locked <0x00000000f8182148> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.jboss.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.java:64) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.select(AbstractNioSelector.java:409) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:206) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:90) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

[jbrittain]

Also, after your recent changes to async-http-client, I get a lot of these:

java.io.IOException: Remotely Closed at org.asynchttpclient.providers.grizzly.filters.AsyncHttpClientTransportFilter$1.failed(AsyncHttpClientTransportFilter.java:47) at org.glassfish.grizzly.filterchain.DefaultFilterChain.notifyFailure(DefaultFilterChain.java:606) at org.glassfish.grizzly.filterchain.DefaultFilterChain.throwChain(DefaultFilterChain.java:490) at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:164) at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114) at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:837) at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

.. followed by these:

java.io.IOException: closed at org.glassfish.grizzly.nio.transport.TCPNIOConnection.checkConnectFailed(TCPNIOConnection.java:277) at org.glassfish.grizzly.nio.transport.TCPNIOConnection.preClose(TCPNIOConnection.java:96) at org.glassfish.grizzly.nio.NIOConnection.close0(NIOConnection.java:428) at org.glassfish.grizzly.nio.transport.TCPNIOConnection.close0(TCPNIOConnection.java:292) at org.glassfish.grizzly.nio.NIOConnection.close(NIOConnection.java:407) at org.glassfish.grizzly.nio.NIOConnection.closeSilently(NIOConnection.java:413) at org.glassfish.grizzly.nio.transport.TCPNIOConnectorHandler.connectAsync(TCPNIOConnectorHandler.java:185) at org.glassfish.grizzly.nio.transport.TCPNIOConnectorHandler.connect(TCPNIOConnectorHandler.java:87) at org.asynchttpclient.providers.grizzly.ProxyAwareConnectorHandler.connect(ProxyAwareConnectorHandler.java:62) at org.asynchttpclient.providers.grizzly.ConnectionManager.doAsyncConnect(ConnectionManager.java:150) at org.asynchttpclient.providers.grizzly.ConnectionManager.doTrackedConnection(ConnectionManager.java:110) at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider.execute(GrizzlyAsyncHttpProvider.java:168) at org.asynchttpclient.AsyncHttpClient.executeRequest(AsyncHttpClient.java:572) at org.asynchttpclient.AsyncHttpClient$BoundRequestBuilder.execute(AsyncHttpClient.java:260) at org.ebaysf.webclient.benchmark.NingAhcGrizzly2BenchmarkTest$1$1.run(NingAhcGrizzly2BenchmarkTest.java:138) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

.. followed by these:

java.io.IOException: The pool is closed at org.glassfish.grizzly.connectionpool.MultiEndpointPool.checkNotClosed(MultiEndpointPool.java:558) at org.asynchttpclient.providers.grizzly.ConnectionPool.obtainSingleEndpointPool(ConnectionPool.java:57) at org.glassfish.grizzly.connectionpool.MultiEndpointPool.take(MultiEndpointPool.java:389) at org.asynchttpclient.providers.grizzly.ConnectionManager.doTrackedConnection(ConnectionManager.java:100) at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider.execute(GrizzlyAsyncHttpProvider.java:170) at org.asynchttpclient.AsyncHttpClient.executeRequest(AsyncHttpClient.java:572) at org.asynchttpclient.AsyncHttpClient$BoundRequestBuilder.execute(AsyncHttpClient.java:260) at org.ebaysf.webclient.benchmark.NingAhcGrizzly2BenchmarkTest$1$1.run(NingAhcGrizzly2BenchmarkTest.java:138) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)

.. followed by these:

Failed to execute get at iteration #211 java.util.concurrent.ExecutionException: java.io.IOException: closed at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:252) at java.util.concurrent.FutureTask.get(FutureTask.java:111) at org.asynchttpclient.providers.grizzly.GrizzlyResponseFuture.get(GrizzlyResponseFuture.java:165) at org.ebaysf.webclient.benchmark.NingAhcGrizzly2BenchmarkTest$2.run(NingAhcGrizzly2BenchmarkTest.java:171) at java.lang.Thread.run(Thread.java:722) Caused by: java.io.IOException: closed at org.glassfish.grizzly.nio.transport.TCPNIOConnection.checkConnectFailed(TCPNIOConnection.java:277) at org.glassfish.grizzly.nio.transport.TCPNIOConnection.preClose(TCPNIOConnection.java:96) at org.glassfish.grizzly.nio.NIOConnection.close0(NIOConnection.java:428) at org.glassfish.grizzly.nio.transport.TCPNIOConnection.close0(TCPNIOConnection.java:292) at org.glassfish.grizzly.nio.NIOConnection.close(NIOConnection.java:407) at org.glassfish.grizzly.nio.NIOConnection.closeSilently(NIOConnection.java:413) at org.glassfish.grizzly.nio.transport.TCPNIOConnectorHandler.connectAsync(TCPNIOConnectorHandler.java:185) at org.glassfish.grizzly.nio.transport.TCPNIOConnectorHandler.connect(TCPNIOConnectorHandler.java:87) at org.asynchttpclient.providers.grizzly.ProxyAwareConnectorHandler.connect(ProxyAwareConnectorHandler.java:62) at org.asynchttpclient.providers.grizzly.ConnectionManager.doAsyncConnect(ConnectionManager.java:150) at org.asynchttpclient.providers.grizzly.ConnectionManager.doTrackedConnection(ConnectionManager.java:110) at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider.execute(GrizzlyAsyncHttpProvider.java:168) at org.asynchttpclient.AsyncHttpClient.executeRequest(AsyncHttpClient.java:572) at org.asynchttpclient.AsyncHttpClient$BoundRequestBuilder.execute(AsyncHttpClient.java:260) at org.ebaysf.webclient.benchmark.NingAhcGrizzly2BenchmarkTest$1$1.run(NingAhcGrizzly2BenchmarkTest.java:138) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) ... 1 more

.. followed by these:

java.util.concurrent.TimeoutException: Timeout exceeded at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider.timeout(GrizzlyAsyncHttpProvider.java:495) at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider$3.onTimeout(GrizzlyAsyncHttpProvider.java:282) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:383) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:362) at org.glassfish.grizzly.utils.DelayedExecutor$DelayedRunnable.run(DelayedExecutor.java:158) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

.. followed by these:

Failed to execute get at iteration #1878 java.util.concurrent.ExecutionException: java.util.concurrent.TimeoutException: Timeout exceeded at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:252) at java.util.concurrent.FutureTask.get(FutureTask.java:111) at org.asynchttpclient.providers.grizzly.GrizzlyResponseFuture.get(GrizzlyResponseFuture.java:165) at org.ebaysf.webclient.benchmark.NingAhcGrizzly2BenchmarkTest$2.run(NingAhcGrizzly2BenchmarkTest.java:171) at java.lang.Thread.run(Thread.java:722) Caused by: java.util.concurrent.TimeoutException: Timeout exceeded at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider.timeout(GrizzlyAsyncHttpProvider.java:495) at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider$3.onTimeout(GrizzlyAsyncHttpProvider.java:282) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:383) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:362) at org.glassfish.grizzly.utils.DelayedExecutor$DelayedRunnable.run(DelayedExecutor.java:158) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) ... 1 more

.. and the test hangs there. Looking at a full JVM stack dump, I find threads doing this:

"pool-1-thread-2" prio=10 tid=0x00007f11ec037000 nid=0x1a9f waiting on condition [0x00007f11eb1f0000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method)

• parking to wait for <0x00000000fd006600> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1043) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1103) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

"pool-1-thread-1" prio=10 tid=0x00007f11ec035800 nid=0x1a9e waiting on condition [0x00007f11eb2f1000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method)

• parking to wait for <0x00000000fd006600> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1043) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1103) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

"connection-pool-delays-thread-pool(1)" daemon prio=10 tid=0x00007f122c57e000 nid=0x1a87 waiting on condition [0x00007f1220ab0000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method)

• parking to wait for <0x00000000fd8ef430> (a java.util.concurrent.LinkedTransferQueue) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.LinkedTransferQueue.awaitMatch(LinkedTransferQueue.java:735) at java.util.concurrent.LinkedTransferQueue.xfer(LinkedTransferQueue.java:644) at java.util.concurrent.LinkedTransferQueue.take(LinkedTransferQueue.java:1137) at org.glassfish.grizzly.threadpool.FixedThreadPool$BasicWorker.getTask(FixedThreadPool.java:105) at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:557) at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:545) at java.lang.Thread.run(Thread.java:722)

"Grizzly-IdleTimeoutFilter-IdleCheck" daemon prio=10 tid=0x00007f122c417800 nid=0x1a86 waiting on condition [0x00007f1222283000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method)

• parking to wait for <0x00000000fc700ff8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1043) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1103) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722)

[rlubke]

Sorry for the delay. I've been on vacation. Will be returning to this issue this week.

[jbrittain]

Quite alright. I'm still here. Welcome back.

[rlubke]

Well, after looking at the wire traffic, I've come to the conclusion that my hardware can't handle 4500 simultaneous connections.

I've captured the wire traffic for the a timed out connection from two locations. From Grizzly's perspective and Wireshark's.

From Grizzly's perspective, there is one complete request/response cycle on the connection followed by another request, but the entire response isn't received.

Wireshark's view of the traffic confirms Grizzly's. However, Wireshark shows a lot of congestion (retransmissions from the server to the client). The server stops sending data for 9 seconds and then the client closes the connection (per the timeout settings).

I've uploaded a tcpdump which can be loaded in Wireshark and shows the packets for the stream in question to dropbox: https://www.dropbox.com/s/455mmno6jnuymyk/dump.pcap.gz

My testing is being done over a wireless connection to a remote server. I plan to move my testing to a two machine setup on our corporate LAN here shortly.

I'm curious, can you share details of your testing environment?

[jbrittain]

First, I agree you can't successfully perform 4500 simultaneous concurrent HTTP requests, each over their own connection over wireless. :)

Next, over a wired connection that I believe has plenty of bandwidth, with AHC+Grizzly I see the above problems, with AHC+Netty I see similar problems, but with Jetty 8 client or Jetty 9 client I do not see those problems. That same level of concurrency, that same number of requests, to the same server on another machine that I was using with AHC+Grizzy and AHC+Netty, the requests all succeed with a 200 status code, and the average response time is pretty low (~4ms).

I can share any details you're wondering about the test environment. Here's a brief description, but let me know what else you're wondering:

2 OpenStack KVM VMs, each running 64-bit Ubuntu Linux 12.04. Lots of time/attention was spent by our internal cloud team to make sure that the network connectivity between these VMs performs well and has no shortage of bandwidth.

On the server VM:

• Tomcat 7.0.40 configured with the NIO connector (alternate server: Apache HTTPD on the same port)
• ulimit -n 16384 set for the JVM process.
• OpenJDK 1.6.0_24 64-bit (but at least three other JVM brands/versions are also benchmarked)
• 500k JSON file sitting in the filesystem as the response to serve to the client: https://github.com/brianmario/yajl-ruby/blob/master/benchmark/subjects/twitter_stream.json

On the client VM:

• My web client benchmark code, a fork and heavy modification of the java-http-client-benchmark code.
• ulimit -n 16384 set for the JVM process.
• OpenJDK 1.6.0_24 64-bit (but at least three other JVM brands/versions are also benchmarked)

I switched back and forth between Tomcat and Apache HTTPD as the server, benchmarking and comparing times just to be sure that the Tomcat server is responding optimally over HTTP, and it is. Incidentally, I ended up with the same client performance regardless of which of these two servers I had answering.

With the Jetty 8 client and Jetty 9 client doing async requests on OpenJDK 1.6 and 1.7, with 100 threads, 40 requests per thread, 10 batches, Jetty client is consistently getting through all requests successfully (no errors) and an average response time of ~4ms. Then, running that same test with AHC+Grizzly or AHC+Netty, I consistently get at least hundreds of errors and an average response time of anywhere from ~6ms to ~12ms. Nothing changed here other than the client being tested.

[slandelle]

Hi,

Would it be possible for you to share your whole client code (both AHC and Jetty), please?

In https://github.com/AsyncHttpClient/async-http-client/issues/328#issuecomment-20646484, you wrote that you had stacktraces coming from JDKFuture which should not be possible (JDKFuture should only be used by the JDKProvider), is it a mistake?

Cheers,

Stéphane

[jbrittain]

Stéphane:

Okay. I'm working on releasing the benchmark code next.. I'm not sure about the JDKFuture question. But, once you can see the benchmark code you can see for yourself which provider the benchmark code used.

[slandelle]

Cool, thanks. I'll soon be off on vacation, but I'll check this out when I'll be back.

My point about the JDKFuture was that I don't understand how you could have a stacktrace such as

java.util.concurrent.ExecutionException: java.net.ConnectException: Cannot assign requested address
at org.asynchttpclient.providers.jdk.JDKFuture.get(JDKFuture.java:143)
at org.asynchttpclient.providers.jdk.JDKFuture.get(JDKFuture.java:118)

while using the GrizzlyProvider. GrizzlyProvider is not supposed to use JDKFuture.

[rlubke]

Any news on the release of the benchmark code?

[jbrittain]

I'm busy with end of sprint activities over here until Monday evening, but I have done the bulk of the work to prepare the code to be released. Once I'm done preparing it, it has to go through Legal, and that usually takes about a day. So, I'm guessing I can show it to you about mid-week next week.

[jbrittain]

Okay, eBay's version of the client benchmark suite is now available here:

https://github.com/eBay/web-client-benchmark

Let me know if you have any questions about it..

[rlubke]

Okay, my counterpart and I have had time to run this benchmark on some 'beefier' equipment.

The benchmarks, as they currently stand, aren't quite apples-to-apples right now. The main problem we see is that the Jetty/Apache benchmarks use around 64 connections. The Grizzly/Netty benchmarks are configured to use 4500.

We do see the timeout occur with Grizzly+4500/Connections when requesting the 500k.json content. However, if we reduce the number of active connections to be inline with Jetty (i.e., 64), then the benchmark is successful. Unfortunately, this is not the case for the Netty provider.

The Jetty client is around 150 req/s faster in our tests (in the large request test, it's about a 12 request difference). I suspect part of the difference is due to the fact that we have to spend some cycles translating Grizzly objects to the AHC equivalent (headers, cookies, etc). However, watching the benchmark, there is a lot of GCs with several full GCs (same for the Netty provider when it's running). This is something we'll be investigating more in-depth in the near future.

Thoughts? Comments?

[rlubke]

Stéphane: It looks like the Netty provider is ignoring the max connections per host configuration. When we set it to 64, there was 6000+ open connections.

[rlubke]

Another difference I'm observing is that the response isn't being consumed in the Jetty9 largeAsyncResponse test case. The test uses a listener that is only notified when the request/response is complete. If you look at the largeSyncResponse test, it's using ContentResponse which will consume/buffer the response.

In AHC's case, the response will be buffered by default unless a custom listener is used.

[slandelle]

@rlubke Yep, the Netty pool is quite buggy...

@jbrittain I agree with Ryan, not storing the response chunks could make a big difference on GC activity as AsyncCompletionHandler automatically stores them.

[jbrittain]

I refactored my copy of the benchmark tests a bit so that each one created a String containing the response body once the response was complete. I believe that would make all of the benchmark tests consume the response. Now I'm re-running the tests, and the main thing I'm seeing different right now is: after I updated to the latest async-http-client 2.0.0-SNAPSHOT sources, Grizzly 2.3.6-SNAPSHOT, and using Netty 3.6.6.Final, I am now getting enough exceptions when I try to use either Grizzly or Netty that my benchmark tests hang, and don't complete. I did try setting different timeouts, and setting different max number of connections settings and the ones I had earlier appear to work best, but the benchmarks still hang. In the same setup, the Jetty 9 client (now also building a response String) completes all benchmarks, and encounters only a small number of errors in the testSyncLargeResponses test. During the Jetty 9 benchmark runs, I am now seeing quite a bit more GC activity, which is what I'd expect now that it's building and dereferencing response strings. This is on Linux with OpenJDK 1.7.0-03.

Running with the Grizzly provider, here are a couple of the exceptions I'm now seeing:

java.util.concurrent.TimeoutException: Timeout exceeded at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider.timeout(GrizzlyAsyncHttpProvider.java:500) at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider$3.onTimeout(GrizzlyAsyncHttpProvider.java:287) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:383) at org.glassfish.grizzly.utils.IdleTimeoutFilter$DefaultWorker.doWork(IdleTimeoutFilter.java:362) at org.glassfish.grizzly.utils.DelayedExecutor$DelayedRunnable.run(DelayedExecutor.java:158) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722) java.io.IOException: The pool is closed at org.glassfish.grizzly.connectionpool.SingleEndpointPool.close(SingleEndpointPool.java:712) at org.glassfish.grizzly.connectionpool.MultiEndpointPool.close(MultiEndpointPool.java:532) at org.asynchttpclient.providers.grizzly.ConnectionManager.destroy(ConnectionManager.java:311) at org.asynchttpclient.providers.grizzly.GrizzlyAsyncHttpProvider.close(GrizzlyAsyncHttpProvider.java:184) at org.asynchttpclient.AsyncHttpClient.close(AsyncHttpClient.java:396) at org.ebaysf.webclient.benchmark.NingAhcGrizzly2BenchmarkTest$2.run(NingAhcGrizzly2BenchmarkTest.java:185) at java.lang.Thread.run(Thread.java:722)

[slandelle]

Hi Jason,

Could you push your updates on your Github repo, please?

[jbrittain]

@slandelle : Okay, it's now committed here:

https://github.com/eBay/web-client-benchmark/commit/13fe4ca156ccb95fb8056aa2a7925753b70a5db5

[rlubke]

I think it's sufficient to update the Jetty9 test to use the BufferingResponseListener without having to update all of the tests to actually produce a body. The key difference was that in the Jetty9 test cases, the sync version internally buffered the response chunks and the async version did. So there was a massive difference in GC behaviors between the two tests. In the case of AHC, unless you tell AHC otherwise, it will buffer the content internally.

My two cents - remove the creation of the body strings.

[rlubke]

Regarding this:

I am now getting enough exceptions when I try to use either Grizzly or Netty that my benchmark tests hang, and >don't complete. I did try setting different timeouts, and setting different max number of connections settings and >the ones I had earlier appear to work best, but the benchmarks still hang.

We're not able to reproduce this on our end - though we're not running the Grizzly2Benchmark - which I think should be excluded or re-written. It was intended as a quick and dirty example on how to run thousands of requests without storing them in a Collection. However, if an error occurs on the consumer, it will close the client - and the producer isn't checking if the client is open or not, so you see IOException about the pool being closed.

Regarding the Grizzly side of things, we'll need more info. Have you verified that there is only 64 connections being opened? What are some of the other errors you're seeing or are they all timeouts? Have you tried adding headers to the request so you can correlate the request/response via wireshark? Any additional information to help us out?

[jbrittain]

Okay, that's very interesting. If there's that much difference between your setup and my setup, then I'm interested in your average benchmark response times of the testAsyncLargeResponses test of AHC vs. Jetty 9, and I'm also interested in hearing about what OS and hardware that is (two separate machines: one server and one client? Bare metal or VMs? CPUs, RAM, etc).

I will have a look at the things you mentioned also.

[rlubke]

Jason,

There's a small snag on my end and I can't access the machines to gather the sys info. As soon as said snag has been cleared, I'll follow up.

[rlubke]

System info:

Box A: Linux 2.6.18-238.0.0.0.1.el5 x86_64 / Enterprise Linux Enterprise Linux Server release 5.6 (Carthage) MemTotal: 98979292 kB CPU: (model name : Intel(R) Xeon(R) CPU X5670 @ 2.93GHz) (24 of these) NIC: Ethernet controller: Intel Corporation 82576 Gigabit Network Connection (rev 01)

Box B: Linux 2.6.18-238.0.0.0.1.el5 x86_64 / Red Hat Enterprise Linux Server release 5.6 (Tikanga) MemTotal: 98979292 kB CPU: (model name : Intel(R) Xeon(R) CPU X5670 @ 2.93GHz) (24 of these) NIC: Ethernet controller: Intel Corporation 82576 Gigabit Network Connection (rev 01)

[jbrittain]

Ryan:

Okay, and neither of these is a virtual machine? Bare metal running Linux? Also, you're running the benchmark client on one, then a web server on the other (separate) machine? If all of that is the case, then the main difference appears to be that we're running on OpenStack KVM virtualized VMs.

[rlubke]

Okay, and neither of these is a virtual machine? Bare metal running Linux?

Correct.

Also, you're running the benchmark client on one, then a web server on the other (separate) machine?

Also correct.

If all of that is the case, then the main difference appears to be that we're running on OpenStack KVM virtualized VMs.

I'll have to see if there are some VMs we can run the tests on here.

[vmalladi]

Hi, any update on this issue, we are seeing below issue intermittently. Let us know if there is a specific scenario/configuration this occurs and if there is any workaround for the same.

[rlubke]

@vmalladi are you running on a VM?

@jbrittain Out of curiosity, have you contacted the OpenStack folks to see if there's any VM tuning that may be performed to increase I/O performance?

[jbrittain]

@rlubke I have not yet. Our next step here is to run the same benchmark on our vmWare hypervised VMs. I'm within a couple of days of getting the results there. That would show us whether it's one specific type of VM or not. Our OpenStack VMs aren't that well tuned at this point, and our vmWare VMs are. I will update you here as soon as I know the results.

[vmalladi]

@rlubke No not in a VM, its a Ubuntu desktop used for development, things have come done with latest Grizzly 2.3.6-snapshot versions. Now that release version is here we are going to try with 2.3.6 release of grizzly. Any idea when AHC2.0 is getting released?

[rlubke]

@vmalladi Grizzly 2.3.6 was released yesterday (integrated into AHC today). No firm date for AHC 2.0. Will see if we can do an AHC 2.0 beta release.

[jbrittain]

@rlubke Congrats on Grizzly 2.3.6!