访问日志没有 elapsed 接口慢 800 毫秒查不出卡在哪段

用户反馈下单要等一秒，翻遍日志只有开始和结束两条，没有耗时字段，数据库、缓存、下游各花了多久全靠猜。第一次遇到会往复杂处想，其实漏掉的多是个小前提。

long t0 = System.nanoTime();
// ...
log.info("path={} cost={}ms db={}ms cache={}ms", path, ms(t0), dbMs, cacheMs);

日志只记了业务事件 没有统一的耗时埋点。请求入口和出口各打一条 中间的分段耗时没有记录。这一点先确认清楚，后面就不用反复试。

碰到「日志缺少耗时」这类问题，我习惯先把当前配置原样备份一份，改坏了立刻换回来，不用现场推。临时改动用注释写上日期和原因，过两周自己都记不清为什么这么写。

动手前把原文件复制一份带时间戳，出问题立刻换回去，比现场分析快得多。

具体做法是，入口记开始时间 出口打总耗时和状态码；在数据库、缓存、RPC 三处各加一段耗时；把分段耗时拼进同一条汇总日志；按 P50 和 P99 做看板 找出最慢的一段。

改完照着核一遍，每条请求日志都有 cost 字段 能看出 800 毫秒里数据库占了多少。