小編給大家分享一下如何解決Java日志級(jí)別,重復(fù)記錄、丟日志的問題,相信大部分人都還不怎么了解,因此分享這篇文章給大家參考一下,希望大家閱讀完這篇文章后大有收獲,下面讓我們一起去了解一下吧!
成都創(chuàng)新互聯(lián)主營(yíng)尚志網(wǎng)站建設(shè)的網(wǎng)絡(luò)公司,主營(yíng)網(wǎng)站建設(shè)方案,重慶APP開發(fā)公司,尚志h5微信小程序搭建,尚志網(wǎng)站營(yíng)銷推廣歡迎尚志等地區(qū)企業(yè)咨詢
不同類庫(kù)可能使用不同日志框架,兼容是個(gè)難題
日志配置文件通常很繁雜,很多同學(xué)習(xí)慣從其他項(xiàng)目或網(wǎng)上博客直接復(fù)制份配置文件,但卻不仔細(xì)研究如何修改。常見錯(cuò)誤發(fā)生于重復(fù)記錄日志、同步日志的性能、異步記錄的錯(cuò)誤配置。
比如沒考慮到日志內(nèi)容獲取的代價(jià)、胡亂使用日志級(jí)別等。
Logback、Log4j、Log4j2、commons-logging、JDK自帶的java.util.logging等,都是Java體系的日志框架,確實(shí)非常多。而不同的類庫(kù),還可能選擇使用不同的日志框架。這樣一來,日志的統(tǒng)一管理就變得非常困難。
SLF4J(Simple Logging Facade For Java)就為解決該問題
提供統(tǒng)一的日志門面API,即圖中紫色部分,實(shí)現(xiàn)中立的日志記錄API
橋接功能,藍(lán)色部分,把各種日志框架API(綠色部分)橋接到SLF4J API。這樣即便你的程序中使用各種日志API記錄日志,最終都可橋接到SLF4J門面API。
適配功能,紅色部分,可實(shí)現(xiàn)SLF4J API和實(shí)際日志框架(灰色部分)綁定。
SLF4J只是日志標(biāo)準(zhǔn),還是需要實(shí)際日志框架。日志框架本身未實(shí)現(xiàn)SLF4J API,所以需前置轉(zhuǎn)換。Logback就是按SLF4J API標(biāo)準(zhǔn)實(shí)現(xiàn),所以才無需綁定模塊做轉(zhuǎn)換。
雖然可用log4j-over-slf4j
實(shí)現(xiàn)Log4j橋接到SLF4J,也可使用slf4j-log4j12
實(shí)現(xiàn)SLF4J適配到Log4j,也把它們畫到了一列,但是它不能同時(shí)使用它們,否則就會(huì)產(chǎn)生死循環(huán)。jcl和jul同理。
雖然圖中有4個(gè)灰色的日志實(shí)現(xiàn)框架,但日常業(yè)務(wù)使用最多的還是Logback和Log4j,都是同一人開發(fā)的。Logback可認(rèn)為是Log4j改進(jìn)版,更推薦使用,基本已是主流。
Spring Boot的日志框架也是Logback。那為什么我們沒有手動(dòng)引入Logback包,就可直接使用Logback?
spring-boot-starter模塊依賴spring-boot-starter-logging模塊
spring-boot-starter-logging模塊自動(dòng)引入logback-classic(包含SLF4J和Logback日志框架)和SLF4J的一些適配器。其中,log4j-to-slf4j用于實(shí)現(xiàn)Log4j2 API到SLF4J的橋接,jul-to-slf4j則是實(shí)現(xiàn)java.util.logging API到SLF4J的橋接。
日志重復(fù)記錄不但給查看日志和統(tǒng)計(jì)工作帶來不必要的麻煩,還會(huì)增加磁盤和日志收集系統(tǒng)的負(fù)擔(dān)。
定義一個(gè)方法實(shí)現(xiàn)debug、info、warn和error四種日志的記錄
Logback配置
配置看沒啥問題,執(zhí)行方法后出現(xiàn)日志重復(fù)記錄
分析
CONSOLE這個(gè)Appender同時(shí)掛載到了倆Logger,定義的
和
,由于定義的
繼承自
,所以同一條日志既會(huì)通過logger記錄,也會(huì)發(fā)送到root記錄,因此應(yīng)用package下日志出現(xiàn)重復(fù)記錄。
如此配置的初衷是啥呢?
內(nèi)心是想實(shí)現(xiàn)自定義logger配置,讓應(yīng)用內(nèi)的日志暫時(shí)開啟DEBUG級(jí)別日志記錄。其實(shí),這無需重復(fù)掛載Appender,去掉
下掛載的Appender即可:
若自定義
需把日志輸出到不同Appender:
比如
應(yīng)用日志輸出到文件app.log
其他框架日志輸出到控制臺(tái)
可設(shè)置
的additivity屬性為false,這就不會(huì)繼承
的Appender
在記錄日志到控制臺(tái)的同時(shí),把日志記錄按照不同級(jí)別記錄到倆文件
執(zhí)行結(jié)果
info.log 文件包含INFO、WARN和ERROR三級(jí)日志,不符預(yù)期
error.log包含WARN和ERROR倆級(jí)別日志,導(dǎo)致日志重復(fù)收集
事故問責(zé)
一些公司使用自動(dòng)化ELK方案收集日志,日志會(huì)同時(shí)輸出到控制臺(tái)和文件,開發(fā)人員在本地測(cè)試不會(huì)關(guān)心文件中記錄的日志,而在測(cè)試和生產(chǎn)環(huán)境又因?yàn)殚_發(fā)人員沒有服務(wù)器訪問權(quán)限,所以原始日志文件中的重復(fù)問題難以發(fā)現(xiàn)。
日志到底為何重復(fù)呢?
當(dāng)日志級(jí)別 ≥ 配置級(jí)別
返回NEUTRAL,繼續(xù)調(diào)用過濾器鏈上的下個(gè)過濾器
否則返回DENY,直接拒絕記錄日志
該案例我們將 ThresholdFilter置 WARN,因此可記錄WARN和ERROR級(jí)日志。
用于比較日志級(jí)別,然后進(jìn)行相應(yīng)處理。
若匹配就調(diào)用onMatch定義的處理方式:默認(rèn)交給下一個(gè)過濾器處理(AbstractMatcherFilter基類中定義的默認(rèn)值)
否則調(diào)用onMismatch定義的處理方式:默認(rèn)也是交給下一個(gè)過濾器
和ThresholdFilter不同,LevelFilter僅配置level無法真正起作用
。
由于未配置onMatch和onMismatch屬性,所以該過濾器失效,導(dǎo)致INFO以上級(jí)別日志都記錄了。
配置LevelFilter的onMatch屬性為ACCEPT,表示接收INFO級(jí)別的日志;配置onMismatch屬性為DENY,表示除了INFO級(jí)別都不記錄:
如此,_info.log
文件只會(huì)有INFO級(jí)日志,不會(huì)再出現(xiàn)日志重復(fù)。
知道了到底如何正確將日志輸出到文件后,就該考慮如何避免日志記錄成為系統(tǒng)性能瓶頸。這可解決,磁盤(比如機(jī)械磁盤)IO性能較差、日志量又很大的情況下,如何記錄日志問題。
定義如下的日志配置,一共有兩個(gè)Appender:
FILE是一個(gè)FileAppender,用于記錄所有的日志;
CONSOLE是一個(gè)ConsoleAppender,用于記錄帶有time標(biāo)記的日志。
把大量日志輸出到文件中,日志文件會(huì)非常大,如果性能測(cè)試結(jié)果也混在其中的話,就很難找到那條日志。所以,這里使用EvaluatorFilter對(duì)日志按照標(biāo)記進(jìn)行過濾,并將過濾出的日志單獨(dú)輸出到控制臺(tái)上。該案例中給輸出測(cè)試結(jié)果的那條日志上做了time標(biāo)記。
配合使用標(biāo)記和EvaluatorFilter,實(shí)現(xiàn)日志的按標(biāo)簽過濾。
測(cè)試代碼:實(shí)現(xiàn)記錄指定次數(shù)的大日志,每條日志包含1MB字節(jié)的模擬數(shù)據(jù),最后記錄一條以time為標(biāo)記的方法執(zhí)行耗時(shí)日志:
執(zhí)行程序后可以看到,記錄1000次日志和10000次日志的調(diào)用耗時(shí),分別是5.1秒和39秒
對(duì)只記錄文件日志的代碼,這耗時(shí)過長(zhǎng)。
FileAppender繼承自O(shè)utputStreamAppender
在追加日志時(shí),是直接把日志寫入OutputStream中,屬同步記錄日志
所以日志大量寫入才會(huì)曠日持久。如何才能實(shí)現(xiàn)大量日志寫入時(shí),不會(huì)過多影響業(yè)務(wù)邏輯執(zhí)行耗時(shí)而影響吞吐量呢?
使用Logback的AsyncAppender
即可實(shí)現(xiàn)異步日志記錄。AsyncAppender類似裝飾模式,在不改變類原有基本功能情況下為其增添新功能。這便可把AsyncAppender附加在其他Appender,將其變?yōu)楫惒健?/p>
定義一個(gè)異步Appender ASYNCFILE,包裝之前的同步文件日志記錄的FileAppender, 即可實(shí)現(xiàn)異步記錄日志到文件
記錄1000次日志和10000次日志的調(diào)用耗時(shí),分別是537毫秒和1019毫秒
異步日志真的如此高性能?并不,因?yàn)檫@并沒有記錄下所有日志。
記錄異步日志撐爆內(nèi)存
記錄異步日志出現(xiàn)日志丟失
記錄異步日志出現(xiàn)阻塞。
模擬慢日志記錄場(chǎng)景:
首先,自定義一個(gè)繼承自ConsoleAppender的MySlowAppender,作為記錄到控制臺(tái)的輸出器,寫入日志時(shí)休眠1秒。
配置文件中使用AsyncAppender,將MySlowAppender包裝為異步日志記錄
測(cè)試代碼
耗時(shí)很短但出現(xiàn)日志丟失:要記錄1000條日志,最終控制臺(tái)只能搜索到215條日志,而且日志行號(hào)變問號(hào)。
原因分析
AsyncAppender提供了一些配置參數(shù),而當(dāng)前沒用對(duì)。
includeCallerData
默認(rèn)false:方法行號(hào)、方法名等信息不顯示
queueSize
控制阻塞隊(duì)列大小,使用的ArrayBlockingQueue阻塞隊(duì)列,默認(rèn)容量256:內(nèi)存中最多保存256條日志
discardingThreshold
丟棄日志的閾值,為防止隊(duì)列滿后發(fā)生阻塞。默認(rèn)隊(duì)列剩余容量 < 隊(duì)列長(zhǎng)度的20%
,就會(huì)丟棄TRACE、DEBUG和INFO級(jí)日志
neverBlock
控制隊(duì)列滿時(shí),加入的數(shù)據(jù)是否直接丟棄,不會(huì)阻塞等待,默認(rèn)是false
隊(duì)列滿時(shí):offer不阻塞,而put會(huì)阻塞
neverBlock為true時(shí),使用offer
public class AsyncAppender extends AsyncAppenderBase{ // 是否收集調(diào)用方數(shù)據(jù) boolean includeCallerData = false; protected boolean isDiscardable(ILoggingEvent event) { Level level = event.getLevel(); // 丟棄 ≤ INFO級(jí)日志 return level.toInt() <= Level.INFO_INT; } protected void preprocess(ILoggingEvent eventObject) { eventObject.prepareForDeferredProcessing(); if (includeCallerData) eventObject.getCallerData(); }}public class AsyncAppenderBase extends UnsynchronizedAppenderBase implements AppenderAttachable { // 阻塞隊(duì)列:實(shí)現(xiàn)異步日志的核心 BlockingQueue blockingQueue; // 默認(rèn)隊(duì)列大小 public static final int DEFAULT_QUEUE_SIZE = 256; int queueSize = DEFAULT_QUEUE_SIZE; static final int UNDEFINED = -1; int discardingThreshold = UNDEFINED; // 當(dāng)隊(duì)列滿時(shí):加入數(shù)據(jù)時(shí)是否直接丟棄,不會(huì)阻塞等待 boolean neverBlock = false; @Override public void start() { ... blockingQueue = new ArrayBlockingQueue (queueSize); if (discardingThreshold == UNDEFINED) //默認(rèn)丟棄閾值是隊(duì)列剩余量低于隊(duì)列長(zhǎng)度的20%,參見isQueueBelowDiscardingThreshold方法 discardingThreshold = queueSize / 5; ... } @Override protected void append(E eventObject) { if (isQueueBelowDiscardingThreshold() && isDiscardable(eventObject)) { //判斷是否可以丟數(shù)據(jù) return; } preprocess(eventObject); put(eventObject); } private boolean isQueueBelowDiscardingThreshold() { return (blockingQueue.remainingCapacity() < discardingThreshold); } private void put(E eventObject) { if (neverBlock) { //根據(jù)neverBlock決定使用不阻塞的offer還是阻塞的put方法 blockingQueue.offer(eventObject); } else { putUninterruptibly(eventObject); } } //以阻塞方式添加數(shù)據(jù)到隊(duì)列 private void putUninterruptibly(E eventObject) { boolean interrupted = false; try { while (true) { try { blockingQueue.put(eventObject); break; } catch (InterruptedException e) { interrupted = true; } } } finally { if (interrupted) { Thread.currentThread().interrupt(); } } }}
默認(rèn)隊(duì)列大小256,達(dá)到80%后開始丟棄<=INFO級(jí)日志后,即可理解日志中為什么只有兩百多條INFO日志了。
可能導(dǎo)致OOM
默認(rèn)值256就已經(jīng)算很小了,且discardingThreshold設(shè)置為大于0(或?yàn)槟J(rèn)值),隊(duì)列剩余容量少于discardingThreshold的配置就會(huì)丟棄<=INFO日志。這里的坑點(diǎn)有兩個(gè):
因?yàn)?strong>discardingThreshold,所以設(shè)置queueSize時(shí)容易踩坑。
比如本案例最大日志并發(fā)1000,即便置queueSize為1000,同樣會(huì)導(dǎo)致日志丟失
discardingThreshold參數(shù)容易有歧義,它不是百分比,而是日志條數(shù)
。對(duì)于總?cè)萘?0000隊(duì)列,若希望隊(duì)列剩余容量少于1000時(shí)丟棄,需配置為1000
意味總可能會(huì)出現(xiàn)阻塞。
若discardingThreshold = 0,那么隊(duì)列滿時(shí)再有日志寫入就會(huì)阻塞
若discardingThreshold != 0,也只丟棄≤INFO級(jí)日志,出現(xiàn)大量錯(cuò)誤日志時(shí),還是會(huì)阻塞
queueSize、discardingThreshold和neverBlock三參密不可分,務(wù)必按業(yè)務(wù)需求設(shè)置:
若優(yōu)先絕對(duì)性能,設(shè)置neverBlock = true
,永不阻塞
若優(yōu)先絕不丟數(shù)據(jù),設(shè)置discardingThreshold = 0
,即使≤INFO級(jí)日志也不會(huì)丟。但最好把queueSize設(shè)置大一點(diǎn),畢竟默認(rèn)的queueSize顯然太小,太容易阻塞。
若兼顧,可丟棄不重要日志,把queueSize設(shè)置大點(diǎn),再設(shè)置合理的discardingThreshold
以上日志配置最常見兩個(gè)誤區(qū)
再看日志記錄本身的誤區(qū)。
SLF4J的{}占位符語法,到真正記錄日志時(shí)才會(huì)獲取實(shí)際參數(shù),因此解決了日志數(shù)據(jù)獲取的性能問題。
這說法對(duì)嗎?
驗(yàn)證代碼:返回結(jié)果耗時(shí)1秒
若記錄DEBUG日志,并設(shè)置只記錄>=INFO級(jí)日志,程序是否也會(huì)耗時(shí)1秒?
三種方法測(cè)試:
拼接字符串方式記錄slowString
使用占位符方式記錄slowString
先判斷日志級(jí)別是否啟用DEBUG。
前倆方式都調(diào)用slowString,所以都耗時(shí)1s。且方式二就是使用占位符記錄slowString,這種方式雖允許傳Object,不顯式拼接String,但也只是延遲(若日志不記錄那就是省去)日志參數(shù)對(duì)象.toString()和字符串拼接的耗時(shí)。
本案例除非事先判斷日志級(jí)別,否則必調(diào)用slowString。
所以使用{}占位符
不能通過延遲參數(shù)值獲取,來解決日志數(shù)據(jù)獲取的性能問題。
除事先判斷日志級(jí)別,還可通過lambda表達(dá)式延遲參數(shù)內(nèi)容獲取。但SLF4J的API還不支持lambda,因此需使用Log4j2日志API,把Lombok的@Slf4j注解替換為**@Log4j2**注解,即可提供lambda表達(dá)式參數(shù)的方法:
這樣調(diào)用debug,簽名Supplier>,參數(shù)就會(huì)延遲到真正需要記錄日志時(shí)再獲?。?br/>
所以debug4并不會(huì)調(diào)用slowString方法
只是換成Log4j2 API,真正的日志記錄還是走的Logback,這就是SLF4J適配的好處。
SLF4J統(tǒng)一了Java日志框架。在使用SLF4J時(shí),要理清楚其橋接API和綁定。若程序啟動(dòng)時(shí)出現(xiàn)SLF4J錯(cuò)誤提示,那可能是配置問題,可使用Maven的dependency:tree命令梳理依賴關(guān)系。
異步日志解決性能問題,是用空間換時(shí)間。但空間畢竟有限,當(dāng)空間滿,要考慮阻塞等待or丟棄日志。如果更希望不丟棄重要日志,那么選擇阻塞等待;如果更希望程序不要因?yàn)槿罩居涗浂枞?,那么就需要丟棄日志。
日志框架提供的參數(shù)化日志記錄方式不能完全取代日志級(jí)別判斷。若你的日志量很大,獲取日志參數(shù)代價(jià)也很大,就要判斷日志級(jí)別,避免不記錄日志也要耗時(shí)獲取日志參數(shù)。
以上是“如何解決Java日志級(jí)別,重復(fù)記錄、丟日志的問題”這篇文章的所有內(nèi)容,感謝各位的閱讀!相信大家都有了一定的了解,希望分享的內(nèi)容對(duì)大家有所幫助,如果還想學(xué)習(xí)更多知識(shí),歡迎關(guān)注創(chuàng)新互聯(lián)行業(yè)資訊頻道!