Spring Boot应用App1日志缺失1分钟并抛HTTP 500错误的原因排查求助
结合你描述的场景——DEV环境Spring Boot应用App1用Log4j v1写日志,偶发1分钟日志缺失+HTTP 500,服务器CPU/内存无异常,3个月出现2-3次——以下是几个高概率的排查方向:
Log4j v1 文件IO阻塞或锁竞争
Log4j v1的FileAppender默认是同步写入,多线程场景下容易出现文件锁竞争。如果某一时刻应用产生大量日志,IO线程被阻塞,不仅日志无法及时写入(出现缺失),还会占用处理请求的业务线程,导致请求超时或直接返回500。另外,如果服务器挂载的存储(比如NFS)出现短暂IO卡顿,即使CPU内存正常,也会触发这个问题。AsyncAppender 队列溢出或阻塞
如果你们用了Log4j v1的AsyncAppender异步写日志,要检查bufferSize配置。当突发日志量超过队列容量时,要么日志被丢弃,要么生产者线程(业务线程)被阻塞,导致请求处理失败,同时这段时间的日志无法落地到文件。Spring Boot 请求线程池耗尽
App1的REST请求处理线程池如果被占满,新请求会直接返回500。线程池耗尽的常见原因是某个请求处理耗时过长(比如调用第三方服务未设置合理超时),而同步写日志的操作会加剧线程阻塞——业务线程卡在写日志的IO操作上,既无法处理新请求,也无法及时写入日志,最终导致日志缺失+500。日志滚动策略的短暂中断
若使用RollingFileAppender按时间/大小滚动日志,Log4j v1在切换日志文件的过程中(关闭旧文件、创建新文件)可能出现短暂的写入中断。如果刚好这段时间有请求出错,对应的日志就会丢失。而且Log4j v1的滚动实现稳定性不如v2,偶发的滚动异常可能导致日志停止写入数分钟。JVM 长时间GC停顿
虽然服务器CPU内存正常,但如果发生了长时间Full GC停顿(比如老年代内存碎片严重、GC参数不合理),应用线程会完全暂停,日志无法写入,请求也无法处理,直接返回500。可以查看App1的GC日志,确认是否有超过1分钟的GC停顿记录。文件系统临时不可用
如果App1的日志目录挂载在远程存储(如NFS),网络短暂波动可能导致存储临时不可达,此时写日志的IO操作会被阻塞,业务线程也会被牵连,最终出现日志缺失和请求500。这种情况是偶发的,和存储网络稳定性相关。Log4j v1 已知bug(未维护风险)
Log4j v1已经停止维护多年,存在不少未修复的bug——比如特定JDK版本下的线程安全问题、IO异常后Appender无法自动恢复等。如果某次写日志触发了这类bug,日志写入线程可能直接挂掉,导致后续日志无法写入,直到应用重启。
内容的提问来源于stack exchange,提问作者Sundararaj Govindasamy

