[HTTPCLIENT-1805] Blocking thread when executing a request in a FutureCallback - ASF JIRA

Details

Type: Improvement
Status: Resolved
Priority: Major
Resolution: Fixed
Affects Version/s: None
Fix Version/s: 5.0 Beta1
Component/s: HttpClient (async)
Labels:
None
Environment:
Environment Oracle JDK 8u121

Flags:

Important

Description

When executing a request within a FutureCallback (inner request) the invoking thread is blocked. The inner request will not be executed and processing the request terminates after the write event.
If the inner request is executed in another thread, the application works fine (see the thenApplyAsync note in the code).

This issue seems already be an issue for another user who reported this in a StackOverflow question: http://stackoverflow.com/questions/32031846/apaches-httpasyncclient-never-returns-after-execute

See the following log when it blocks:

IM-WEBAPP 2017-01-20 09:27:44,506 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.MainClientExec  - [exchange: 4] start execution
IM-WEBAPP 2017-01-20 09:27:44,507 [I/O dispatcher 1] DEBUG org.apache.http.client.protocol.RequestAddCookies  - CookieSpec selected: default
IM-WEBAPP 2017-01-20 09:27:44,507 [I/O dispatcher 1] DEBUG org.apache.http.client.protocol.RequestAuthCache  - Auth cache not set in the context
IM-WEBAPP 2017-01-20 09:27:44,507 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.InternalHttpAsyncClient  - [exchange: 4] Request connection for {tls}->http://localhost:3128->https://permissions-api.apps.bosch-iot-cloud.com:443
IM-WEBAPP 2017-01-20 09:27:44,507 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager  - Connection request: [route: {tls}->http://localhost:3128->https://permissions-api.apps.bosch-iot-cloud.com:443][total kept alive: 1; route allocated: 1 of 20; total allocated: 1 of 200]
IM-WEBAPP 2017-01-20 09:27:44,507 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl  - http-outgoing-0 127.0.0.1:57860<->127.0.0.1:3128[ACTIVE][r:r][ACTIVE][r][NOT_HANDSHAKING][0][0][0][0]: Set timeout 0
IM-WEBAPP 2017-01-20 09:27:44,507 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager  - Connection leased: [id: http-outgoing-0][route: {tls}->http://localhost:3128->https://permissions-api.apps.bosch-iot-cloud.com:443][total kept alive: 0; route allocated: 1 of 20; total allocated: 1 of 200]
IM-WEBAPP 2017-01-20 09:27:44,507 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.client.InternalHttpAsyncClient  - [exchange: 4] Connection allocated: CPoolProxy{http-outgoing-0 [ACTIVE]}
IM-WEBAPP 2017-01-20 09:27:44,507 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl  - http-outgoing-0 127.0.0.1:57860<->127.0.0.1:3128[ACTIVE][r:r][ACTIVE][r][NOT_HANDSHAKING][0][0][0][0]: Set attribute http.nio.exchange-handler
IM-WEBAPP 2017-01-20 09:27:44,508 [I/O dispatcher 1] DEBUG org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl  - http-outgoing-0 127.0.0.1:57860<->127.0.0.1:3128[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][0][0][0][0]: Event set [w]

The stack of the blocking thread:

Thread [I/O dispatcher 1] (Suspended)	
	sun.misc.Unsafe.park(boolean, long) line: not available [native method]	
	java.util.concurrent.locks.LockSupport.park(java.lang.Object) line: 175	
	java.util.concurrent.CompletableFuture$Signaller.block() line: 1693	
	java.util.concurrent.ForkJoinPool.managedBlock(java.util.concurrent.ForkJoinPool$ManagedBlocker) line: 3323	
	java.util.concurrent.CompletableFuture<T>.waitingGet(boolean) line: 1729	
	java.util.concurrent.CompletableFuture<T>.get() line: 1895	
	BlockingThreadMainApplication.lambda$0(org.apache.http.impl.nio.client.CloseableHttpAsyncClient, java.io.InputStream) line: 60	
	BlockingThreadMainApplication$$Lambda$4.1112414583.apply(java.lang.Object) line: not available	
	java.util.concurrent.CompletableFuture<T>.uniApply(java.util.concurrent.CompletableFuture<S>, java.util.function.Function<? super S,? extends T>, java.util.concurrent.CompletableFuture.UniApply<S,T>) line: 602	
	java.util.concurrent.CompletableFuture$UniApply<T,V>.tryFire(int) line: 577	
	java.util.concurrent.CompletableFuture<T>.postComplete() line: 474	
	java.util.concurrent.CompletableFuture<T>.complete(T) line: 1962	
	BlockingThreadMainApplication$1.completed(org.apache.http.HttpResponse) line: 83	
	BlockingThreadMainApplication$1.completed(java.lang.Object) line: 1	
	org.apache.http.concurrent.BasicFuture<T>.completed(T) line: 119	
	org.apache.http.impl.nio.client.DefaultClientExchangeHandlerImpl<T>.responseCompleted() line: 177	
	org.apache.http.nio.protocol.HttpAsyncRequestExecutor.processResponse(org.apache.http.nio.NHttpClientConnection, org.apache.http.nio.protocol.HttpAsyncRequestExecutor$State, org.apache.http.nio.protocol.HttpAsyncClientExchangeHandler) line: 436	
	org.apache.http.nio.protocol.HttpAsyncRequestExecutor.inputReady(org.apache.http.nio.NHttpClientConnection, org.apache.http.nio.ContentDecoder) line: 326	
	org.apache.http.impl.nio.client.InternalRequestExecutor.inputReady(org.apache.http.nio.NHttpClientConnection, org.apache.http.nio.ContentDecoder) line: 83	
	org.apache.http.impl.nio.conn.ManagedNHttpClientConnectionImpl(org.apache.http.impl.nio.DefaultNHttpClientConnection).consumeInput(org.apache.http.nio.NHttpClientEventHandler) line: 265	
	org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(org.apache.http.impl.nio.DefaultNHttpClientConnection) line: 81	
	org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(java.lang.Object) line: 39	
	org.apache.http.impl.nio.client.InternalIODispatch(org.apache.http.impl.nio.reactor.AbstractIODispatch<T>).inputReady(org.apache.http.nio.reactor.IOSession) line: 121	
	org.apache.http.impl.nio.reactor.BaseIOReactor.readable(java.nio.channels.SelectionKey) line: 162	
	org.apache.http.impl.nio.reactor.BaseIOReactor(org.apache.http.impl.nio.reactor.AbstractIOReactor).processEvent(java.nio.channels.SelectionKey) line: 337	
	org.apache.http.impl.nio.reactor.BaseIOReactor(org.apache.http.impl.nio.reactor.AbstractIOReactor).processEvents(java.util.Set<java.nio.channels.SelectionKey>) line: 315	
	org.apache.http.impl.nio.reactor.BaseIOReactor(org.apache.http.impl.nio.reactor.AbstractIOReactor).execute() line: 276	
	org.apache.http.impl.nio.reactor.BaseIOReactor.execute(org.apache.http.nio.reactor.IOEventDispatch) line: 104	
	org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run() line: 588	
	java.lang.Thread.run() line: 745

Be aware that this issue could sometimes be a Heisenbug and the application terminates successfully in debugging. When running normally it fails on my machine with 100%.

You can simply reproduce this issue with the following code or use the attached maven project:

import java.io.IOException;
import java.io.InputStream;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.ExecutionException;

import org.apache.http.HttpHost;
import org.apache.http.HttpResponse;
import org.apache.http.client.config.RequestConfig;
import org.apache.http.client.methods.HttpGet;
import org.apache.http.concurrent.FutureCallback;
import org.apache.http.impl.nio.client.CloseableHttpAsyncClient;
import org.apache.http.impl.nio.client.HttpAsyncClientBuilder;
import org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager;
import org.apache.http.impl.nio.reactor.DefaultConnectingIOReactor;
import org.apache.http.nio.reactor.IOReactorException;

public class BlockingThreadMainApplication
{
   private static final int POOL_PER_ROUTE = 20;
   private static final int POOL_MAX = 200;
   private static final int CONNECT_TIMEOUT = 10000;
   private static final int SOCKET_TIMEOUT = 60000;
   private static final String PUBLIC_KEYS_URL = "https://permissions-api.apps.bosch-iot-cloud.com/2/rest/publickeys";

   private static HttpHost proxy = null;

   private int requestCounter = 0;

   public static void main(final String[] args) throws InterruptedException, ExecutionException, IOException
   {
      // include this lines if you are behind a proxy server
      // proxy = new HttpHost("localhost", 3128);

      final BlockingThreadMainApplication application = new BlockingThreadMainApplication();

      try (CloseableHttpAsyncClient asyncClient = application.createAsynClient())
      {

         // these request work like they should
         application.createRequest(asyncClient).get();
         application.createRequest(asyncClient).get();

         System.out.println("Execute request with inner request");
         final Object object = application.createRequestWithInnerRequest(asyncClient).get();
         // will never be invoked
         System.out.println("Yeaha, application completed. Resolved last response " + object.getClass().getName());
      }
   }

   private CompletableFuture<?> createRequestWithInnerRequest(final CloseableHttpAsyncClient asyncClient)
      throws InterruptedException, ExecutionException
   {
      // it works like a charm when using thenApplyAsync so it is executed in another thread
      return createRequest(asyncClient).thenApply(i ->
      {
         // execute another request and get its result
         try
         {
            System.out.println("executing request in thenApply");
            createRequest(asyncClient).get(); // never comes back
            System.out.println("executed request in thenApply");
         }
         catch (InterruptedException | ExecutionException e)
         {
            throw new IllegalStateException(e);
         }
         return i;
      });
   }

   public CompletableFuture<InputStream> createRequest(final CloseableHttpAsyncClient asyncClient)
   {
      final int requestId = ++requestCounter;
      final CompletableFuture<InputStream> toBeCompleted = new CompletableFuture<>();
      final FutureCallback<HttpResponse> callback = new FutureCallback<HttpResponse>()
      {
         @Override
         public void completed(final HttpResponse response)
         {
            System.out.println("completed " + requestId);
            try
            {
               toBeCompleted.complete(response.getEntity().getContent());
            }
            catch (UnsupportedOperationException | IOException e)
            {
               System.out.println("failed to get InputStream from response " + requestId);
               toBeCompleted.completeExceptionally(e);
            }
         }

         @Override
         public void cancelled()
         {
            System.out.println("cancelled " + requestId);
            toBeCompleted.cancel(true);
         }

         @Override
         public void failed(final Exception e)
         {
            System.out.println("failed " + requestId);
            toBeCompleted.completeExceptionally(e);
         }
      };

      asyncClient.execute(getGetRequest(), callback);
      return toBeCompleted;
   }

   private CloseableHttpAsyncClient createAsynClient()
   {
      // Create common default configuration
      final RequestConfig clientConfig = RequestConfig.custom().setConnectTimeout(CONNECT_TIMEOUT)
         .setSocketTimeout(SOCKET_TIMEOUT).setConnectionRequestTimeout(SOCKET_TIMEOUT).setProxy(proxy).build();

      DefaultConnectingIOReactor ioreactor;
      PoolingNHttpClientConnectionManager asyncConnectionManager;
      try
      {
         ioreactor = new DefaultConnectingIOReactor();
         asyncConnectionManager = new PoolingNHttpClientConnectionManager(ioreactor);
         asyncConnectionManager.setMaxTotal(POOL_MAX);
         asyncConnectionManager.setDefaultMaxPerRoute(POOL_PER_ROUTE);
      }
      catch (final IOReactorException e)
      {
         throw new RuntimeException(e);
      }

      final CloseableHttpAsyncClient client = HttpAsyncClientBuilder.create().setDefaultRequestConfig(clientConfig)
         .setConnectionManager(asyncConnectionManager).build();
      client.start();
      return client;
   }

   private HttpGet getGetRequest()
   {
      return new HttpGet(PUBLIC_KEYS_URL);
   }
}

I don't think it is related to ~~HTTPASYNC-35~~ or ~~HTTPASYNC-34~~ who sounds similiar.

Just one last note: Why is 4.1.2 released but not in this Jira project?

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending

blocking-thread-example-application.zip
20/Jan/17 13:47
7 kB
Michael Ernst

Blocking thread when executing a request in a FutureCallback

Details

Description

Attachments

Attachments

Activity

People

Dates