sleep_until() does not wake up until 5 seconds

[rom1v]

Hi,

In a WASM project, I use wasmtimer 0.4.0 (the current latest version), and I often call wasmtimer::tokio::sleep_until(deadline).await, with a deadline which is in the order of a few milliseconds in the future (typically 0~50ms):

// simplification of my code
loop {
    let deadline = …;
    wasmtimer::tokio::sleep_until(deadline).await;
    log::info!("{}", my_own_get_current_time_ms());
    do_something();
}

Some calls work to sleep_until() work as expected, but some calls wake up only almost 5 seconds later.

Btw, if I log the timestamps (with my own log function based on Performance.now()), then the log is always printed at exactly the same timestamp modulo 5 seconds (for example xxxxxxx0564 ms or xxxxxxx5564 ms).

After a quick search in the codebase, this specific 5 seconds timeout might come from here: https://github.com/whizsid/wasmtimer-rs/blob/7a5f83f98bed85e8d3c20c259ccebeaa9487bf62/src/timer/global.rs#L63

Any idea about the issue?

Thank you

[whizsid]

Hi, That code segment is using when there is no any event scheduled in the timer. By the way are you using NodeJS or Browser?

[rom1v]

That code segment is using when there is no any event scheduled in the timer.

Is that possible that a race condition causes the lib to think that no remaining event is scheduled?

By the way are you using NodeJS or Browser?

Browser (chromium).

[rom1v]

.unwrap_or(Duration::from_secs(5));

That code segment is using when there is no any event scheduled in the timer.

If I change this duration to 2 seconds, then my sleep_until() blocks for 2 seconds instead of 5.

diff --git a/src/timer/global.rs b/src/timer/global.rs
index 5e183de..7f12da7 100644
--- a/src/timer/global.rs
+++ b/src/timer/global.rs
@@ -60,7 +60,7 @@ fn schedule_callback(timer: Arc<Mutex<Timer>>, when: Duration) {
                     Duration::new(0, 0)
                 }
             })
-            .unwrap_or(Duration::from_secs(5));
+            .unwrap_or(Duration::from_secs(2));
         drop(timer_lock);

         schedule_callback(timer, sleep_dur);

[rom1v]

This fixes the issue:

diff --git a/src/timer/global.rs b/src/timer/global.rs
index 5e183de..6b4239e 100644
--- a/src/timer/global.rs
+++ b/src/timer/global.rs
@@ -42,14 +42,6 @@ fn schedule_callback(timer: Arc<Mutex<Timer>>, when: Duration) {
         let now = Instant::now();
         timer_lock.advance_to(now);

-        // Each call to `schedule_callback` calls `schedule_callback` again, but also leaves
-        // the possibility for `schedule_callback` to be called in parallel. Since we don't
-        // want too many useless callbacks, we...
-        // TODO: ugh, that's a hack
-        if Arc::strong_count(&timer) > 20 {
-            return;
-        }
-
         // We call `schedule_callback` again for the next event.
         let sleep_dur = timer_lock
             .next_event()

[rom1v]

There's probably a leak somewhere, this count keeps increasing:

diff --git a/src/timer/global.rs b/src/timer/global.rs
index 5e183de..31ee6fb 100644
--- a/src/timer/global.rs
+++ b/src/timer/global.rs
@@ -42,13 +42,7 @@ fn schedule_callback(timer: Arc<Mutex<Timer>>, when: Duration) {
         let now = Instant::now();
         timer_lock.advance_to(now);

-        // Each call to `schedule_callback` calls `schedule_callback` again, but also leaves
-        // the possibility for `schedule_callback` to be called in parallel. Since we don't
-        // want too many useless callbacks, we...
-        // TODO: ugh, that's a hack
-        if Arc::strong_count(&timer) > 20 {
-            return;
-        }
+        log::info!("===== Arc::strong_count(&timer): {}", Arc::strong_count(&timer));

         // We call `schedule_callback` again for the next event.
         let sleep_dur = timer_lock