Timer adds a surprising amount of delay vs thread::sleep

[vlovich]

For the following test case I see std::thread::sleep take ~11ms but Timer can take up to 40+ms. That's a surprising amount of added latency and I don't see anything in the docs calling this out as intended behavior so figured I'd file a bug while I investigate.

    #[test]
    fn timer_duration() {
        test_executor!(async move {
            let start = Instant::now();
            std::thread::sleep(Duration::from_millis(10));
            let elapsed = start.elapsed();
            assert!(elapsed >= Duration::from_millis(10), "Thread sleep returned too soon: {elapsed:?}");
            assert!(elapsed <= Duration::from_millis(30), "Thread sleep took way too long to run: {elapsed:?}");
            eprintln!("Thread sleep took {:?}", elapsed);

            let start = Instant::now();
            Timer::new(Duration::from_millis(10)).await;
            let elapsed = start.elapsed();
            assert!(elapsed >= Duration::from_millis(10), "Timer expired too soon: {elapsed:?}");
            assert!(elapsed <= Duration::from_millis(30), "Timer took way too long to run: {elapsed:?}");
        });
    }

[vlovich]

Instrumenting the code, I see process_timers getting invoked twice almost instantaneously (which is strange since it's way into the future) and then twice after ~40ms.

One potential thing I'm investigating is whether the preemption timer is fighting with the user timer since they both clobber the same Source in uring.rs (latency_preemption_timeout_src).

[vlovich]

No that was a dead end. I did write a very simple program to verify that io_uring by itself does indeed wake up within the 10ms requested.

sleep_io_uring.c.txt

I instrumented a bunch of stuff within glommio and as best I can tell the sys_membarrier sycall is the thing that's taking all that time. If I switch to the mprotect or fallback strategy, the timers complete normally.

[vlovich]

Ok. Thankfully it's much simpler. This only happens on the first timer because it takes that long to register the membarrier when you have more than 1 thread & all Rust tests have 2 threads.

Given that the strategy is almost certainly going to be used, I feel like we should front-load that when we construct the executor in the first place to avoid this latency.