鹰眼系统日志信息能够将分布式调用链上产生的日志信息串联起来，最主要归功于打印出了traceId。
一个普通的请求，在分布式微服务环境下，可能又调用了很多微服务来完成该请求。不同的服务散落在不同的机器上，日志数据也可能保持在各自的机器上，就算将它们汇总在一个文件上，由于日志数据庞大，一条日志的前后可能都是毫不相干的日志信息。根本无法做到跟着请求的调用日志来排查问题。
但是如果有一个唯一标识来标记同一个请求的调用链上产生的日志，那么我们就可以根据该标识查询出该调用链上产生的所有日志信息。
那么此时的问题就为，如何产生traceId以及如何在打印日志时带上traceID
鹰眼系统日志是利用skywalking+logback自带的功能实现打印日志带上traceId的。因为利用了skywalking，所以traceId自然就是使用skywalking产生的traceId。
打印日志带上TraceId
<configuration scan="true" scanPeriod="30 seconds">
<include optional="true" resource="logback-include.xml"/>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<Pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %X{fddTraceId} %msg%n</Pattern>
</encoder>
</appender>
//自定义"tid"格式转换器
<conversionRule conversionWord="tid" converterClass="org.apache.skywalking.apm.toolkit.log.logback.v1.x.LogbackPatternConverter"/>
<appender name="SERVER_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${LOGS_DIR:-logs}/server-ELK.log</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<FileNamePattern>${LOGS_DIR:-logs}/server.%d{yyyy-MM-dd}-ELK.log</FileNamePattern>
<MaxHistory>5</MaxHistory>
</rollingPolicy>
<encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
<providers>
<pattern>
<pattern>
{
"ts": "%date{yyyy-MM-dd HH:mm:ss.SSS}",
"tid": "%tid",
"level": "%level",
"thread": "%thread",
"class": "%logger{60}:%L",
"method": "%method",
"message": "%message",
"exception": "%exception{10}",
"appId":"${DomainID}"
}
</pattern>
</pattern>
<version/>
<logLevelValue/>
</providers>
</encoder>
</appender>
<root>
<level value="${LOGS_LEVEL:-INFO}" />
<appender-ref ref="STDOUT" />
<appender-ref ref="SERVER_LOG"/>
</root>
</configuration>
先从logback.xml配置文件入手，可以观察到这里定义了tid这个字段来输出traceId，而tid的输出由org.apache.skywalking.apm.toolkit.log.logback.v1.x.LogbackPatternConverter这个类来转换。
这里每个%后面带着的信息，都会有一个对应的converter来生成数据。例如level由LevelConverter来生成,还有date等等。
可以在package ch.qos.logback.classic下的PatternLayout中看到。
public class PatternLayout extends PatternLayoutBase<ILoggingEvent> {
public static final Map<String, String> defaultConverterMap = new HashMap<String, String>();
public static final String HEADER_PREFIX = "#logback.classic pattern: ";
static {
defaultConverterMap.putAll(Parser.DEFAULT_COMPOSITE_CONVERTER_MAP);
defaultConverterMap.put("d", DateConverter.class.getName());
defaultConverterMap.put("date", DateConverter.class.getName());
defaultConverterMap.put("r", RelativeTimeConverter.class.getName());
defaultConverterMap.put("relative", RelativeTimeConverter.class.getName());
defaultConverterMap.put("level", LevelConverter.class.getName());
defaultConverterMap.put("le", LevelConverter.class.getName());
defaultConverterMap.put("p", LevelConverter.class.getName());
....
}
public class LevelConverter extends ClassicConverter {
public String convert(ILoggingEvent le) {
return le.getLevel().toString();
}
}
这里主要的就是convert这个方法，接受一个event，返回一个字符串。
public abstract String convert(E event);
这里我们看一下tid指定的这个LogbackPatternConverter是如何返回traceId的。
public class LogbackPatternConverter extends ClassicConverter {
public LogbackPatternConverter() {
}
public String convert(ILoggingEvent iLoggingEvent) {
return "TID: N/A";
}
}
发现这里根本就没有输出traceId，而是输出一个默认的TID:N/A。真正输出traceId的其实是在skywalking-agent的apm-tooklt-logback-1.x-activation插件上实现的。由该插件对该conver方法进行增强。
可以查看skywalking中关于apm-sniffer/apm-tookit-activation/apm-tookit-logback-1.x-activation的源码。
public class LogbackPatternConverterActivation extends ClassInstanceMethodsEnhancePluginDefine {
public static final String INTERCEPT_CLASS = "org.apache.skywalking.apm.toolkit.activation.log.logback.v1.x.PrintTraceIdInterceptor";
public static final String ENHANCE_CLASS = "org.apache.skywalking.apm.toolkit.log.logback.v1.x.LogbackPatternConverter";
public static final String ENHANCE_METHOD = "convert";
/**
* @return the target class, which needs active.
*/
@Override
protected ClassMatch enhanceClass() {
//这里指定增强`LogbackPatternConverter`这个类
return byName(ENHANCE_CLASS);
}
/**
* @return null, no need to intercept constructor of enhance class.
*/
@Override
public ConstructorInterceptPoint[] getConstructorsInterceptPoints() {
return null;
}
/**
* @return the collection of {@link StaticMethodsInterceptPoint}, represent the intercepted methods and their
* interceptors.
*/
@Override
public InstanceMethodsInterceptPoint[] getInstanceMethodsInterceptPoints() {
return new InstanceMethodsInterceptPoint[] {
new InstanceMethodsInterceptPoint() {
@Override
//进一步指定了`LogbackPatternConverter`这个类的`convert`方法
public ElementMatcher<MethodDescription> getMethodsMatcher() {
return named(ENHANCE_METHOD).and(takesArgumentWithType(0, "ch.qos.logback.classic.spi.ILoggingEvent"));
}
@Override
public String getMethodsInterceptor() {
//交由`PrintTraceIdInterceptor`这个类进行增强的逻辑
return INTERCEPT_CLASS;
}
@Override
public boolean isOverrideArgs() {
return false;
}
}
};
}
}
看看org.apache.skywalking.apm.toolkit.activation.log.logback.v1.x.PrintTraceIdInterceptor这个类
public class PrintTraceIdInterceptor implements InstanceMethodsAroundInterceptor {
@Override
public void beforeMethod(EnhancedInstance objInst, Method method, Object[] allArguments, Class<?>[] argumentsTypes,
MethodInterceptResult result) throws Throwable {
}
@Override
public Object afterMethod(EnhancedInstance objInst, Method method, Object[] allArguments, Class<?>[] argumentsTypes,
Object ret) throws Throwable {
if (!ContextManager.isActive()) {
if (allArguments[0] instanceof EnhancedInstance) {
SkyWalkingContext skyWalkingContext = (SkyWalkingContext) ((EnhancedInstance) allArguments[0]).getSkyWalkingDynamicField();
if (skyWalkingContext != null) {
return "TID:" + skyWalkingContext.getTraceId();
}
}
}
return "TID:" + ContextManager.getGlobalTraceId();
}
@Override
public void handleMethodException(EnhancedInstance objInst, Method method, Object[] allArguments,
Class<?>[] argumentsTypes, Throwable t) {
}
}
在这里就能明白TID是如何被打印出来的了
在logback中配置tid这个字段的conver为skywalking的log-tookit中的LogbackPatternConverter 。使其在输出tid字段数据的时候，调用LogbackPatternConverter的cover方法，但是这个方法并不是真正输出traceId的地方，只是起到一个触发的作用，毕竟traceId的传播都在skywalking-agent的相关增强逻辑中，所以输出tarceId也由插件进行实现，直接增强LogbackPatternConverter的cover方法，在调用该方法后返回真正的traceId。
