RBA的技术分享

有的时候你的业务系统会对外提供一些服务. 比如HTTP服务. 这样使用方可能是我们C端用户,也有可能是我们的QA同学. 特别是在反馈问题的时候我们希望能够有一个统一的唯一标识符能够提供给用户. 让用户在反馈问题的时候,能够带上一个关键字, 比如相应的请求的带上的时间戳(timestamp). 或者是请求号(requestNo)这样在定位问题的时候能够比较快速的确定问题上下文.进而进行排查. 当然还有比这里刚刚说的两个参数更通用的办法.那就是使用TraceID; 而这篇备忘性质的文章主要是记录基本的处理办法和一部分技术细节.
注意: 此篇文章的方法已经不适用于最新版本的skywalking ,如果你在使用如大于8.2.0版本的代码.请确认是否其它方法
源代码: skywalking - apache

traceId的基本使用

一般研发用得多的就是用来串一下日志上下文. 复杂一点的就是跨线程,跨服务情况下的日志关联与分析. 这个基本能解决95% 以上的问题. 只是使用起来不是那么的易用. 需要开发能有基本的日志查找与问题排查能力.

简单的trace系统可以自己搞一个trace生成与传递方案即可. 复杂一些的应用就需要完善的trace系统来支撑了. 比如这里的开源的skywalking. 这里不过多展开. 有兴趣的同学再找其它资料了解.

有了traceId 后最基本的使用方法: 把 traceID记录到日志的固定字段中.并且由中间件框架自动完成.这样对业务可以做到无侵入. 使用方一般只需要配置一行logback或者是log4j`的配置.比如这个

# 这个是摘自猿辅导的一段日志配置.
# 使用的日志框架是sl4j + log4j2 (这个也应该是springBoot 的官方方案 )
Configuration:
  properties:
    property:
      - name: logPath
        value: /path/to/log/
      - name: filename
        value: app-name.log
      - name: pattern
        value: "%d{yyyy-MM-dd HH:mm:ss.SSS} [%p] [%t] [%c] @@@traceId=%traceId@@@ %m%n"
      - name: httpRequestPattern
        value: "%-d{yyyy-MM-dd HH:mm:ss.SSS} @@@traceId=%traceId@@@ %m%n"

配置后就会打出如下日志数据: 注意看里面的traceID

2021-10-22 17:40:09.448 [WARN] [http-nio-8080-exec-29] [com.yuanli.leo.framework.controller.aop.ControllerMonitorInterceptor] @@@traceId=xk8whcq4akgjl2ufdn7@@@ ControllerHandleError: RankController.rank(..)

这种无侵入,无感知的框架,能够无侵入的把traceID打印到日志中. 但是现在我想把这个TraceID 友好的吐出到HTTP接口中. 这样QA同学就可以反馈问题的时候带上关键上下文信息. 让后面的定位与排查问题更高效. 此时就需要在业务代码中主动获取TraceID

根据官方issue: how get traceId in business code? #2786 (这个链接目前直接无法打开.需要download源代码.然后再回退到大概版本:8.2.0 , 因为我司目前使用的是这个版本. 而开源版本在后面进行了较大的改动.)

对于log4j2大概可以参看这份代码:TraceIdConverter - github

简单总结: log4j需要打印一些自定义的标签的时候(注:准确说是一些自定义格式) 需要实现一个自定义的converter. skywalking 定义了一个自己的实现如下:

/*
 * Licensed to the Apache Software Foundation (ASF) under one or more
 * contributor license agreements.  See the NOTICE file distributed with
 * this work for additional information regarding copyright ownership.
 * The ASF licenses this file to You under the Apache License, Version 2.0
 * (the "License"); you may not use this file except in compliance with
 * the License.  You may obtain a copy of the License at
 *
 *     http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 *
 */

package org.apache.skywalking.apm.toolkit.log.log4j.v2.x;

import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.pattern.ConverterKeys;
import org.apache.logging.log4j.core.pattern.LogEventPatternConverter;

/**
 * {@link TraceIdConverter} is a log4j2 plugin, by annotation as {@link Plugin}. It convert the pattern key: traceId.
 * Use '%traceId' in log4j2's config. '%traceId' will output as TID:xxxx
 * <p>
 */
@Plugin(name = "TraceIdConverter", category = "Converter")
@ConverterKeys({"traceId"})
public class TraceIdConverter extends LogEventPatternConverter {

    /**
     * Constructs an instance of LoggingEventPatternConverter.
     *
     * @param name  name of converter.
     * @param style CSS style for output.
     */
    protected TraceIdConverter(String name, String style) {
        super(name, style);
    }

    public static TraceIdConverter newInstance(String[] options) {
        return new TraceIdConverter("traceId", "traceId");
    }

    @Override
    public void format(LogEvent event, StringBuilder toAppendTo) {
        Log4j2OutputAppender.append(toAppendTo);
    }
}

简单翻译一下就是: 这个转换器是用来解析log4j2中自定义的标签的. 而它要处理的标签就是:%traceId
而如其注释所说: 在没有启动agent的时候,这个会输出一个默认值:TID: N/A.而 这个是通过如下的类实现的.:
正如其注释所述: As default, append "TID: N/A" to the output message, if SkyWalking agent in active mode, append the real traceId , 也就是说,如果启动了javaAgent就会输出一个处理过的真实的TraceID

package org.apache.skywalking.apm.toolkit.log.log4j.v2.x;

public class Log4j2OutputAppender {
    /**
     * As default, append "TID: N/A" to the output message, if SkyWalking agent in active mode, append the real traceId
     * in the recent Context, if existed, or empty String.
     *
     * @param toAppendTo origin output message.
     */
    public static void append(StringBuilder toAppendTo) {
        toAppendTo.append("TID: N/A");
    }
}

到此,我们大概了解到了skywalking的traceID生成原理. 通过动态代理,或者是通过字节码技术来处理的动态代理把原来实现的默认方法代理掉,然后替换其默认的行为.这样就可以做一些框架想做的事情. 以上理解不一定对, 后面如果有时间深入了解,我会回过头来修改这里的表述..

上面是对于在log4j2中获取traceID的办法. 而对于在应用中获取traceID. skywalking提供了一个TraceContext类来承接此部分需求. 其代码如下:

package org.apache.skywalking.apm.toolkit.trace;

import java.util.Optional;

/**
 * Try to access the sky-walking tracer context. The context is not existed, always. only the middleware, component, or
 * rpc-framework are supported in the current invoke stack, in the same thread, the context will be available.
 * <p>
 */
public class TraceContext {

    /**
     * Try to get the traceId of current trace context.
     *
     * @return traceId, if it exists, or empty {@link String}.
     */
    public static String traceId() {
        return "";
    }

    /**
     * Try to get the segmentId of current trace context.
     *
     * @return segmentId, if it exists, or empty {@link String}.
     */
    public static String segmentId() {
        return "";
    }

    /**
     * Try to get the spanId of current trace context. The spanId is a negative number when the trace context is
     * missing.
     *
     * @return spanId, if it exists, or empty {@link String}.
     */
    public static int spanId() {
        return -1;
    }

    /**
     * Try to get the custom value from trace context.
     *
     * @return custom data value.
     */
    public static Optional<String> getCorrelation(String key) {
        return Optional.empty();
    }

    /**
     * Put the custom key/value into trace context.
     *
     * @return previous value if it exists.
     */
    public static Optional<String> putCorrelation(String key, String value) {
        return Optional.empty();
    }

}

同样的道理. 如果我们想用traceID那我们可以调用:TraceContext.traceId()方法即可.

注: 如果想要traceID生效,一定是在启用了javaAgent的情况下才会有正确的值.

下面是我的代码:

// 由于猿辅导进行了简单的封装, 所以是另外一个类.这里就不细表了
String traceId = YfdTraceContext.traceId();
httpServletResponse.addHeader(HEADER_X_LEO_TRACE_ID, traceId);

这样C端就可以轻松获取当前调用的traceID.方便在出问题的时候一步定位所有的日志.

注: 这里说的几个类已经从源代码库中移除: Remove agent codes and clean up #7588 可能是有更方案的. 目前还没有深入研究

• 其它日志系统是怎样记录traceID的. 这个logback是通过mdc来完成上下文相关的数据的转换的. 而这个相对更通用些. skywalking里面也有相应的支持logback进行日志打印tracieId的支持类. 具体可以查看skywalking的源代码.

参考文档

0. 增加对log4j以及log4j2的扩展，支持在日志输出格式增加traceid #9
1. SkyWalking--打印traceId到日志/获取traceId
2. how get traceId in business code? #2786
3. Skywalking -- print traceid to log / get traceid
4. Skywalking 6.2.0中文文档: 使用 TraceContext.traceId() API得到traceId
5. TraceIdConverter.java
6. 源码解析文章：skywalking
7. skywalking获取traceId(tid)的方式
8. Arthas实践--获取分布式追踪的traceId