log.info("user logged in")看起來免費。其實不然。在這一行程式碼背後，是一連串的決策——要不要緩衝、要不要刷新、要阻塞還是丟棄、同一執行緒還是另一個——而每一個選擇都拿延遲、吞吐量與耐用性做交換。這篇文章將帶你走完整條鏈路，從方法呼叫一直到位元組寫入磁碟碟片。
如果你曾經好奇，為什麼你的 p99 延遲會莫名其妙地飆高、為什麼 crash 之後日誌會消失，或者「非同步日誌」究竟帶來了什麼好處，這篇文章就是為你而寫。
先畫張地圖：Facade 與 Implementation
Java 的日誌機制分成兩層，把這兩層搞混是造成困惑的最大來源。
Facade 是你程式碼呼叫的 API。Implementation 才是真正把位元組寫出去的那一層。
your code
│ log.info(...)
▼
┌───────────────────────────────┐
│ Facade: SLF4J (or Log4j2 API)│ ← 你編譯時依賴的介面
└──────────────┬────────────────┘
│ 執行期綁定
┌───────────┼────────────┬──────────────┐
▼ ▼ ▼ ▼
Logback Log4j2 Core java.util.logging ...
(the engine that buffers, formats, and flushes)
Enter fullscreen mode Exit fullscreen mode
- SLF4J — 事實上的標準 Facade。你的應用程式應該對這個介面做日誌。
- Logback — SLF4J 的參考實作。穩定且廣泛使用。
- Log4j2 — 以效能為導向的實作，以其無鎖的非同步 logger 聞名。
- java.util.logging (JUL) — 內建於 JDK，很少有人故意選擇它。
為什麼要分兩層？這樣你就可以在不改任何 log. 呼叫的情況下更換底層引擎。這篇文章中所有有趣的東西——緩衝、刷新、非同步魔法——都發生在 Implementation 層。
單次日誌呼叫的解剖
在討論刷新之前，我們先看看一次 log.info(...) 到底做了什麼。它有五個階段：
1. Level check → INFO 等級對這個 logger 是否啟用？（很便宜，通常是最快的退出點）
2. Build LogEvent → 擷取訊息、時間戳、執行緒、MDC 上下文，可能還有堆疊追蹤
3. Filter → 執行任何已設定的過濾器
4. Layout / encode → 把事件轉成位元組（例如 "2026-07-28 12:00:01 INFO ..."）
5. Append → 把這些位元組寫到目的地（檔案、控制台、socket）Enter fullscreen mode Exit fullscreen mode
第 5 階段——Append——正是同步與非同步、刷新與不刷新的分歧點。這也是最昂貴的階段，因為它可能會碰觸到磁碟。
小提醒：第 1 階段就是為什麼有時候會看到
if (log.isDebugEnabled())。當等級關閉時，它可以跳過第 2–5 階段。搭配現代的參數化日誌（log.debug("x={}", x)），框架會在真正建立字串之前就做檢查——所以log.debug("x=" + x)才是真正的反模式，因為字串串接不管等級是否開啟都會發生。
同步日誌：預設值，以及它隱藏的兩層緩衝
「同步」代表 append 發生在你的應用程式執行緒上。你的執行緒在 log.info(...) 回傳之前，不會結束等待。簡單、可預測——而所有的刷新細節就在這裡。
大多數人忽略的細微之處：在你的日誌陳述式與實際寫入磁碟之間，存在兩個獨立的緩衝區。
your app thread
│ writes formatted bytes
▼
┌─────────────────────┐
│ App-level buffer │ ← Appender 內的 BufferedOutputStream
│ (e.g. 4 KB) │ flush() 清空「這個」緩衝區
└──────────┬──────────┘
│ flush()
▼
┌─────────────────────┐
│ OS page cache │ ← 核心的快取，仍在 RAM 中
│ (kernel memory) │ fsync() 清空「這個」緩衝區
└──────────┬──────────┘
│ fsync()
▼
┌─────────────────────┐
│ Physical disk │ ← 現在它能在斷電後存活
└─────────────────────┘
Enter fullscreen mode Exit fullscreen mode
兩種不同的操作，清空兩個不同的緩衝區，而人們經常把它們搞混：
-
flush()把位元組從應用程式緩衝區推送到OS page cache。flush 之後，其他程序（例如tail -f）就能看到你的日誌行。但它仍然在 RAM 裡——核心當機或斷電還是會遺失。 -
fsync()（透過FileChannel.force()）強制 OS 把 page cache 寫到實體儲存裝置。這才是真正讓日誌行在 crash 後存活的操作——而且慢非常多。 大多數日誌框架只提供第一層緩衝區的控制項，預設基本上不會碰第二層。這就是隱藏在眼前的耐用性取捨。
immediateFlush：最重要的控制項
Logback 與 Log4j2 的檔案 appender 都提供 immediateFlush：
Logback：
<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<file>app.log</file>
<immediateFlush>true</immediateFlush> <!-- 預設：true -->
<encoder>
<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
Enter fullscreen mode Exit fullscreen mode
Log4j2：
<File name="FILE" fileName="app.log" immediateFlush="true">
<PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
</File>
Enter fullscreen mode Exit fullscreen mode
它的作用是：
-
immediateFlush=true（預設值）：每次日誌事件後都呼叫flush()。呼叫返回的瞬間，你的日誌行已經在 OS cache 裡。如果 JVM crash 仍然安全（OS 仍有這些位元組，之後會寫入）。但這也代表每行日誌都要一次系統呼叫——在高負載下會拖垮吞吐量。 -
immediateFlush=false：讓BufferedOutputStream累積到滿（通常 8 KB）才 flush。系統呼叫大幅減少，吞吐量大幅提升。代價是：如果 JVM 當掉，應用程式緩衝區裡最多 8 KB 的最新、最重要的日誌將永遠消失。 這就是同步刷新取捨的一句話總結：為了安全而每行都 flush，或者為了速度而做緩衝。
注意：Log4j2 會為其非同步 logger 自動套用
immediateFlush=false的行為——因為在非同步世界中，耐用性的解決方案不同（後續會說明）。
那麼同步日誌在 crash 時能存活嗎？
取決於哪一種 crash 以及哪一種 flush 設定：
| 失敗類型 | immediateFlush=true |
immediateFlush=false |
搭配 fsync |
|---|---|---|---|
| JVM crash（例外、OOM） | ✅ 安全（OS 有） | ⚠️ 遺失 app buffer | ✅ 安全 |
| kill -9 程序 | ✅ 安全（OS 有） | ⚠️ 遺失 app buffer | ✅ 安全 |
| OS 核心 panic | ❌ 遺失 page cache | ❌ 遺失更多 | ✅ 安全 |
| 斷電 | ❌ 遺失 page cache | ❌ 遺失更多 | ✅ 安全 |
幾乎沒有人會對每行日誌都做
fsync——它慢到令人痛苦（每次呼叫都要好幾毫秒）。日誌通常被視為「盡力而為的耐用性」，而這通常是正確的選擇。只是要清楚你實際得到的保證是什麼。
非同步日誌：讓 I/O 離開熱路徑
同步日誌真正的問題不在於正確性，而在於你的請求執行緒必須支付 I/O 代價。如果磁碟卡住、日誌輪轉停滯、或緩衝區在錯誤的時機 flush，那個延遲就會直接落在剛好在那一刻做日誌的使用者請求上。這是造成 p99 延遲神秘飆高的常見原因。
非同步日誌透過把日誌事件交給另一個執行緒、然後立即返回來解決這個問題：
app thread background thread
│ log.info(...) │
│──── enqueue event ────► [ queue ] │
│ returns instantly │──► format + write + flush
▼ ▼
keep serving the request does the slow I/O
Enter fullscreen mode Exit fullscreen mode
你的應用程式執行緒的工作縮小到「把事件丟進佇列然後繼續前進」。慢速的工作——格式化、寫入、刷新——發生在沒有人在等待的專用日誌執行緒上。
這個想法有兩種截然不同的實作，而差異就在於此。
版本 1：Logback / Log4j2 AsyncAppender（阻塞佇列）
這是經典做法：用一個真正的 appender 包在 async appender 裡面，後端使用 BlockingQueue（ArrayBlockingQueue）。
<!-- Logback -->
<appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
<queueSize>256</queueSize> <!-- 預設：256 -->
<discardingThreshold>51</discardingThreshold> <!-- 預設：queueSize 的 20% -->
<neverBlock>false</neverBlock> <!-- 預設：false -->
<appender-ref ref="FILE"/>
</appender>
Enter fullscreen mode Exit fullscreen mode
在壓力下決定其行為的三個控制項：
-
queueSize— 佇列能容納多少事件。越大越能吸收較大的突發流量，但會使用更多記憶體。 -
discardingThreshold— 當佇列達到這個滿度時，丟棄較低優先權的事件（TRACE/DEBUG/INFO），保留 WARN/ERROR。Logback 預設為剩餘 20%。設成0代表永不丟棄。 -
neverBlock— 當佇列完全滿時的處理方式：-
false（預設）：應用程式執行緒阻塞直到有空間。你保留每一筆日誌，但你重新引入了原本想避免的延遲——非同步在高負載下悄悄變回同步。 -
true：丟棄事件並繼續前進。延遲維持平穩，但突發時會遺失日誌。 這裡沒有免費的午餐。在持續過載下，有界佇列只有三種選擇：阻塞生產者、丟棄事件，或無限制成長（OOM）。每個非同步 logger 都只是在選擇何時做哪一種。
-
版本 2：Log4j2 Async Loggers（LMAX Disruptor）
Log4j2 的招牌功能是建構在 LMAX Disruptor 之上的 Async Loggers——這是一個源自高頻交易的無鎖環形緩衝區。這與阻塞佇列是完全不同的東西，也是 Log4j2 能在基準測試中表現如此激進的原因。
<!-- 讓所有 logger 都非同步（系統屬性） -->
<!-- -Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector -->
<!-- 或混合使用：特定 logger 非同步，其餘同步 -->
<AsyncLogger name="com.myapp" level="info"/>
<Root level="info">
<AppenderRef ref="FILE"/>
</Root>
Enter fullscreen mode Exit fullscreen mode
為什麼要用環形緩衝區而不是佇列？兩個原因：
1. 無鎖 = 無爭用。 BlockingQueue 使用鎖；當許多執行緒同時做日誌時，它們會爭奪這把鎖而序列化。Disruptor 使用預先配置的環形緩衝區與原子序列計數器（CAS）來取代鎖。生產者與消費者透過游標位置協調，而不是互斥。在高執行緒數量下，這就是差異所在——Log4j2 自己的數據顯示，async loggers 可以在阻塞佇列已經 plateau 的情況下，維持每秒數百萬筆訊息。
ring buffer (pre-allocated slots, reused forever)
┌───┬───┬───┬───┬───┬───┬───┬───┐
│ 5 │ 6 │ 7 │ │ │ 1 │ 2 │ 3 │
└───┴───┴───┴─▲─┴───┴───┴───┴─▲─┘
│ │
consumer cursor producer cursor
(writes to disk) (app threads publish here)
Enter fullscreen mode Exit fullscreen mode
2. 無垃圾。 環形緩衝區的 slot 只配置一次，並且重複使用。佇列則是每個事件都要配置一個新節點，增加垃圾收集器的負擔。Disruptor 預先配置，因此在穩態下幾乎不產生垃圾——這代表日誌不會造成 GC 停頓。Log4j2 搭配「無垃圾」版面配置模式，重用 StringBuilder 與緩衝區，讓你能在近乎零配置的情況下大量做日誌。
當環形緩衝區滿了會發生什麼？AsyncQueueFullPolicy
與之前相同的根本問題——有界緩衝區可能溢位——而 Log4j2 讓這個政策變得明確：
-
Default政策：生產執行緒阻塞（忙碌等待）直到有 slot 可用。不會遺失日誌，但反壓會影響你的應用程式執行緒。 -
Discard政策：滿時丟棄等級等於或低於設定等級的事件（預設：丟棄 INFO 及以下）。保持延遲平穩，遺失低優先權日誌。 - 你也可以插入自訂政策。 還有一個需要注意的尖銳邊緣：如果日誌呼叫發生在背景消費者執行緒本身（例如在 layout 或例外處理常式內做日誌），阻塞會造成死鎖——因此 Log4j2 會偵測到這種情況，並改走同步路徑。
耐用性的轉折：非同步可能遺失同步設定不會遺失的日誌
這是人們容易忘記的取捨。使用非同步日誌，當你的應用程式執行緒從 log.error("about to crash") 返回時，該事件只是靜靜地待在記憶體中的佇列裡。它尚未被格式化，更不用說寫入或刷新。
如果 JVM 在接下來的毫秒內 crash，那個解釋 crash 的錯誤日誌——就消失了。而在同步且 immediateFlush=true 的設定下，同一行日誌已經在 OS cache 裡，得以存活。
這就是非同步日誌的殘酷諷刺：它在你日誌量最大的時候最快，而那通常正是事情出錯之前。
因應措施：
-
關機勾點 / 優雅排空。 兩個框架都會嘗試在正常關機時排空佇列。這能處理乾淨的退出，但無法處理
kill -9或硬當機。 - 將嚴重錯誤同步記錄。 常見模式：INFO/DEBUG 使用非同步，但 ERROR/FATAL 走同步且 immediate-flush 的 appender，確保重要資訊是耐用的。
- 接受遺失。 對於高流量、低價值的日誌（存取日誌、除錯追蹤），在硬當機時遺失最後幾百筆是可以接受的。把保證等級與日誌的價值配對。
給它們數字（以及基準測試的陷阱）
從慢到快的粗略吞吐量排序：
sync + immediateFlush=true ▓▓ (每行一次系統呼叫)
sync + immediateFlush=false ▓▓▓▓▓▓ (有緩衝)
async AsyncAppender (queue) ▓▓▓▓▓▓▓▓▓▓
async Loggers (Disruptor) ▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓
Enter fullscreen mode Exit fullscreen mode
但是——每個誠實的基準測試都會告訴你——你的實際結果會有很大差異，因為：
- 尖峰吞吐量與持續吞吐量是不同的問題。 非同步很擅長吸收突發流量。但你的磁碟真實寫入頻寬是硬天花板。如果你持續產生的日誌量超過磁碟能排出的量，佇列就會滿，非同步就會退化成它的滿載政策（阻塞或丟棄）。非同步並沒有讓你的磁碟變快——它只是把你的應用程式與磁碟的抖動解耦。
-
版面配置成本常常是真正的瓶頸。 帶有呼叫者位置資訊的複雜 pattern（
%class、%line、%method）會在每一行日誌上強制進行堆疊追蹤——這可能比寫入本身還昂貴。在熱路徑中避免位置資訊。 - 微基準測試會說謊。 在一個緊密的迴圈中做日誌、其他什麼都不跑，並不能反映真實應用程式中 GC、CPU 快取與其他執行緒都在競爭的狀況。 實際的 takeaway 不是一個數字，而是一棵決策樹。
實務決策指南
大多數服務的預設值：
非同步日誌（如果可以就用 Log4j2 Async Loggers，否則用 Logback AsyncAppender），搭配能吸收你典型突發流量的有界佇列，並在壓力下丟棄低優先權事件。
當你需要每一行日誌（稽核、合規、金融）：
同步 + immediateFlush=true。接受吞吐量損失；你買的是耐用性。只有在你真的不能在斷電時遺失資料時才加上 fsync——並且要知道它會讓你付出代價。
當延遲神聖不可侵犯（交易、即時系統）：
使用 Log4j2 Async Loggers 搭配無垃圾版面配置與丟棄政策——永遠不要讓日誌阻塞請求執行緒，也不要讓它觸發 GC。
涵蓋大多數人的穩健混合方案：
INFO/DEBUG → 非同步，壓力下丟棄 (高流量、低價值)
WARN/ERROR → 同步，immediateFlush=true (低流量、高價值)
Enter fullscreen mode Exit fullscreen mode
你為雜訊換取速度，為訊號換取耐用性。
真正需要記住的五件事
-
一次日誌呼叫下方有兩個緩衝區。
flush()清空應用程式緩衝區到 OS；fsync()清空 OS 到磁碟。它們不是同一件事，只有第二個能在斷電後存活。 -
immediateFlush是同步的核心控制項。true= 安全但每行一次系統呼叫；false= 快速但在 crash 時遺失應用程式緩衝區。 - 非同步把 I/O 從請求執行緒移開——消除了延遲抖動——但每一個有界佇列在持續過載下最終都必須阻塞、丟棄，或 OOM。要知道你的實作選擇了哪一種。
- Disruptor 的勝利來自無鎖與無垃圾，而不是魔法。它在高執行緒數量下打敗阻塞佇列，並避免 GC 停頓。
- 非同步拿耐用性換速度。 解釋你 crash 的那行日誌，最有可能在佇列中遺失。把關鍵日誌走同步路徑。 日誌感覺像是你程式碼中最無聊的一行。它也是少數同時悄悄觸及並行、記憶體階層、系統呼叫、GC 與耐用性的程式碼之一。現在你知道那行程式碼真正做了什麼。🚀 ---
你的日誌設定是同步且安全，還是非同步且快速？而「非同步日誌吃掉我的 crash log」這種事，有沒有發生在你身上？歡迎在留言區告訴我。
0 Comments
Log in to join the conversation.No comments yet. Be the first to share your thoughts.