Skip to content

trace log

liubao edited this page Sep 2, 2022 · 5 revisions

访问日志

假设有如下调用场景:

Browser  ->  Spring Cloud Gateway -> Consumer -> Provider

当某次Browser调用出现异常的时候,需要快速找到故障所在的位置,并且快速检索出相关的日志,特别是 每个微服务的实例比较多的情况下。

请求调用链追踪日志开启后,会在各个服务日志里面打印trace id,结合日志采集系统,检索trace id, 能够把一次业务请求相关的日志上下文圈定出来。

日志格式和含义

|Trace ID|事件名称|来源|目标|HTTP状态|耗时|URL

来源和目标可能为空。

开启或者关闭请求日志

spring:
  cloud:
    servicecomb:
      context:
        enableTraceInfo: true

可以通过配置项开启请求调用追踪日志,配置项可以在程序运行时通过配置中心下发,从而实现按需开启。

开启后,会输出类似如下的日志:

  • Spring Cloud Gateway
[ctor-http-nio-5] access_logger                            : 6310a42625a8378c|WebFlux receive request|127.0.0.1||0|0|/order/checkToken
[undedElastic-28] access_logger                            : 6310a42625a8378c|Gateway start request|127.0.0.1|order:192.168.125.104|0|0|/checkToken
[ctor-http-nio-3] access_logger                            : 6310a42625a8378c|Gateway finish request|127.0.0.1|order:192.168.125.104|200|155|/checkToken
[ctor-http-nio-5] access_logger                            : 6310a42625a8378c|WebFlux finish request|127.0.0.1||200|157|/order/checkToken
  • WebFlux
[ctor-http-nio-1] access_logger                            : 6310a42a625f7ab5|WebFlux receive request|127.0.0.1||0|0|/sayHello
[ctor-http-nio-1] access_logger                            : 6310a42a625f7ab5|WebFlux finish request|127.0.0.1||200|17|/sayHello
  • WebMVC
[nio-9098-exec-2] access_logger                            : 6310a9379d330fd0|WebMVC receive request|127.0.0.1||0|0|/invocationContextFeign
[nio-9098-exec-2] access_logger                            : 6310a9379d330fd0|Feign start request||price|0|0|/invocationContext
[nio-9098-exec-2] access_logger                            : 6310a9379d330fd0|Feign finish request||price|200|2|/invocationContext
[nio-9098-exec-2] access_logger                            : 6310a9379d330fd0|WebMVC finish request|127.0.0.1||200|3|/invocationContextFeign

[nio-9098-exec-8] access_logger                            : 6310a937b2d30a32|WebMVC receive request|127.0.0.1||0|0|/invocationContext
[nio-9098-exec-8] access_logger                            : 6310a937b2d30a32|RestTemplate start request||192.168.125.104:9090|0|0|/invocationContext
[nio-9098-exec-8] access_logger                            : 6310a937b2d30a32|RestTemplate finish request||192.168.125.104:9090|200|1|/invocationContext
[nio-9098-exec-8] access_logger                            : 6310a937b2d30a32|WebMVC finish request|127.0.0.1||200|2|/invocationContext

业务自定义日志

在一些关键业务环节,比如访问数据库、发生消息通知等,有时候也需要记录访问日志。

  • WebMVC

参考 AccessLogRequestInterceptor 代码。

public class AccessLogRequestInterceptor implements RequestInterceptor {
  private final ContextProperties contextProperties;

  private final AccessLogLogger accessLogLogger;

  public AccessLogRequestInterceptor(ContextProperties contextProperties,
      AccessLogLogger accessLogLogger) {
    this.contextProperties = contextProperties;
    this.accessLogLogger = accessLogLogger;
  }

  @Override
  public void apply(RequestTemplate requestTemplate) {
    if (!contextProperties.isEnableTraceInfo()) {
      return;
    }

    InvocationContext context = InvocationContextHolder.getOrCreateInvocationContext();
    accessLogLogger.log(context, "Feign start request",
        requestTemplate.request().url(),
        null,
        requestTemplate.feignTarget().name(),
        0, 0);
  }

  @Override
  public int getOrder() {
    return Ordered.HIGHEST_PRECEDENCE + 2;
  }
}
  • WebFlux

使用 WebFlux ,需要从 ServerWebExchange 获取上下文,并显示传递:

  @GetMapping(
      path = "/testWebClientRetry",
      produces = MediaType.APPLICATION_JSON_VALUE)
  public Mono<String> testWebClientRetry(ServerWebExchange exchange,
      @RequestParam(name = "invocationID") String invocationID) {
    return webClientBuilder.build().get()
        .uri("http://webflux/testWebClientRetry?invocationID={1}", invocationID)
        .attribute(InvocationContextHolder.ATTRIBUTE_KEY, exchange.getAttribute(InvocationContextHolder.ATTRIBUTE_KEY))
        .retrieve()
        .bodyToMono(String.class);
  }

然后可以参考 AccessLogExchangeFilterFunction 代码获取上下文和记录访问日志。

public class AccessLogExchangeFilterFunction implements ExchangeFilterFunction, Ordered {
  private final ContextProperties contextProperties;

  private final AccessLogLogger accessLogLogger;

  public AccessLogExchangeFilterFunction(
      ContextProperties contextProperties, AccessLogLogger accessLogLogger) {
    this.contextProperties = contextProperties;
    this.accessLogLogger = accessLogLogger;
  }

  @Override
  public int getOrder() {
    // after RetryExchangeFilterFunction
    return 10;
  }

  @Override
  public Mono<ClientResponse> filter(ClientRequest request, ExchangeFunction next) {
    if (!contextProperties.isEnableTraceInfo()) {
      return next.exchange(request);
    }

    InvocationContext context = request.attribute(InvocationContextHolder.ATTRIBUTE_KEY).isPresent() ?
        (InvocationContext) request.attribute(InvocationContextHolder.ATTRIBUTE_KEY).get() : new InvocationContext();
    String url = request.url().getPath();
    String target = request.url().getHost() + ":" + request.url().getPort();
    accessLogLogger.log(context,
        "WebClient start request", url,
        null, target, 0, 0);

    long begin = System.currentTimeMillis();
    return next.exchange(request).doOnSuccess(response -> {
      accessLogLogger.log(context, "WebClient finish request", url,
          null, target, response.rawStatusCode(),
          System.currentTimeMillis() - begin);
    }).doOnError(error -> {
      accessLogLogger.log(context, "WebClient finish request", url,
          null, target, -1,
          System.currentTimeMillis() - begin);
    });
  }
}
Clone this wiki locally