一文搞懂Java日志級別，重復記錄、丟日志問題

1 新手村試煉

1.1 框架煩多！

不同類庫可能使用不同日志框架，兼容難！

1.2 配置復雜

由于配置文件煩雜！很多同學喜歡從其他項目或網上直接閉眼復制一份。

1.3 隨意度高

因為不會直接導致代碼 bug，測試人員也難及時發現問題，開發就沒仔細考慮日志內容獲取的性能開銷、隨意選用日志級別。

2 SLF4J

Logback、Log4j、Log4j2、commons-logging、JDK自帶的java.util.logging等，都是Java體系的日志框架。

不同的類庫，還可能選擇使用不同的日志框架，導致日志統一管理困難。

SLF4J（Simple Logging Facade For Java）就為解決該問題

提供統一的日志門面API，即圖中紫色部分，實現中立的日志記錄API

橋接功能，藍色部分，把各種日志框架API（綠色部分）橋接到SLF4J API。這樣即便你的程序中使用各種日志API記錄日志，最終都可橋接到SLF4J門面API。

適配功能，紅色部分，可實現SLF4J API和實際日志框架（灰色部分）綁定。

SLF4J只是日志標準，還是需要實際日志框架。日志框架本身未實現SLF4J API，所以需前置轉換。Logback就是按SLF4J API標準實現，所以才無需綁定模塊做轉換。

雖然可用log4j-over-slf4j實現Log4j橋接到SLF4J，也可使用slf4j-log4j12實現SLF4J適配到Log4j，也把它們畫到了一列，但是它不能同時使用它們，否則就會產生死循環。jcl和jul同理。

雖然圖中有4個灰色的日志實現框架，但日常業務使用最多的還是Logback和Log4j，都是同一人開發的。Logback可認為是Log4j改進版，更推薦使用，基本已是主流。

Spring Boot的日志框架也是Logback。那為什么我們沒有手動引入Logback包，就可直接使用Logback？

spring-boot-starter模塊依賴spring-boot-starter-logging模塊

spring-boot-starter-logging模塊自動引入logback-classic（包含SLF4J和Logback日志框架）和SLF4J的一些適配器。其中，log4j-to-slf4j用于實現Log4j2 API到SLF4J的橋接，jul-to-slf4j則是實現java.util.logging API到SLF4J的橋接。

4 異步日志提高性能?

知道了到底如何正確將日志輸出到文件后，就該考慮如何避免日志記錄成為系統性能瓶頸。這可解決，磁盤（比如機械磁盤）IO性能較差、日志量又很大的情況下，如何記錄日志問題。

定義如下的日志配置，一共有兩個Appender：

FILE是一個FileAppender，用于記錄所有的日志；

CONSOLE是一個ConsoleAppender，用于記錄帶有time標記的日志。

把大量日志輸出到文件中，日志文件會非常大，如果性能測試結果也混在其中的話，就很難找到那條日志。所以，這里使用EvaluatorFilter對日志按照標記進行過濾，并將過濾出的日志單獨輸出到控制臺上。該案例中給輸出測試結果的那條日志上做了time標記。

配合使用標記和EvaluatorFilter，實現日志的按標簽過濾。

測試代碼：實現記錄指定次數的大日志，每條日志包含1MB字節的模擬數據，最后記錄一條以time為標記的方法執行耗時日志：

執行程序后可以看到，記錄1000次日志和10000次日志的調用耗時，分別是5.1秒和39秒

對只記錄文件日志的代碼，這耗時過長。

源碼解析

FileAppender繼承自OutputStreamAppender

在追加日志時，是直接把日志寫入OutputStream中，屬同步記錄日志

所以日志大量寫入才會曠日持久。如何才能實現大量日志寫入時，不會過多影響業務邏輯執行耗時而影響吞吐量呢？

AsyncAppender

使用Logback的AsyncAppender

即可實現異步日志記錄。AsyncAppender類似裝飾模式，在不改變類原有基本功能情況下為其增添新功能。這便可把AsyncAppender附加在其他Appender，將其變為異步。

定義一個異步Appender ASYNCFILE，包裝之前的同步文件日志記錄的FileAppender， 即可實現異步記錄日志到文件

記錄1000次日志和10000次日志的調用耗時，分別是537毫秒和1019毫秒

異步日志真的如此高性能？并不，因為這并沒有記錄下所有日志。

AsyncAppender異步日志坑

記錄異步日志撐爆內存

記錄異步日志出現日志丟失

記錄異步日志出現阻塞。

案例

模擬慢日志記錄場景：

首先，自定義一個繼承自ConsoleAppender的MySlowAppender，作為記錄到控制臺的輸出器，寫入日志時休眠1秒。

配置文件中使用AsyncAppender，將MySlowAppender包裝為異步日志記錄

測試代碼

耗時很短但出現日志丟失：要記錄1000條日志，最終控制臺只能搜索到215條日志，而且日志行號變問號。

原因分析

AsyncAppender提供了一些配置參數，而當前沒用對。

源碼解析

includeCallerData

默認false：方法行號、方法名等信息不顯示

queueSize

控制阻塞隊列大小，使用的ArrayBlockingQueue阻塞隊列，默認容量256：內存中最多保存256條日志

discardingThreshold

丟棄日志的閾值，為防止隊列滿后發生阻塞。默認隊列剩余容量 ＜ 隊列長度的20%，就會丟棄TRACE、DEBUG和INFO級日志

neverBlock

控制隊列滿時，加入的數據是否直接丟棄，不會阻塞等待，默認是false

隊列滿時：offer不阻塞，而put會阻塞

neverBlock為true時，使用offer

public class AsyncAppender extends AsyncAppenderBase { // 是否收集調用方數據 boolean includeCallerData = false; protected boolean isDiscardable(ILoggingEvent event) { Level level = event.getLevel(); // 丟棄 ≤ INFO級日志 return level.toInt() <= Level.INFO_INT; } protected void preprocess(ILoggingEvent eventObject) { eventObject.prepareForDeferredProcessing(); if (includeCallerData) eventObject.getCallerData(); } } public class AsyncAppenderBase extends UnsynchronizedAppenderBase implements AppenderAttachable { // 阻塞隊列：實現異步日志的核心 BlockingQueue blockingQueue; // 默認隊列大小 public static final int DEFAULT_QUEUE_SIZE = 256; int queueSize = DEFAULT_QUEUE_SIZE; static final int UNDEFINED = -1; int discardingThreshold = UNDEFINED; // 當隊列滿時：加入數據時是否直接丟棄，不會阻塞等待 boolean neverBlock = false; @Override public void start() { ... blockingQueue = new ArrayBlockingQueue(queueSize); if (discardingThreshold == UNDEFINED) //默認丟棄閾值是隊列剩余量低于隊列長度的20%，參見isQueueBelowDiscardingThreshold方法 discardingThreshold = queueSize / 5; ... } @Override protected void append(E eventObject) { if (isQueueBelowDiscardingThreshold() && isDiscardable(eventObject)) { //判斷是否可以丟數據 return; } preprocess(eventObject); put(eventObject); } private boolean isQueueBelowDiscardingThreshold() { return (blockingQueue.remainingCapacity() < discardingThreshold); } private void put(E eventObject) { if (neverBlock) { //根據neverBlock決定使用不阻塞的offer還是阻塞的put方法 blockingQueue.offer(eventObject); } else { putUninterruptibly(eventObject); } } //以阻塞方式添加數據到隊列 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(); } } } }

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

22

23

24

25

26

27

28

29

30

31

32

33

34

35

36

37

38

39

40

41

42

43

44

45

46

47

48

49

50

51

52

53

54

55

56

57

58

59

60

61

62

63

64

65

66

67

68

69

70

71

72

73

74

75

默認隊列大小256，達到80%后開始丟棄<=INFO級日志后，即可理解日志中為什么只有兩百多條INFO日志了。

queueSize 過大

可能導致OOM

queueSize 較小

默認值256就已經算很小了，且discardingThreshold設置為大于0（或為默認值），隊列剩余容量少于discardingThreshold的配置就會丟棄<=INFO日志。這里的坑點有兩個：

因為discardingThreshold，所以設置queueSize時容易踩坑。

比如本案例最大日志并發1000，即便置queueSize為1000，同樣會導致日志丟失

discardingThreshold參數容易有歧義，它不是百分比，而是日志條數。對于總容量10000隊列，若希望隊列剩余容量少于1000時丟棄，需配置為1000

neverBlock 默認false

意味總可能會出現阻塞。

若discardingThreshold = 0，那么隊列滿時再有日志寫入就會阻塞

若discardingThreshold != 0，也只丟棄≤INFO級日志，出現大量錯誤日志時，還是會阻塞

queueSize、discardingThreshold和neverBlock三參密不可分，務必按業務需求設置：

若優先絕對性能，設置neverBlock = true，永不阻塞

若優先絕不丟數據，設置discardingThreshold = 0，即使≤INFO級日志也不會丟。但最好把queueSize設置大一點，畢竟默認的queueSize顯然太小，太容易阻塞。

若兼顧，可丟棄不重要日志，把queueSize設置大點，再設置合理的discardingThreshold

以上日志配置最常見兩個誤區

再看日志記錄本身的誤區。

使用日志占位符就無需判斷日志級別?

SLF4J的{}占位符語法，到真正記錄日志時才會獲取實際參數，因此解決了日志數據獲取的性能問題。

這說法對嗎？

驗證代碼：返回結果耗時1秒

若記錄DEBUG日志，并設置只記錄>=INFO級日志，程序是否也會耗時1秒？

三種方法測試：

拼接字符串方式記錄slowString

使用占位符方式記錄slowString

先判斷日志級別是否啟用DEBUG。

前倆方式都調用slowString，所以都耗時1s。且方式二就是使用占位符記錄slowString，這種方式雖允許傳Object，不顯式拼接String，但也只是延遲（若日志不記錄那就是省去）日志參數對象.toString()和字符串拼接的耗時。

本案例除非事先判斷日志級別，否則必調用slowString。

所以使用{}占位符不能通過延遲參數值獲取，來解決日志數據獲取的性能問題。

除事先判斷日志級別，還可通過lambda表達式延遲參數內容獲取。但SLF4J的API還不支持lambda，因此需使用Log4j2日志API，把Lombok的@Slf4j注解替換為**@Log4j2**注解，即可提供lambda表達式參數的方法：

這樣調用debug，簽名Supplier，參數就會延遲到真正需要記錄日志時再獲取：

所以debug4并不會調用slowString方法

只是換成Log4j2 API，真正的日志記錄還是走的Logback，這就是SLF4J適配的好處。

總結

SLF4J統一了Java日志框架。在使用SLF4J時，要理清楚其橋接API和綁定。若程序啟動時出現SLF4J錯誤提示，那可能是配置問題，可使用Maven的dependency:tree命令梳理依賴關系。

異步日志解決性能問題，是用空間換時間。但空間畢竟有限，當空間滿，要考慮阻塞等待or丟棄日志。如果更希望不丟棄重要日志，那么選擇阻塞等待；如果更希望程序不要因為日志記錄而阻塞，那么就需要丟棄日志。

日志框架提供的參數化日志記錄方式不能完全取代日志級別判斷。若你的日志量很大，獲取日志參數代價也很大，就要判斷日志級別，避免不記錄日志也要耗時獲取日志參數。

API Java

版權聲明：本文內容由網絡用戶投稿，版權歸原作者所有，本站不擁有其著作權，亦不承擔相應法律責任。如果您發現本站中有涉嫌抄襲或描述失實的內容，請聯系我們jiasou666@gmail.com 處理，核實后本網站將在24小時內刪除侵權內容。