業務日志內容與格式探討

在開發日志系統，簡單的日志系統用ELK即可，代碼量很少。在分析日志時，發現大量日志格式存在問題，真正的工作在於日志內容的分類、日志格式的梳理。

日志級別概述

ERROR

• ERROR是最高級別錯誤，反映系統發生了非常嚴重的故障，無法自動恢復到正常態工作，需要人工介入處理。系統需要將錯誤相關痕跡以及錯誤細節記錄ERROR日志中，方便后續人工回溯解決。

WARN

• WARN是低級別異常日志，反映系統在業務處理時觸發了異常流程，但系統可恢復到正常態，下一次業務可以正常執行。但WARN級別問題需要開發人員給予足夠關注，往往表示有參數校驗問題或者程序邏輯缺陷，當功能邏輯走入異常邏輯時，應該考慮記錄WARN日志。

INFO

• INFO日志主要記錄系統關鍵信息，旨在保留系統正常工作期間關鍵運行指標，開發人員可以將初始化系統配置、業務狀態變化信息，或者用戶業務流程中的核心處理記錄到INFO日志中，方便日常運維工作以及錯誤回溯時上下文場景復現。

DEBUG

• 開發人員可以將各類詳細信息記錄到DEBUG里，起到調試的作用，包括參數信息，調試細節信息，返回值信息等等。其他等級不方便顯示的信息都可以通過DEBUG日志來記錄

使用WARN和統計報警

由於WARN是低級別異常日志，不需要馬上處理。但是如果頻次過於頻繁，達到一定閾值，就發出報警，進行處理。

強調ERROR報警

ERROR的報出應該伴隨着業務功能受損，即上面提到的系統中發生了非常嚴重的問題，必須有人馬上處理。

ERROR日志目標

給處理者直接准確的信息：error信息形成自身閉環。

1. 問題定位：發生了什么問題，哪些功能受到影響
2. 獲取幫助信息：直接幫助信息或幫助信息的存儲位置
3. 通過報警知道解決方案或者找何人解決

實用模板

日志模板2選1：

log.error(“[接口名或操作名] [Some Error Msg] happens. [Probably Because]. [Probably need to do] [params] .”);

log.error(“[接口名或操作名] [Some Error Msg] happens. [Probably Because]. [please contact xxx@xxx] [params] .”);

盡量按上述模板完成，如果實施起來有難度，至少ERROR 日志打印時需要在做一個自我問答，能非常有效的幫助評估這條報警是否有意義：這條報警看到之后我能處理嗎？ 應該怎么處理? 如果是同事看到能處理或者及時通知聯系人呢嗎？ 因為你不可能保證隨時都處在工作狀態，但報警時隨時有可能出現的。

日志輸出內容

日志輸出的注意點

我不確定大家是否遇到過下面的情況：*排查問題時，發現那塊出現錯誤的地方有日志輸出，但是輸出的日志對於排查問題一點用都沒有**，每當出現這種情況的時候我都想罵人。

好的日志需要有哪些內容呢？

• 發生時間
• 出現問題的線程
• 日志級別
• 出現問題的類文件，類的哪一行，異常棧
• 程序入參
• 相應的程序員的注釋等

（可選項）

• 會話標識，能知道是哪個客戶端或者是哪個用戶觸發，登陸賬號，seesion信息等
• 通過RequestID來對請求進行唯一的標記，目的是可以通過RequestID將一個請求在系統中的執行過程串聯起來。根據不同的目的生成RequestID，必要時在RequestID中盡量編碼更多的信息

日志框架選型

新的Log4j 2.x版本有了大幅的性能提升、新的插件系統，以及配置設置方面的很多改善。Log4j 1.x 在高並發情況下出現死鎖導致cpu使用率異常飆升，而Log4j2.x基於LMAX Disruptor的異步日志在多線程環境下性能會遠遠優於Log4j 1.x和logback。

• Log4j 2.x 日志升級的詳細流程（針對各種混合使用Log4j 1.x，Logback，JCL,JUL等）

log4j2-spring.xml配置

springboot 推薦***-spring.xml的命名規范。

日志配置主要涉及2點：

1. who？ 就是誰輸出日志，可指定根目錄、或者具體的包路徑

<Loggers>
    <Logger name="com.foo.Bar" level="trace">
      <AppenderRef ref="Console"/>
    </Logger>
    <Root level="error">
      <AppenderRef ref="Console"/>
    </Root>
  </Loggers>

2. 輸出的目錄與格式

<Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %t %-5level %C{36} %M %L %msg%xEx%n"/>
    </Console>
  </Appenders>

日志包含基本內容：

• 發生時間
• 出現問題的線程
• 日志級別
• 出現問題的類文件，類的哪一行，異常棧

循環日志文件：日志文件大於閥值的時候，就開始寫一個新的日志文件

<!--
    循環日志文件：日志文件大於閥值的時候，就開始寫一個新的日志文件
    這個會打印出所有的信息，每次大小超過size，則這size大小的日志會自動存入按年份-月份建立的文件夾下面並進行壓縮，作為存檔

    fileName    : 指定當前日志文件的位置和文件名稱
    filePattern : 指定當發生Rolling時，文件的轉移和重命名規則
    SizeBasedTriggeringPolicy : 指定當文件體積大於size指定的值時，觸發Rolling
    DefaultRolloverStrategy : 指定最多保存的文件個數
    TimeBasedTriggeringPolicy : 這個配置需要和filePattern結合使用
        注意filePattern中配置的文件重命名規則是${FILE_NAME}_%d{yyyy-MM-dd}_%i，最小的時間粒度是dd，即天，
        TimeBasedTriggeringPolicy指定的size是1，結合起來就是每1天生成一個新文件
-->

<RollingRandomAccessFile name="INFO" fileName="logs/${FILE_NAME}.log" filePattern="log/${FILE_NAME}_%d{yyyy-MM-dd}_%i.log.gz">
    <Filters>
        <ThresholdFilter level="WARN" onMatch="DENY" onMismatch="NEUTRAL"/>
        <ThresholdFilter level="TRACE" onMatch="ACCEPT" onMismatch="DENY"/>
    </Filters>
    <PatternLayout pattern=" %d{yyyy-MM-dd HH:mm:ss.SSS} %t %-5level %C{36} %M %L %msg%xEx%n"/>
    <Policies>
        <TimeBasedTriggeringPolicy interval="1"/>
        <SizeBasedTriggeringPolicy size="1MB"/>
    </Policies>
    <DefaultRolloverStrategy max="20"/>
</RollingRandomAccessFile>

配置格式擴展

1. 自定義格式：

%t：線程名稱

%p：日志級別

%c：日志消息所在類名

%m：消息內容

%M：輸出執行方法

%d：發生時間，%d{yyyy-MM-dd HH:mm:ss,SSS}，輸出類似：2011-10-18 22:10:28,921

%x: 輸出和當前線程相關聯的NDC(嵌套診斷環境),尤其用到像java servlets這樣的多客戶多線程的應用中。

%L：代碼中的行數

%n：換行

<PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %class{36} %L %M -%msg%xEx%n"/>

2. Logger Names

package org.apache.test;
 
public class MyTest {
    private static final Logger logger = LogManager.getLogger();
}

3. 代碼日志打印

With Java 8 you can achieve the same effect with a lambda expression. You no longer need to explicitly check the log level:

 Java-8 style optimization: no need to explicitly check the log level:
 the lambda expression is not evaluated if the TRACE level is not enabled
logger.trace("Some long-running operation returned {}", () -> expensiveOperation());

在java8中不用顯示判斷日志級別，如果未啟用該日志級別，則不會執行lambda表達式。

自定義過濾器類

log4j2中用ThreadContext代替MD

public class ThreadContextFilter implements Filter {


    @Override
    public void init(FilterConfig filterConfig) throws ServletException {

    }

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        try {
            ThreadContext.put("UUID", StaticUUID.ID);    //StaticUUID是自己寫的類，用於生成UUID常量。
            ThreadContext.put("ip", request.getLocalAddr());
            chain.doFilter(request, response);
        } finally {
        //清除ThreadContext,避免內存泄露
            ThreadContext.clearAll();
        }
    }

    @Override
    public void destroy() {

    }

}

這樣可以在日志中動態輸出一些信息，如ip,用戶名等。

<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level %class{1.}:%L - IP:%X{ip}&amp;ID:%X{UUID}  %msg%xEx%n" />

阿里java編程規范-日志部分：

日志規約

【強制】應用中不可直接使用日志系統（Log4j、Logback）中的API，而應依賴使用日志框架SLF4J中的API，使用門面模式的日志框架，有利於維護和各個類的日志處理方式統一。
      import org.slf4j.Logger;
      import org.slf4j.LoggerFactory;
          private static final Logger logger = LoggerFactory.getLogger(Abc.class);        
      slf4j是日志門面框架，其僅提供日志記錄的API，而不實現日志記錄的功能，slf4j需要通過適配庫適配到log4j或logback等日志系統來實現日志的記錄。使用slf4j api能夠提升代碼和應用的可移植性，在使用不同日志系統的應用之間能夠做到無縫的適配。同時，使用slf4j api的應用，在切換日志系統時（比如從logback切換到log4j2，不需要代碼改造）

【強制】日志文件推薦至少保存15天，因為有些異常具備以“周”為頻次發生的特點。

【強制】應用中的擴展日志（如打點、臨時監控、訪問日志等）命名方式：appName_logType_logName.log。
       logType:日志類型，推薦分類有stats/desc/monitor/visit等；
       logName:日志描述。這種命名的好處：通過文件名就可知道日志文件屬於什么應用，什么類型，什么目的，也有利於歸類查找。
       正例：mppserver應用中單獨監控時區轉換異常，如： mppserver_monitor_timeZoneConvert.log
       說明：推薦對日志進行分類，如將錯誤日志和業務日志分開存放，便於開發人員查看，也便於通過日志對系統進行及時監控。

【強制】對trace/debug/info級別的日志輸出，必須使用條件輸出形式或者使用占位符的方式。
       說明：logger.debug("Processing trade with id: " + id + " symbol: " + symbol); 如果日志級別是warn，上述日志不會打印，但是會執行字符串拼接操作，如果symbol是對象，會執行toString()方法，浪費了系統資源，執行了上述操作，最終日志卻沒有打印。
       正例：（條件）
           if (logger.isDebugEnabled()) { 
               logger.debug("Processing trade with id: " + id + " symbol: " + symbol); 
             }      
       正例：（占位符）
           logger.debug("Processing trade with id: {} symbol : {} ", id, symbol);     
      占位符方式，log4j2/logback支持，log4j1.x是不直接支持的，只能通過slf4j庫適配

【強制】避免重復打印日志，浪費磁盤空間，務必在log4j.xml中設置additivity=false。
        正例：
           additivity默認為true，即通過該logger輸出的日志會同時輸出到root logger，如果還為該logger指定了獨立的appender，就會導致這部分日志重復輸出

【強制】異常信息應該包括兩類信息：案發現場信息和異常堆棧信息。如果不處理，那么通過關鍵字throws往上拋出。
        正例：
            logger.error(各類參數或者對象toString + "_" + e.getMessage(), e);             
      記錄異常日志的常見錯誤：
        logger.error(e);
        logger.error(e.getMessage());
        logger.error("上下文"+e.getMessage())；        
      上面這幾種都是錯的！請確保使用的是兩個入參的API，如error(String s, Throwable t)

【推薦】謹慎地記錄日志。生產環境禁止輸出debug日志；有選擇地輸出info日志；如果使用warn來記錄剛上線時的業務行為信息，一定要注意日志輸出量的問題，避免把服務器磁盤撐爆，並記得及時刪除這些觀察日志。
        說明：大量地輸出無效日志，不利於系統性能提升，也不利於快速定位錯誤點。記錄日志時請思考：這些日志真的有人看嗎？看到這條日志你能做什么？能不能給問題排查帶來好處？不要認為日志記錄不怎么消耗性能，我見過不少事無巨細式的日志把系統性能嚴重拖慢的案例

【參考】可以使用warn日志級別來記錄用戶輸入參數錯誤的情況，避免用戶投訴時，無所適從。注意日志輸出的級別，error級別只記錄系統邏輯出錯、異常等重要的錯誤

參考

• spring boot 各版本中使用 log4j2 記錄日志
• logback layouts
• log4j2 layouts
• log4j2配置固定內容(IP等)
• log4j patten格式
• log4jtester
• Log4J2 配置文件模板及代碼說明
• log4j2配置固定內容(IP等)

---

tips:本文屬於自己學習和實踐過程的記錄，很多圖和文字都粘貼自網上文章，沒有注明引用請包涵！如有任何問題請留言或郵件通知，我會及時回復。