線上頻繁FullGC?慌得一比!竟是Log4j2的這個“特性”坑了我
最近生產環境遇到一個頻繁FullGC問題,用這一篇文章記錄下來。先劇透原因,總結一句話原因如下:
?本文記錄了一次因 Log4j2 配置、JVM 參數和應用依賴變更等多因素疊加導致的頻繁 Full GC 線上故障。通過分析 GC 日志、內存 Dump 和源碼,最終定位到是因引入 Servlet 依賴導致 Log4j2 線程緩存失效,進而引發大對象直接晉升老年代所致。本文詳細記錄了排查思路、根因分析及解決方案。
一、事情起因
某一天夜晚系統上線后,沒過多久運維便找上門,系統存在Full GC告警,一分鐘Full GC超過5次。(出現問題的系統使用Log4j2框架,對應版本2.31.8)
1.JVM監控看板
上線后Full GC頻次立馬上來了,可以確定Full GC和本次版本有關系。先回退版本,優先解決問題為主。同時找運維dump內存快照,方便后續分析問題。
c0d2f38966e898d01af1febc4a5462f6.png
2.GC日志
GC日志顯示很明顯,通過GC日志可以粗略分析如下:Minor GC觸發次數:82 Full GC觸發次數:105次
- Minor GC頻率高:新生代 GC 已觸發 82 次,說明短期對象頻繁創建。
- Full GC頻率更高:Full GC 觸發 105 次(> Minor GC次數),證明存在 內存分配嚴重失衡:
對象未能在新生代回收,被迫晉升到老年代
老年代快速填滿(日志中GC前占用96.2%)
最終頻繁觸發Full GC(影響系統性能)。
圖片
交給AI分析下,以下表格比較直觀:
內存區域 | GC前占用 | GC后占用 | 變化趨勢 |
新生代 (Eden) | 100% (3.13GB已滿) | 30% (約0.94GB) | ↓70% |
新生代 (Survivor區) | 0% (完全閑置) | 0% (持續閑置) | 失效狀態 |
老年代 (CMS) | 96.2% (1.84GB/1.87GB) | 33.3% (0.65GB/1.87GB) | ↓63%,但殘余仍過高 |
問題關鍵是,一次 Young GC 后老年代仍占用 0.65GB,說明有大量本應回收的對象常駐老年代,這是典型的內存泄漏或不當晉升的跡象。
二、問題排查
有了AI分析的加持,我們大致明白原因是系統中頻繁創建大對象直接晉升到老年代 快速填滿老年代進而觸發Full GC。剩下的就是進行具體問題排查了。
問題排查的思路如下:
1.梳理本次系統上線內容
本次上線是將舊系統的dubbo依賴去除,然后引入公司內部xxx-rpc框架,本次并沒有其他業務代碼的修改。初步懷疑是公司內部xxx-rpc的問題,但是這個框架已經在其他項目都推廣了,也沒有反饋過此問題,所以通過代碼改動回溯并沒有定位到具體的問題。
2.內存快照Dump
出現問題之后就立馬找運維dump了內存快照,這次再通過dump文件分析下問題:
2.1 按照包名過濾
首先懷疑是我們系統代碼導致的GC問題,按照系統包名進行過濾。按照Objects數量排序,這里查看數量級沒有問題
圖片
2.2 按照類數量排序
這里看到char數組和String數量最多,而且占用的內存也是最高的。這通常意味著問題與大量的字符串處理操作有關,例如日志、JSON 序列化/反序列化等。看下char[]數組關聯的引用:
圖片
圖片
通過with incoming references查看引用列表:
看到這個圖好像是發現問題了,Shallow Heap大小都是固定的值2MB+。
圖片
對象內容都是一些日志內容,而且查看日志內容也不大,為了達到預設的容量(1MB),會用一個默認值(空字符)來填充數組,這在內存快照中看到的就是大量\u0000。(StringBuilder 的機制)
圖片
這里可以想到可能是系統日志框架搞了鬼,每次打印日志時都生成一個2MB+的大對象,再看這個char的引用是一個StringBuilder。通過char數組的GC root也能夠證明這一點。
圖片
現在排查的大致方向明確了:
系統頻繁Full GC的原因是使用的日志框架不停的創建StringBuilder(StringBuilder的底層就是用的char數組)導致。通過這個方向去代碼中進一步排查。
3.查看系統JVM配置
系統JVM配置中有一個配置 -XX:PretenureSizeThreshold=2097152,含義是如果創建的對象大于2MB后就會直接進入老年代。結合上面的問題,會有大量的對象頻繁分配到老年代,導致Full GC頻發。
圖片
另外詢問AI這個參數配置是否合理,得到回復:
- 重新評估 JVM 參數:慎重考慮 -XX:PretenureSizeThreshold=2097152 這個參數的必要性。這個參數非常激進,它改變了對象的正常晉升規則。對于絕大多數應用,尤其是大量存在臨時大對象(如你的日志場景)的應用,移除這個參數讓對象優先在新生代分配,可能是更好的選擇。讓 JVM 自己管理對象晉升通常更合理。
三、代碼追蹤
通過MAT工具已經定位到大致的方向了,剩下的就是要排查代碼中對于Log的使用,查看是哪里的配置導致了問題。
1.Log框架
搜索系統中使用的log框架。
圖片
系統通過lombok的注解@Log4j2來進行日志打印,那么就開始看下log4j2底層代碼,通過代碼進行直接搜索:
圖片
另外log4j-core 包下也做了類似搜索,只有這里有更多線索值得追溯,繼續往后跟蹤。
2.本地Debug溯源
直接可以本地啟動Debug下,遇到有log.info即可進入到創建StringBuilder的地方:
圖片
這里是每次打印log都會進入,然后執行new StringBuilder(MAX_REUSABLE_MESSAGE_SIZE),這里看到buffer都是用的空字符串進行占位,一個char[1048576]數組占用的空間計算如下:
- 數組長度:1048576=2^20=1MB(元素個數)
- 每個char占用:2字節(Java中char是16位)
- 數據分占用:1048576×2=2097152字節=2MB
如果再加上對象頭的開銷,實際占用是超過2097152的,再參考MAT中對象占用大小2097168,這似乎都對應上了。接著繼續跟這個判斷邏輯:
final ThreadLocal<FormatBufferHolder> FORMAT_BUFFER_HOLDER_REF
Constants.ENABLE_THREADLOCALS ? ThreadLocal.withInitial(FormatBufferHolder:new) : null;
public static final boolean ENABLE_THREADLOCALS
!IS_WEB_APP &PropertiesUtil.getProperties().getBooleanProperty("log4j2.enable.threadlocals", true);
public static final boolean IS_WEB_APP = Propertiesutil.getproperties().getBooleanProperty(
"1og4j2.is.webapp", iscLassAvailable("javax.servlet.Servlet") || isCLassAvailable("jakarta.servlet.Servlet"));
可以看到這里log4j2.enable.threadlocals=false或者被判定isWebApp的話 都會使得FORMAT_BUFFER_HOLDER_REF為null,最終每次都會new StringBuilder()創建大對象:
3.代碼配置
繼續跟著上面問題跟蹤,查看系統配置。
- 系統MAX_REUSABLE_MESSAGE_SIZE為多少?
- log4j2.enable.threadlocals配置為false或者系統被識別為webApp?
繼續通過代碼搜索:
圖片
- 系統配置的MAX_REUSABLE_MESSAGE_SIZE為10048576(1MB)
- log4j2.enable.threadlocals已經配置了true
- 系統被誤識別為webApp應用,由于引入公司其他段對的包間接引入了tomcat包,引入了Servlet類,導致識別為webApp應用
圖片
圖片
系統中引入了javax.servlet.Servlet類,所以被誤識別為webApp應用,進而導致每次日志打印都會創建一個2MB的StringBuilder() 對象。
4.原理解釋
這個問題的核心在于解釋下面的代碼的含義,以及log4j2.maxReusableMsgSize、log4j2.enable.threadlocals等配置的意義:
圖片
- log4j2.enable.threadlocals=true時,在線程執行的周期內打印的日志都可以復用創建的StringBuilder緩沖區,它會隨著線程的創建而創建,并在線程結束時被垃圾回收。這個緩沖區的核心目的是復用:通過線程本地變量(ThreadLocal)為每個線程分配一個固定的緩沖區,在每次日志格式化操作中重復使用它,從而避免頻繁創建和銷毀 StringBuilder 對象,避免了短期對象的創建,降低新生代的 GC 頻率,減少垃圾回收(GC)壓力。
- log4j2.maxReusableMsgSize顧名思義這個配置即為緩沖區大小,定義了每個線程本地緩存中 StringBuilder 緩沖區的初始容量。
5.解決方式
解決方式很簡單,修改log4j2配置即可。修改isWebApp為false,強制覆蓋 isWebApp判斷,并且減小緩存maxResuableMsggSize大小。
圖片
四、事后復盤
上面已經找到了問題的所在,但是還是有些問題沒有得到明確的解釋:
1.系統之前都跑的好好的,為何本次上線才導致這個問題出現?其他團隊是否也遇到了類似問題?
這個問題幾乎是身邊同事、領導都在問的,問題的開始我也有同樣的疑惑。(該問題僅限定于同樣使用Log4j2框架的系統)
這里直接看我們系統正常系統和我們系統的一些差異對比,這里會更加直觀,下面也有詳細配置的差異:
配置項 | 正常系統(其他團隊系統) | 故障系統(我們團隊系統) | 后果 |
| 默認 (0.5KB) | 顯式配置為 1MB | 創建的對象大小不同 |
| 默認 (0) | 顯式配置為 2MB | 大對象分配策略不同 |
依賴 | 有(引入公司內部xxx-rpc框架導致) | 有(引入公司內部xxx-rpc框架導致) | 導致線程緩存失效 |
最終效果 | 小對象在新生代回收 | 大對象直擊老年代 | 頻繁 Full GC |
接著看下我們系統的一些具體配置:
1.1log4j2配置不當
本次接入了公司內部xxx-rpc框架間接引入了Servlet類,導致log4j2框架將系統識別為webApp,導致log4j2.enable.threadlocals=true失效,其他系統也同樣有此問題,但是其他系統并沒有顯示去配置log4j2一些屬性,都是使用默認配置
maxReusableMsgSize默認值為0.5KB,其他系統即使每次都new StringBuilder()出來 也不會進入老年代中,不會產生Full GC問題
圖片
1.2JVM參數配置不當
我們系統配置的-XX:PretenureSizeThreshold=2097152,也就是超過2MB的大對象直接分配到老年代。而其他系統并未配置此JVM參數,-XX:PretenureSizeThreshold 這個參數的默認值是 0。默認情況下所有對象都會首先嘗試在新生代(Young Generation)進行分配,而不會僅僅因為對象大就直接進入老年代。
1.3log4j2 2.23.1緩存頂格分配
該問題同1.1,默認緩存大小為0.5k,即使頂格分配也不會出現問題。上面查看log4j2 2.23.1版本的源碼,每次都按照maxResuableMsgSize配置頂格創建對應的StringBuilder緩存。這個改動是從2.17.0版本之后修改的,我們再看下2.17.0版本源碼的處理:
2.17.0版本初始創建255字節,然后按需擴容。再詢問AI Log4j2框架后續版本這樣改動的目的:
在對 Log4j2 不同版本間 MAX_REUSABLE_MESSAGE_SIZE
處理方式的差異進行溯源和思考。從“按需創建”到“頂格分配”的變化,確實是 Log4j2 演進過程中一個值得探討的設計抉擇。
?? 版本行為對比
為了更清晰地展示提到的兩個版本在處理上的差異,整理了以下表格:
特性 | Log4j2 ~2.17.0 | Log4j2 2.23.1 |
分配策略 | 初始創建較小(如 255 字節)的 | **"頂格分配"**,直接創建指定 |
核心目標 | 節省單個線程的初始內存占用 | 追求極致的格式化性能 ,避免任何可能的中間擴容操作 |
性能表現 | 若日志消息超長,可能觸發多次擴容和數組復制,帶來額外的性能開銷 | 絕大多數情況下一次分配,無需擴容,格式化操作更快 |
內存占用 | 初始內存占用較低,但遇到大消息時,擴容后可能最終占用與頂格分配相似的內存 | 每個線程初始內存占用即固定 ,與配置的 |
適用場景 | 對內存資源非常敏感,且日志消息長度普遍較短的環境 | 追求高性能日志記錄,能夠接受以固定內存換取性能,且日志消息長度多變的環境 |
?? 頂格分配的設計考量
Log4j2 團隊在后續版本中選擇“頂格分配”策略,并非一個缺陷,而是基于特定目標的權衡:
- 極致性能優先:日志記錄在許多應用中屬于高頻操作。"頂格分配" 最直接的好處是避免了
StringBuilder
在后續格式化過程中因容量不足而進行的多次擴容。每次擴容都涉及申請新內存、復制舊數據、回收舊數組等一系列操作,這在高性能場景下是不可忽視的開銷。預先分配足夠大的空間,消除了這個不確定性。 - 內存與性能的權衡:這體現了軟件設計中常見的 “以空間換時間” 的策略。開發者通過適當提高
MAX_REUSABLE_MESSAGE_SIZE
,可以換取更穩定、更高效的日志記錄性能。當然,這也要求開發者對自身系統的日志大小有一定的了解,并接受每個線程所需的內存開銷會相應增加。 - 預期內的內存占用:頂格分配使得每個線程的日志緩沖區內存占用變得可預測。對于一個配置了固定大小線程池的應用,可以相對準確地計算出 Log4j2 線程本地緩存所需的總內存(線程數 ×
MAX_REUSABLE_MESSAGE_SIZE
× 2字節),方便進行資源規劃。
?? 潛在的問題
- 初衷:為了在高性能日志記錄中避免反復擴容
StringBuilder
(擴容涉及數組復制,成本高),直接分配一個足夠大的緩沖區在性能上是最優的。 - 副作用:當這個機制因為
isWebApp
誤判而失效,線程本地緩存被禁用時,每次日志記錄都“頂格分配”一個大緩沖區的行為就從性能優化變成了性能災難和內存殺手。
1.4 Logback和Log4j2的對比
Spring Boot 默認使用的是 Logback日志框架,這里給出和Log4j2的對比:
- Logback:可以看作是 Log4j 1.x 的官方正統繼承者和現代化改進版。由同一作者(Ceki Gülcü)開發,旨在解決 Log4j 1.x 的諸多痛點,并原生支持 SLF4J。它的設計是漸進式的演進。
- Log4j 2:這是 Apache 基金會的一個全新項目,受 Logback 思想的啟發,但完全從頭開始重寫。它旨在吸收 Logback 的優點,同時解決其架構上的一些局限性,并引入更革命性的特性(如無垃圾日志記錄)。它的設計是顛覆式的革新。
簡單比喻:
- Log4j 1.x -> Logback:像是從 Windows XP 升級到了 Windows 7,系統更流暢、界面更美觀、功能更強。
- Logback -> Log4j 2:像是從 Windows 系統切換到了 macOS,理念和底層架構都有了巨大的變化,旨在提供一種更極致的體驗。
詳細對比表:Logback vs. Log4j2
特性維度 | Logback | Log4j2 | 分析與解釋 |
出身與作者 | Ceki Gülcü,作為 Log4j 1.x 的繼任者 | Apache 基金會,受啟發但完全重寫 | Logback 是“正統”,Log4j2 是“新貴”。 |
性能表現 | 優秀 。比 Log4j 1.x 有顯著提升。 | 極致 。尤其是在異步日志模式下,性能遠超 Logback。 | 這是 Log4j2 的最大賣點 。其異步模式基于LMAX Disruptor(一個高性能的無鎖環形隊列庫),極大減少了線程爭用,在高并發場景下性能提升數個數量級。 |
異步日志 | 支持,通過 | 支持,提供兩種方式:** | Logback 的 |
垃圾回收友好度 | 良好。 | 極佳 。支持 “無垃圾”(Garbage-Free) 或“低垃圾”模式。 | Log4j2 在記錄日志時可重用對象(如 |
配置方式 | XML 或 Groovy。支持條件處理 ( | XML, JSON, YAML, Properties。功能更強大的條件配置和腳本支持。 | Log4j2 的配置更加靈活和強大,例如可以在配置中直接使用系統屬性或環境變量進行復雜邏輯判斷。 |
自動重載配置 | 支持,且可靠。 | 支持,且更可靠。 | 兩者都支持在應用不重啟的情況下重載配置文件,對于生產環境調試非常有用。 |
插件架構 | 有,但相對簡單。 | 功能強大且易于擴展 。 | Log4j2 的插件系統非常成熟,只需使用 |
社區與維護 | 穩定維護。但新特性迭代較慢。 | 非常活躍 。Apache 頂級項目,持續迭代,修復迅速。 | Log4j2 的社區活躍度和發展勢頭明顯優于 Logback。但之前的 Log4Shell 漏洞也提醒我們,新特性多也可能帶來新的風險。 |
安全性 | 歷史上較為穩定,未出現嚴重遠程漏洞。 | 曾因 Log4Shell(CVE-2021-44228)漏洞而蒙上陰影。 | 這是一個重要的考量點。Log4Shell 之后,Log4j2 團隊在安全方面投入了巨大精力,安全性已得到顯著增強。 |
2.isWebApp的判斷是Log4j2的Bug嗎?為何webApp應用就不能共享線程緩存?
同樣這個問題也是我們大家一直疑問的地方,log4j2框架是不是存在Bug,為何webApp就禁止線程內禁止使用共享的緩存?
這里直接問了AI:
log4j2對于WebApp的處理不是bug,而是有意設計的安全措施。原因如下:
- 在傳統的Web容器(如Tomcat、Jetty)中,應用可能會被頻繁重新部署,且線程會被重用。如果使用線程本地緩存(threadlocals),在重新部署時,線程本地對象可能無法被及時清理,從而持有舊類加載器的引用,導致內存泄漏(類加載器無法被垃圾回收)。
- 因此,log4j2在檢測到Web應用時禁用線程本地緩存,以防止內存泄漏。這是一種保守但安全的策略。
- 問題在于,log4j2的檢測機制基于類路徑中是否存在
javax.servlet.Servlet
類,這對于Spring Boot應用(使用嵌入式Servlet容器)可能產生誤判。Spring Boot應用通常不會像傳統Web容器那樣頻繁重新部署,因此禁用緩存可能是不必要的。
接著追問,對于SpringBoo應用包含嵌入式容器是否存在問題:
Spring Boot應用與 Log4j2 內存泄漏擔憂
- 傳統 Web 容器 vs Spring Boot 嵌入式容器:
傳統容器(Tomcat, WebSphere):應用會頻繁地熱部署(Hot Deployment) 和 卸載(Undeploy)。線程由容器管理,會在部署之間被復用。如果Log4j2在這些線程的ThreadLocal里存了東西,當下一個應用部署后,舊應用的ClassLoader因為被ThreadLocal引用而無法被GC回收,就造成了ClassLoader泄漏,最終導致內存泄漏。
Spring Boot 嵌入式容器:您的應用和Tomcat服務器是同一個JVM進程,同一個ClassLoader。應用的生命周期就是JVM的生命周期。通常不會存在“應用卸載但容器線程仍在”的情況。當您停止JVM時,一切都會被回收。
- 結論: 在 Spring Boot 嵌入式容器 中,由Log4j2的ThreadLocal引起內存泄漏的風險極低。因為不存在應用獨立 reload 而線程池存活的場景。整個JVM同生共死,因此,在您的場景下,大膽地使用
-Dlog4j2.is.webapp=false
來啟用線程本地緩存是安全且正確的做法,無需過分擔心內存泄漏問題。這個安全措施主要是為傳統部署模式設計的,對于Spring Boot的嵌入式部署模式來說,它過于保守了。
因此,本次事故并非 Log4j2 的‘Bug’,而是其‘高性能設計’與我們應用‘特定配置’及‘意外環境’(誤判為 WebApp)相結合后產生的一個‘副作用’。