CODEWITHSUNDEEP
spring-integration
Tom
Tom

Reputation: 101

Request response latency time for int-http:outbound-gateway

I would like to time an API request I have setup in Spring Integration using an . The response time should be added as a message header so it can be audited downstream and recorded along with other data.

Both HTTP success and error responses should be timed, e.g. I want to know how long it took for a server to issue a 500 response. I'm also already using the Retry and CircuitBreaker advice (as I want that functionality).

I've written a custom advice (from reading the docs) and added to my :

public class RequestResponseTimeInterceptor extends AbstractRequestHandlerAdvice {

private static final Logger LOG = Logger.getLogger(RequestResponseTimeInterceptor.class);


protected Object doInvoke(ExecutionCallback callback, Object target, Message<?> message) throws Exception {
    long before = System.currentTimeMillis();

    try {
        Object result = callback.execute();

        long after = System.currentTimeMillis();
        message = MessageBuilder.fromMessage(message).setHeader("requestResponseTime", after - before).build();

        return result;
    }
    catch (MessageHandlingException e) {
        long after = System.currentTimeMillis();
        Message modifiedFailedMessage = MessageBuilder.fromMessage(e.getFailedMessage()).setHeader("requestResponseTime", after - before).build();

        throw new MessageHandlingException(modifiedFailedMessage, e.getMessage(), e.getCause());
    }
}


<bean id="calculationRetry" class="org.springframework.integration.handler.advice.RequestHandlerRetryAdvice"/>
<bean id="calculationCircuitBreaker" class="org.springframework.integration.handler.advice.RequestHandlerCircuitBreakerAdvice"/>
<bean id="timer" class="com.integration.audit.RequestResponseTimeInterceptor"/>

<int-http:request-handler-advice-chain>
        <ref bean="timer"/>
        <ref bean="calculationRetry"/>
        <ref bean="calculationCircuitBreaker"/>
</int-http:request-handler-advice-chain>

It works by timing between the callback execution. I had a problem that failed HTTP responses (e.g. HTTP 500) are wrapped in a MessageHandlingException (in Spring Integration, by design), which stops the rest of the advice from finishing and timing the response.

I have solved this in the code sample by catching the exception, adding the response time as a message header, re-creating the exception and throwing it (so it gets picked up by my error channel). This seems to work OK - but feel like it's not the best solution. It also times the full duration of any retries (from my Retry advice) rather than the last retry.

Is there a better way to time HTTP request/response that will work nicely with existing Retry advice, and with failed HTTP response codes?

Appreciate your feedback!

Edit: Based on Artem's information.

The order of the advice in request-handler-advice-chain is important (it is an ordered chain after all). So putting the 'timer' at the end of the chain means it only times request/responses, rather than multiple retries or circuit breakers.

I updated the advice based on Artem's comments so it is now actually returning a Message. I can then read the new "requestResponseTime" header downstream in the pipeline as needed.

Here's the new code:

public class RequestResponseTimeInterceptor extends AbstractRequestHandlerAdvice {

private static final Logger LOG = Logger.getLogger(RequestResponseTimeInterceptor.class);

protected Object doInvoke(ExecutionCallback callback, Object target, Message<?> requestMessage) throws Exception {
    long before = System.currentTimeMillis();

    try {
        Object result = callback.execute();

        long after = System.currentTimeMillis();

        Message<?> responseMessage = (Message<?>) result;

        return MessageBuilder.withPayload(responseMessage.getPayload())
                            .setHeader(MessageHeaderConstants.REQUEST_RESPONSE_TIME, after - before).build();
    }
    catch (MessageHandlingException e) {
        //Catch HTTP errors (e.g. 500s) so we can also time the response
        long after = System.currentTimeMillis();
        Message modifiedFailedMessage = MessageBuilder.fromMessage(e.getFailedMessage()).setHeader(MessageHeaderConstants.REQUEST_RESPONSE_TIME, after - before).build();

        //rethrow new exception for error handling
        throw new MessageHandlingException(modifiedFailedMessage, e.getMessage(), e.getCause());
    }
}



    <int-http:request-handler-advice-chain>
        <ref bean="calculationCircuitBreaker"/>
        <ref bean="calculationRetry"/>
        <ref bean="timer"/>
    </int-http:request-handler-advice-chain>

Upvotes: 1

Views: 460

Answers (1)

Artem Bilan
Artem Bilan

Reputation: 121262

First of all think if your timer really should include all the retries. And that doesn’t seem for me valuable to count timeout for opened circuit breaker. I mean that it would be much realist to reorder your advices different way: circuit first, retry and only then timer. This way you will count only real http requests and won’t go to that part with opened circuit.

Regarding your exception concern. That’s definitely is OK to rebuild message with required headers. For this purpose we have introduced a ErrorMessageStrategy: https://docs.spring.io/spring-integration/docs/latest-ga/reference/html/whats-new.html#_errormessagepublisher_and_errormessagestrategy

On the other hand, please, pay attention to the Spring Cloud Sleuth project: https://cloud.spring.io/spring-cloud-sleuth/

Upvotes: 1

Related Questions