assertion failed: new >= now - 1000
主线位置：请求主线的
request_filter，限流通常放在这里：Rate::observe记一次，Rate::rate读速率，超了就回 429。Rate的两格固定窗口和惰性重置见限流。
sequenceDiagram participant A as 线程 A participant R as last_reset participant B as 线程 B A->>R: 读到 0 now=10 B->>R: CAS 0 到 10 成功 A->>R: CAS 0 到 10 失败 拿到 10 Note over A: 10 减 1000 下溢
实验 crate exp-pingora/pitb-lab，bin p27_rate（debug 和 release 都跑）；M2 Max、macOS 27、rustc 1.99.0，pingora-limits 0.9.0，tokio 钉在 1.53.2（原因见怎么读这一卷，这一章不用 tokio）。跑的时候本机负载在 7 到 13 之间（uptime），其他写手的实验也在跑。
现象
8 个线程共用一个 Rate::new(Duration::from_millis(10))，一刻不停地 observe。first：Rate::new 之后立刻开始，跑 1 秒：
let r = Arc::new(Rate::new(interval));
std::thread::sleep(delay);
let start = Instant::now();
let handles: Vec<_> = (0..8)
.map(|i| {
let r = r.clone();
std::thread::spawn(move || {
let mut n = 0u64;
while start.elapsed() < Duration::from_secs(secs) {
r.observe(&(n % 64), 1);
n += 1;
}
// ...
release：
thread '<unnamed>' (5989290) panicked at ~/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/pingora-limits-0.9.0/src/rate.rs:174:17:
assertion failed: new >= now - 1000
...
interval 10ms, start 0ns after Rate::new, 1 s: 1 threads finished, 7 panicked
debug：
thread '<unnamed>' (5989269) panicked at ~/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/pingora-limits-0.9.0/src/rate.rs:174:32:
attempt to subtract with overflow
...
interval 10ms, start 0ns after Rate::new, 1 s: 1 threads finished, 7 panicked
两种构建各跑了 4 次，每次都是 8 个线程里 7 个 panic。docs/user_guide/rate_limiter.md 和 pingora-proxy/examples/rate_limiter.rs 的写法是 static RATE_LIMITER: Lazy<Rate> = Lazy::new(|| Rate::new(Duration::from_secs(1)));：第一次用到时才创建。把窗口改小，服务刚启动、并发请求一起到的那一秒就是这个窗口；示例用的 1 秒正好碰不到（原因见下）。
later：Rate::new 之后先睡 1.1 秒，再跑 3 秒。release 跑了 6 次，没有 panic；debug 跑了 18 次，有 10 次出现 panic，打出位置的都在另一行。下面是其中一次，输出经 sort | uniq -c 汇总，线程号换成了 N（out/p27-debug-later.txt 是其中 10 次）：
1 interval 10ms, start 1.1s after Rate::new, 3 s: 5 threads finished, 3 panicked
3 thread '<unnamed>' (N) panicked at ~/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/pingora-limits-0.9.0/src/rate.rs:147:23:
147 行第 23 列的消息同样是 attempt to subtract with overflow。
出处
Rate::maybe_reset，observe 和 rate 每次都先调它：
fn maybe_reset(&self) -> u64 {
// should be short enough not to overflow
let now = Instant::now().duration_since(self.start).as_millis() as u64;
let last_reset = self.last_reset_time.load(Ordering::SeqCst);
let past_ms = now - last_reset;
if past_ms < self.reset_interval_ms {
// no need to reset
return past_ms;
}
let red_or_blue = self.red_or_blue();
match self.last_reset_time.compare_exchange(
last_reset,
now,
Ordering::SeqCst,
Ordering::Acquire,
) {
Ok(_) => {
// ...
}
Err(new) => {
// another thread beats us to it
assert!(new >= now - 1000); // double check that the new timestamp looks right
}
}
past_ms
}
时间是从 Rate::new 起算的毫秒数，u64。
- 第 174 行：两个线程同时发现该重置了，一个 CAS 成功，另一个拿到
Err(new)，去检查new >= now - 1000。创建后第一秒内now < 1000，now - 1000下溢：debug 在减法处 panic（第 32 列），release 回绕成一个接近u64::MAX的数，比较必然失败，断言 panic（第 17 列）。窗口不小于 1 秒时，第一次重置发生在now >= 1000之后，碰不到；窗口小于 1 秒，第一秒内就有好几次重置，多线程下几乎必然撞上。 - 第 147 行：线程 A 先取了
now，还没读last_reset，线程 B 用一个更晚的now完成了重置；A 读到的last_reset比自己的now大，now - last_reset下溢。这和第一秒无关，每次重置都可能发生，窗口越小重置越频繁。debug 下 panic；release 下回绕成一个巨大的past_ms，接着走「该重置了」的分支（见下面的框）。
两行都从 pingora-limits 的第一个提交 0bca116（2023-05-08，在 0.1.0 之前）就在。tag 之后到 84f21ee，main 上 pingora-limits 只有 c1c4a0d（Estimator 的加法溢出），rate.rs 没有改。这是一个上游问题，两处都改成 saturating_sub 就够了。
问： 线上跑的是 release，第一秒之后 release 也不 panic，是不是就可以不管？
答： 第 147 行在 release 下不 panic，但回绕出来的 past_ms 让落后的那个线程以为「好久没重置了」：它的 CAS 拿着刚读到的 last_reset 去换，往往能成功，于是把时间戳往回拨，再清掉一格、翻转一次。刚完成的那个窗口的计数可能就这样被清掉，rate() 读到 0。实验 p27_rate zero 10 5：8 个线程不停 observe 同一个键，第 9 个线程每毫秒读一次 rate()，数读到 0 的次数（跳过开头三个窗口）。原版和把这两行改成 saturating_sub 的拷贝（src/rate_patched.rs）交替跑，release，5 对：
interval 10ms, 5 s: worker panics 0, rate() samples 3943, read 0: 0, smallest non-zero 9740600/s
interval 10ms, 5 s: worker panics 0, rate() samples 3901, read 0: 0, smallest non-zero 9230000/s
interval 10ms, 5 s: worker panics 0, rate() samples 3612, read 0: 65, smallest non-zero 100/s
interval 10ms, 5 s: worker panics 0, rate() samples 3305, read 0: 2, smallest non-zero 731000/s
interval 10ms, 5 s: worker panics 0, rate() samples 3021, read 0: 28, smallest non-zero 100/s
interval 10ms, 5 s: worker panics 0, rate() samples 3918, read 0: 0, smallest non-zero 9707100/s
interval 10ms, 5 s: worker panics 0, rate() samples 3834, read 0: 25, smallest non-zero 6776300/s
interval 10ms, 5 s: worker panics 0, rate() samples 3950, read 0: 0, smallest non-zero 8358400/s
interval 10ms, 5 s: worker panics 0, rate() samples 3809, read 0: 3, smallest non-zero 5823100/s
interval 10ms, 5 s: worker panics 0, rate() samples 3902, read 0: 1, smallest non-zero 8168600/s
修法
在上游修好之前，窗口不要小于 1 秒。 fix：Rate::new(Duration::from_secs(1))，同样 8 个线程，从创建起跑 3 秒：
interval 1s, start 0ns after Rate::new, 3 s: 8 threads finished, 0 panicked
debug、release 各跑了 3 次，都没有 panic。1 秒的窗口第一次重置在 now >= 1000 之后，第 174 行碰不到；第 147 行仍然可能，但每秒只有一次重置，实验 zero 1000 20（debug，20 秒，跑两次）没有 panic，也没有读到 0。
需要更细的窗口，就把 rate.rs 的两行改掉，用 [patch.crates-io] 换成自己的拷贝：
let past_ms = now.saturating_sub(last_reset); // PATCH: another thread may have reset with a later `now`
// ...
assert!(new >= now.saturating_sub(1000)); // PATCH: `now` < 1000 in the first second
补丁版在 debug 下 first、later 各跑 5 次：
5 interval 10ms, start 0ns after Rate::new, 1 s: 8 threads finished, 0 panicked
5 interval 10ms, start 1.1s after Rate::new, 3 s: 8 threads finished, 0 panicked
在代理里，即使 panic 了也只结束当前请求的任务（客户端空回复），但限流这种「每个请求都经过」的代码，一 panic 就是那一秒里一大片请求。
怎么确认没中招
- 搜
Rate::new(和Rate::new_with_estimator_config(：窗口小于 1 秒，并且会被多个线程（多个工作线程、或多线程运行时）同时调用。 - 日志搜
pingora-limits-0.9.0/src/rate.rs:174和rate.rs:147。 - 用上面的
p27_rate first在自己的窗口值上跑一次 release。
小结
Rate::maybe_reset里两处u64减法会下溢：第 174 行在创建后的第一秒（窗口小于 1 秒时），第 147 行在任何一次重置的竞争里。- release 的报错是
assertion failed: new >= now - 1000，debug 是attempt to subtract with overflow；release 下第 147 行不 panic，但可能清掉刚完成的窗口，rate()读到 0。 - 上游问题，从第一个提交就在，main 未修。窗口用 1 秒及以上，或者打两行
saturating_sub的补丁。