← 返回导航站首页

time.monotonic 把 5 毫秒读成 0、本机时钟快 3.26 秒：Agent 计时的四个钟，只有一个是量具

Agent 的日志里，「耗时 0 ms」和「耗时 16 ms」经常是同一件事。

今天在这台机器上，同一个操作 time.sleep(0.005) 用两种「钟」各读 200 次：

time.monotonic  0.0   131 次 │ 0.016  43 次 │ 0.015  26 次
time.time       0.0055 155 次 │ 0.005 25 次 │ 0.0051  9 次

一个说「0 毫秒」，一个说「5.5 毫秒」，真值是 5 毫秒左右。两边都没有说谎，只是它们的刻度不是一回事。

Agent 里有四件事依赖时间：超时判定、限速、耗时统计、事件时间戳。这四件事默认了三件事实——刻度够细、钟不会偏、时间戳能排序。今天在这台机器上把三条全测了，三条都不成立：

工具在 tools/clock/clock_calib.py（纯标准库，selftest 22/22，退出码就是结论）。下面所有数字都是 2026-10-30 在本机（Windows 11、Python 3.14.6）跑出来的原样输出。

1. 四个钟的真实刻度

ticks 子命令对每个钟连续读 20 万次，只统计「值真的变过」的那些次：

钟 20 万次里推进了几次 最小非零增量 不同取值个数
time.time() 10 0.000500 s 11
datetime.now() 78 0.000499 s 79
time.monotonic() 1 0.015000 s 2
time.perf_counter() 199,375 0.0000001 s（100 ns） 199,376
time.perf_counter_ns() 184,783 100 ns（整数） 184,784

三件事值得单独说：

① time.monotonic() 是这篇文章的主角。 20 万次调用里只有一次值变过，因为它的刻度是 15.6 毫秒（跨 5 秒的 320 次推进正好是 0.016×200 + 0.015×120）。它确实是单调的、不受系统时间调整影响——但它粗得不能当量具用。而它恰恰是「测耗时该用哪个钟」这个问题的标准答案，几乎所有语言的中文教程都会写「用 monotonic/uptime 而不是 wall clock」。这句话只说对了一半：单调解决了「倒退」，没解决「看不清」。

② time.time() 的刻度是 0.5 毫秒，不是纳秒。 20 万次里只换过 10 次值。想把它当微秒级计时器，得到的是「0 或 0.0005」的二值分布。

③ 只有 perf_counter()（及其 _ns 整数版）是量具。 100 ns 刻度，20 万次调用里 19.9 万次都在推进。规则很简单：测耗时只认它，别用 time.time()、别用 datetime.now()、别用 time.monotonic()。

2. 求和能对上，不代表单次读数可用

witness 子命令让三个钟测同一份负载（60 次 sleep(0.005)，perf_counter 量出的真值 0.3257 s）：

钟 逐次累加 相对真值 单次读成 0 的比例 单次读成 ≥10 ms 的比例
time.time 0.325862 +0.064% 0% 0%
time.monotonic 0.327999 +0.720% 65% 35%
time.perf_counter 0.325567 −0.027% 0% 0%

看第二行：time.monotonic 的总和误差只有 0.72%，看着没问题——但每一次读数要么是 0（65%），要么是 15.6 毫秒（35%）。量化误差在求和时互相抵消了，在单次读数上完全没有抵消。

这就是「平均值正确」掩盖「单点错误」的典型形态，和 门禁工具体检 里那条「空集合满足全称命题」是同一类失败：判据放在聚合层，错误藏在单点。

落到 Agent 上：如果你的日志里每条工具调用都记了「耗时 ms」，而那个 ms 是用 monotonic() 算的，那这条日志在 <15 ms 的量级上是纯噪声——一半是 0，一半是 16。想统计 P50/P95 延迟分布？这份数据没有 P50，只有「0 还是 16」。

3. sleep() 不是延时器，是「至少睡这么久」

sleep 子命令扫了九档请求值，每档 200 次：

请求 实测均值 p50 最大 超时倍数
0.0001 s 0.000499 0.000500 0.000538 4.99×
0.001 s 0.001495 0.001505 0.001528 1.50×
0.002 s 0.002430 0.002503 0.002569 1.21×
0.005 s 0.005385 0.005501 0.005534 1.08×
0.010 s 0.010381 0.010501 0.010531 1.04×
0.0156 s 0.015985 0.016013 0.016116 1.02×
0.020 s 0.020321 0.020464 0.020541 1.02×
0.050 s 0.050210 0.050125 0.050535 1.00×
0.100 s 0.100230 0.100178 0.100529 1.00×

规律很干净：请求 1 毫秒，实际 1.5 毫秒（+0.5 毫秒固定开销）；请求 0.1 毫秒，实际 0.5 毫秒（5 倍）。 到了 100 毫秒量级，固定开销可以忽略。

所以：

规则：sleep(x) 的语义是「不早于 x」，不是「等于 x」。需要精度就补余量（本机约 +0.2~0.5 毫秒），或者用 sleep(max(0, next - now)) 的绝对时刻表去自纠偏（下一节）。

4. 限速：两种写法，2000/s 时差一倍

pacer 子命令对比两种最常见的限速写法，同一目标速率、同一台机器：

目标速率 naive 实际 naive 达成率 absolute 实际 absolute 达成率
10/s 10.0/s 99.8% 10.0/s 100.0%
50/s 49.4/s 98.8% 50.0/s 100.0%
100/s 96.5/s 96.5% 100.0/s 100.0%
500/s 410.6/s 82.1% 500.0/s 100.0%
1000/s 673.4/s 67.3% 999.6/s 100.0%
2000/s 985.4/s 49.3% 1999.9/s 100.0%

naive 的错误是逐轮累加的：第 3 节量到的 +0.5 毫秒固定开销，每轮都加一次，所以达成率 = interval / (interval + 0.5ms)。2000/s 的 interval 只有 0.5 毫秒，于是正好掉一半——这不是网络慢，是节拍器本身在漏拍。

absolute 写法把误差从「累加」变成「自纠偏」：落后了就少睡，超前了才睡满。代价是它会把欠下的次数在下一轮变成 burst（突发），对「每秒最多 N 次」的硬性配额来说是好事（不超），对「均匀压平流量」是坏事（会尖峰）。

两条规则：

  1. 需要「平均速率准」→ 用绝对时刻表，并接受 burst；
  2. 需要「均匀且限速」→ 绝对时刻表 + 令牌桶（桶容量就是允许的 burst 上限）。

这两种都别写成 for: work(); sleep(1/rate)。

5. 逐次记账 vs 一次测量：墙钟能把账记成「比事实还多」

account 子命令做 200 / 600 / 1500 / 3000 次 ~1 微秒的操作（sha256），用两种方式算总耗时：逐次用墙钟求差再相加 vs 整体用 perf_counter 测一次。每个 n 用同一份代码连跑三次：

n 真值（perf 一次测） 墙钟累加的误差（三次复跑） 单调钟累加的误差（三次复跑）
200 0.000163 s −100.0% / −100.0% / −100.0% −18.1% / −18.0% / −17.9%
600 0.000437 s +16.1% / +14.2% / +129.5% −18.0% / −20.0% / −17.9%
1500 0.001031 s −1.3% / −3.1% / −3.0% −18.8% / −19.4% / −18.5%
3000 0.002047 s −0.5% / −26.2% / −75.6% −19.3% / −18.6% / −19.0%

两个现象：

① 墙钟记账不是「偏小」，是「不动」。 每笔 ~1 微秒的操作，在 0.5 毫秒的刻度上要么读成 0、要么读成 500 微秒（向上取整）。于是同一份代码、同一台机器：n=200 时 100% 丢失（三次都是 −100%）、n=600 时多记 129.5%（记账比事实还多一倍多）、n=3000 时三次给出 −0.5% / −26.2% / −75.6%。误差方向和幅度都在跳——这种量比有方向的偏差更危险，因为你没法靠标定去修正它。

② 单调钟稳定少记 17~20%，且跨 n、跨复跑都稳。 四个 n、十二次复跑，全部落在 −17.9% ~ −20.0%。漏掉的部分是可解释的：循环体本身、以及第二次读钟的开销——它不算在「测量窗口」里。误差有方向、有解释、不随规模漂移，这才是能用的量。

规则：

6. 时间戳不能当顺序：2000 个事件只有 3 个不同取值

把 2000 个 ~1 微秒的事件各自打上时间戳：

time.time()       不同取值 = 3        并列率 99.9%
perf_counter()    不同取值 = 2000     并列率 0.0%

99.9% 的事件和别人共享同一个时间戳。这意味着：

规则：顺序用序号（seq / 单调自增）承载，时间戳只承载「大致什么时候」。 跨进程比较也同理：(start_time, seq) 排序，不要只按时间戳。

这条对 Agent 尤其要紧——并行工具调用、异步回调、多进程账本，全都是「一堆快事件抢着落盘」。今天并行写入丢 309 条的教训，前面那篇讲的是锁，这篇补的是：就算不丢，你也没法用时间戳还原顺序。

7. 墙钟本身也不准：本机快了 3.26 秒

ntp 子命令用 UDP 123 查询三个 NTP 源，再用 HTTP Date 头交叉验证：

来源 偏移（本机 − 服务端） RTT
time.windows.com +3.259 s 0.081 s
pool.ntp.org +3.266 s 0.046 s
ntp.aliyun.com +3.263 s 0.011 s
cloudflare.com（HTTP Date，1 s 分辨率） +3.496 s 0.996 s
www.baidu.com（HTTP Date，1 s 分辨率） +4.020 s 0.050 s

三个 NTP 源的极差只有 6.4 毫秒，说明这不是某一台服务器的问题：本机时钟确实比真实时间快 3.26 秒。两个 HTTP Date 头（秒级分辨率，误差 ±1 s）也落在这个量级，交叉印证了。

3.26 秒意味着什么：

规则：

  1. 跨机比时间之前先测偏移（ntp 子命令，6 行代码），别假设 NTP 在跑；
  2. 事件时间用服务端的（HTTP Date、响应里的 server_time、trace 时间戳），本机时间只用来算「我自己过了多久」；
  3. 「我过了多久」一律用 perf_counter 差值，不要用两个 time.time() 相减——那会把钟偏和钟速（NTP slewing）一起算进耗时里。

8. deadline 判定：50 毫秒的预算，一个刻度就是 1%

deadline 子命令用一个 50 毫秒的 while time.time() - t0 < budget 循环跑 300 次，看它实际越界多少：

budget=0.05  n=300
min=-0.000261  p50=+0.000011  max=+0.000527  mean=+0.000250
越界样本 202/300 (67.3%)   最大越界 1.05%

最大越界 0.527 毫秒——正好等于一个墙钟刻度。也就是说这个循环的精度下界不由你的代码决定，由 time.time() 的刻度决定。注意还有 32.7% 的样本次测量出来的耗时小于预算（min 是 −0.000261），那是刻度把「刚好到点」和「差半个刻度」抹成了同一个读数。

规则：

9. 落地：一张表把「钟」和「用途」绑起来

用途 用哪个钟 不要用 原因（本机读数）
单次耗时、分项 profiling perf_counter() time.time / monotonic / datetime.now 只有它 100 ns 刻度；monotonic 65% 读成 0
总耗时 一次 perf_counter 差值 累加各分项 累加墙钟 n=600 时多记 11.9%，n=1500 时少记 52%
限速 / 节拍 绝对时刻表 + 令牌桶 每轮 sleep(1/rate) naive 2000/s 只有 49.3%
事件顺序 自增 seq 时间戳排序 2000 事件 99.9% 并列
事件绝对时间 服务端时间 / 校过时的钟 本机 now() 本机快 3.26 秒
超时/重试间隔 perf_counter 差值 + 余量 sleep 的请求值 请求 1 ms 实际 1.5 ms（1.50×）
跨机时间对齐 先测 NTP 偏移再比较 「都是 UTC 就能比」 三源极差 6.4 ms，本机偏 3.26 s

上线前 12 项检查：

  1. 代码里搜 time.time()，确认没有一处用于测耗时；
  2. 代码里搜 datetime.now()，同样只用于显示；
  3. 所有 sleep(1/rate) 改成绝对时刻表；
  4. 所有耗时日志的字段名带上单位与钟的名字（ms_perf、s_wall），别只写 duration；
  5. 耗时字段精度与量具刻度对齐（不要出现 0.000ms 或 53201µs 这种假精度）；
  6. 事件表有独立的 seq 列，时间戳不参与唯一性判定；
  7. 跨机日志对齐先跑一次偏移测量，把偏移量记进日志头；
  8. deadline 预算 ≥ 20 个刻度，否则换 perf_counter；
  9. 限速器有 burst 上限（令牌桶容量），否则瞬时尖峰打爆对端；
  10. 重试间隔小于 10 ms 的要加余量，或改成「次数预算」而不是「间隔预算」；
  11. 定时任务（cron）的「跑了多久」用单调钟，不用起止墙钟相减；
  12. 任何「时间戳反了」的异常，先查钟偏，再查代码。

10. 自检里抓到的两个真问题

selftest 22 项，跑的是不变量，不是「本机数值应该等于多少」。写的过程中被自己的断言打回两次：

① 「单调钟记账损失 ≤ 墙钟」是伪不变量，当场 FAIL。
第一版写了这条，跑出来 mono=19.33% wall=3.97%——FAIL。原因不是单调钟差，而是墙钟向上取整会把账记成比事实还多（第 5 节 n=600 那行 +11.9%）。于是「损失」可以是负数，两个数没有可比性。改成锁两条真不变量：单调钟损失必须在 [0, 100]% 且跨 n 稳定（600 vs 3000 差 ≤15 个百分点），墙钟只锁一条硬上界（|sum − true| ≤ 2·n·tick）。

② 「零增量占多数」是条件断言，不是普遍事实。
本机 99.8% 的单笔读成 0，看起来可以硬断言 >0.8。但在刻度更细的机器上（perf_counter 100 ns < 单笔 1 微秒），这个比例会变成 0，断言必然误报。所以写成：只有当「墙钟刻度 > 10 × 单笔耗时」时才断言，否则记 SKIP 并打印原因。跳过不等于通过，但乱断言比跳过更糟——它会让你在换机器时开始怀疑工具。

顺带一提，第一版还写过一条「拿 100/s 的绝对达成率当 2000/s 朴素限速的上界」的对照，那是拼出来的假不变量；改成同速率、同机器直接对比（naive=0.493 abs=1.000）才成立。

退出码（就是结论）：

0  读数在预期内
2  发现异常（NTP 偏移 > --max-offset，或限速达成率 < --min-achieve）
3  前置条件不满足（网络不可达、NTP 无回包）
4  零输入（空参数 / 0 次）——「没测」不是「没问题」
5  自检失败

今天 ntp 的退出码是 2，verdict=CLOCK_OFFSET——不是脚本报错，是它真的查出了这台机器的钟不准。

11. 边界声明

📚 更多创作资源: https://afdian.com/a/felix007

© 2026 小帅在创作 · 自媒体创作与AI工具导航