日志與追蹤的完美融合：OpenTelemetry MDC實踐指南

作者：crossoverJie 2024-09-11 08:10:46

開發前端

通常我們排查問題的方式是先查詢異常日志，判斷是否是當前系統的問題。如果不是，則在日志中撈出 trace_id 再到鏈路查詢系統中查詢鏈路，看看具體是哪個系統的問題，然后再做具體的排查。

前言

通常我們排查問題的方式是先查詢異常日志，判斷是否是當前系統的問題。

如果不是，則在日志中撈出 trace_id 再到鏈路查詢系統中查詢鏈路，看看具體是哪個系統的問題，然后再做具體的排查。

類似于這樣：

圖片

日志中會打印 trace_id 和 span_id。

如果日志系統做的比較完善的話，還可以直接點擊 trace_id 跳轉到鏈路系統里直接查詢鏈路信息。

MDC

這里的日志里關聯 trace 信息的做法有個專有名詞：MDC:(Mapped Diagnostic Context)。

簡單來說就是用于排查問題的上下文信息，通常是由鍵值對組成，類似于這樣的數據：

{  
  "timestamp" : "2024-08-05 17:27:31.097",  
  "level" : "INFO",  
  "thread" : "http-nio-9191-exec-1",  
  "mdc" : {  
    "trace_id" : "26242f945af80b044a60226af00211fb",  
    "trace_flags" : "01",  
    "span_id" : "3a7842b3e28ed5c8"  
  },  
  "logger" : "com.example.demo.DemoApplication",  
  "message" : "request: name: \"1232\"\n",  
  "context" : "default"  
}

在 Java 中的 Log4j 和 Logback 都有提供對應的實現。

如果我們使用了 OpenTelemetry 提供的 javaagent 再配合 logback 或者 Log4j 時就會自動具備打印 MDC 的能力：

java -javaagent:/Users/chenjie/Downloads/blog-img/demo/opentelemetry-javaagent-2.4.0-SNAPSHOT.jar xx.jar

比如我們只需要這樣配置這樣一個JSON 輸出的 logback 即可：

<appender name="PROJECT_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">  
    <file>${PATH}/demo.log</file>  
  
    <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">  
        <fileNamePattern>${PATH}/demo_%i.log</fileNamePattern>  
        <maxIndex>1</maxIndex>  
    </rollingPolicy>  
  
    <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">  
        <maxFileSize>100MB</maxFileSize>  
    </triggeringPolicy>  
  
    <layout class="ch.qos.logback.contrib.json.classic.JsonLayout">  
        <jsonFormatter  
                class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter">  
            <prettyPrint>true</prettyPrint>  
        </jsonFormatter>  
        <timestampFormat>yyyy-MM-dd' 'HH:mm:ss.SSS</timestampFormat>  
    </layout>  
  
</appender>  
  
<root level="INFO">  
    <appender-ref ref="STDOUT"/>  
    <appender-ref ref="PROJECT_LOG"/>  
</root>

圖片

就會在日志文件中輸出 JSON 格式的日志，并且帶上 MDC 的信息。

自動 MDC 的原理

我也比較好奇 OpenTelemetry 是如何自動寫入 MDC 信息的，這里以 logback 為例。

@Override  
public ElementMatcher<TypeDescription> typeMatcher() {  
  return implementsInterface(named("ch.qos.logback.classic.spi.ILoggingEvent"));  
}  
  
@Override  
public void transform(TypeTransformer transformer) {  
  transformer.applyAdviceToMethod(  
      isMethod()  
          .and(isPublic())  
          .and(namedOneOf("getMDCPropertyMap", "getMdc"))  
          .and(takesArguments(0)),  
      LoggingEventInstrumentation.class.getName() + "$GetMdcAdvice");  
}

會在調用 ch.qos.logback.classic.spi.ILoggingEvent.getMDCPropertyMap()/getMdc() 這兩個函數中進行埋點。

這些邏輯都是寫在 javaagent 中的。

這個函數其實默認情況下會返回一個 logback 內置 MDC 的 map 數據（這里的數據我們可以自定義配置）。

而這里要做的就是將 trace 的上下文信息寫入這個 mdcPropertyMap 中。

以下是 OpenTelemetry agent 中的源碼：

Map<String, String> spanContextData = new HashMap<>();  
  
SpanContext spanContext = Java8BytecodeBridge.spanFromContext(context).getSpanContext();  
  
if (spanContext.isValid()) {  
  spanContextData.put(traceIdKey(), spanContext.getTraceId());  
  spanContextData.put(spanIdKey(), spanContext.getSpanId());  
  spanContextData.put(traceFlagsKey(), spanContext.getTraceFlags().asHex());  
}  
spanContextData.putAll(ConfiguredResourceAttributesHolder.getResourceAttributes());  
  
if (LogbackSingletons.addBaggage()) {  
  Baggage baggage = Java8BytecodeBridge.baggageFromContext(context);  
  
  // using a lambda here does not play nicely with instrumentation bytecode process  
  // (Java 6 related errors are observed) so relying on for loop instead  for (Map.Entry<String, BaggageEntry> entry : baggage.asMap().entrySet()) {  
    spanContextData.put(  
        // prefix all baggage values to avoid clashes with existing context  
        "baggage." + entry.getKey(), entry.getValue().getValue());  
  }}  
  
if (contextData == null) {  
  contextData = spanContextData;  
} else {  
  contextData = new UnionMap<>(contextData, spanContextData);  
}

這就是核心的寫入邏輯，從這個代碼中也可以看出直接從上線文中獲取的 span 的 context，而我們所需要的 trace_id/span_id 都是存放在 context 中的，只需要 get 出來然后寫入進 map 中即可。

從源碼里還得知，只要我們開啟 -Dotel.instrumentation.logback-mdc.add-baggage=true 配置還可以將 baggage 中的數據也寫入到 MDC 中。

而得易于 OpenTelemetry 中的 trace 是可以跨線程傳輸的，所以即便是我們在多線程里打印日志時 MDC 數據依然可以準確無誤的傳遞。

MDC 的原理

public static final String MDC_ATTR_NAME = "mdc";

圖片

在 logback 的實現中是會調用剛才的 getMDCPropertyMap() 然后寫入到一個 key 為 mdc 的 map 里，最終可以寫入到文件或者控制臺。

這樣整個原理就可以串起來了。

自定義日志數據

提到可以自定義 MDC 數據其實也是有使用場景的，比如我們的業務系統經常有類似的需求，需要在日志中打印一些常用業務數據：

userId、userName
客戶端 IP等信息時

此時我們就可以創建一個 Layout 類來繼承 ch.qos.logback.contrib.json.classic.JsonLayout:

public class CustomJsonLayout extends JsonLayout {
    public CustomJsonLayout() {
    }

    protected void addCustomDataToJsonMap(Map<String, Object> map, ILoggingEvent event) {
        map.put("user_name", context.getProperty("userName"));
        map.put("user_id", context.getProperty("userId"));
        map.put("trace_id", TraceContext.traceId());
    }
}


public class CustomJsonLayoutEncoder extends LayoutWrappingEncoder<ILoggingEvent> {  
    public CustomJsonLayoutEncoder() {  
    }  
    public void start() {  
        CustomJsonLayout jsonLayout = new CustomJsonLayout();  
        jsonLayout.setContext(this.context);  
        jsonLayout.setIncludeContextName(false);  
        jsonLayout.setAppendLineSeparator(true);  
        jsonLayout.setJsonFormatter(new JacksonJsonFormatter());  
        jsonLayout.start();  
        super.setCharset(StandardCharsets.UTF_8);  
        super.setLayout(jsonLayout);  
        super.start();  
    }}

這里的 trace_id 是之前使用 skywalking 的時候由 skywalking 提供的函數：org.apache.skywalking.apm.toolkit.trace.TraceContext#traceId

接著只需要在 logback.xml 中配置這個 CustomJsonLayoutEncoder 就可以按照我們自定義的數據輸出日志了：

<appender name="PROJECT_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">  
    <file>${PATH}/app.log</file>  
  
    <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">  
        <fileNamePattern>${PATH}/app_%i.log</fileNamePattern>  
        <maxIndex>1</maxIndex>  
    </rollingPolicy>  
  
    <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">  
        <maxFileSize>100MB</maxFileSize>  
    </triggeringPolicy>  
  
    <encoder class="xx.CustomJsonLayoutEncoder"/>  
</appender>

<root level="INFO">  
    <appender-ref ref="STDOUT"/>  
    <appender-ref ref="PROJECT_LOG"/>  
</root>

雖然這個功能也可以使用日志切面來打印，但還是沒有直接在日志中輸出更加方便，它可以直接和我們的日志關聯在一起，只是多加了這幾個字段而已。

Spring Boot 使用

OpenTelemetry 有給 springboot 應用提供一個 spring-boot-starter 包，用于在不使用 javaagent 的情況下也可以自動埋點。

<dependencies>
  <dependency>
    <groupId>io.opentelemetry.instrumentation</groupId>
    <artifactId>opentelemetry-spring-boot-starter</artifactId>
    <version>OPENTELEMETRY_VERSION</version>
  </dependency>
</dependencies>

但在早期的版本中還不支持直接打印 MDC 日志：

圖片

總結

以上就是關于 MDC 在 OpenTelemetry 中的使用，從使用和源碼邏輯上都分析了一遍，希望對 MDC 和 OpenTelemetry 的理解更加深刻一些。

關于 MDC 相關的概念與使用還是很有用的，是日常排查問題必不可少的一個工具。

責任編輯：武曉燕來源： crossoverJie

日志排查鏈路

日志與追蹤的完美融合：OpenTelemetry MDC實踐指南

前言

MDC

自動 MDC 的原理

MDC 的原理

自定義日志 數據

Spring Boot 使用

最新的版本已經支持

總結

自定義日志數據