微服務開發系列:如何列印好日誌

zxdposter發表於2022-11-24

原始碼地址

微服務開發系列:開篇
微服務開發系列:為什麼選擇 kotlin
微服務開發系列:為什麼用 gradle 構建
微服務開發系列:目錄結構,保持整潔的檔案環境
微服務開發系列:服務發現,nacos 的小補充
微服務開發系列:怎樣在框架中選擇開源工具
微服務開發系列:資料庫 orm 使用
微服務開發系列:如何列印好日誌
微服務開發系列:鑑權
微服務開發系列:認識到序列化的重要性
微服務開發系列:設計一個統一的 http 介面內容形式
微服務開發系列:利用異常特性,把異常納入框架管理之中
微服務開發系列:利用 knife4j,生成最適合微服務的文件

日誌對一個系統來說是非常重要的。

我遇到過很多問題,找日誌完全是無跡可尋,甚至前端很多請求發現十分耗時,最後一通查下來,都不知道時間到底耗在哪裡,然後問題也無法復現了,只能透過不斷的亡羊補牢加日誌判斷問題到底出在哪裡。

雖然有 arthas 這樣很有想法的工具,但是這種工具你不一定能用,一般是用來排查比較詭異的問題,還有就是時間很長了之後,很難透過 arthas 去還原出來當時的情況,而且就算你能還原,網路波動的問題能還原嗎?

所以直接透過日誌去排查是最好的,最直接方便,一般不會有人阻止你去看日誌,作為一個開發人員,要想不加班,一定要多加日誌。

當然新增日誌也要合情合理,出現異常問題才去報告,日誌要有規律有跡可循,控制日誌的輸出保持在合理的範圍之內,有些開發人員的日誌,多細節的東西都輸出,結果造成了日誌檔案十分巨大,因此最好還是能只列印最有效的日誌。

只列印最有效的日誌,在不斷測試的過程中最佳化對日誌輸入,不僅僅體現了對日誌的重視,還能夠幫助開發者在開發的過程中梳理邏輯思路,使表達更為通暢,並且在未來對這段程式碼最佳化重構時,也能加深自己的理解,重構出更優秀的模組。

1 日誌輸出

框架中的日誌輸出全都是使用日誌檔案,並沒有使用帶有第三方服務的日誌框架,因為不想在多加任何服務了。

也沒有使用任何資料庫去記錄日誌,因為覺得檔案就可以了,只要熟練運用 linux 的過濾命令,查問題是很快的。

2 框架日誌配置

框架的日誌使用的是 spring boot 本身的配置,並沒有做類似用 spring-logback.xml 這種配置。

一個是因為覺得麻煩,還有一個就是 spring 提供的日誌配置已經完全足夠使用了。

日誌的配置統一使用 nacos config 中配置的 logging.yml

logging:
  pattern:
    console: '%clr(%d{${LOG_DATEFORMAT_PATTERN:yyyy-MM-dd HH:mm:ss.SSS}}){faint} %clr(${LOG_LEVEL_PATTERN:%5p}) %clr(${PID: }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint}%clr(%X{REQUEST_ID}){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:%wEx}'
    file: '%d{${LOG_DATEFORMAT_PATTERN:yyyy-MM-dd HH:mm:ss.SSS}} ${LOG_LEVEL_PATTERN:%5p} ${PID: } --- [%t] %-40.40logger{39} :%X{REQUEST_ID} %m%n${LOG_EXCEPTION_CONVERSION_WORD:%wEx}'
  file:
    name: ${SERVER_COMMON.BASE:${user.home}/server-common}/logs/server/${spring.application.name}/${spring.application.name}.log
    max-history: 20
    max-size: 50MB
  level:
    root: warn
    cn.framework: debug
    cn.gateway: debug
    cn.business: debug

裡面的配置項,全都是 spring 自帶的,該配置任何專案都必須引用,全部的日誌路徑都統一在一個位置。

3 日誌打包格式

spring boot 預設的日誌框架配置,日誌在打包時,格式為 gz 格式,非常推薦這種格式。

使用 gz 的好處是,linux 包含了自帶的 zgrep 命令可以直接搜尋打包後的檔案,如果你使用 zip 格式打包,那麼在你想查詢歷史日誌時,你必須把 zip 檔案解壓。

因此 gz 格式能很方便的讓運維人員查詢問題。

4 日誌 pattern

上面的配置使用了 logging.pattern.console 和 logging.pattern.file 配置了日誌的輸出格式,直接複製過來的,除了多了一個 REQUEST_ID 的佔位符,其它完全與原來的格式相同。

4.1 Request-Id

Request-Id  是 spring cloud gateway 給每個請求都產生的一個唯一 ID,類似於主鍵一樣。

框架裡面受到了這個的啟發,把 Request-Id 傳遞給了兩個地方

  1. 下游系統
  2. http response header 中

4.1.1 傳到下游系統

傳給下游系統就是為了讓上面日誌配置的佔位符生效,具體的實現方式在 framework:cn.framework.config.logging.MvcLoggingConfigurer 類中。

這樣配合 gateway:cn.gateway.framework.filter.LoggingFilter 就能把一個請求所有的日誌都集齊了。

LoggingFilter.java 列印了一個請求最真實的耗時時間,從發起請求到返回結果,這樣就能立馬判斷出一個請求耗時高到底是哪裡出了問題。

MvcLoggingConfigurer.java 就讓上面的佔位符生效,只要是單執行緒列印的日誌,都會帶上 Request-Id,如果開發人員靈活一些,也能把 Request-Id 帶上放在併發請求裡面,更近一步列印 Request-Id+ThreadId,這樣問題就很好查詢了。

閘道器列印
image.png
下游系統列印
image.png

4.1.2 傳到前端

這樣的目的是,方便在前端使用介面處問題時,能夠透過 network 請求中看到的 Request-Id,給到後端,裡面查到所有相關的日誌。

前端可以選擇在判斷請求出現問題時,就把 Request-Id 列印在 console 裡面,這樣不用等到再次開啟 F12 瀏覽器控制檯去復現錯誤,萬一復現不出來就很有用了。

因為 console 的輸出不會因為瀏覽器控制檯的開啟關閉而消失。

5 日誌輸出規範

在框架中列印日誌,請儘量遵守下面幾點:

  1. 日誌中不能使用中文,這是由於系統面臨的環境是不可控的,隨時可能讓中文日誌變成亂碼,使用英文和數字是最穩妥的
  2. 儘量不要使用過多符號,複雜過多的符號在生產環境並不能有效的提高閱讀效率,反而造成 linux 下檔案管道過濾時的麻煩
  3. 一個重要的方法內儘量包含唯一標識,比如功能名稱,這樣過濾日誌更方便
  4. 謹慎選擇輸出日誌,避免列印大量、重複的日誌,造成空間浪費和排查困難

6 HTTP 請求耗時

gateway:cn.gateway.framework.filter.LoggingFilter 除了列印了所有請求的耗時,也將請求的耗時,傳給了前端的 http response header 中,引數名是 Cost

這樣做有一個好處,就是前端在發現請求較慢時,就能透過 network 的請求耗時和 Cost 作對比,如果 network >> Cost,說明網路本身就慢。

前端最好在判斷耗時過長時,把 Cost 列印在 F12 瀏覽器控制檯中。

7 Log 物件生成

由於 kotlin 中不能再使用任何 lombok 的註解,因此 Log 變數也不能透過註解的方式直接生成。

於是經過了一段時間在網上的探索,有一種更加方便的獲取 Log 變數的方式,實現在類 cn.vte.framework.common.log.Slf4k 中。

實現的邏輯是 kotlin 的變數擴充套件加上 reified 泛型固定,想要獲取 Log 變數時,只需要引入即可。

Log 物件並不是使用的常規 Slf4jLog,而是使用的 [KotlinLogging](https://github.com/MicroUtils/kotlin-logging) 封裝後的 Log,相比於一般 Log 物件,多支援了一些 kotlin 的特性。

8 http body 獲取

框架中提供了一種獲取 requestBodyresponseBody 的方式。

能夠在不影響請求流的情況下,獲取的請求的 body。

實現方式參考了 spring cloud 的 ModifyResponseBodyGatewayFilterFactoryModifyRequestBodyGatewayFilterFactory

開啟方式,是需要再 gateway 下的 bootstrap.yml 中,路由配置下增加 filter。

LoggingFilter 中,雖然獲取到了,但是並沒有列印,如果有需要可以自行列印出來。

閘道器列印請求的完整結果
image.png

相關文章