給日誌打標籤,讓你的日誌定位再無困難

菠菜東發表於2020-07-18

背景

不知道各位在生產日誌中定位問題時有沒有碰到這樣的場景:由於coding的時候日誌輸出的比較少,出現問題時,很難通過日誌去定位到問題。又或者是,你明明coding的時候有輸出日誌。但是在龐大的日誌檔案中,由於業務執行緒併發比較多,你輸出的日誌又沒有加關鍵資訊。你也很難定位到你所需要的日誌資訊。


之前在公司裡寫業務程式碼時,為了使每個RPC呼叫能被日誌記錄下來,我們在公司基礎元件裡定義了一個切面,攔截所有的RPC呼叫,方法開始之前,在日誌裡輸出呼叫的服務和方法以及引數,方法結束時輸出方法的耗時。我相信很多人也是這麼做的。


這樣一來 ,所有的呼叫都能通過引數裡的關鍵資訊被搜尋到。也能定位到呼叫是什麼結束的以及耗時。


但是在有些業務方法中,也打上了很多的業務日誌。由於核心業務的tps和qps很高,日誌是互相穿插的。如果你的日誌沒有打上關鍵的業務資訊(比如訂單號,業務ID),那就很難在日誌中被定位出來。


也許有些童鞋會說,用執行緒號呀。通過搜尋業務ID定位到呼叫開始的地方,再搜尋這條執行緒的執行緒號,就可以定位整個請求的所有日誌。其實之前我也是這麼幹的,但是執行緒一般都是由執行緒池進行管理的,在tps很高的業務中,同一個執行緒號有可能短時間會出現多次,但是卻是不同的請求。而且業務方法中可能也會有非同步執行緒,導致了執行緒號會變。這樣對於定位日誌就又增加了難度。當然最後可以通過對時間戳的分析,還是可以定位到具體日誌。但是這樣就增加了定位的時間成本。


如果你的公司對微服務使用了分散式追蹤,那麼定位日誌可以通過traceId來解決。如果沒有在生產上應用分散式追蹤,又想在併發比較高的應用的日誌上快速定位到所需要的日誌。其中一個比較有效的辦法就是:規範日誌的輸出格式


在每行日誌輸出時儘可能的加上關鍵的業務資訊,然後定位起來就比較清晰了,例如:


file


這裡每一行日誌都加上了訂單號和請求ID,我們把這樣的日誌頭資訊稱之為日誌標籤,有了這些標籤定位起來就比較容易了。


那這樣是不是意味著每寫一行日誌,都必須加上這樣日誌標籤資訊呢?這是不是也麻煩了?


答案是不用的。


推薦一款自動給日誌打標籤實現精確定位的日誌切面框架,你使用了這個,你的日誌可以實現自定義的業務標籤!


點選Aspect-log跳轉到開源主頁,或者複製以下地址:

https://gitee.com/bryan31/aspect-log

file

Aspect-log介紹

這是一款小巧,輕量級,對業務幾乎無侵入的日誌切面框架。特性為:

  • 使用簡單,不侵入業務程式碼。只需要在方法上配置標註
  • 支援log4j,logback,log4j2三種常見的日誌框架
  • 配置極其簡單。提供“一鍵配置”,自動識別日誌框架
  • 在方法上配置,無論呼叫多深或者非同步呼叫。也可以統一加上日誌標籤
  • 無效能損耗

使用方法很簡單,如果你是springboot,aspect-log提供了自動裝配,GAV為:

<dependency>
  <groupId>com.yomahub</groupId>
  <artifactId>aspect-log-spring-boot-starter</artifactId>
  <version>1.2</version>
</dependency>

如果你是spring,GAV為:

<dependency>
  <groupId>com.yomahub</groupId>
  <artifactId>aspect-log-core</artifactId>
  <version>1.2</version>
</dependency>


配置方式

如果你使用spring,需要在專案裡的application.xml裡定義:

<bean class="com.yomahub.aspectlog.aop.AspectLogAop"/>

如果你使用springboot,AspectLog切面會自動裝配好。

一鍵配置方法

這種方式用javassit實現,只需要一句話就可以實現。自動識別當前主流的日誌框架。

@SpringBootApplication
public class Runner {

    static {AspectLogEnhance.enhance();}//進行日誌增強,自動判斷日誌框架

    public static void main(String[] args) {
        try {
            SpringApplication.run(Runner.class, args);
        } catch (Throwable e) {
            e.printStackTrace();
        }
        while (true) {
            try {
                Thread.sleep(60000);
            } catch (Throwable e) {
                e.printStackTrace();
            }
        }
    }
}

針對於主流的Log日誌框架作了適配(推薦用這種)

針對於每種Log日誌框架提供了適配,具體使用方法請參照專案主頁裡的文件。



如何使用

接下來在你的方法上加上@AspectLog標註,簡單的例子如下:

@AspectLog({"id"})
public void demo1(String id,String name){
  log.info("這是第一條日誌");
  log.info("這是第二條日誌");
  log.info("這是第三條日誌");
  new Thread(() -> log.info("這是非同步日誌")).start();
}

假設id的值為'NO1234',日誌打出來的樣子如下:

2020-02-08 20:22:33.945 [main] INFO  Demo - [NO1234] 這是第一條日誌
2020-02-08 20:22:33.945 [main] INFO  Demo - [NO1234] 這是第二條日誌
2020-02-08 20:22:33.945 [main] INFO  Demo - [NO1234] 這是第三條日誌
2020-02-08 20:22:33.948 [Thread-3] INFO  Demo - [NO1234] 這是非同步日誌

@AspectLog支援多個標籤:

@AspectLog({"id","name"})
public void demo1(String id,String name){
  log.info("這是第一條日誌");
  log.info("這是第二條日誌");
  log.info("這是第三條日誌");
  new Thread(() -> log.info("這是非同步日誌")).start();
}

假設傳入id的值為'NO1234',name為'jenny',日誌打出來的樣子如下:

2020-02-08 22:09:40.101 [main] INFO  Demo - [NO1234-jenny] 這是第一條日誌
2020-02-08 22:09:40.101 [main] INFO  Demo - [NO1234-jenny] 這是第二條日誌
2020-02-08 22:09:40.102 [main] INFO  Demo - [NO1234-jenny] 這是第三條日誌
2020-02-08 22:09:40.103 [Thread-3] INFO  Demo - [NO1234-jenny] 這是非同步日誌

@AspectLog支援自定pattern和多個引數的連線符

@AspectLog(value = {"id","name"},pattern = "<-{}->",joint = "_")
public void demo(String id,String name){
  log.info("加了patter和joint的示例");
}

日誌打出來的樣子如下:

2020-02-08 22:09:40.103 [main] INFO  Demo - <-NO1234_jenny-> 加了patter和joint的示例

@AspectLog支援點操作符,適用於物件的取值,支援型別為業務物件和Map

@AspectLog({"person.id","person.age","person.company.department.dptId"})
public void demo(Person person){
  log.info("多引數加多層級示例");
}

日誌打出來的樣子如下:

2020-02-08 22:09:40.110 [main] INFO  Demo - [31-25-80013] 多引數加多層級示例

@AspectLog支援自定義Convert,適用於更復雜的業務場景

@AspectLog(convert = CustomAspectLogConvert.class)
public void demo(Person person){
  log.info("自定義Convert示例");
}
public class CustomAspectLogConvert implements AspectLogConvert {
    @Override
    public String convert(Object[] args) {
        Person person = (Person)args[0];
        return "PERSON(" + person.getId() + ")";
    }
}

日誌列印出來的樣子如下:

2020-02-20 17:05:12.414 [main] INFO  Demo - [PERSON(31] 自定義Convert示例

@AspectLog支援程式設計式設值

public void demo(){
  AspectLogContext.putLogValue("[SO1001]");
  log.info("程式碼控制示例");
}

日誌打出來的樣子:

2020-02-08 22:09:40.110 [main] INFO  Demo - [SO1001] 程式碼控制示例


結尾

日誌輸出對於一個服務來說,即是執行軌跡的記錄,也是尋錯找源的根本。日誌打的全面而工整,對於排查問題來說,是事半功倍的,相信小夥伴都有看過亂糟糟的日誌吧,在一堆這樣的日誌檔案中取尋根溯源,那是極其痛苦的。

我相信很多開發者都有著程式碼潔癖,工程的架構,程式碼的結構,變數的定義,都有著苛刻的要求。這是種好習慣,這種好習慣會使程式碼的閱讀和理解事半功倍。

所以Aspect-log就是這樣一款能讓你的日誌也變得工整和賞心悅目的工具。

最後附上Aspect-log的工程主頁,歡迎關注和提出issue

希望這款小工具能讓你的日誌變得工整,能讓你的排查變得簡單而快捷。



聯絡作者

微信關注 「jishuyuanren」或者掃描以下二維碼獲取更多技術乾貨:

file

相關文章