监控里偶尔出现耗时 -3ms,日志打印 elapsed=-3.2ms,同一时间段还有一条 NTP 同步记录。改成 time.Since 之后负数再没出现过。日志里能对上时间点,这种反而好排。

time.Now 同时带墙上时钟和单调时钟读数,转成 Unix() 之后只剩下会被调整的那部分。两个采样点之间发生回拨,相减就得到负数,耗时统计要的是间隔不是绝对时刻。这一点先确认清楚,后面就不用反复试。

start := time.Now()
time.Sleep(50 * time.Millisecond)
fmt.Println(time.Since(start))

「单调时钟」排查到最后往往是很小的一处差异,前面那些复杂猜测可以先放一放。能分两步做的操作就别合成一步,中间看一眼返回值,出问题好判断。

报错里带路径的,先去看那个路径在不在、权限对不对。同一份配置存在多处的,先确认改的是被加载的那一份。

处理上按这个顺序:用 time.Since 或 Sub 这类保留单调读数的接口 别自己转 Unix;比较先后用 Before/After 不要比数值;需要序列化时再取墙上时间 只用于展示;监控对负数耗时直接告警。

结果对不对很好判断,连续跑一万次 耗时全部为正 监控里不再出现负数尖刺。

作者 9823189