Repeated reducer execution seems to be delayed by few `ms`

[Shubham8287]

Reported on public discord - https://discord.com/channels/1037340874172014652/1363060408285532253.

A few milliseconds of delay can be expected when the module is busy with other tasks, but this should be investigated if the module isn't doing anything else.

Repro steps:

1. Publish this module

use spacetimedb::{duration, rand::seq::index, reducer, table, ReducerContext, ScheduleAt, Table, TimeDuration, Timestamp};

#[reducer]
fn test_reducer(ctx: &ReducerContext, test: Timer) {
    let now = ctx.timestamp;
    let last_timestamp = ctx.db.timer_tracker().iter().find(|t| t.scheduled_id == test.scheduled_id).map(|t| t.last_timestamp).expect("No last timestamp found");

    let elapsed = now
        .duration_since(last_timestamp)
        .unwrap_or_default()
        .as_millis();

    log::info!("Scheduled Reducer delay: {}ms", elapsed);
    ctx.db.timer_tracker().scheduled_id().update(TimerTracker {
        scheduled_id: test.scheduled_id,
        last_timestamp: ctx.timestamp,
    });
}

#[table(name = timer, public, scheduled(test_reducer))]
pub struct Timer {
    #[primary_key]
    #[auto_inc]
    scheduled_id: u64,
    scheduled_at: ScheduleAt,
}

#[table(name = timer_tracker)]
pub struct TimerTracker {
    #[primary_key]
    pub scheduled_id: u64,
    pub last_timestamp: Timestamp,
}

#[spacetimedb::reducer(init)]
pub fn init(ctx: &ReducerContext) {
    log::info!("Start Invoke");
    let loop_duration: TimeDuration = TimeDuration::from_micros(100_000); //20 ms

    let timer = ctx.db.timer().insert(Timer {
        scheduled_id: 0,
        scheduled_at: loop_duration.into(),
    });


    ctx.db.timer_tracker().insert(TimerTracker {
        scheduled_id: timer.scheduled_id,
        last_timestamp: ctx.timestamp,
    });
}

2. check module logs, you will find consistenly 2-5ms delay between consecutive occurence of repeated reducer.

Investigation:

After running a scheduled reducer, SchedulerActor uses a follow-up internal transaction to delete row entry or Schedule a reducer again incase of repeated reducer

handle_repeated_reducer gets called in this second transaction, Entry made to queue here will yeild back after dur from "now" instead of last scheduled reducer transaction's time.

Duration here should be adjusted to be reduced by the gap between these two transactons.

[gefjon]

Reported specifically on Windows. Reporter said that on Maincloud (hosted on Linux), the variance was significantly less pronounced.

[Pepn]

I had this problem severely running on the maincloud (C# module) not running locally on my WSL