hc-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Changgeng Li (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (HTTPASYNC-88) Race condition caused SocketTimeoutException
Date Fri, 13 Feb 2015 16:48:12 GMT

    [ 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: dev-unsubscribe@hc.apache.org
For additional commands, e-mail: dev-help@hc.apache.org


Mime
View raw message