1. 项目背景业务场景某 SaaS 平台的订单服务在每周一早上 9 点业务高峰期总会莫名其妙地全量 Full GC每次持续 5-8 秒。运维打开 GC 日志发现日志是 JDK 8 的-XX:PrintGCDetails格式——输出包含了数百 MB 的垃圾回收细节但在关键时刻Full GC 前 30 秒日志断了——因为日志轮转配置不合理关键证据被覆盖。痛点JDK 8 老式 GC 日志的混乱-XX:PrintGCDetails、-XX:PrintGCDateStamps、-XX:PrintHeapAtGC、-Xloggc:gc.log——4 个参数各自独立互不协调。运维经常配了前三个忘了第四个导致日志缺时间戳或缺堆快照。Unified Logging 的富矿未被开采JDK 9 引入的统一日志系统-Xlog有 150 个标签——gc*、safepoint*、classload、oscontainer、threados——但大部分团队只用-Xlog:gc*其余诊断能力白白浪费。日志洪水的治理缺失没有轮转策略、没有分级输出info/debug/trace、没有按标签过滤——一个 10GB GC 日志中 99% 是噪声。真到排查问题时要么找不到关键段要么磁盘被吞光。本章从 Unified Logging 的标签-级别-装饰器-输出四元组模型出发为微服务制定一份可复用的 JVM 日志参数模板最后展示如何将 JVM 日志接入 ELK/Loki 做结构化检索。2. 项目设计小胖在导出一个 3GB 的 gc.log 文件JVM 直接卡死。小胖大师为什么 GC 日志有 3GB 大啊我们就跑了 2 天而且我把-XX:PrintGCDetails都配了怎么 Full GC 前 30 秒的日志完全找不到——被覆盖了大师叹气你这是 JDK 8 的日志四件套还没退役。来我先帮你把 JDK 8 的参数翻译成 JDK 21 的 Unified LoggingJDK 8 参数JDK 21 Unified Logging 等价说明-XX:PrintGC-Xlog:gc基础 GC 日志-XX:PrintGCDetails-Xlog:gc*GC 详细日志含堆信息-XX:PrintGCDateStamps-Xlog:gc*:filegc.log:time带时间戳-Xloggc:gc.log包含在:filegc.log中输出到文件-XX:PrintHeapAtGC-Xlog:gcheaptrace每次 GC 前后堆快照-XX:PrintGCTimeStamps默认在:time装饰器中显示uptime 时间你那个 3GB 的日志就是因为PrintGCDetails打印了每次 GC 的完整堆信息加上没有按标签过滤。Unified Logging 的语法只有一个公式-Xlog:[tag1][tag2...][*][level][:outputfilepath[:filesizeNM][:filecountN][:whatdecorators]]拆解标签 (tag)gc、gcheap、gcage、safepoint、classload、oscontainer、threados等 150 个级别 (level)off、trace、debug、info、warning、error输出 (output)stdout、stderr、filepath装饰器 (decorators)time、uptime、timemillis、pid、tid、level、tags技术映射Unified Logging ↔ 图书馆分类系统——标签是书架类别号级别是书的难度等级装饰器是每本书封面上的条形码信息输出是在哪个阅览室阅读。小胖那如果我既要 GC 日志、又要 Safepoint 日志、还要容器感知日志——难道要配三条-Xlog大师不用——Unified Logging 支持多个-Xlog参数共存。我一般给生产服务配三条-Xlog:gc*info:file/var/log/app/gc-%t.log:time,level,tags:filesize50M,filecount5-Xlog:safepoint*:file/var/log/app/safepoint-%t.log:time,level:filesize10M,filecount3-Xlog:oscontainertrace第一条GC 详细日志轮转50MB×5 个文件带时间戳和标签第二条Safepoint 日志单独文件排查卡顿神器第三条容器 CPU/内存感知信息输出到 stdout会被容器日志驱动收集技术映射GC 日志 ↔ 食堂进货记录每天进出多少食材Safepoint 日志 ↔ 食堂停业检修记录每次停多久、为什么停容器日志 ↔ 食堂物业缴费单CNY 水电费——容器资源限制信息。小白为什么要把 Safepoint 单独拆一个日志文件它很重要吗大师极其重要Safepoint 是所有线程的全局暂停点。每当需要 GC、偏向锁撤销、代码反优化等操作时JVM 必须让所有 Java 线程都暂停。-Xlog:safepoint*会记录每次 Safepoint 的详细信息[info][safepoint ] Safepoint EnableBiasedLocking, Time since last: 0 ms, Reaching safepoint: 0.02 ms, Cleanup: 0.01 ms, At safepoint: 0.05 ms, Total: 0.08 ms如果你的服务偶尔出现 1-2 秒的莫名卡顿但 GC 日志显示停顿只有 50ms——那大概率是 Safepoint 的问题如某个线程在 JNI 调用中不肯回来、或巨型方法编译卡住。技术映射GC 停顿 ↔ 全班停课打扫卫生大家都知道要停多久、为什么停Safepoint 停顿 ↔ 教室突然停课因为有人拉响了火警——你不知道为什么停、会停多久。小胖那classload日志又是怎么回事我从来没关注过类加载。大师-Xlog:classloadinfo这个标签能救命。每次类被加载/卸载时输出[info][class,load] java.util.HashMap source: jrt:/java.base [info][class,load] com.example.UserService source: file:/app/classes/排查类加载问题的三大场景ClassCastException同一个类被两个 ClassLoader 加载——日志会显示 source 来自不同 jar。Metaspace OOM突然大量类被加载——日志能显示谁在疯狂加载类。启动慢看哪些类的加载耗时最长。3. 项目实战3.1 环境准备组件版本用途JDKOpenJDK 21Unified Logging 已内置日志分析grep/awk/jq结构化搜索 GC 日志ELK / Loki可选生产级结构化存储3.2 分步实现步骤一从 JDK 8 日志格式迁移到 Unified Logging目标把老项目的 JDK 8 GC 参数替换为等效的-Xlog配置。# JDK 8 旧参数不要再用 # -XX:PrintGC# -XX:PrintGCDetails# -XX:PrintGCDateStamps# -XX:PrintHeapAtGC# -XX:PrintGCTimeStamps# -Xloggc:/var/log/gc.log# -XX:UseGCLogFileRotation# -XX:NumberOfGCLogFiles5# -XX:GCLogFileSize50M# JDK 21 等价配置 -Xlog:gc*info:file/var/log/gc-%t.log:time,level,tags,pid:filesize50M,filecount5步骤二探索 Unified Logging 的标签体系目标列出所有可用标签选择生产环境最需要的标签组。# 查看所有可用的日志标签和级别java-Xlog:loggingtrace-version21|grepAvailable log# 输出标签大类示例# gc, gcheap, gcage, gcergo, gcphases, gcref# safepoint, safepointstats# classload, classunload, classpreview# oscontainer, osthread# threados, threadsmr# compiler, compilation# exceptions推荐的生产标签组合# 最小生产配置必配JVM_LOG_COMMON-Xlog:gc*,safepoint*:file/var/log/jvm/gc-%t.log:time,level,tags,pid:filesize50M,filecount5# 附加诊断非默认开启故障排查时按需加JVM_LOG_DIAG-Xlog:classloadinfo:file/var/log/jvm/classload-%t.log:time:filesize20M,filecount3JVM_LOG_CONTAINER-Xlog:oscontainertrace# 完整模板java$JVM_LOG_COMMON$JVM_LOG_CONTAINER-jarapp.jar步骤三用-Xlog排查一次Safepoint 卡顿目标运行一个会触发长 Safepoint 的程序用 Unified Logging 定位根因。// SafepointDemo.java —— 触发长 Safepoint 的演示publicclassSafepointDemo{// 一个有大量循环的巨型方法——JIT 编译时需要很长时间// 在此期间其他线程不能到达 Safepointstaticvolatilebooleanrunningtrue;publicstaticvoidbusyMethod(){longsum0;// 这个循环足够大JIT 编译它时需要较长时间for(inti0;i10_000_000;i){sumi*i;sum%Integer.MAX_VALUE;}System.out.println(busyMethod done: sum);}publicstaticvoidmain(String[]args)throwsException{System.out.println(PID: ProcessHandle.current().pid());// 线程 A反复触发 GC需要 SafepointThreadgcThreadnewThread(()-{while(running){System.gc();// 触发 Safepointtry{Thread.sleep(200);}catch(InterruptedExceptione){break;}}},GC-Trigger);// 线程 B反复调用 busyMethod让 JIT 编译ThreadbusyThreadnewThread(()-{for(inti0;i100running;i){busyMethod();}runningfalse;},Busy-Thread);gcThread.start();Thread.sleep(500);// 等 GC 先运行一段时间busyThread.start();gcThread.join();busyThread.join();System.out.println(运行结束查看 safepoint.log);}}javac SafepointDemo.java# 同时记录 GC 和 Safepoint 日志java-Xlog:gc*info:filegc_demo.log:time,level:filesize10M,filecount3\-Xlog:safepoint*debug:filesafepoint_demo.log:time,level:filesize10M,filecount3\SafepointDemo# 分析 Safepoint 日志找耗时最长的 SafepointgrepReaching safepointsafepoint_demo.log|awk{ match($0, /Reaching safepoint: ([0-9.]) ms/, a); if (a[1] 1.0) print a[1] ms - $0 }|sort-rn|head-10步骤四结构化 GC 日志以供 ELK/Loki 检索目标将 GC 日志解析为结构化格式JSON方便在 ELK/Promtail 中按标签、GC 类型过滤。# GC 日志的行格式# [2026-01-01T12:00:00.1230800][info][gc] GC(0) Pause Young (Allocation Failure) ...# 转为 JSON 日志简化版脚本catgc_demo.log|whileIFSread-rline;dotimestamp$(echo$line|sed-ns/\[\([^]]*\)\].*/\1/p|head-1)gctype$(echo$line|grep-oPPause \w|head-1)duration$(echo$line|grep-oP\d\.\dms|head-1)if[-n$timestamp][-n$gctype];thenecho{\ts\:\$timestamp\,\type\:\$gctype\,\duration\:\$duration\}fidonegc_structured.jsonl可能遇到的坑-Xlog标签匹配规则gc*匹配所有以gc开头的标签gc、gcheap、gcref等但gc*的语法不合法——只能用*在末尾做通配。日志输出到 stdout 时被容器日志驱动截断某些容器运行时Docker/containerd默认对 stdout 单行有 16KB 限制——超长 GC 日志行可能被截断。修复用:file输出到文件而非 stdout。Unified Logging 的%t占位符filegc-%t.log中的%t被替换为 PID——但如果同一台机器跑多个 JVM记得给不同进程用不同的文件名前缀防止冲突。装饰器太多增大日志体积:time,level,tags,pid,tid,uptime每个装饰器都会显著增加每行日志的长度——精简到诊断必需即可通常time,level,tags足够。3.3 测试验证验证矩阵验证点命令预期结果Unified Logging 的 GC 日志输出java -Xlog:gc*info:filetest.log -versiontest.log 含带标签的 GC 事件文件轮转java -Xlog:gc*info:filerotating.log:filesize1M,filecount3 ...运行至文件 1MB生成 rotating.log.0, .1, .2 等轮转文件Safepoint 日志运行 SafepointDemo记录每次 Safepoint 的到达时间和耗时标签通配-Xlog:gcage*trace仅输出对象年龄相关的 GC 日志日志级别过滤-Xlog:gc*debugvs-Xlog:gc*infodebug 输出的条目远多于 info#!/bin/bashecho 1. GC 日志输出验证 java-Xlog:gc*info:filegc_test.log-Xmx64m-cp.\-cbyte[] bnew byte[10*1024*1024];System.gc();Thread.sleep(1000);21echoGC 日志行数:$(wc-lgc_test.log)echoecho 2. 文件轮转验证 # 写入大量 GC 日志触发轮转1MB 限制java-Xlog:gc*info:filerotate_test.log:filesize1k,filecount3\-Xmx64m-cp.\-cfor(int i0;i1000;i){byte[] bnew byte[1024*64];System.gc();}ls-larotate_test.log*2/dev/nullechoecho 3. 标签分类验证 java-Xlog:gcheaptrace:fileheap_detail.log-Xmx64m\-cSystem.gc();21grepgcheapheap_detail.log|head-3echoecho 4. 级别过滤验证 java-Xlog:gcinfo:filegc_info.log-Xlog:gcdebug:filegc_debug.log\-Xmx64m-cSystem.gc();21echoinfo 级别条目数:$(wc-lgc_info.log)echodebug 级别条目数:$(wc-lgc_debug.log)echodebug 应包含更多条目4. 项目总结4.1 优点与缺点维度优点缺点统一语法一个-Xlog语法覆盖所有 JVM 日志——不再需要记忆 5-6 个互不协调的参数标签体系庞大150初次使用需要查阅文档文件轮转内置轮转filesizefilecount不再依赖外部 logrotate轮转文件名规则不灵活固定后缀.0,.1…无法自定义日期命名标签过滤可精确按gcage或safepointstats过滤——只输出你关心的通配符只支持末尾的*不支持正则或中间通配多输出不同标签输出到不同文件GC → 大文件轮转Safepoint → 小文件容器 → stdout额外增加 I/O 开销——每条日志可能写多个文件无 GC 触发Unified Logging 只是日志框架不像jmap -histo:live会触发 Full GC如果不轮转文件大小可能无限增长吞光磁盘4.2 适用场景线上 GC 问题排查-Xlog:gc*info:filegc.log:filesize50M,filecount5作为所有微服务的标配。Safepoint 卡顿定位-Xlog:safepoint*debug单独文件记录每次全局暂停的到达时间。类加载泄漏排查-Xlog:classloaddebug追踪每个类的加载和卸载事件。容器化内存诊断-Xlog:oscontainertrace输出 JVM 感知到的容器 CPU/Memory 限制。JIT 行为观察-Xlog:compilation*查看哪些方法被编译、反优化及原因。不适用场景极致性能要求的场景纳秒级交易——日志 I/O 本身有开销可在生产关闭debug/trace级别仅保留info。无需持久化日志的临时测试——用-Xlog:gc*:stdout直接输出到终端观察即可。4.3 注意事项类型详细说明filesize的Mvsmvskfilesize50M中的M必须大写——大小写敏感写成50m会被解析失败装饰器timevsuptimetime 绝对的 ISO 8601 时间戳uptime JVM 启动以来的秒数——time适合 ELKuptime适合关联 GC 日志的相对时间Safepoint 日志的性能开销safepoint*debug每次 Safepoint 都会输出高频率的 Safepoint 场景如每秒上百次会产生大量 I/O——测试环境可用生产慎选 debugjcmd动态修改日志级别启动后的日志级别可以通过jcmd pid VM.log outputgcdebug动态调整——无需重启 JVM4.4 常见踩坑经验案例 1Unified Logging 标签写错后静默失败某团队配置-Xlog:gcheapinfo发现 GC 日志完全没有输出。排查了 1 小时发现——gcheap需要在trace级别才有输出因为 heap 详情是 trace 级别事件。根因不同标签的日志事件绑定了不同的默认级别——gc是 infogcheap是 trace。修复用-Xlog:gcheaptrace或直接-Xlog:gc*info让所有 GC 标签都按 info 输出。案例 2filesize设太小导致 GC 频繁轮转 I/O 爆炸某服务配置filesize1M且 GC 很频繁——每 10 秒一次轮转。磁盘在高峰期 I/O wait 飙到 60%因为日志轮转本身也要 I/O。根因filesize不能太小——轮转操作关闭旧文件、打开新文件的 I/O 开销在高频轮转场景不能忽略。修复改为filesize100M减少轮转频率。案例 3ELK 的 Grok 表达式不匹配 JDK 21 GC 日志格式升级到 JDK 21 后之前 JDK 8 的 ELK GC 日志解析规则全部失效——因为日志格式从旧式2024-01-01T12:00:00.1230800: 123.456: [GC...变成了新式[2024-01-01T12:00:00.1230800][info][gc] GC(0)...。根因格式不兼容——Unified Logging 的输出格式与 JDK 8 的PrintGCDetails完全不同。修复更新 ELK 的 Grok pattern 匹配新格式。4.5 思考题进阶题Unified Logging 支持通过jcmd动态修改日志级别。请验证——先启动一个不输出 GC 日志的 JVM用jcmd VM.log outputgcinfo打开 GC 日志再用jcmd VM.log outputgcoff关闭。观察动态修改对 GC 日志输出的即时影响。实战题你的监控系统要求 GC 日志必须以 JSON 格式输出以便与 Loki Grafana 集成。但 Unified Logging 只支持纯文本输出。请用-Xlog的装饰器组合设计一种方案可以是日志采集端的解析规则也可以是 JVM 端的后处理将 GC 日志转为 JSON 输出。答案提示思考题 1 答案见本章步骤四结构化部分 第 12 章 jcmd思考题 2 参考src/hotspot/share/logging/logTagSet.cpp了解标签体系内部结构。下一章预告第 14 章将深入 Java 模块系统JPMS——从 module-info 到迁移 checklist把一个胖 JAR 反射的示例改造成最小化模块应用。延伸阅读与资源Redis 8 实战精讲从 CRUD 到源码构建高可用缓存系统Redis 实战修炼与原理进阶Python 3实战精进从脚本到高并发订单引擎python入门Rquests从菜鸟脚本到企业级SDK的网络实战圣经Milvus向量数据库实战修炼从 0 到 1精通向量检索与生产落地MongoDB 实战进阶与内核修炼后端工程师的 AI 转型第一课Ollama 与私有化大模型实战10倍开发者的 Dify 魔法书从零构建全栈 AI 应用后端工程师转型AI第一课-Ollama 与私有化大模型实战大型语言模型(LLM) vLLM 高性能推理落地实战Agent开发之LlamaIndex 实战修炼与源码进阶大语言模型Transformers 实战修炼与源码剖析