1. 本文檔目的
幫助不熟悉Logback的同學(xué)欢唾,合理配置、使用Logback粉捻,提升日志打印性能礁遣,降低冗余日志的打印肩刃;
規(guī)范各項(xiàng)目的日志打铀罨簟;
2. Logback 生產(chǎn)配置文件推薦
2.1 生產(chǎn)環(huán)境日志配置
- 用在測(cè)試呢燥、灰度垂谢、線上環(huán)境;
- 采用異步 appender 提升性能疮茄;
- error 和 dubbo 日志單獨(dú)打永闹臁;
<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="false" debug="false">
<!-- 配置文件中可以被引用的屬性力试,value 值推薦通過(guò) maven 打包時(shí)替換 -->
<property name="LOG_HOME" value="${log.sys.path}"/>
<property name="LOG_LEVEL" value="${log.sys.level}"/>
<!-- 根日志:這個(gè)文件是全部所有的日志內(nèi)容 -->
<appender name="rootAllFile" class="ch.qos.logback.core.rolling.RollingFileAppender">
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<FileNamePattern>${LOG_HOME}/root.%d{yyyy-MM-dd}.%i.log</FileNamePattern>
<maxHistory>30</maxHistory>
<totalSizeCap>500GB</totalSizeCap>
<!-- 按時(shí)間回滾的同時(shí)徙邻,按文件大小來(lái)回滾 -->
<timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
<maxFileSize>1GB</maxFileSize>
</timeBasedFileNamingAndTriggeringPolicy>
</rollingPolicy>
<encoder>
<pattern>
[%level] [%thread] [%d{yyyy-MM-dd HH:mm:ss.SSS}] [%mdc{traceid}] [%mdc{jdb_traceid}] [%logger{0}] [%msg]%n
</pattern>
</encoder>
</appender>
<!-- error 日志單獨(dú)輸出,上線重點(diǎn)關(guān)注這個(gè)文件的日志 -->
<appender name="errorFile" class="ch.qos.logback.core.rolling.RollingFileAppender">
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<FileNamePattern>${LOG_HOME}/error.%d{yyyy-MM-dd}.%i.log</FileNamePattern>
<maxHistory>30</maxHistory>
<totalSizeCap>500GB</totalSizeCap>
<!-- 按時(shí)間回滾的同時(shí)畸裳,按文件大小來(lái)回滾 -->
<timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
<maxFileSize>1GB</maxFileSize>
</timeBasedFileNamingAndTriggeringPolicy>
</rollingPolicy>
<encoder>
<pattern>
[%level] [%thread] [%d{yyyy-MM-dd HH:mm:ss.SSS}] [%mdc{traceid}] [%mdc{jdb_traceid}] [%logger] [%msg]%n
</pattern>
</encoder>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>
</appender>
<!-- 告警日志,可以提供告警工具缰犁,監(jiān)控這個(gè)文件來(lái)發(fā)送告警信息 -->
<appender name="alarmFile" class="ch.qos.logback.core.rolling.RollingFileAppender">
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<FileNamePattern>${LOG_HOME}/monitor/alarm.%d{yyyy-MM-dd}.log</FileNamePattern>
<maxHistory>30</maxHistory>
<totalSizeCap>50GB</totalSizeCap>
</rollingPolicy>
<encoder>
<pattern>
[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%mdc{traceid}] [%msg]%n
</pattern>
</encoder>
</appender>
<!-- dubbo 日志,要多注意怖糊,某個(gè)服務(wù)出現(xiàn)問題 dubbo 框架日志會(huì)打印到這里帅容,如超時(shí) -->
<appender name="rpcFile" class="ch.qos.logback.core.rolling.RollingFileAppender">
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<FileNamePattern>${LOG_HOME}/rpc.%d{yyyy-MM-dd}.log</FileNamePattern>
<maxHistory>30</maxHistory>
<totalSizeCap>50GB</totalSizeCap>
</rollingPolicy>
<encoder>
<pattern>
[%level] [%thread] [%mdc{traceid}] [%d{yyyy-MM-dd HH:mm:ss.SSS}] [%logger] [%msg]%n
</pattern>
</encoder>
</appender>
<!-- 用來(lái)提升異步性能的appender -->
<!--<appender name="asyncRootAppender" class="ch.qos.logback.classic.AsyncAppender">-->
<!--<!– 不丟棄日志,最大長(zhǎng)度設(shè)置為 2048 –>-->
<!--<discardingThreshold>0</discardingThreshold>-->
<!--<queueSize>2048</queueSize>-->
<!--<appender-ref ref="rootAllFile"/>-->
<!--</appender>-->
<!-- 注意 additivity 決定了是否累加 appender -->
<logger name="rpc-event" level="WARN" additivity="false">
<appender-ref ref="rpcFile"/>
</logger>
<logger name="com.jiupai.pay.commons.log.monitor.MonitorLog">
<appender-ref ref="alarmFile"/>
</logger>
<root level="${LOG_LEVEL}">
<!-- 異步 appender 性能提升的同時(shí)有一些問題需要注意 -->
<!-- 如果不能接受這些問題伍伤,改為 rootAllFile 通過(guò)減少日志等方式提升性能 -->
<!--<appender-ref ref="asyncRootAppender"/>-->
<appender-ref ref="rootAllFile"/>
<appender-ref ref="errorFile"/>
</root>
</configuration>
2.2 開發(fā)環(huán)境的日志配置
- 用在本地做調(diào)試的日志配置并徘;
- 為避免沖突把變量放到 local-ip.properties 中比較合適;
<?xml version="1.0" encoding="UTF-8"?>
<!-- 每分鐘自動(dòng)掃描下配置變化扰魂,并且打印 logback 內(nèi)部的日志信息 -->
<configuration scan="true" debug="${log.logback.debug}">
<!-- 打印到控制臺(tái)的標(biāo)準(zhǔn)輸出麦乞,WEB 環(huán)境下就是輸出到 catalina.out 文件中 -->
<appender name="stdoutAppender" class="ch.qos.logback.core.ConsoleAppender">
<target>System.out</target>
<encoder>
<pattern>[%p][%d{yyyy-MM-dd HH:mm:ss}][%X{traceid}][%X{user_name}][%X{interface}][%c %L][%m]%n</pattern>
</encoder>
</appender>
<root level="${log.sys.level}">
<appender-ref ref="stdoutAppender"/>
</root>
</configuration>
3.日志打印規(guī)約
日志打印應(yīng)遵循如下原則:
- 避免打印冗余日志:同樣的日志輸出多次,類似信息輸出多次劝评;
- 避免打印不易查詢和統(tǒng)計(jì)的日志:RD 應(yīng)善于利用 AWK姐直、SED、CUT蒋畜、WC 等函數(shù)声畏,打印的日志應(yīng)利于日志的分析、統(tǒng)計(jì)姻成、查詢:
- 避免打印“無(wú)效”的日志:日志的目的是方便 RD 觀察插龄、分析程序運(yùn)行情況愿棋,不利于此目的的日志應(yīng)避免打印或優(yōu)化輸出:
本地開發(fā)調(diào)試時(shí)使用 開發(fā)的 logback 配置辫狼;
將 logback 的日志級(jí)別放到 pom 或?qū)傩晕募谐醢撸?Maven 根據(jù)環(huán)境打包辛润;
禁止將生產(chǎn)日志設(shè)置為 DEBUG 或修改其配置膨处;
LoggerFactory.getLogger(Class clazz) ;
僅依賴 SLF4J API砂竖,不要依賴 Commons-Logging API真椿;
getLogger時(shí)僅傳遞類名字;
正例:Logger logger = LoggerFactory.getLogger(UserService.class);
反例:Logger logger = LoggerFactory.getLogger("userService");
非正常流程的日志如 catch 塊浙于、不期望的兼容處理:使用 Warn 及以上級(jí)別打印方法护盈;
正常流程作為程序診斷參考,留痕參考羞酗,證明程序正確性的日志:使用 Info 級(jí)別腐宋,并盡量使用 logger.info(String format, Object... arguments) 這個(gè)方法重載;
異常日志要打印異常棧檀轨,注意打印異常棧胸竞,提示消息的格式化不能依賴 Logback ,使用 logger.error(String msg, Throwable t) 重載方法:
DEBUG 日志盡量使用 logger.debug(String format, Object... arguments) 参萄;
正例:
try{
logger.debug("|UserUpdate|更新用戶信息|userInfo = [{}]",userInfo);
int x = userDao.update(userInfo);
if(x != 1){
logger.warn("|UserUpdate|用戶信息未更新成功,做兼容處理|x = [{}]",x);
// 兼容更新失敗邏輯
.....
}
logger.info("|UserUpdate|用戶信息更新完成|userInfo = [{}]|",userInfo);
}catch(Exception e){
logger.error("|UserUpdate|用戶信息更新失敗|msg = [" + e.getMessage() + "]|", e);
}
反例:
try{
// 和正確的版本比卫枝,有30倍的性能差讹挎,盡量不要這么用。
logger.debug("|UserUpdate|更新用戶信息|userInfo = [{" + userInfo + "}]");
int x = userDao.update(userInfo);
if(x != 1){
// 異常不期望日志淤袜,應(yīng)該是 warn 或者 error
logger.info("|UserUpdate|用戶信息未更新成功,做兼容處理|x = [{" + x + "}]");
// 兼容更新失敗邏輯
.....
}
// 正常期望日志,不要用 warn
logger.wan("|UserUpdate|用戶信息更新完成|userInfo = [{}]|",userInfo);
}catch(Exception e){
// 這個(gè) API 無(wú)法打印出異常棧
logger.error("|UserUpdate|用戶信息更新失敗|msg = [{}]|", e.getMessage ,e);
}
給每類日志添加一個(gè)可方便統(tǒng)計(jì)的 key 串(推薦英文)崇摄;
項(xiàng)目成員約定:日志提示信息采用中文還是英文并維持一套擎值;
變量輸出推薦:使用中括號(hào)包裹,包裹時(shí)不加空格逐抑,方便區(qū)分變量輸出的是空格鸠儿、空串、null串厕氨;
正例:
logger.info("|EnterpRegCtrl|引擎處理開始|enterpInfo = [{}]|",enterpInfo);
int engineRs = doInvokeEngine(enterpInfo);
String engineMsg = getEngineMsg(engineRs);
logger.info("|EnterpRegCtrl|引擎結(jié)束|engineRs = [{}]|engineMsg = [{}]|",engineRs,engineMsg);
反例:
logger.info("risk engine begin process",enterpInfo);
int engineRs = doInvokeEngine(enterpInfo);
String engineMsg = getEngineMsg(engineRs);
logger.info("引擎結(jié)束 , engineMsg : {} , engineRs = {}",engineRs,engineMsg);
維持當(dāng)前項(xiàng)目 logback 版本,無(wú)統(tǒng)一升級(jí)指令命斧,不升級(jí)田晚;
當(dāng)前部分代碼直接依賴了 logback 的API,升級(jí)可能導(dǎo)致奇怪問題冯丙。
4. Linux 下的日志分析
4.1 常用分析命令
日志查詢和瀏覽命令
- tail:查詢?nèi)罩疚募┪踩罩救馔撸S脜?shù)
-f / -xxf : 循環(huán)讀取,用來(lái)監(jiān)控日志胃惜; - grep:查詢符合條件的日志
-A [N] : 顯示符合條件的日志及后面 N 行日志泞莉;
-B [N] : 顯示符合條件的日志及前面 N 行日志;
-C [n] : 顯示符合條件的日志及前后 N 行日志船殉;
-v [msg] : 排查掉符合條件的日志不顯示鲫趁; - cat:查看日志全部?jī)?nèi)容
-n / -b : 顯示行號(hào)
日志分割和統(tǒng)計(jì)命令: - awk:強(qiáng)大的日志分析工具,三兩句話無(wú)法解釋利虫;
-F : 指定分割符挨厚; - cut:按行切分日志;
-d -f : 指定切分符糠惫,-d 和 -f 疫剃; - wc:統(tǒng)計(jì)文本字符數(shù)和行數(shù)
-l : 統(tǒng)計(jì)一共有多少行;
以上命令的參數(shù)大小寫敏感硼讽,僅列出常用參數(shù)和選項(xiàng)巢价,更多的還是需要系統(tǒng)性自學(xué)和應(yīng)用。
4.2 查詢并過(guò)濾日志
查詢符合條件的日志
- 基于 traceId 的查詢,推薦: grep -A 可以顯示錯(cuò)誤棧壤躲;
- 基于自己的日志 key 的查詢城菊,推薦先統(tǒng)計(jì)行數(shù)再顯示;
例子
## 知道符合條件的日志不多碉克,如有異常5行可以顯示
grep -A 5 "<日志ID>" 文件
## 看下符合條件的行數(shù)凌唬,如果太多不要直接顯示了
grep -A 10 "<關(guān)鍵字>" 文件 | wc -l
## 修改關(guān)鍵字或排除一些內(nèi)容看行數(shù)
grep -A 10 "<關(guān)鍵字>" 文件 | grep -v "<要排除的日志>" | wc -l
## 觀察關(guān)系的日志
tail -f 文件 | grep -C 10 "<關(guān)鍵字>"
4.3 統(tǒng)計(jì)某類日志
- 使用 wc -l 做簡(jiǎn)單行數(shù)統(tǒng)計(jì)客税;
- 使用 awk 做復(fù)雜的統(tǒng)計(jì)霎挟;
## 統(tǒng)計(jì)類日志出現(xiàn)次數(shù)麻掸,先確認(rèn)下統(tǒng)計(jì)內(nèi)容
grep "<關(guān)鍵字>" 文件 | head -n 10
## 統(tǒng)計(jì)出現(xiàn)次數(shù)
grep "<關(guān)鍵字>" 文件 | wc -l
## 對(duì)某日志中變量做累加統(tǒng)計(jì)脊奋,
## 每行的日志模式:[%level] [%thread] [%d{yyyy-MM-dd HH:mm:ss.SSS}] [%mdc{traceid}] [%mdc{jdb_traceid}] [%msg]%n
## %msg 的格式為 |MQConsumer|ReceiveSuccess|ifSuccess = [true]|Key = [T_PAYRISK_URC_5f800c4ddad84ab4a939ed54dd5389c3]|
## 1. 先找打符合條件的日志
## 2. 按照固定模式分割诚隙,以中括號(hào)切分久又,%msg 是第14列
## 3. 按照豎線切分地消,可以打印或統(tǒng)計(jì) ifSuccess 的次數(shù)脉执,下面是打印
awk -F '[\]\[\]' '{print $14}' a.log | awk -F '|' '{print $4}'
4.4 按照行來(lái)定位日志
常用來(lái)查詢異常半夷,知道發(fā)生了異常迅细,然后看具體異常棧
## 找到符合條件的日志和行號(hào)
cat -n <文件名稱> | grep "<關(guān)鍵字>"
## 記下行號(hào)茵典,假設(shè)上面的行發(fā)生在 m 行, 那么顯示 m 的前后50行日志
cat -n <文件名> | tail +<m-50> | head -n 100
5. 需要了解的一些基本知識(shí)點(diǎn)
Logback 官網(wǎng)有200多頁(yè)文檔贴浙,對(duì) Logback 有很全面的介紹崎溃,推薦閱讀:
5.1 Appender 的累加性 和 Logger 的繼承
- Logback 的 Appender 表示日志的輸出方向盯质,每一個(gè) appender 表示輸出到一個(gè)文件呼巷、控制臺(tái)等王悍,每一個(gè) logger 可以有 0 到多個(gè) Appender。
- Appender 是累加的鲜漩,Logger 是有繼承關(guān)系的孕似,使用類名作為 logger 的 name喉祭,logger 就有很明顯的繼承層次雷绢。如以 com.jiupai.pay 命名的 logger 是所有以此前綴為 name 的 logger 的 parent习寸。
- 所有 logger 都有 root logger 就是配置文件的 root 節(jié)點(diǎn)代表的 logger霞溪。 logger 會(huì)從 parent 繼承 appender 并做累計(jì)。如 root logger 有一個(gè) appender 寫入到 console坊饶。
- 這個(gè)時(shí)候再指定 com.jiupai.pay 這個(gè) logger 的 appender 到一個(gè)文件匿级,則每條 com.jiupai.pay logger 都會(huì)分別寫入到 console 和 file 中痘绎,日志會(huì)重復(fù)輸出兩次。
- 每個(gè) logger 可以有多個(gè) appender 尔苦,如 root logger 指定兩個(gè) appender : file 和 console 允坚,則每條日志都會(huì)寫入到兩次稠项。
- 因此展运,配置 logback 時(shí)一定要注意是否需要指定多個(gè) appender 乐疆,以及每個(gè) logger 實(shí)際會(huì)有幾個(gè) appender贬养。
5.2 異步 Appender 的潛在問題
一般的 Appender 是同步寫入的误算,并且默認(rèn)每一次 logger.info("需要寫入的日志信息"); 調(diào)用都會(huì)發(fā)生一次 IO 操作儿礼,對(duì)于本地文件的寫入庆寺,一般耗時(shí)在 30 微秒左右。
logback 的 AsyncAppender 實(shí)際上就是創(chuàng)建了一個(gè) BlockingQueue 知纷,當(dāng)日志寫入請(qǐng)求(log event)到來(lái)時(shí)琅轧,將這個(gè)請(qǐng)求 push 到 BlockingQueue 中乍桂。
因此 AsyncAppender 的異步會(huì)有如下幾個(gè)問題:
- 如果需要打印的日志含有一些復(fù)雜對(duì)象睹酌,并且這個(gè)對(duì)象在接下來(lái)可能會(huì)變憋沿,那么打印的日志信息可能不準(zhǔn)確:
- 如果未正確關(guān)閉程序卤妒,logback 框架無(wú)法正常停止则披,則可能會(huì)丟失掉還在 BlockingQueue 的日志士复,導(dǎo)致日志輸出可能不全阱洪;
- 如果日志量過(guò)大冗荸,BlockingQueue 的長(zhǎng)度過(guò)大蚌本,內(nèi)存占用會(huì)很高舷嗡,甚至?xí)G掉無(wú)法 push 到隊(duì)列中的日志嵌莉,甚至性能下降锐峭。
public void doRegister(User user){
// 使用異步 appender 只祠,如果量很大抛寝,則這條日志很可能被丟掉熊杨;
logger.info("|UserRegister|用戶注冊(cè)|user = [{}]|",user);
// …… 做一些處理
user.setUserID("123");
// 再次輸出 信息桂躏,則第一次打印的 userId 可能也是 123剂习;
// 如果程序這個(gè)時(shí)候被kill 了鳞绕,則這個(gè)條日志還可能不會(huì)輸出;
logger.info(""|UserRegister|更新用戶信息|user = [{}]|",user");
}
5.3 何時(shí)選擇 AsyncAppender
AsyncAppender 有一些配置可以部分解決上述 4.2 提到的 異步 Appender 的潛在問題们何,但是這些配置應(yīng)該結(jié)合業(yè)務(wù)情況決定是否使用(否則 logback 肯定會(huì)把 AsyncAppender 作為首選推薦)。
壓測(cè)是參考非唯一標(biāo)準(zhǔn)
壓測(cè) QPS/TPS 上去了控轿,但是某些壓測(cè)無(wú)法觀察出上出異步 Appender 的問題冤竹;
考慮業(yè)務(wù)日志是否絕大部分都是輸出了基本類型變量
基本類型變量,Logback 做異步任務(wù)的時(shí)候是做了數(shù)據(jù)提取的(includeCallerData),這個(gè)時(shí)候可以少考慮日志輸出數(shù)據(jù)不準(zhǔn)確的潛在問題茬射;
考慮業(yè)務(wù)系統(tǒng)停機(jī)是否優(yōu)雅
如果業(yè)務(wù)系統(tǒng)集成各種框架不需要粗暴的 kill -9 操作鹦蠕,停機(jī)時(shí)丟失日志的風(fēng)險(xiǎn)不大;
考慮業(yè)務(wù)系統(tǒng)是否容忍上述日志問題
上述問題在抛,大部分系統(tǒng)是可以接受的钟病,且發(fā)生概率較小霜定;
如果非常擔(dān)心上述問題档悠,可以考慮為業(yè)務(wù)系統(tǒng)提供一個(gè)同步 logger ,部分場(chǎng)景需要同步打印可以使用同步 logger 打印日志。
異常日志不推薦異步輸出
首先,異常不是系統(tǒng)經(jīng)常發(fā)生的,壓測(cè)時(shí)也一樣,如果經(jīng)常需要打印肆糕,那需要考慮換一種代碼實(shí)現(xiàn)或日志打印級(jí)別(如warn)
其次始赎,異常應(yīng)和告警應(yīng)及時(shí) flush 到硬盤,方便問題查詢厕隧;
6. 選擇其他日志框架
6.1 面向門面編程
程序代碼要嚴(yán)格遵守:面向門面 SLF4J 的 API 編程建丧,即使使用代碼來(lái)初始化日志框架,也應(yīng)該盡量遵循面向接口編程原則,不要直接依賴日志框架 API。
6.2 Log4J
不推薦了,logback 明確是作為 log4j 的繼任者,重新了很多組件著蛙,性能更高暂吉,沒理由使用 log4j。
6.3 Log4J 2
具官網(wǎng)介紹,從原理分析,和部分實(shí)測(cè)擂红,Log4J 2 的性能確實(shí)別 logback 高变秦,但是 log4j 2 原理要比 logback 復(fù)雜,實(shí)際應(yīng)用穩(wěn)定性未知。