歡迎訪問我的GitHub
https://github.com/zq2599/blog_demos
內容：所有原創文章分類匯總及配套原始碼，涉及Java、Docker、Kubernetes、DevOPS等；
本篇概覽
-
經過《Jaeger開發入門(java版)》的實戰，相信您已經能將自己的應用接入Jaeger，并用來跟蹤定位問題了，本文將介紹Jaeger一個小巧而強大的輔助功能，用少量改動大幅度提升定位問題的便利性：將業務日志與Jaeger的trace關聯
-
在正式開始前，咱們先來看一個具體的問題：
- 一次web請求可能有多條業務日志(log4j或者logback配置的那種)，這和您寫代碼執行log.info的次數有關，假設有10條，那么十次請求就有一百條業務日志；
- 通過jaeger發現這十次請求中有一次耗時特別長，想定位一下具體原因，現在問題來了：一共有100條業務日志，到底哪些是和Jaeger中耗時長的那一次請求有關？
-
您可能會說：有些業務特征如user-id，咱們可以寫入span的tag或者log中，這樣通過span查到user-id，再去日志中查找含有此user-id的日志即可，這樣確實可以，但未必每條日志都有user-id，所以并非最佳方式
-
好在Jaeger官方給出了一種簡單有效的方案：基于MDC，Jaeger的SDK在日志中注入trace相關的變數
關于MDC
-
關于sl4j的MDC不是本篇的重點，因此只把本篇用到的特性簡單說說即可，經驗豐富的您如果對MDC已經了解，請跳過此節
-
在sl4j的組態檔中可以配置日志的格式，例如logback的組態檔如下，可見模板中新增了一段內容[user-id=%X{user-id}]：
<appender name="console" >
<filter >
<level>INFO</level>
</filter>
<encoder>
<!--%logger{10}表示類名過長時會自動縮寫-->
<pattern>%d{HH:mm:ss} [%thread] %-5level %logger{10} [user-id=%X{user-id}] %msg%n</pattern>
<charset>utf-8</charset>
</encoder>
</appender>
- 再來看一段日志的代碼，先呼叫MDC.put方法將一個鍵值對寫入當前執行緒的診斷背景關系map(diagnostic context map)，鍵名和上面的模板中配置的%X{user-id}一模一樣：
@GetMapping("/test")
public void test() {
MDC.put("user-id", "user-" + System.currentTimeMillis());
log.info("this is test request");
}
- 現在把代碼運行起來，列印日志看看，如下所示，之前模板中配置的%X{user-id}已被替換成了user-1632122267618，就是代碼中MDC.put設定的值：
15:17:47 [http-nio-18081-exec-6] INFO c.b.j.c.c.HelloConsumerController [user-id=user-1632122267618] this is test request
-
以上就是MDC的基本功能：對日志模板中的變數進行填充，填充的內容可以用MDC.put方法隨意設定；
-
此刻聰明的您應該能猜到jaeger官方的方案是如何實作的了，沒錯，就是借助MDC將trace資訊填充到日志模板中，這樣每行日志都有了trace資訊，咱們在jaeger web頁面中感興趣的任何一次trace，都能找到對應的日志了
關于Jaeger的官方方案
- Jaeger的官方方案如下圖所示，SDK已經把traceId、spanId、sampled寫入當前執行緒的診斷背景關系map(diagnostic context map)，只要日志模板中配置上述三個變數，就會在所有業務日志中輸出它們具體的值：
- 看起來似乎非常簡單，那就動手編碼試試吧
編碼實戰
-
jaeger與MDC的關聯只是個小功能，沒必要大張旗鼓的新建專案，基于《Jaeger開發入門(java版)》的代碼繼續開發即可，也就是說修改兩個子工程jaeger-service-consumer和jaeger-service-provider的原始碼，讓它們的業務日志列印出Jaeger的trace資訊
-
首先從jaeger-service-provider工程開始，增加一個標準的logback日志組態檔logback.xml，如下所示，日志模板中已添加了traceId、spanId、sampled變數：
<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="60 seconds" debug="false">
<contextName>logback</contextName>
<!--輸出到控制臺-->
<appender name="console" >
<filter >
<level>INFO</level>
</filter>
<encoder>
<!--%logger{10}表示類名過長時會自動縮寫-->
<pattern>%d{HH:mm:ss} [%thread] %-5level %logger{10} [traceId=%X{traceId} spanId=%X{spanId} sampled=%X{sampled}] %msg%n</pattern>
<charset>utf-8</charset>
</encoder>
</appender>
<root level="info">
<appender-ref ref="console" />
</root>
</configuration>
- 再去檢查配置類，確認JaegerTracer實體化時用了MDCScopeManager引數，如下所示，咱們在上一章已經這么做了，可以維持不變：
package com.bolingcavalry.jaeger.provider.config;
import io.jaegertracing.internal.MDCScopeManager;
import io.opentracing.contrib.java.spring.jaeger.starter.TracerBuilderCustomizer;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
@Configuration
public class JaegerConfig {
@Bean
public TracerBuilderCustomizer mdcBuilderCustomizer() {
// 1.8新特性，函式式介面
return builder -> builder.withScopeManager(new MDCScopeManager.Builder().build());
}
}
- 接下來是在業務代碼中隨意加幾行列印日志的代碼，如下圖紅框所示：
- 接下來繼續修改jaeger-service-consumer子工程，具體步驟與剛才改造jaeger-service-provider時一模一樣，就不多占用篇幅贅述了，記得在業務代碼中隨意加幾行日志，如下圖紅框：
- 開發完成，開始驗證吧
驗證
-
像《Jaeger開發入門(java版)》那樣操作，將jaeger-service-consumer和jaeger-service-provider編譯構建制作成docker鏡像
-
用docker-compose將所有服務啟動，然后通過瀏覽器訪問jaeger-service-consumer的服務，多訪問幾次
-
打開jaeger的web頁面，可以看到多次請求的trace，咱們隨機選擇一個，滑鼠點擊下圖紅框中的圓點：
- 此時會跳轉到該trace的詳情頁，注意頁面的url，如下圖紅框，里面的2037fe105d73f4a5就是traceid：
- 用2037fe105d73f4a5搜索jaeger-service-provider的日志，由于應用部署在docker中，咱們要用docker log和grep命令組合來過濾，如下所示，咱們代碼寫的日志都列印出來了，并且紅框中就是traceid等關鍵資訊
- 再去查看jaeger-service-consumer的日志，如下圖紅框，本次請求相關的日志也可以通過traceid搜索到：
- 至此，本篇實戰就完成了，Jaeger的web頁面上的任何一個trace，現在都能輕易找到與之對應的所有業務日志，這在定位問題時簡直是如虎添翼的效果，如果您的系統用了ELK或者EFK來匯總所有分布式服務的日志，那就更高效了
你不孤單，欣宸原創一路相伴
- Java系列
- Spring系列
- Docker系列
- kubernetes系列
- 資料庫+中間件系列
- DevOps系列
歡迎關注公眾號：程式員欣宸
微信搜索「程式員欣宸」，我是欣宸，期待與您一同暢游Java世界...
https://github.com/zq2599/blog_demos
轉載請註明出處，本文鏈接：https://www.uj5u.com/houduan/387686.html
標籤：Java