Intermittent `Failed to acquire key` Errors in Concurrent `RateLimiter` Usage with `FakeRelativeClock`

[NOBLES5E]

Test Code:

Repo here: https://github.com/NOBLES5E/governor-bug

fn main() {
    let clock = FakeRelativeClock::default();
    let quota = Quota::per_second(nonzero!(2500u32));
    let lim = Arc::new(RateLimiter::hashmap_with_clock(quota, clock));
    let ms = Duration::from_millis(1);
    let key = Bytes::from("conflict_key");

    crossbeam::scope(|scope| {
        for _ in 0..10 {
            let key = key.clone();
            let lim = lim.clone();
            scope.spawn(move |_| {
                for _ in 0..250 {
                    let ret = lim.check_key(&key).expect("Failed to acquire key");
                    lim.clock().advance(100 * ms);
                }
            });
        }
    })
    .unwrap();
}

Observed Behavior:
Occasionally, the test fails with an error similar to:

Failed to acquire key: NotUntil { state: StateSnapshot { t: Nanos(400µs), tau: Nanos(999.6ms), time_of_measurement: Nanos(60.5008s), tat: Nanos(60.5008s) }, start: Nanos(0ns) }

Check https://github.com/NOBLES5E/governor-bug/actions/runs/12728781775/job/35479772416 for example.

Expected Behavior:
Given the rate limiter is configured with a quota of 2500 requests per second and each thread performs 250 requests with a total simulated time advancement that should comfortably accommodate the quota, the check_key method should not fail.

[antifuchs]

OK, a few suspicious things here:

1. The tat and time_of_check are identical. That is consistent across all panics I've observed; it is pretty indicative of "you're exceeding the rate limit on an artificially-advanced clock".
2. The check and the advance of the clock are separated, so could be interrupted by interleaved thread scheduling.
3. This succeeds with only one thread but already fails when there are only two threads.
4. It also succeeds if we wrap the check & clock advancement in a mutex, but fails if we only wrap the clock advancement in a mutex.

So we have two operations that can happen per thread, and they get interleaved arbitrarily:

• check and consume a cell
• advance the clock

I wonder if an interleaved sequence of operations exists that will cause the burst balance to be used up seemingly spuriously.

[antifuchs]

Update: It's funny and insidious. I think I've found the issue, and it took a bit of working to get there (the error message wasn't helpful alone, I needed to see the positive measurements first).

My comment above is mistaken: There are three operations that happen per thread:

1. CUR - retrieve the current time t0 (src)
2. CHK(t) - check if the cell at t, the time from above, can be consumed (src)
3. ADV - advance the clock (via FakeRelativeClock::advance)

The issue becomes slightly less unclear once you write it out, I think:

• t1: CUR - t0
• t2: CUR - t0
• t1: CHK(t0)
• t1: ADV
• t1: CUR - t1, CHK(t1), ADV - a bunch of times, until the expected time of arrival for the next cell is way past t0.
• t2: CHK(t0) - failure

CHK(t) in step 2 changes the rate limiter state and changes it according to the time passed in, ensuring that attempting a measurement at a previous time will fail - it's way before the next expected time of arrival!

So I think this means that the FakeRelativeClock isn't safe to use in a multi-threaded context; Maybe the type its now() method returns ought to be something that turns into Nanos only when tested... but even that can run into the same concurrency issue above.

That insight was enabled by #270, I think I can rewrite this slightly less annoyingly backwards-incompatible, too.

[NOBLES5E]

Thanks for spending time figuring this out!