Time-keeping broken with `UpdateMode::Reactive` (X11 and WASM)

[Azorlogh]

Bevy version

Bevy 0.14.1 and main

X11 adapter: AdapterInfo { name: "NVIDIA GeForce RTX 2060", vendor: 4318, device: 7817, device_type: DiscreteGpu, driver: "NVIDIA", driver_info: "555.58.02", backend: Vulkan }
WASM adapter:AdapterInfo { name: "NVIDIA GeForce GTX 980, or similar", vendor: 4318, device: 0, device_type: Other, driver: "WebGL", driver_info: "2.0", backend: Gl }

Happens on native X11, and WASM (Firefox and Chrome)

What you did

Run this example:

use std::time::Duration;

use bevy::{
    input::common_conditions::input_just_pressed,
    prelude::*,
    winit::{UpdateMode, WinitSettings},
};

fn main() {
    App::new()
        .add_plugins(DefaultPlugins.build())
        .add_systems(Startup, |mut cmds: Commands| {
            cmds.spawn(Camera2dBundle::default());
        })
        .add_systems(
            Update,
            (run, switch.run_if(input_just_pressed(KeyCode::KeyU))).chain(),
        )
        .run();
}

fn switch(mut settings: ResMut<WinitSettings>) {
    settings.focused_mode = match settings.focused_mode {
        UpdateMode::Continuous => {
            info!("Switching to continuous!");
            UpdateMode::reactive(Duration::from_secs(1))
        }
        UpdateMode::Reactive { .. } => {
            info!("Switching to reactive!");
            UpdateMode::Continuous
        }
    };
    settings.unfocused_mode = settings.focused_mode;
}

fn run(time: Res<Time>, settings: ResMut<WinitSettings>, mut gizmos: Gizmos) {
    info!("{} {:?}", time.delta_seconds(), settings.focused_mode);
    gizmos.circle_2d(
        Vec2::from_angle(time.elapsed_seconds() * std::f32::consts::TAU) * 128.0,
        32.0,
        Color::WHITE,
    );
}

What went wrong

• Initially, delta_time is consistent
• The circle revolves at 1 revolution per second.
• Press U, to switch to reactive mode
• Now the delta_time increases every frame, until it caps off at 0.25s
  • As a result, the circle moves around instead of appearing roughly in the same place (what you would expect if the app updates ~every second)
• Press U again, to switch back to continuous mode
  • The next frame has a low delta_time, as expected BUT
  • The following frame gets a strange lag spike at 0.25s, making the circle briefly appear in another position before going back to rotating normally.

Additional information

X11 logs

2024-08-09T15:29:24.328881Z  INFO update_mode_switch: 0.006974337 Continuous
2024-08-09T15:29:24.335733Z  INFO update_mode_switch: 0.006931047 Continuous
2024-08-09T15:29:24.342786Z  INFO update_mode_switch: 0.006965437 Continuous
2024-08-09T15:29:24.342826Z  INFO update_mode_switch: Switching to reactive!
2024-08-09T15:29:24.349579Z  INFO update_mode_switch: 0.006900987 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true }
2024-08-09T15:29:24.422030Z  INFO update_mode_switch: 0.006958497 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true }
2024-08-09T15:29:25.342941Z  INFO update_mode_switch: 0.006940747 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true }
2024-08-09T15:29:26.343144Z  INFO update_mode_switch: 0.05999414 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true }
2024-08-09T15:29:27.343763Z  INFO update_mode_switch: 0.25 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true }
2024-08-09T15:29:28.343784Z  INFO update_mode_switch: 0.25 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true }
2024-08-09T15:29:29.343866Z  INFO update_mode_switch: 0.25 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true }
2024-08-09T15:29:29.812715Z  INFO update_mode_switch: 0.25 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true }
2024-08-09T15:29:29.812754Z  INFO update_mode_switch: Switching to continuous!
2024-08-09T15:29:29.813895Z  INFO update_mode_switch: 0.25 Continuous
2024-08-09T15:29:29.814938Z  INFO update_mode_switch: 0.25 Continuous
2024-08-09T15:29:29.815371Z  INFO update_mode_switch: 0.00067504 Continuous
2024-08-09T15:29:29.816060Z  INFO update_mode_switch: 0.001055621 Continuous
2024-08-09T15:29:29.816653Z  INFO update_mode_switch: 0.000581371 Continuous
2024-08-09T15:29:29.817327Z  INFO update_mode_switch: 0.00066637 Continuous
2024-08-09T15:29:29.817929Z  INFO update_mode_switch: 0.000625411 Continuous

X11 logs (different run showing a single normal continuous frame in between the freaky 0.25s frames)

2024-08-09T15:37:07.687200Z  INFO update_mode_switch: 0.006944937 Continuous
2024-08-09T15:37:07.694232Z  INFO update_mode_switch: 0.006939317 Continuous
2024-08-09T15:37:07.701115Z  INFO update_mode_switch: 0.006946427 Continuous
2024-08-09T15:37:07.701148Z  INFO update_mode_switch: Switching to reactive!
2024-08-09T15:37:07.708097Z  INFO update_mode_switch: 0.006948797 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true }
2024-08-09T15:37:07.809416Z  INFO update_mode_switch: 0.006945327 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true }
2024-08-09T15:37:08.532579Z  INFO update_mode_switch: 0.006942567 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true }
2024-08-09T15:37:08.532621Z  INFO update_mode_switch: Switching to continuous!
2024-08-09T15:37:08.533378Z  INFO update_mode_switch: 0.08901965 Continuous
2024-08-09T15:37:08.534797Z  INFO update_mode_switch: 0.25 Continuous
2024-08-09T15:37:08.535216Z  INFO update_mode_switch: 0.000840611 Continuous
2024-08-09T15:37:08.535908Z  INFO update_mode_switch: 0.00076325 Continuous
2024-08-09T15:37:08.536541Z  INFO update_mode_switch: 0.000646981 Continuous
2024-08-09T15:37:08.537180Z  INFO update_mode_switch: 0.000634641 Continuous

WASM logs

INFO examples/window/update_mode_switch.rs:27 Switching to reactive! wasm_example.js:435:21
INFO examples/window/update_mode_switch.rs:39 0.006 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true } wasm_example.js:435:21
INFO examples/window/update_mode_switch.rs:39 0.008 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true } wasm_example.js:435:21
INFO examples/window/update_mode_switch.rs:39 0.082 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true } wasm_example.js:435:21
INFO examples/window/update_mode_switch.rs:39 0.25 Reactive { wait: 1s, react_to_device_events: true, react_to_user_events: true, react_to_window_events: true } 8 wasm_example.js:435:21
INFO examples/window/update_mode_switch.rs:31 Switching to continuous! wasm_example.js:435:21
INFO examples/window/update_mode_switch.rs:39 0.25 Continuous wasm_example.js:435:21
INFO examples/window/update_mode_switch.rs:39 0.002 Continuous wasm_example.js:435:21
INFO examples/window/update_mode_switch.rs:39 0.013 Continuous wasm_example.js:435:21
INFO examples/window/update_mode_switch.rs:39 0.008 Continuous wasm_example.js:435:21
INFO examples/window/update_mode_switch.rs:39 0.012 Continuous wasm_example.js:435:21

[tychedelia]

The behavior that I'm seeing on macOS is that when I switch into reactive mode, the circle does not animate correct for the first few frames before the delta stabilizes. This seems to be the opposite of what's described in "what went wrong"?

[Azorlogh]

Update:
It seems that Time<Virtual> has its delta-time capped at 0.25s, so this part is easily explained.
I think this reduces the problem to being a delay in the reported delta-times.
When switching to reactive mode, it reports the previous, smaller delta-times of continuous mode for a few frames, causing animations to slow down.
When switching back to continuous mode, it reports the previous, larger delta-times of reactive mode for a few frames, causing animations to speed up.

I suspect it's actually unrelated to UpdateMode, and is just a quirk of bevy's timekeeping logic since frame times are reported from the render thread. The timings take a while to arrive so I guess we always read delta-times from a few frames back

[aloucks]

Have you tried using Time<Fixed>?