log.info("user logged in")看起来免费，其实不然。这一行背后是一连串决策——缓冲与否、刷新与否、阻塞或丢弃、同线程或另一线程——每一项都在 延迟、吞吐量 和 持久性 之间权衡。本文从方法调用一直讲到字节落盘。
如果你曾想知道为什么 p99 延迟会出现神秘尖峰、为什么日志会在崩溃后消失，或“异步日志”到底带来了什么，这篇文章就是为你准备的。
首先看全景：外观层 vs 实现层
Java 日志是双层蛋糕，混淆这两层是造成困惑的头号原因。
外观层 是你的代码调用的 API。实现层 是真正写字节的组件。
your code
│ log.info(...)
▼
┌───────────────────────────────┐
│ Facade: SLF4J (or Log4j2 API)│ ← 你编译时依赖的接口
└──────────────┬────────────────┘
│ 运行时绑定
┌───────────┼────────────┬──────────────┐
▼ ▼ ▼ ▼
Logback Log4j2 Core java.util.logging ...
（真正负责缓冲、格式化与刷新的引擎）
Enter fullscreen mode Exit fullscreen mode
- SLF4J — 事实上的外观层标准。你的应用应面向它打日志。
- Logback — SLF4J 的参考实现，稳健且广泛部署。
- Log4j2 — 性能导向的实现，以其无锁异步记录器闻名。
- java.util.logging (JUL) — JDK 内置，很少被有意选用。
为什么要拆分？这样你就可以在不改任何 log. 调用的前提下更换引擎。本文所有有趣的内容——缓冲、刷新、异步魔法——都发生在实现层。
一次日志调用的解剖
在讨论刷新之前，先看看 log.info(...) 到底做了什么。共有五个阶段：
1. 级别检查 → 此 logger 是否开启 INFO？（廉价，通常是最快的提前退出点）
2. 构建 LogEvent → 捕获消息、时间戳、线程、MDC 上下文，可能还有堆栈
3. 过滤 → 执行已配置的过滤器
4. 布局/编码 → 将事件转为字节（"2026-07-28 12:00:01 INFO ..."）
5. 追加 → 将字节写入目标（文件、控制台、套接字）Enter fullscreen mode Exit fullscreen mode
阶段 5——追加——正是同步/异步、刷新与否的舞台。它也是迄今为止最昂贵的阶段，因为它可能触及磁盘。
小技巧： 阶段 1 就是你有时看到
if (log.isDebugEnabled())的原因。当日志级别关闭时，它会跳过阶段 2–5。使用现代参数化日志（log.debug("x={}", x)）时，框架会在构建字符串前完成检查——而log.debug("x=" + x)才是真正的反模式，因为字符串拼接无论如何都会执行。
同步日志：默认方式及其隐藏的两个缓冲层
“同步”意味着追加发生在你的应用线程上。你的线程直到写入完成才会从 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。刷新后，其他进程（如tail -f）就能看到你的日志行。但它仍在 RAM 中——内核崩溃或掉电就会丢失。 -
fsync()（通过FileChannel.force()）强制 OS 将页缓存写入物理存储。这才是真正让日志行在崩溃后幸存的操作——而且慢得多。 大多数日志框架只提供针对第一层缓冲的开关，默认情况下基本不碰第二层。这就是隐藏在眼前的持久性权衡。
那么同步日志能在崩溃后幸存吗？
取决于哪种崩溃和哪种刷新设置：
| 故障类型 | immediateFlush=true |
immediateFlush=false |
使用 fsync |
|---|---|---|---|
| JVM 崩溃（异常、OOM） | ✅ 安全（OS 持有） | ⚠️ 丢失应用缓冲 | ✅ 安全 |
| kill -9 进程 | ✅ 安全（OS 持有） | ⚠️ 丢失应用缓冲 | ✅ 安全 |
| OS 内核崩溃 | ❌ 丢失页缓存 | ❌ 丢失更多 | ✅ 安全 |
| 掉电 | ❌ 丢失页缓存 | ❌ 丢失更多 | ✅ 安全 |
几乎没人会对每行日志做
fsync——它慢得令人发指（每次调用毫秒级）。日志通常被视为“尽力而为的持久化”，这通常是正确的选择。只要清楚你实际得到的保障即可。
异步日志：让请求线程脱离热路径
同步日志真正的问题不是正确性，而是你的请求线程承担 I/O 代价。如果磁盘卡顿、日志滚动阻塞、缓冲在错误时机刷新，那笔延迟就会直接落在恰好在那刻记录日志的用户请求上。这正是神秘 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
你的应用线程只需“把事件丢进队列然后继续”。真正慢的工作——格式化、写入、刷新——发生在没人等待的专用日志线程上。
这个思路有两种截然不同的实现，而差异正是全部关键。
方案一：Logback / Log4j2 AsyncAppender（阻塞队列）
这是经典做法：用一个基于 BlockingQueue（ArrayBlockingQueue）的异步 appender 包裹真实 appender。
<!-- Logback -->
<appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
<queueSize>256</queueSize> <!-- default: 256 -->
<discardingThreshold>51</discardingThreshold> <!-- default: 20% of queueSize -->
<neverBlock>false</neverBlock> <!-- default: 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）。每个异步记录器只是选择在何时做哪一种。
-
方案二：Log4j2 Async Loggers（LMAX Disruptor）
Log4j2 的招牌特性是Async Loggers，构建于LMAX Disruptor——一个源自高频交易的无锁环形缓冲。这与阻塞队列是完全不同的东西，也是 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 自己的数据表明，异步记录器可在阻塞队列已达瓶颈时维持数百万条消息/秒。
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. 无垃圾。 环形缓冲的槽位一次性分配并永久复用。队列为每个事件分配新节点，会喂垃圾回收器。Disruptor 预分配，因此在稳态下几乎不产生垃圾——这意味着日志不会引起 GC 停顿。Log4j2 还搭配“无垃圾”布局模式，复用 StringBuilder 和缓冲区，让你能近乎零分配地狂打日志。
环形缓冲满时会发生什么？AsyncQueueFullPolicy
与之前相同的基本问题——有界缓冲可能溢出——Log4j2 把策略明确化：
-
Default策略：生产线程阻塞（忙等/等待）直到有空位。没有日志丢失，但反压会击中应用线程。 -
Discard策略：满时丢弃配置级别及以下的事件（默认丢弃 INFO 及以下）。保持延迟平稳，丢失低优先级日志。 - 你也可以插入自定义策略。 还有一个值得注意的尖锐边界：如果日志调用发生在后台消费者线程本身（例如在布局或异常处理器内部打日志），阻塞会导致死锁——因此 Log4j2 会检测到并改走同步路径。
持久性反转：异步可能丢失同步方案不会丢失的日志
这是人们容易忘记的权衡。使用异步日志，当你的应用线程从 log.error("about to crash") 返回时，该事件只是静静地躺在内存中的队列里。它尚未被格式化，更不用说写入或刷新。
如果 JVM 在下一毫秒崩溃，那条解释崩溃的错误日志——就没了。而在同步 immediateFlush=true 的日志中，同一行早已在 OS 缓存中并得以幸存。
这就是异步日志的残酷讽刺：它在你打日志最多的时候最快，而那往往正是出问题的前一刻。
缓解措施：
-
关闭钩子 / 优雅排空。 两个框架都会在正常关闭时尝试排空队列。这能处理干净退出，但无法应对
kill -9或硬崩溃。 - 致命错误走同步。 常见模式：INFO/DEBUG 用异步，但 ERROR/FATAL 走同步、立即刷新的 appender，确保重要内容持久。
- 接受损失。 对于高流量、低价值日志（访问日志、调试跟踪），硬崩溃时丢失最后几百条是可以接受的。让保障与日志价值匹配。
量化一下（以及基准测试的陷阱）
吞吐量从慢到快的粗略排序：
sync + immediateFlush=true ▓▓ (每行一次 syscall)
sync + immediateFlush=false ▓▓▓▓▓▓ (已缓冲)
async AsyncAppender (queue) ▓▓▓▓▓▓▓▓▓▓
async Loggers (Disruptor) ▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓
Enter fullscreen mode Exit fullscreen mode
但是——每份诚实的基准测试都会指出——你的实际表现差异极大，因为：
- 峰值吞吐与持续吞吐是两个问题。 异步非常擅长吸收突发。但磁盘真正的写入带宽是硬天花板。如果你持续产生的日志量超过磁盘能排出的速度，队列就会填满，异步会退化为其满策略（阻塞或丢弃）。异步并不会让你的磁盘变快——它只是把你的应用与磁盘的抖动解耦。
-
布局成本往往才是真正的瓶颈。 带调用位置（
%class、%line、%method）的复杂 pattern 会强制对每行日志做堆栈遍历——这可能比写入本身更贵。在热路径上避免位置信息。 - 微基准会撒谎。 在空循环中打日志无法反映真实应用中 GC、CPU 缓存和其他线程都在竞争的场景。 实际的收获不是一个数字，而是一棵决策树。
实用决策指南
大多数服务的默认选择：
异步日志（能用 Log4j2 Async Loggers，否则用 Logback AsyncAppender），队列大小设为能吸收典型突发，并在压力下丢弃低优先级事件。
当你需要每一行日志（审计、合规、金融）时：
同步 + immediateFlush=true。接受吞吐量损失；你在购买持久性。只有在真正无法承受掉电丢数据时才加 fsync——并清楚它会让你付出代价。
当延迟神圣不可侵犯（交易、实时）时：
Log4j2 Async Loggers + 无垃圾布局 + 丢弃策略——永远不要让日志阻塞请求线程，也永远不要让它触发 GC。
覆盖大多数人的稳健混合方案：
INFO/DEBUG → async, discard-under-pressure (高流量，低价值)
WARN/ERROR → sync, immediateFlush=true (低流量，高价值)
Enter fullscreen mode Exit fullscreen mode
你为噪音获得速度，为信号获得持久。
真正需要记住的五件事
-
一次日志调用下面有两个缓冲。
flush()清空应用缓冲到 OS；fsync()清空 OS 到磁盘。它们不是一回事，只有第二种能在掉电后幸存。 -
immediateFlush是同步的核心旋钮。true= 安全但每行一次 syscall；false= 快但崩溃时丢失应用缓冲。 - 异步把 I/O 从请求线程移走——消除延迟抖动——但每个有界队列在持续过载下最终必须阻塞、丢弃或 OOM。清楚你的方案会选择哪一种。
- Disruptor 靠无锁和无垃圾取胜，不是靠魔法。它在高线程数下击败阻塞队列，并避免 GC 停顿。
- 异步用持久性换速度。 解释你崩溃的那条日志，最有可能在队列中丢失。把关键日志走同步路径。 日志感觉像是代码库里最无聊的一行。但它也是少数同时悄然触及并发、内存层次、syscall、GC 和持久性的地方之一。现在你知道那一行真正做了什么。🚀 ---
你的日志设置是同步-安全，还是异步-快速？“异步日志吃掉我的崩溃日志”这种情况发生过吗？欢迎在评论区告诉我。
0 Comments
Log in to join the conversation.No comments yet. Be the first to share your thoughts.