概覽
各位小夥伴大家好,我又回來更新了,上一篇我們討論了為什麼要使用日誌框架,這次我們深入問題的根源,為什麼我們需要日誌,日誌具體如何使用?
大多數開發人員會糾結日誌該怎麼輸出,什麼時候輸出,輸出了會不會有人看等問題,讓我們跳出開發人員的局限來考慮這個問題:誰需要日誌?日誌有幾種?日誌都需要輸出什麼?如何輸出日誌?
誰需要日誌?
- 開發者 開發人員在開發過程中需要輸出一些變量方便調試,正確的做法是使用日誌來輸出(使用 System.out來輸出,一不小心發布到線上,會被項目經理痛批);其次線上問題很難重放,用戶的表述一般都會失真,況且很多用戶發現 bug 就刪 app 關網頁走人了
- 運維人員 整個系統大部分時間都是運維人員來維護,日誌可以幫助運維人員來了解系統狀態(很多運維繫統接入的也是日誌),運維人員發現日誌有異常信息也可以及時通知開發來排查
- 運營人員 沒錯,就是運營人員,比如電商的轉化率、視頻網站的完播率、普通PV數據等都可以通過日誌進行統計,隨著大數據技術的普及,這部分日誌占比也越來越高
- 安全人員 雖然大多數企業不重視安全,但是安全也可以通過日誌來進行預警,比如某個用戶突然大額轉帳、再比如資料庫突然出現大量無條件分頁查庫(拖庫)等等
日誌有幾種?
- 調試日誌 用於開發人員開發或者線上回溯問題。
- 診斷日誌 一般用於運維人員監控系統與安全人員分析預警。
- 埋點日誌 一般用於運營決策分析,也有用作微服務調用鏈路追蹤的(運維、調試)。
- 審計日誌 與診斷日誌類似,診斷日誌偏向運維,審計日誌偏向安全。
日誌都需要輸出什麼?
註:日誌級別會在下面講解
- 調試日誌 DEBUG 或者 TRACE 級別,比如方法調用參數,網絡連接具體信息,一般是開發者調試程序使用,線上非特殊情況關閉這些日誌 INFO 級別,一般是比較重要卻沒有風險的信息,如初始化環境、參數,清理環境,定時任務執行,遠程調用第一次連接成功 WARN 級別,有可能有風險又不影響系統繼續執行的錯誤,比如系統參數配置不正確,用戶請求的參數不正確(要輸出具體參數方便排查),或者某些耗性能的場景,比如一次請求執行太久、一條 SQL 執行超過兩秒,某些第三方調用失敗,不太可能被運行的if分支等 ERROR 級別,用於程序出錯列印堆棧信息,不應該用於輸出程序問題之外的其他信息,需要注意列印了日誌異常(Exception)就不應該拋(throw)了
- 診斷日誌 一般輸出 INFO 級別,請求響應時間,內存占用等等,線上接入監控系統時打開,建議輸出到獨立的文件,可以考慮 JSON 格式方便外部工具分析
- 埋點日誌 業務按需定製,比如上文提到的轉化率可以在用戶付款時輸出日誌,完播率可以在用戶播放完成後請求一次後台輸出日誌,一般可輸出 INFO 級別,建議輸出到獨立的文件,可以考慮JSON格式方便外部工具分析
- 審計日誌 大多 WARN 級別或者 INFO 級別,一般是敏感操作即可輸出,登陸、轉帳付款、授權消權、刪除等等,建議輸出到獨立的文件,可以考慮JSON格式方便外部工具分析
一般調試日誌由開發者自定義輸出,其他三種應該根據實際業務需求來定製。
日誌的其他注意點
- 線上日誌應儘量謹慎,要思考:這個位置輸出日誌能幫助排除問題嗎?輸出的信息與排查問題相關嗎?輸出的信息足夠排除問題嗎?做到不少輸出必要信息,不多輸出無用信息(拖慢系統,淹沒有用信息)
- 超級 SessionId 與 RequestId,無論是單體應用還是微服務架構,應該為每個用戶每次登陸生成一個超級 SessionId,方便跟蹤區分一個用戶;RequestId,每次請求生成一個 RequestId,用於跟蹤一次請求,微服務也可以用於鏈路追蹤
- 日誌要儘量單行輸出,一條日誌輸出一行,否則不方便閱讀以及其他第三方系統或者工具分析
- 公司內部應該制定一套通用的日誌規範,包括日誌的格式,變量名(駝峰、下劃線),分隔符(「=」或「:」等),何時輸出(比如規定調用第三方前後輸出INFO日誌),公司的日誌規範應該不斷優化、調整,找到適合公司業務的最佳規範
OK,理論就聊到這裡,接下來讓我們回到技術層面。
使用概念
如果要想要學會使用日誌框架,先要理解幾個簡單概念,Logger、Appenders、Layout、日誌級別與級別繼承(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 查找配置文件位置規則如下(後續文章會講如何修改位置)
- logback 嘗試在類路徑中找到一個名為 logback-test.xml 的文件。
- 如果找不到此類文件,則 logback 會嘗試在類路徑中找到名為 logback.groovy 的文件。
- 如果找不到這樣的文件,它將在類路徑中檢查文件 logback.xml。
- 如果找不到此類文件,則通過查找文件 META-INF\services\ch.qos.logback.classic.spi.Configurator,如果有這個文件且內容是 com.qos.logback.classic.spi.Configurator 實現類的全類名,直接加載這個實現類。
- 如果以上方法均不能成功執行,則 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就不在此展開了,具體可以參考
- logback:logback.qos.ch/manual/layo…
- log4j:logging.apache.org/log4j/2.x/m…
log4j2 配置文件位置
log4j2 支持 XML、JSON、YAML 或者 properties 格式的配置文件,具體查找方式如下:
- 檢查「 log4j.configurationFile」系統屬性,如果有,嘗試使用與文件擴展名匹配的ConfigurationFactory加載配置。
- 如果未設置系統屬性,則屬性 ConfigurationFactory 將在類路徑中查找 log4j2-test.properties。
- 如果找不到此類文件,則 YAML ConfigurationFactory將在類路徑中查找 log4j2-test.yaml或log4j2-test.yml。
- 如果找不到此類文件,則 JSON ConfigurationFactory 將在類路徑中查找 log4j2-test.json或log4j2-test.jsn。
- 如果找不到這樣的文件,XML ConfigurationFactory 將在類路徑中查找 log4j2-test.xml。
- 如果找不到測試文件,則屬性 ConfigurationFactory 將在類路徑上查找 log4j2.properties。
- 如果找不到屬性文件,則 YAML ConfigurationFactory 將在類路徑上查找 log4j2.yaml或log4j2.yml。
- 如果無法找到 YAML 文件,則 JSON ConfigurationFactory 將在類路徑上查找 log4j2.json或log4j2.jsn。
- 如果無法找到 JSON 文件,則 XML ConfigurationFactory 將嘗試在類路徑上找到 log4j2.xml。
- 如果找不到配置文件,使用 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 有很多優點,更多內容請關注後續文章)。關於日誌如何輸出本人也是經驗之談,免不了紕漏,歡迎補充指正,另外每個公司都有不同的應用場景,具體應該遵守公司統一規範。
本篇更多傾向基礎使用,接下來的文章將展開對比、原理以及擴展日誌框架,敬請各位小夥伴們期待。
作者:雞員外連結:https://juejin.im/post/5e1472776fb9a047f42e659c