【Feign扩展】OpenFeign日志打印Http请求参数和响应数据

SpringBoot使用log4j2

在Spring Boot中所有的starter 都是基于spring-boot-starter-logging的，默认使用Logback。使用Log4j2的话，你需要排除 spring-boot-starter-logging 的依赖，并添加 spring-boot-starter-log4j2的依赖。

配置依赖

        <!-- 自定义验证注解 -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-validation</artifactId>
            <exclusions>
                <exclusion>
                    <groupId>org.springframework.boot</groupId>
                    <artifactId>spring-boot-starter-logging</artifactId>
                </exclusion>
            </exclusions>
        </dependency>

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-log4j2</artifactId>
        </dependency>

OpenFeign日志配置

feign的配置类

public class BaseFeignConfig {

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

单个服务应用配置类

@FeignClient(value = "crm-base",configuration = BaseFeignConfig.class )
public interface BaseFeign {

    @GetMapping("/getAppInfo")
    ResponseEx<Object> getAppInfo(@RequestParam(name = "appId") Integer appId);
}

日志级别配置

logging.level.com.charles.feign.BaseFeign=debug

打印效果

23-04-18 15:01:04 DEBUG http-nio-8080-exec-1 crm-emergency traceId- userId- com.linjiu.feign.BaseFeign.log:72:[BaseFeign#getAppInfo] ---> GET http://crm-base/getAppInfo?appId=-1 HTTP/1.1 
2023-04-18 15:01:04 DEBUG http-nio-8080-exec-1 crm-emergency traceId- userId- com.linjiu.feign.BaseFeign.log:72:[BaseFeign#getAppInfo] ---> END HTTP (0-byte body) 
2023-04-18 15:02:37 DEBUG http-nio-8080-exec-3 crm-emergency traceId- userId- com.linjiu.feign.BaseFeign.log:72:[BaseFeign#getAppInfo] ---> END HTTP (0-byte body) 
2023-04-18 15:02:38 DEBUG http-nio-8080-exec-3 crm-emergency traceId- userId- com.linjiu.feign.BaseFeign.log:72:[BaseFeign#getAppInfo] <--- HTTP/1.1 200 (205ms) 
2023-04-18 15:02:38 DEBUG http-nio-8080-exec-3 crm-emergency traceId- userId- com.linjiu.feign.BaseFeign.log:72:[BaseFeign#getAppInfo] connection: keep-alive 
2023-04-18 15:02:38 DEBUG http-nio-8080-exec-3 crm-emergency traceId- userId- com.linjiu.feign.BaseFeign.log:72:[BaseFeign#getAppInfo] content-type: application/json 
2023-04-18 15:02:38 DEBUG http-nio-8080-exec-3 crm-emergency traceId- userId- com.linjiu.feign.BaseFeign.log:72:[BaseFeign#getAppInfo] date: Tue, 18 Apr 2023 07:02:38 GMT 
2023-04-18 15:02:38 DEBUG http-nio-8080-exec-3 crm-emergency traceId- userId- com.linjiu.feign.BaseFeign.log:72:[BaseFeign#getAppInfo] keep-alive: timeout=60 
2023-04-18 15:02:38 DEBUG http-nio-8080-exec-3 crm-emergency traceId- userId- com.linjiu.feign.BaseFeign.log:72:[BaseFeign#getAppInfo] transfer-encoding: chunked 
2023-04-18 15:02:38 DEBUG http-nio-8080-exec-3 crm-emergency traceId- userId- com.linjiu.feign.BaseFeign.log:72:[BaseFeign#getAppInfo]  
2023-04-18 15:02:38 DEBUG http-nio-8080-exec-3 crm-emergency traceId- userId- com.linjiu.feign.BaseFeign.log:72:[BaseFeign#getAppInfo] {"data":[{ ...

源码解析

SynchronousMethodHandler#executeAndDecode，发送请求。如果日志级别不是Logger.Level.NONE，打印日志。

  Object executeAndDecode(RequestTemplate template, Options options) throws Throwable {
    Request request = targetRequest(template);

    if (logLevel != Logger.Level.NONE) {
      logger.logRequest(metadata.configKey(), logLevel, request);
    }

    Response response;
    long start = System.nanoTime();
    try {
      response = client.execute(request, options);
      // ensure the request is set. TODO: remove in Feign 12
      response = response.toBuilder()
          .request(request)
          .requestTemplate(template)
          .build();
    } catch (IOException e) {
      if (logLevel != Logger.Level.NONE) {
        logger.logIOException(metadata.configKey(), logLevel, e, elapsedTime(start));
      }
      throw errorExecuting(request, e);
    }
    long elapsedTime = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start);


    if (decoder != null)
      return decoder.decode(response, metadata.returnType());

    CompletableFuture<Object> resultFuture = new CompletableFuture<>();
    asyncResponseHandler.handleResponse(resultFuture, metadata.configKey(), response,
        metadata.returnType(),
        elapsedTime);

    try {
      if (!resultFuture.isDone())
        throw new IllegalStateException("Response handling not done");

      return resultFuture.join();
    } catch (CompletionException e) {
      Throwable cause = e.getCause();
      if (cause != null)
        throw cause;
      throw e;
    }
  }

Slf4jLogger#logRequest，判断是否允许debug日志输出

    protected void logRequest(String configKey, Level logLevel, Request request) {
        if (this.logger.isDebugEnabled()) {
            super.logRequest(configKey, logLevel, request);
        }

    }

Logger#logRequest，打印具体的请求日志。

  protected void logRequest(String configKey, Level logLevel, Request request) {
    log(configKey, "---> %s %s HTTP/1.1", request.httpMethod().name(), request.url());
    if (logLevel.ordinal() >= Level.HEADERS.ordinal()) {

      for (String field : request.headers().keySet()) {
        for (String value : valuesOrEmpty(request.headers(), field)) {
          log(configKey, "%s: %s", field, value);
        }
      }

      int bodyLength = 0;
      if (request.body() != null) {
        bodyLength = request.length();
        if (logLevel.ordinal() >= Level.FULL.ordinal()) {
          String bodyText =
              request.charset() != null
                  ? new String(request.body(), request.charset())
                  : null;
          log(configKey, ""); // CRLF
          log(configKey, "%s", bodyText != null ? bodyText : "Binary data");
        }
      }
      log(configKey, "---> END HTTP (%s-byte body)", bodyLength);
    }
  }

AsyncResponseHandler#handleResponse，处理响应。打印日志用的是logger.logAndRebufferResponse

  void handleResponse(CompletableFuture<Object> resultFuture,
                      String configKey,
                      Response response,
                      Type returnType,
                      long elapsedTime) {
    // copied fairly liberally from SynchronousMethodHandler
    boolean shouldClose = true;

    try {
      if (logLevel != Level.NONE) {
        response = logger.logAndRebufferResponse(configKey, logLevel, response,
            elapsedTime);
      }
    } catch (final Exception e) {
      resultFuture.completeExceptionally(e);
    }
  }
        

Logger实体类创建，FeignClientFactoryBean#feign创建Feign。

    protected Builder feign(FeignContext context) {
        FeignLoggerFactory loggerFactory = (FeignLoggerFactory)this.get(context, FeignLoggerFactory.class);
        Logger logger = loggerFactory.create(this.type);
        Builder builder = ((Builder)this.get(context, Builder.class)).logger(logger).encoder((Encoder)this.get(context, Encoder.class)).decoder((Decoder)this.get(context, Decoder.class)).contract((Contract)this.get(context, Contract.class));
        this.configureFeign(context, builder);
        return builder;
    }

DefaultFeignLoggerFactory#create，创建日志类。

    public Logger create(Class<?> type) {
        return (Logger)(this.logger != null ? this.logger : new Slf4jLogger(type));
    }

使用slf4j进行创建，类型是com.linjiu.feign.BaseFeign。这也解释了需要配置logging.level.com.charles.feign.BaseFeign=debug才能输出日志。有时间专门来一篇博客，看看slf4j日志的生效逻辑和Springboot日志生效的逻辑。

    public Slf4jLogger(Class<?> clazz) {
        this(LoggerFactory.getLogger(clazz));
    }