[
https://issues.apache.org/jira/browse/HTTPASYNC-88?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14320375#comment-14320375
]
Changgeng Li commented on HTTPASYNC-88:
---------------------------------------
This doesn't explain why everything works fine if I change the sleep interval
to 600ms.
The issue originally happens in our production environment where a http request
normally takes less than 300ms and the socketTimeout value is 2 seconds.
I still don't have a whole picture of the design and the root cause. To me,
after a response is got, the session should be put into pool, and when the next
request are trying to use the same session, the start of inactivity time should
be counted from the time the session is acquired from the pool. As how long the
session should be keep alive in the pool should be controlled by the keepAlive
parameter of connection pool.
This also may be an issue in httpcore-nio rather than http-asyncclient. Per my
tracing, org.apache.http.impl.nio.client.LoggingAsyncRequestExecutor.timeout is
always called if the sleepInterval in above test case is larger than 200ms, the
different behavior is caused by this if branch:
{code}
0 final HttpAsyncClientExchangeHandler handler =
getHandler(conn);¬
1 if (handler != null) {¬
2 handler.failed(new SocketTimeoutException());¬
3 handler.close();¬
4 }¬
{code}
If the sleep interval is much larger than 200ms, handler will always be null.
That's why I think there's some race condition.
> Race condition caused SocketTimeoutException
> --------------------------------------------
>
> Key: HTTPASYNC-88
> URL: https://issues.apache.org/jira/browse/HTTPASYNC-88
> Project: HttpComponents HttpAsyncClient
> Issue Type: Bug
> Affects Versions: 4.0.2
> Environment: Linux
> Jdk1.6.0_45
> Reporter: Changgeng Li
>
> This issue can be reproduced by following test case.
> {code}
> import org.apache.http.client.methods.HttpGet;
> import org.apache.http.client.protocol.HttpClientContext;
> import org.apache.http.impl.nio.client.CloseableHttpAsyncClient;
> import org.apache.http.impl.nio.client.HttpAsyncClients;
> import org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager;
> import org.apache.http.impl.nio.reactor.DefaultConnectingIOReactor;
> import org.apache.http.impl.nio.reactor.IOReactorConfig;
> import org.apache.http.nio.reactor.IOReactorException;
> import org.junit.Test;
> import java.util.concurrent.ExecutionException;
> import java.util.concurrent.Future;
> import java.util.concurrent.TimeUnit;
> import java.util.concurrent.TimeoutException;
> public class AsyncClientTest {
> @Test
> public void testTimeout()
> throws InterruptedException, ExecutionException,
> TimeoutException, IOReactorException {
> PoolingNHttpClientConnectionManager manager = new
> PoolingNHttpClientConnectionManager(
> new DefaultConnectingIOReactor(buildConfig()));
> manager.setDefaultMaxPerRoute(10);
> manager.setMaxTotal(10);
> CloseableHttpAsyncClient httpclient =
> HttpAsyncClients.custom().setConnectionManager(manager).build();
> HttpGet httpget = new HttpGet("http://localhost:8080/";);
> HttpClientContext localContext = HttpClientContext.create();
> httpclient.start();
> // Pass local context as a parameter
> for (int j = 0; j < 1000; j++) {
> for (int i = 0; i < 5; i++) {
> Future<HttpResponse> future = httpclient.execute(httpget,
> localContext, null);
> HttpResponse response = future.get(5000L,
> TimeUnit.MILLISECONDS);
> System.out.println("Response: " + response.getStatusLine());
> Thread.sleep(180 + i * 10);
> }
> }
> }
> private IOReactorConfig buildConfig() {
> final IOReactorConfig.Builder ioReactorConfigBuilder =
> IOReactorConfig.custom();
> ioReactorConfigBuilder.setConnectTimeout(100);
> ioReactorConfigBuilder.setInterestOpQueued(false);
> ioReactorConfigBuilder.setIoThreadCount(3);
> ioReactorConfigBuilder.setSelectInterval(100);
> ioReactorConfigBuilder.setShutdownGracePeriod(500L);
> ioReactorConfigBuilder.setSoKeepAlive(true);
> ioReactorConfigBuilder.setSoLinger(-1);
> ioReactorConfigBuilder.setSoReuseAddress(false);
> ioReactorConfigBuilder.setSoTimeout(200);
> ioReactorConfigBuilder.setTcpNoDelay(false);
> return ioReactorConfigBuilder.build();
> }
> }
> {code}
> It needs a standalone webserver, for me I just start my tomcat.
> Changing the sleep time to
> {code}
> Thread.sleep(181 + i * 10);
> {code}
> would make the reproduce chance much lower.
> The exception I normally got is:
> {code}
> java.util.concurrent.ExecutionException: java.net.SocketTimeoutException
> at org.apache.http.concurrent.BasicFuture.getResult(BasicFuture.java:68)
> at org.apache.http.concurrent.BasicFuture.get(BasicFuture.java:94)
> at org.apache.http.AsyncClientTest.testTimeout(AsyncClientTest.java:36)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
> at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
> at
> com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:74)
> at
> com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:211)
> at
> com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:67)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> at com.intellij.rt.execution.application.AppMain.main(AppMain.java:134)
> Caused by: java.net.SocketTimeoutException
> at
> org.apache.http.nio.protocol.HttpAsyncRequestExecutor.timeout(HttpAsyncRequestExecutor.java:286)
> at
> org.apache.http.impl.nio.client.LoggingAsyncRequestExecutor.timeout(LoggingAsyncRequestExecutor.java:121)
> at
> org.apache.http.impl.nio.client.InternalIODispatch.onTimeout(InternalIODispatch.java:85)
> at
> org.apache.http.impl.nio.client.InternalIODispatch.onTimeout(InternalIODispatch.java:37)
> at
> org.apache.http.impl.nio.reactor.AbstractIODispatch.timeout(AbstractIODispatch.java:172)
> at
> org.apache.http.impl.nio.reactor.BaseIOReactor.sessionTimedOut(BaseIOReactor.java:255)
> at
> org.apache.http.impl.nio.reactor.AbstractIOReactor.timeoutCheck(AbstractIOReactor.java:493)
> at
> org.apache.http.impl.nio.reactor.BaseIOReactor.validate(BaseIOReactor.java:205)
> at
> org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:281)
> at
> org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:105)
> at
> org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:584)
> at java.lang.Thread.run(Thread.java:662)
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
