五年Java經驗,面試還是說不出日誌該怎麼寫更好?——日誌規範與最佳實踐篇

雞員外發表於2020-01-07

本文是一個系列,歡迎關注

檢視上一篇文章可以掃描文章下方的二維碼,點選往期回顧-日誌系列即可檢視所有相關文章

概覽

各位小夥伴大家好,我又回來更新了,上一篇我們討論了為什麼要使用日誌框架,這次我們深入問題的根源,為什麼我們需要日誌,日誌具體如何使用?

大多數開發人員會糾結日誌該怎麼輸出,什麼時候輸出,輸出了會不會有人看等問題,讓我們跳出開發人員的侷限來考慮這個問題:誰需要日誌?日誌有幾種?日誌都需要輸出什麼?如何輸出日誌?

誰需要日誌?

  • 開發者 開發人員在開發過程中需要輸出一些變數方便除錯,正確的做法是使用日誌來輸出(使用 System.out來輸出,一不小心釋出到線上,會被專案經理痛批);其次線上問題很難重放,使用者的表述一般都會失真,況且很多使用者發現 bug 就刪 app 關網頁走人了
  • 運維人員 整個系統大部分時間都是運維人員來維護,日誌可以幫助運維人員來了解系統狀態(很多運維繫統接入的也是日誌),運維人員發現日誌有異常資訊也可以及時通知開發來排查
  • 運營人員 沒錯,就是運營人員,比如電商的轉化率、視訊網站的完播率、普通PV資料等都可以通過日誌進行統計,隨著大資料技術的普及,這部分日誌佔比也越來越高
  • 安全人員 雖然大多數企業不重視安全,但是安全也可以通過日誌來進行預警,比如某個使用者突然大額轉賬、再比如資料庫突然出現大量無條件分頁查庫(拖庫)等等

日誌有幾種?

  • 除錯日誌 用於開發人員開發或者線上回溯問題。
  • 診斷日誌 一般用於運維人員監控系統與安全人員分析預警。
  • 埋點日誌 一般用於運營決策分析,也有用作微服務呼叫鏈路追蹤的(運維、除錯)。
  • 審計日誌 與診斷日誌類似,診斷日誌偏向運維,審計日誌偏向安全。

日誌都需要輸出什麼?

注:日誌級別會在下面講解

  • 除錯日誌
    • DEBUG 或者 TRACE 級別,比如方法呼叫引數,網路連線具體資訊,一般是開發者除錯程式使用,線上非特殊情況關閉這些日誌
    • INFO 級別,一般是比較重要卻沒有風險的資訊,如初始化環境、引數,清理環境,定時任務執行,遠端呼叫第一次連線成功
    • WARN 級別,有可能有風險又不影響系統繼續執行的錯誤,比如系統引數配置不正確,使用者請求的引數不正確(要輸出具體引數方便排查),或者某些耗效能的場景,比如一次請求執行太久、一條 SQL 執行超過兩秒,某些第三方呼叫失敗,不太可能被執行的if分支等
    • ERROR 級別,用於程式出錯列印堆疊資訊,不應該用於輸出程式問題之外的其他資訊,需要注意列印了日誌異常(Exception)就不應該拋(throw)了
  • 診斷日誌 一般輸出 INFO 級別,請求響應時間,記憶體佔用等等,線上接入監控系統時開啟,建議輸出到獨立的檔案,可以考慮 JSON 格式方便外部工具分析
  • 埋點日誌 業務按需定製,比如上文提到的轉化率可以在使用者付款時輸出日誌,完播率可以在使用者播放完成後請求一次後臺輸出日誌,一般可輸出 INFO 級別,建議輸出到獨立的檔案,可以考慮JSON格式方便外部工具分析
  • 審計日誌 大多 WARN 級別或者 INFO 級別,一般是敏感操作即可輸出,登陸、轉賬付款、授權消權、刪除等等,建議輸出到獨立的檔案,可以考慮JSON格式方便外部工具分析

一般除錯日誌由開發者自定義輸出,其他三種應該根據實際業務需求來定製。

日誌的其他注意點

  1. 線上日誌應儘量謹慎,要思考:這個位置輸出日誌能幫助排除問題嗎?輸出的資訊與排查問題相關嗎?輸出的資訊足夠排除問題嗎?做到不少輸出必要資訊,不多輸出無用資訊(拖慢系統,淹沒有用資訊)
  2. 超級 SessionId 與 RequestId,無論是單體應用還是微服務架構,應該為每個使用者每次登陸生成一個超級 SessionId,方便跟蹤區分一個使用者;RequestId,每次請求生成一個 RequestId,用於跟蹤一次請求,微服務也可以用於鏈路追蹤
  3. 日誌要儘量單行輸出,一條日誌輸出一行,否則不方便閱讀以及其他第三方系統或者工具分析
  4. 公司內部應該制定一套通用的日誌規範,包括日誌的格式,變數名(駝峰、下劃線),分隔符(“=”或“:”等),何時輸出(比如規定呼叫第三方前後輸出INFO日誌),公司的日誌規範應該不斷優化、調整,找到適合公司業務的最佳規範

OK,理論就聊到這裡,接下來讓我們回到技術層面。

使用概念

如果要想要學會使用日誌框架,先要理解幾個簡單概念,LoggerAppendersLayout日誌級別級別繼承(Level Inheritance)

Logger(日誌例項)

用於輸出日誌,呼叫一次org.slf4j.LoggerFactory#getLogger(java.lang.Class<?>)org.slf4j.LoggerFactory#getLogger(java.lang.String)就會產生一個日誌例項,相同引數會共用同一個例項。

Appenders

日誌輸出器,logback 預定義了輸出到控制檯、檔案、Socket 伺服器、MySQL、PostgreSQL、Oracle 和其他資料庫、JMS 和 UNIX Syslog 系統呼叫等實現,通過配置檔案配置即可使用,當然我們常用的只有控制檯和檔案兩種。

Layout

用於控制日誌輸出格式,前文所說的”自動輸出日誌相關資訊,如:日期、執行緒、方法名稱等等“就可以用 Layout 來控制,實際使用很簡單,寫一個 Layout 格式定義表示式(pattern)即可,使用方法類似於Java 的SimpleDateFomat

日誌級別

RFC 5424 (page 11)規定了 8 種日誌級別,但是SLF4j 只定義了 5 種日誌級別,分別是 ERROR、WARN、INFO、DEBUG、TRACE 這五個級別從高到低,配置級別越高日誌輸出就越少,如下圖

日誌級別

我們看到滑動條上五個點正好對應五個級別,滑動指示器可以左右移動,指示器作為分界點,指示器左側都可以輸出,右側都不能輸出,左右調整指示器就可以調整日誌的輸出,滑倒右側就可以全部輸出,滑倒左側就可以減少輸出,那麼是否能夠徹底關閉輸出呢?答案是可以的,配置檔案中還可以配置為 ALL 與 OFF,分別對應所有(等價於TRACE)與關閉。

級別繼承

理解了日誌級別,讓我們來考慮如下場景:

  • 某些重要業務輸出 INFO 級別,其他業務輸出WARN級別的日誌,同時關閉所有庫、框架的日誌

有需求就會有解決方案,其實很簡單,logback 與 log4j 都支援按照日誌例項來配置,現在問題解決了,但是新的問題又來了,如果線上所有日誌都輸出 INFO 級別,難道要一個一個配置嗎?這時候就就要請出我們上面所提到的級別繼承,如果 Java 一樣,logback 與 log4j 中也都是單根繼承模型,Java 中是 Object,日誌中是 ROOT,如下圖:

級別繼承

有了繼承機制,我們只需要將 ROOT 調整到 INFO 級別,再按照需求細化調整我們業務對應的 logger 例項級別即可滿足絕大多數場景。

Codding 實戰

問:把大象裝冰箱分幾步?分三步:1、引入依賴,2、編碼輸出日誌,3、調整配置檔案。前文已經講過步驟一,如果沒有看過的讀者請移步公眾號檢視往期回顧,這裡直接進入步驟二。

步驟二

如果專案中使用了Lombok,那麼可以直接在類上面加@Slf4j註解既可獲得日誌例項,否則可以使用static final org.slf4j.Logger logger = LoggerFactory.getLogger(TestLog.class);來獲取日誌例項

具體日誌輸出方法如下:

logger.trace("A TRACE Message");
logger.debug("A DEBUG Message");
logger.info("An INFO Message");
logger.warn("A WARN Message");
logger.error("An ERROR Message");
複製程式碼

這裡有個注意點,儘量使用引數佔位而不要手動拼接字串,如下

String level = "Trace";
// 反例
logger.trace("A " + level + " Message");
// 正確的做法
logger.trace("A {} Message", level);
複製程式碼

這樣做可以提高效率,如果不輸出日誌,第一種情況也會拼接字串造成效能損耗,第二種就不會有此問題(阿里巴巴Java開發手冊(華山版)這裡表述有問題,佔位符效率更高是因為儘量延遲進行字串處理,如果不需要輸出的日誌就不處理了,下一篇原理分析會展開),另外我們也不需要if (logger.isTraceEnabled())來進行判斷了(效能損耗不高,但是程式碼好看多了)。

步驟三

配置檔案需要區分 logback 與 log4j2,兩種框架在配置檔案上有差別但很相似,來看具體配置檔案。

logback 配置檔案位置

logback 支援 xml 與 groovy 指令碼兩種配置方式,logback 查詢配置檔案位置規則如下(後續文章會講如何修改位置)

  1. logback 嘗試在類路徑中找到一個名為 logback-test.xml 的檔案。
  2. 如果找不到此類檔案,則 logback 會嘗試在類路徑中找到名為 logback.groovy 的檔案。
  3. 如果找不到這樣的檔案,它將在類路徑中檢查檔案 logback.xml。
  4. 如果找不到此類檔案,則通過查詢檔案 META-INF\services\ch.qos.logback.classic.spi.Configurator,如果有這個檔案且內容是 com.qos.logback.classic.spi.Configurator 實現類的全類名,直接載入這個實現類。
  5. 如果以上方法均不能成功執行,則 logback 會使用 BasicConfigurator 自動進行自我配置,會將日誌輸出到控制檯。

這段長長的文字其實不用看,我們就把 logback.xml 放入 Classpath 根目錄就可以了。。

logback 配置檔案編寫規則

logback 配置檔案主要分為三類,一個或多個 Appender,用於定義輸出位置(不同檔案位置,或者網路又或者資料庫);一個或多個 Logger,用於細化配置不同 logger 的輸出級別以及位置;一個 ROOT,是一個特殊的logger,用於配置根 Logger。

日誌配置檔案格式

我們一起來看下面的配置檔案例項

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="false" debug="false">

    <!-- 定義日誌檔案的儲存地 -->
    <property name="LOG_PATH" value="/var/log"/>

    <property name="CONSOLE_LOG_PATTERN"
              value="%d{HH:mm:ss.SSS} %-5level [%10.10thread] %-30.30logger{29}\(%4L\\) - %msg%n"/>
    <!-- 控制檯輸出 -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>utf-8</charset>
        </encoder>
    </appender>

    <!-- 檔案日誌格式(列印日誌,不列印行號) -->
    <property name="FILE_LOG_PATTERN"
              value="%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%10.10thread] %-30.30logger{29} - %msg%n"/>

    <appender name="FILE_ALL" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在記錄的日誌檔案的路徑及檔名 -->
        <file>${LOG_PATH}/log.log</file>
        <!-- 日誌記錄器的滾動策略,按日期,按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!-- yyyy-MM-dd 按日滾動 -->
            <fileNamePattern>${LOG_PATH}/log-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <!-- 單個檔案最大50M -->
            <maxFileSize>50MB</maxFileSize>
            <!--  最多佔用5G磁碟空間,500個檔案(總共不能超過該5G) -->
            <maxHistory>500</maxHistory>
            <totalSizeCap>5GB</totalSizeCap>
        </rollingPolicy>
        <!-- 追加方式記錄日誌 -->
        <append>true</append>
        <!-- 日誌檔案的格式 -->
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>${FILE_LOG_PATTERN}</pattern>
            <charset>utf-8</charset>
        </encoder>
    </appender>

    <!-- 日誌輸出級別 STDOUT:控制檯;FILE_ALL:檔案 -->
    <root level="warn">
        <appender-ref ref="STDOUT"/>
    </root>
    <logger name="druid.sql" level="warn" additivity="true"/>
    <logger name="druid.sql.ResultSet" level="warn" additivity="true"/>
    <logger name="com.alibaba.druid.pool.DruidDataSource" level="debug" additivity="true">
        <appender-ref ref="FILE_ALL"/>
    </logger>
</configuration>
複製程式碼

上面配置檔案定義了兩個 Appender,一個輸出控制檯,另一個輸出到檔案並且自動滾動。需注意的是property標籤相當於定義一個變數,可以使用${xxx}進行引用,CONSOLE_LOG_PATTERN 與 FILE_LOG_PATTERN 定義了控制檯與檔案列印格式,具體編寫方式類似於 Java 的SimpleDateFomat就不在此展開了,具體可以參考

log4j2 配置檔案位置

log4j2 支援 XML、JSON、YAML 或者 properties 格式的配置檔案,具體查詢方式如下:

  1. 檢查“ log4j.configurationFile”系統屬性,如果有,嘗試使用與副檔名匹配的ConfigurationFactory載入配置。
  2. 如果未設定系統屬性,則屬性 ConfigurationFactory 將在類路徑中查詢 log4j2-test.properties。
  3. 如果找不到此類檔案,則 YAML ConfigurationFactory將在類路徑中查詢 log4j2-test.yaml或log4j2-test.yml。
  4. 如果找不到此類檔案,則 JSON ConfigurationFactory 將在類路徑中查詢 log4j2-test.json或log4j2-test.jsn。
  5. 如果找不到這樣的檔案,XML ConfigurationFactory 將在類路徑中查詢 log4j2-test.xml。
  6. 如果找不到測試檔案,則屬性 ConfigurationFactory 將在類路徑上查詢 log4j2.properties。
  7. 如果找不到屬性檔案,則 YAML ConfigurationFactory 將在類路徑上查詢 log4j2.yaml或log4j2.yml。
  8. 如果無法找到 YAML 檔案,則 JSON ConfigurationFactory 將在類路徑上查詢 log4j2.json或log4j2.jsn。
  9. 如果無法找到 JSON 檔案,則 XML ConfigurationFactory 將嘗試在類路徑上找到 log4j2.xml。
  10. 如果找不到配置檔案,使用 DefaultConfiguration 自動配置,將日誌輸出到控制檯。

這段更長的文字當然也不用看,我們就把 log4j2.xml 放入 Classpath 根目錄就可以了

log4j2 配置檔案編寫

log4j 也是 Logger 與 Appender 配置項,也有一個ROOT的特殊 Logger,Appender 比logback支援更多輸出位置,如kafka、Cassandra、Flume等。

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="debug" strict="true">
    <!--  定義變數,可以被${xxx}引用  -->
    <Properties>
        <Property name="baseDir">logs</Property>
    </Properties>

    <!--  定義 Appenders 用來指定輸出位置 -->
    <Appenders>
        <!-- 日誌滾動 $${date:yyyy-MM}:按月滾動資料夾 按小時、檔案序號滾動,每次滾動都使用gz壓縮 -->
        <RollingFile name="RollingFile" fileName="${baseDir}/log.log"
                     filePattern="${baseDir}/$${date:yyyy-MM}/log-%d{yyyy-MM-dd-HH}-%i.log.gz">
            <!-- 日誌格式 -->
            <PatternLayout pattern="%d %p %c{1.} [%t] %m%n"/>
            <Policies>
                <!-- 時間滾動(按月滾動目錄,按小時滾動檔案) -->
                <TimeBasedTriggeringPolicy/>
                <!-- 檔案大小滾動(1小時內超過250M,強制滾動一次) -->
                <SizeBasedTriggeringPolicy size="250 MB"/>
            </Policies>
            <!-- 每天最多100個檔案 -->
            <DefaultRolloverStrategy max="100">
                <!-- 刪除策略,超過三十天刪除,如果總檔案小於100G,檔案數量小於10個,則不會被刪除 -->
                <Delete basePath="${baseDir}" maxDepth="2">
                    <IfFileName glob="*/app-*.log.gz">
                        <IfLastModified age="30d">
                            <IfAny>
                                <IfAccumulatedFileSize exceeds="100 GB"/>
                                <IfAccumulatedFileCount exceeds="10"/>
                            </IfAny>
                        </IfLastModified>
                    </IfFileName>
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>
    </Appenders>

    <Loggers>
        <!-- 多個logger -->
        <Logger name="org.apache.logging.log4j.test2" level="debug" additivity="false">
            <AppenderRef ref="RollingFile"/>
        </Logger>

        <!-- 一個ROOT -->
        <Root level="trace">
            <AppenderRef ref="STDOUT"/>
        </Root>
    </Loggers>
</Configuration>
複製程式碼

可以看得出 log4j2 與 logback 配置檔案書寫大同小異,甚至同樣需要注意additivity="true"時導致的日誌重複輸出問題,畢竟 log4j1 與 logback 都是 Ceki大神都作品。

總結

得益於 Ceki 大佬的努力,日誌使用幾乎沒有有差異(Logback 與 Log4j2,Google 於 2018年4月開源了流式(fluent)日誌框架 Flogger,Slf4j 也將在 2.0 版本支援,而 log4j2 再次落後,不過筆者認為 log4j2 有很多優點,更多內容請關注後續文章)。關於日誌如何輸出本人也是經驗之談,免不了紕漏,歡迎補充指正,另外每個公司都有不同的應用場景,具體應該遵守公司統一規範。

本篇更多傾向基礎使用,接下來的文章將展開對比、原理以及擴充套件日誌框架,敬請各位小夥伴們期待。

本文相關程式碼

如果覺得寫的不錯,求關注、求點贊、求轉發,如果有問題或者文中有錯誤,歡迎留言討論。

掃描關注公眾號,第一時間獲得更新

掃碼關注

參考

logging.apache.org/log4j/2.x/m…

logback.qos.ch/manual/conf…

相關文章