开放问答
高并发 Java 服务里 Logback 同步刷盘到底吃掉多少 P99?怎么量化又不丢日志?
该问题的正文、回答与评论。
提问者 程知远-817 · 状态 open
LogbackJavaP99日志性能调优
【背景】 我做了 3 年性能优化,最近帮一个团队复盘一个 Java 17 / Spring Boot 3 的无状态服务(8C16G,QPS 稳态约 3k,高峰 6k+),链路是「网关 → 本服务 → MySQL + Redis」。P50 稳定 15ms,但高峰期 P99 偶发飙到 120–180ms,持续几秒后自行恢复,一周大概出现 3–4 次。
【现象】
- CPU 利用率峰值只有 55%,排除 CPU 瓶颈;
- MySQL 慢日志干净,Redis 无慢查询;
- HikariCP active 峰值 12/30,idle 充足,不是连接池问题;
- 但用 arthas trace 抓 30 秒,发现每次请求路径里累计约 20 次 log.info(...) 调用,高峰期单次耗时从稳态的 0.02ms 涨到 3–8ms,20 次叠加就是 60–160ms——刚好对上 P99 毛刺的量级;
- 日志配置:ConsoleAppender + FileAppender(immediateFlush=true),落本地 NVMe SSD,日志级别 INFO,单条平均 200 字节左右。
【已尝试的排查与结果】
- 把 FileAppender 的 immediateFlush 改成 false → P99 毛刺从 120ms 降到约 70ms,有所缓解但没根治;
- 换 AsyncAppender(queueSize=8192,discardingThreshold=0 防丢)→ P99 毛刺基本消失,但运维团队担心极端场景下队列溢出仍会丢日志,不敢直接上生产;
- iostat -x 1 看高峰期磁盘 util 只有 12%、await 0.3ms,看起来磁盘本身没压力,但怀疑是"大量小写 + fsync"的元数据开销没体现在 util 上。
【卡点 & 期望得到的答案形态】
- 在"不能丢日志"的硬约束下,有没有一种 Appender 配置组合(比如 RollingFileAppender + 特定 buffer 策略),能把同步刷盘对请求路径的 p99 影响压到 1ms 以内?希望看到具体配置片段 + 量化数据(before/after 的 p99 对比);
- 怎么在常态监控里加一个"单次 log.info 耗时"或"日志写入耗时"的指标,让这类隐性开销不再靠 arthas 事后抓?希望看到具体的埋点方式(是改 Appender、用 MDC 计时、还是用 JMX);
- 有没有人踩过"immediateFlush=false 看似省了 fsync,结果 OS page cache 写回风暴反而更伤"的坑?如果有,希望听到现象描述和当时的 iostat / /proc/pagetypeinfo 数据。
打个比方:现在的状况就像每个快递包裹都要等邮差亲手塞进信箱、按铃、确认签收才肯走——包裹不多(QPS 3k),但高峰期邮差一趟要送 20 个,每个都要按铃,整条街就堵了。我想搞清楚的是:到底能不能让邮差"投进信箱就走",又不让任何一个包裹丢。
已采纳
回答者
回答正文
评论
暂无评论。