2

I am stuck with this weird situation where sometimes my HTTP requests don't go out or I don't get a HTTP response to my request sporadically. My application makes several (100s) http requests to other 3rd party service periodically most of which work absolutely fine. I use the CloseableHttpAsyncClient (Version 4.0) with a custom HttpRequestIntercerptor and HttpResponseInterceptor. These were mainly added for debugging purpose with the RequestInterceptor is the last interceptor in the chain and the ResponseInterceptor is the first one. The idea was to log each http request at the last stage before it sends the actual request and to log each http response when it is first received.

I have the following pattern to setup the async client:

    HttpAsyncClientBuilder asyncClientBuilder = HttpAsyncClientBuilder.create();
    asyncClientBuilder.addInterceptorLast(new MyHttpRequestInterceptor());
    asyncClientBuilder.addInterceptorFirst(new MyHttpResponseInterceptor());
    IOReactorConfig reactorConfig = IOReactorConfig.DEFAULT;

    reactorConfig.setConnectTimeout(5 * 60 * 1000); // 5 mins 
    reactorConfig.setSoTimeout(5 * 60 * 1000); // 5 mins
    asyncClientBuilder.setDefaultIOReactorConfig(reactorConfig);
    System.setProperty("http.maxConnections", "100");

    this.asyncHttpClient = asyncClientBuilder.useSystemProperties().build();
    this.asyncHttpClient.start();

To make the request I do:

HttpGet httpGet = new HttpGet("some url");
asyncHttpClient.execute(httpGet, new AsyncHTTPResponseHandler(requestMetadata));

Here is my AsyncHTTPResponseHandler class:

class AsyncHTTPResponseHandler implements FutureCallback<HttpResponse> {

    // local copy of the request for reference while processing the response.
    private RequestMetadata requestMetadata;

    public AsyncHTTPResponseHandler(final RequestMetadata requestMetadata) {
        this.setRequestMetadata(requestMetadata);
        Thread.currentThread().setUncaughtExceptionHandler(new HttpUncaughtExceptionHandler(requestMetadata));
    }

    @Override
    public void cancelled() {
        logger.error("AsyncHTTPResponseHandler#Http request id: {} cancelled",
                requestMetadata.getRequestId()));
    }

    @Override
    public void completed(HttpResponse response) {
        logger.debug("Received HTTP Response for request id: {}",
                requestMetadata.getRequestId());
        //handleHttpResponse(requestMetadata, response);
    }

    @Override
    public void failed(Exception e) {
        logger.error("AsyncHTTPResponseHandler#Error in Http request id: " + requestMetadata.getRequestId(), e);
    }

}

Based on this setup, I see the following cases based on my interceptors logs: 1. My application http request triggers an asyncclient HttpRequest and I get the HttpResponse -- Success. 2. My application http request triggers an asyncclient HttpRequest (the interceptor logs it) and I don't get the HttpResponse for this request --- Don't know why? 3. My application http request does not trigger an asyncclient HttpRequest (the interceptor does not log it) and I don't get the HttpResponse for this request --- Don't know why?

Any tips or suggestions on what I can do fix this or debug this problem further?

Thanks!!

bsam
  • 1,838
  • 3
  • 20
  • 26

1 Answers1

0

So, thought I will share my findings and solution here.

We were experiencing symptoms similar to this bug: https://issues.apache.org/jira/browse/HTTPASYNC-79

If you enable DEBUG logging for "org.apache.http.impl.nio" package, then you can see the exchanges. Note: The logs will be very verbose.

The issue was resolved by upgrading the HttpAsyncClient library from 4.0 to 4.0.2. I have also enabled socket and Connection timeouts. You should see timeout exceptions in the log files with this.

Here is how my HttpAsyncClient instance looks now:

    HttpAsyncClientBuilder asyncClientBuilder = HttpAsyncClientBuilder.create();
    asyncClientBuilder.addInterceptorLast(new MyHttpRequestInterceptor());
    asyncClientBuilder.addInterceptorFirst(new MyHttpResponseInterceptor());

    // reactor config
    IOReactorConfig reactorConfig = IOReactorConfig.custom()
            .setConnectTimeout(TIMEOUT_5_MINS_IN_MILLIS)
            .setSoTimeout(TIMEOUT_5_MINS_IN_MILLIS).build();

    asyncClientBuilder.setDefaultIOReactorConfig(reactorConfig);

    // request config
    RequestConfig requestConfig = RequestConfig.custom()
            .setConnectTimeout(TIMEOUT_5_MINS_IN_MILLIS)
            .setConnectionRequestTimeout(TIMEOUT_5_MINS_IN_MILLIS)
            .setSocketTimeout(TIMEOUT_5_MINS_IN_MILLIS).build();
    asyncClientBuilder.setDefaultRequestConfig(requestConfig);

    // connection config
    ConnectionConfig connectionConfig = ConnectionConfig.custom()
            .setMalformedInputAction(CodingErrorAction.IGNORE)
            .setUnmappableInputAction(CodingErrorAction.IGNORE)
            .build();
    asyncClientBuilder.setDefaultConnectionConfig(connectionConfig);

    System.setProperty("http.maxConnections", "100");
    System.setProperty("http.conn-manager.timeout", "300000"); // 5 mins

    this.asyncHttpClient = asyncClientBuilder.useSystemProperties().build();
bsam
  • 1,838
  • 3
  • 20
  • 26