订单接口平时 80 毫秒,大促涨到 3 秒,日志里每条都打印整个订单对象,单条两万多字符。乍看像缓存或者权限的锅,追下去往往不是。

log.info('order done id={} amount={}', o.getId(), o.getAmount());
# 异步 appender
<AsyncLogger name='biz' level='info'/>

追下去是这么回事:日志把整个对象序列化,字段多、嵌套深,字符串拼接和磁盘写入都压在业务线程里同步做。

「日志打印大对象」相关的验证我通常做两遍,改完一次、隔天再看一次,确认不是临时生效。一次只改一处,改完立刻验证,几个改动叠在一起,出问题就说不清是谁导致的。

先做最小复现,能稳定跑出来的问题,排查成本会低一个数量级。别只看报错的最后一行,往上看几行,真正的起因通常在上面。

同类问题如果隔一段时间又出现,多半是某个定时任务或重启流程把改动冲掉了。

具体做法是,日志只打关键字段和主键;对象转字符串放到异步线程;按环境区分日志级别。

验收就看一点,压测同一接口,日志体积降到十分之一,P99 回到百毫秒级。

作者 9823189