Is there a way to record response times of feign client

Question

@FeignClient(...)
public interface SomeClient {
@RequestMapping(value = "/someUrl", method = POST, consumes = "application/json")
    ResponseEntity<String> createItem(...);

}

Is there a way to find the response times for createItem api call? We are using spring boot, actuator, prometheus.

Answer 1

We have straight forward as well as a customized way for logging the feign clients request and response (including the response time). We have to inject the feign.Logger.Level bean, that's it.

1. THE DEFAULT/ STRAIGHT FORWARD WAY

@Bean
Logger.Level feignLoggerLevel() {
  return Logger.Level.BASIC;
}

there are BASIC,FULL,HEADERS,NONE(default) logging levels are available for more details

The above bean injection will give you the logging of feign request and response in the below format:

REQUEST:

refer

log(configKey, "---> %s %s HTTP/1.1", request.httpMethod().name(), request.url());

ex:2019-09-26 12:50:12.163 [DEBUG] [http-nio-4200-exec-5] [com.sample.FeignClient:72] [FeignClient#getUser] ---> END HTTP (0-byte body)

where the configkey means FeignClientClassName#FeignClientCallingMethodName ex: ApiClient#apiMethod.

RESPONSE

refer

log(configKey, "<--- HTTP/1.1 %s%s (%sms)", status, reason, elapsedTime);

ex:2019-09-26 12:50:12.163 [DEBUG] [http-nio-4200-exec-5] [com.sample.FeignClient:72] [FeignClient#getUser] <--- HTTP/1.1 200 OK (341ms)

the elapsedTime is what the response time taken for the API call.

NOTE: If you prefer the default way of the feign client logging then we have to consider the underlying application logging level as well because the feign.Slf4jLogger class logging with the feign request and response details with the DEBUG level (refer). If the underlying logging level above DEBUG then you may need to specify the explicit logger for the feign logging package/class otherwise it will not work.

2. THE CUSTOMIZED WAY If you prefer logging with your customized format then you can extend the feign.Logger class and customize your logging. For a typical example if I want to log the header details of request and response in a single line as a list(by default Logger.Level.HEADERS prints the header in multiple lines):

package com.test.logging.feign;

import feign.Logger;
import feign.Request;
import feign.Response;
import lombok.extern.slf4j.Slf4j;

import java.io.IOException;

import static feign.Logger.Level.HEADERS;

@Slf4j
public class customFeignLogger extends Logger {

    @Override
    protected void logRequest(String configKey, Level logLevel, Request request) {

        if (logLevel.ordinal() >= HEADERS.ordinal()) {
            super.logRequest(configKey, logLevel, request);
        } else {
            int bodyLength = 0;
            if (request.requestBody().asBytes() != null) {
                bodyLength = request.requestBody().asBytes().length;
            }
            log(configKey, "---> %s %s HTTP/1.1 (%s-byte body) %s", request.httpMethod().name(), request.url(), bodyLength, request.headers());
        }
    }

    @Override
    protected Response logAndRebufferResponse(String configKey, Level logLevel, Response response, long elapsedTime)
            throws IOException {
        if (logLevel.ordinal() >= HEADERS.ordinal()) {
            super.logAndRebufferResponse(configKey, logLevel, response, elapsedTime);
        } else {
            int status = response.status();
            Request request = response.request();
            log(configKey, "<--- %s %s HTTP/1.1 %s (%sms) %s", request.httpMethod().name(), request.url(), status, elapsedTime, response.headers());
        }
        return response;
    }


    @Override
    protected void log(String configKey, String format, Object... args) {
        log.debug(format(configKey, format, args));
    }

    protected String format(String configKey, String format, Object... args) {
        return String.format(methodTag(configKey) + format, args);
    }
}

also we have to inject the customFeignLogger class bean

  @Bean
    public customFeignLogger customFeignLogging() {
        return new customFeignLogger();
    }

If you are building FeignClient by yourself then you can build it with the customized logger:

 Feign.builder().logger(new customFeignLogger()).logLevel(Level.BASIC).target(SomeFeignClient.class,"http://localhost:8080");

Answer 2

Add the following annotation to your project.

package com.example.annotation

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface DebugTracking {
    @Aspect
    @Component
    public static class DebugTrackingAspect {
        @Around("@annotation(com.example.annotation.DebugTracking)")
        public Object trackExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
            StopWatch stopWatch = new StopWatch();
            stopWatch.start(joinPoint.toShortString());

            Exception exceptionThrown = null;

            try {
                // Execute the joint point as usual
                return joinPoint.proceed();

            } catch (Exception ex) {
                exceptionThrown = ex;
                throw ex;

            } finally {
                stopWatch.stop();

                System.out.println(String.format("%s took %dms.", stopWatch.getLastTaskName(), stopWatch.getLastTaskTimeMillis()));

                if (exceptionThrown != null) {
                    System.out.println(String.format("Exception thrown: %s", exceptionThrown.getMessage()));
                    exceptionThrown.printStackTrace();

                }
            }
        }
    }
}

Then annotate the methods you want to track in your @FeignClient with @DebugTracking.

Answer 3

I'm using the following (with Spring and Lombok) :

@Configuration // from Spring
@Slf4j // from Lombok
public class MyFeignConfiguration {
    @Bean // from Spring
    public MyFeignClient myFeignClient() {
        return Feign.builder()
            .logger(new Logger() {
                @Override
                protected void log(String configKey, String format, Object... args) {
                    LOG.info( String.format(methodTag(configKey) + format, args)); // LOG is the Lombok Slf4j object
                }
            })
            .logLevel(Logger.Level.BASIC) // see https://cloud.spring.io/spring-cloud-netflix/multi/multi_spring-cloud-feign.html#_feign_logging
            .target(MyFeignClient.class,"http://localhost:8080");
    }
}

Answer 4

correct way doing this is using custom logger as pointed above. Using @Aspect is wrong. With that you create additional wrapper around the service. Feign already records this metric. Get that metric from feign.