Skip to content

Grizzly provider TimeoutException making async requests #328

@jbrittain

Description

@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);

}

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions