trace log

访问日志

假设有如下调用场景：

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

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

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

日志格式和含义

|Trace ID|HTTP状态|耗时|URL|

开启或者关闭请求日志

spring:
  cloud:
    servicecomb:
      context:
        enableTraceInfo: true

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

开启后，会输出类似如下的日志：

access_logger: |63c63d3af6604f5c|200|1|POST /benchmark/template/delay/z0|

Access log在一个阶段处理完成记录。比如上面的日志表示收到请求到处理完成的时间为1ms。

日志里面包含上下文信息

spring:
  cloud:
    servicecomb:
      context:
        traceContexts: x-microservice-name,x-instance-id

可以在访问日志里面包含请求上下文信息，上述配置会将请求方的微服务名称和实例ID记录在日志中。

access_logger: |order|6a2f4e7cff6c4834a3410c2ae2d35d13|63bbe527d181f076|200|1|/hello|

日志的前两项信息为请求方的微服务名称和实例ID。

业务自定义日志

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

• WebMVC

public class WebMvcAccessLogExample {
  private final ContextProperties contextProperties;

  private final AccessLogLogger accessLogLogger;

  public WebMvcAccessLogExample(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, 
        requestTemplate.request().url(),
        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);
  }

然后获取上下文和记录访问日志。

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

  private final AccessLogLogger accessLogLogger;

  public WebFluxAccessLogExample(
      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,
        url,
        0, 0);

    long begin = System.currentTimeMillis();
    return next.exchange(request).doOnSuccess(response -> {
      accessLogLogger.log(context, url,
          response.rawStatusCode(),
          System.currentTimeMillis() - begin);
    }).doOnError(error -> {
      accessLogLogger.log(context, url,
          -1,
          System.currentTimeMillis() - begin);
    });
  }
}

注意： 记录访问日志会降低性能，特别是在网关等对性能要求很高的异步场景。性能优先场景，不建议业务自定义日志，Spring Cloud Huawei的访问日志进行了额外优化。