線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

前言

前些天接手了一個有些年頭的Spring Boot項目,今天好不容易修復了一個bug,中間過程真是特別“酸爽”,覺得有必要記錄一下。

情況是這樣的,這個bug我在本地開發環境復現不了,又沒辦法直連線上數據庫debug,所以我只能去服務器上翻日誌文件,然後發現一個10G+的日誌文件nohup.out,所有的運行日誌全都在這個文件裡,你們知道我當時心裡在想什麼嗎?就特別想和寫這項目的前輩好好聊聊人生……

沒辦法我只能按照程序出問題的大概時間慢慢去排查日誌,過程之艱辛就不談了,說多了都是淚!

突然想起了羅永浩在發佈會上的那句話:“原諒他們,因為他們不知道自己在做什麼。

好不容易改完bug,我又花了點時間改造了一下老項目的日誌模塊,實現了日誌按級別、按天、按大小切多文件存儲、同時錯誤日誌自動保存到數據庫,後面集成前端頁面後可以很方便的排查問題,最後又花了點時間瞭解了一下Spring Boot框架默認加載日誌框架的機制。

目錄

  1. 為什麼Spring Boot不需要任何配置就能輸出日誌?
  2. 如何自定義日誌輸出?
  3. 輸出日誌到控制檯——高亮顯示關鍵信息
  4. 輸出日誌到文件——按級別、日期、大小切分
  5. 輸出日誌到數據庫——關鍵信息自動保存到數據庫
  6. 總結

為什麼Spring Boot不需要任何配置就能輸出日誌?

不知道大家有沒有注意過這個現象:一個新建的Spring Boot項目,什麼都不用配置,啟動的時候控制檯就會輸出一堆日誌:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

這是怎麼回事?根據我的猜想肯定是Spring Boot默認加載了某個日誌框架。

觀察一下項目的Maven依賴關係可以發現Spring Boot確實默認依賴了spring-boot-starter-logging模塊,spring-boot-starter-logging模塊又依賴了logback、log4j等具體的日誌框架:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

那麼問題來了,Spring Boot默認的日誌模塊是哪一個呢?

看一下自動加載的核心配置文件spring.factories,可以發現Spring Boot默認加載了兩個監聽器,分別是ClasspathLoggingApplicationListener和LoggingApplicationListener:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

這兩個監聽器都實現了GenericApplicationListener接口,而GenericApplicationListener接口又繼承自Spring框架的ApplicationListener

頂級接口。

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

ApplicationListener接口有什麼用?

熟悉Spring Boot內部機制的人應該知道,在應用的整個啟動過程中會經歷啟動、啟動中、初始化、環境準備等幾個階段,在每個階段系統都會回調ApplicationListener接口中的onApplicationEvent方法,在這個回調方法裡我們通常會做一些初始化的工作。

看一下LoggingApplicationListener監聽器的實現邏輯:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

在收到Spring容器啟動事件的回調後,系統開始去加載並初始化日誌框架;

繼續看一下get方法:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

這個SYSTEMS是個Map對象,默認加載了LogbackLoggingSystem、Log4J2LoggingSystem和JavaLoggingSystem三套日誌框架:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

get方法的邏輯就是循環SYSTEMS找出classpath下已經存在的日誌框架,如果存在多個則取第一個即LogbackLoggingSystem,所以Spring Boot默認使用的是Logback日誌框架。

如何自定義日誌輸出?

很多時候系統默認的日誌配置並不能滿足我們的開發需求,那我們就需要對Logback進行自定義配置,那麼Logback的配置文件是啥?

我們還是從源碼入手,先來看一下LogbackLoggingSystem的初始化方法:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

首先會去嘗試加載Logback自己的初始化配置文件,包括logback-test.groovy、logback-test.xml、logback.groovy和logback.xml4個文件:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

如果沒有加載到標準配置文件,就會去嘗試加載Spring的初始化配置文件,包括logback-test-spring.groovy,logback-test-spring.xml,logback-spring.groovy,logback-spring.xml4個文件;

最後如果上面兩種方式都沒有加載到配置文件,則去加載默認的配置;

通常我們會使用logback-spring.xml作為我們自定義的配置文件名稱。

輸出日誌到控制檯——高亮顯示關鍵信息

其實Logback不用配置默認就會輸出日誌到控制檯,但是我發現所有日誌都是一個顏色,看起來費勁。怎麼辦?改!

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

我們使用ConsoleAppender構造一個appender,然後通過encoder節點可以傳入一個自定義的日誌輸出格式,將關鍵信息高亮顯示:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

輸出日誌到文件——按級別、日期、大小切分

將日誌信息輸出到文件是非常必要的,出問題時我們可以查找日誌文件排查問題。

但是隨著應用的運行時間越來越長,日誌文件也會變得越來越大,那麼將所有日誌輸出到一個文件的做法就不合適了,我們需要按日誌級別、日期、大小來切分日誌文件。

我們使用RollingFileAppender構造一個appender,RollingFileAppender的主要作用就是可以滾動記錄日誌,它有兩個重要的策略:RollingPolicy和 TriggeringPolicy。RollingPolicy決定了日誌滾動方式,TriggeringPolicy決定了日誌滾動的觸發條件。

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

以這個例子來講,它是基於時間和文件大小的滾動策略,每天會新生成一個日誌文件;或者當日志文件達到指定大小時也會進行滾動生成新的日誌文件。

輸出日誌到數據庫——關鍵信息自動保存到數據庫

雖然日誌可以輸出到文件,但是很多時候我們排查問題時依然感覺是比較麻煩的,可不可以將關鍵日誌自動存到數據庫,然後通過一個頁面來查看日誌呢?

答案當然是可以的!我們使用DBAppender來構造一個appender,然後通過connectionSource節點配置數據庫信息:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

有人要問了:日誌數據會存到哪張表?可以自定義表結構嗎?

Logback默認提供了一個logging_event表來存儲日誌數據:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

其中formatted_message字段用來存具體的日誌信息,arg0-arg3共4個字段用來存我們的參數:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

Logback默認的日誌表最多隻能存4個自定義參數,很多時候並不能滿足我們的業務需求,我們可以進行自定義處理。

那麼我們該怎麼做呢?沒頭緒的話那就先看一下默認的DBAppender的實現邏輯吧:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

我列了一下DBAppender裡面有2個比較重要的點:

一是創建Insert SQL語句;

二是綁定SQL參數並完成數據插入;

既然我們要自定義表結構,那麼這兩塊代碼的邏輯肯定要改,新建一個類繼承DBAppender並重寫它的getInsertSQL和subAppend方法:

線上程序出bug,排查起來很麻煩?一個好的日誌系統是關鍵

getInsertSQL返回我們自定義表的插入語句,subAppend方法裡我們重新綁定相應的參數。

總結

記錄日誌是一件非常有必要的事情,它可以幫助我們快速定位解決問題,所以我們在開發過程中要儘可能多的記錄日誌。

Spring Boot框架默認使用Logback作為日誌框架,我們可以通過自定義配置的方式將日誌輸出到控制檯、文件或者數據庫中。


“分享乾貨,收穫快樂”

我是一名程序員,喜歡我的文章歡迎 關注 及 轉發,我會經常與大家分享工作當中的實用技巧與經驗。


分享到:


相關文章: