【实战总结】RPC分布式链路追踪

1、原理

• 通过RPC框架提供的RpcContext进行traceId传递，RpcContext是大多数RPC框架提供的一个
• ThreadLocal内部实现，供使用方进行传参
• 要在rpc调用前进行设置才可以，否则下游provider拿不到，因为调用后即销毁 保证传值key唯一性，防止无意中被覆盖
• 这里使用了session而不是原始的attachment，是处于某个方法调用声明周期中间调用多个provider，防止调用一次失效（待验证复杂链路追踪）

2、实现

全局切面

/**
 * @description: 全局切面增强
 */
@Aspect
@Component("globalAspect")
public class GlobalAspect {
 
    @Resource
    private GlobalAspectEventPublisher globalAspectEventPublisher;
 
    @Around("@annotation(com.xxx.common.aspect.annotation.GlobalAspect)")
    public Object around(ProceedingJoinPoint pjp) {
        Object result = null;
 
        try {
            RpcTraceUtil.traceBegin();
 
            preHandle(pjp);
 
            if (GlobalAspectHolder.isCanAspectExec()) {
                result = pjp.proceed();
            }
 
            postHandle(result);
        } catch (Exception e) {
            errorHanle(e);
        } finally {
            RpcTraceUtil.traceEnd();
            return finalHandle(result);
        }
    }
}

RpcTraceUtil工具类

/**
 * @description: RPC跟踪工具类
 */
public class RpcTraceUtil {
 
    private final static String GLOBAL_KEY = "uuid";
 
    private final static String TRACE_ID_KEY = GLOBAL_KEY + "trace_id_key";
 
    private final static ThreadLocal<String> TRACE_ID_HOLDER = new ThreadLocal<>();
 
    /**
     * 跟踪开始
     */
    public static void traceBegin() {
        initTraceId();
        putTraceId();
    }
 
    /**
     * 跟踪结束
     */
    public static void traceEnd() {
        clearTraceId();
        RpcContext.getContext().clearSession();
    }
 
    /**
     * 获取跟踪ID
     */
    public static String getTraceId() {
        return TRACE_ID_HOLDER.get();
    }
 
    private static void initTraceId() {
        String traceId = null == RpcContext.getContext().getSessionAttribute(TRACE_ID_KEY) ? generateTraceId()
                : String.valueOf(RpcContext.getContext().getSessionAttribute(TRACE_ID_KEY));
        TRACE_ID_HOLDER.set(traceId);
    }
 
    /**
     * 设置跟踪Id
     */
    private static void putTraceId() {
        RpcContext.getContext().setSessionAttribute(TRACE_ID_KEY, TRACE_ID_HOLDER.get());
    }
 
    /**
     * 清除跟踪ID
     */
    private static void clearTraceId(){
        TRACE_ID_HOLDER.remove();
    }
 
    /**
     * 生成跟踪ID
     *
     * @return
     */
    private static String generateTraceId() {
        try {
            return DigestUtils.md5DigestAsHex(String.valueOf(SysClockUtil.getCurrentTimeMillis()).getBytes("UTF-8"));
        } catch (UnsupportedEncodingException e) {
            e.printStackTrace();
            return UUID.randomUUID().toString();
        }
    }

3、日志配置

logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <property name="log.info.location" value="/export/Logs/xxx"/>

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder charset="UTF-8">
        <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{80} traceId=%X{trace-id}, parentId=%X{parent-id} spanId=%X{span-id}  - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="SYS_INFO"
              class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.info.location}/system_info.log</file>
        <append>true</append>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>INFO</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${log.info.location}/system_info.%d{yyyy-MM-dd}.%i.log
            </fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy
                    class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <maxHistory>100</maxHistory>
        </rollingPolicy>

        <encoder charset="UTF-8">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{80} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="SYS_ERROR"
              class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.info.location}/system_error.log</file>
        <append>true</append>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${log.info.location}/system_error.%d{yyyy-MM-dd}.%i.log
            </fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy
                    class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <maxHistory>100</maxHistory>
        </rollingPolicy>

        <encoder charset="UTF-8">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{80} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="APP_INFO"
              class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.info.location}/app_info.log</file>
        <append>true</append>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>INFO</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${log.info.location}/app_info.%d{yyyy-MM-dd}.%i.log
            </fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy
                    class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <maxHistory>100</maxHistory>
        </rollingPolicy>

        <encoder charset="UTF-8">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{80} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="APP_ERROR"
              class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.info.location}/app_error.log</file>
        <append>true</append>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${log.info.location}/app_error.%d{yyyy-MM-dd}.%i.log
            </fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy
                    class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <maxHistory>100</maxHistory>
        </rollingPolicy>

        <encoder charset="UTF-8">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{80} - %msg%n</pattern>
        </encoder>
    </appender>

    <logger name="com.xxx" level="INFO" additivity="false">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="APP_INFO"/>
        <appender-ref ref="APP_ERROR"/>
    </logger>


    <root level="INFO">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="SYS_INFO"/>
        <appender-ref ref="SYS_ERROR"/>
    </root>
</configuration>