search

rust-windowing / winit

Window handling library in pure Rust
https://docs.rs/winit/
Apache License 2.0
4.86k stars 909 forks source link

[MacOS] Continuous events like MouseMotion and MouseWheel seem laggy in 0.20 #1418

Open slmjkdbtl opened 4 years ago

slmjkdbtl commented 4 years ago

before 0.20 (pseudocode):

// smooth
loop {
    ev.poll_events(|e| {
        match e {
            DeviceEvent::MouseMotion => {
                // deal with mouse movement
            }
        }
    });
    update();
    render();
}

after 0.20:

// laggy
ev.run(move |e, flow| {
    match e {
        DeviceEvent::MouseMotion => {
            // deal with mouse movement
        },
        RedrawRequested => {
            update();
            render();
        }
        MainEventsCleared => {
            window.request_redraw();
        }
    }
})

Not sure if it's me not setting up correctly. It's pretty obvious in my 3d first person camera example, the example is running at >60fps, movement with keyboard is smooth, but the camera movement which responds to mousemove looks like 20 fps. I have 2 binaries for comparison between 2 versions (I'm using glutin not winit directly, so glutin 0.22 vs glutin 0.21): mousemove_lag_test.zip.

pixelprizm commented 4 years ago

I am experiencing a similar issue where the mouse events lag behind the cursor, and there is a large amount of lag when you click and hold.

Here's a Gist with a demo: https://gist.github.com/egauderman/e0e3958f9ac4508f4a0e5839107fbd5a

aclysma commented 4 years ago

I’ve been seeing this too for a while. I had some notes on it here:

https://github.com/aclysma/skulpin/issues/31

pixelprizm commented 4 years ago

I'm curious if it's possible to investigate the similarities/differences between winit and Reprocessing uses for window events, as I used Reprocessing in the past for graphics programming and it didn't have this mouse lag issue (on the same device).

slmjkdbtl commented 4 years ago

@egauderman Or just compare changes between 0.20 and 0.19? I didn't have the problem with 0.19, this looks like a problem related to the eventloop refactor

aclysma commented 4 years ago

I spent a good amount of time trying to figure this out tonight. The lag is pretty conspicuous when printing out all events. Here's what it looks like just dragging the mouse:

Smoothly moving the mouse

wakeup
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7875    NewEvents(Poll)
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 0.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1268.15625, y: 444.6015625 }, modifiers: (empty) } })
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (0.0, 1.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1267.6640625, y: 445.0859375 }, modifiers: (empty) } })
cleared
ready!
take events
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7875    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7875    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 0.0) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7875    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1268.15625, y: 444.6015625 }, modifiers: (empty) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7875    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7875    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (0.0, 1.0) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7875    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1267.6640625, y: 445.0859375 }, modifiers: (empty) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7875    MainEventsCleared
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7875    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7892    RedrawEventsCleared
wakeup
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7892    NewEvents(Poll)
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 1.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1266.1875, y: 447.0234375 }, modifiers: (empty) } })
cleared
ready!
take events
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7892    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7892    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7892    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 1.0) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7892    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1266.1875, y: 447.0234375 }, modifiers: (empty) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7893    MainEventsCleared
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7893    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7921    RedrawEventsCleared
wakeup
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7921    NewEvents(Poll)
cleared
ready!
take events
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7921    MainEventsCleared
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7921    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7939    RedrawEventsCleared
wakeup
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7939    NewEvents(Poll)
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 1.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1262.7421875, y: 450.4140625 }, modifiers: (empty) } })
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 1.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1260.7734375, y: 452.8359375 }, modifiers: (empty) } })
cleared
ready!
take events
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7939    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7939    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7939    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 1.0) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7939    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1262.7421875, y: 450.4140625 }, modifiers: (empty) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7939    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7939    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7940    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 1.0) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7940    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1260.7734375, y: 452.8359375 }, modifiers: (empty) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7940    MainEventsCleared
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7940    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7955    RedrawEventsCleared
wakeup
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7955    NewEvents(Poll)
cleared
ready!
take events
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7956    MainEventsCleared
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7956    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7971    RedrawEventsCleared
wakeup
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7971    NewEvents(Poll)
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -2.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 2.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-2.0, 2.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1256.8359375, y: 456.2265625 }, modifiers: (empty) } })
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -2.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-2.0, 1.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1252.8984375, y: 458.6484375 }, modifiers: (empty) } })
cleared
ready!
take events
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7972    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -2.0 } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7972    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 2.0 } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7972    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-2.0, 2.0) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7972    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1256.8359375, y: 456.2265625 }, modifiers: (empty) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7972    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -2.0 } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7972    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7972    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-2.0, 1.0) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7972    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1252.8984375, y: 458.6484375 }, modifiers: (empty) } }
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7972    MainEventsCleared
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7972    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:40Z WARN  skulpin::app::app] EVENT AT 7977    RedrawEventsCleared
wakeup

Smoothly move the mouse but add a left click while moving the mouse

But throw in clicking the mouse while being careful to keep the mouse moving:

wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8194    NewEvents(Poll)
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 1.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1231.15625, y: 478.9921875 }, modifiers: (empty) } })
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8195    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8195    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8195    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 1.0) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8195    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1231.15625, y: 478.9921875 }, modifiers: (empty) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8195    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8195    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8213    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8213    NewEvents(Poll)
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8214    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8214    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8227    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8227    NewEvents(Poll)
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8227    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8227    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8245    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8245    NewEvents(Poll)
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8246    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8246    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8260    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8260    NewEvents(Poll)
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8260    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8261    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8280    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8280    NewEvents(Poll)
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8280    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8280    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8292    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8292    NewEvents(Poll)
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8292    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8292    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8309    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8309    NewEvents(Poll)
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8309    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8309    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8325    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8325    NewEvents(Poll)
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8325    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8325    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8342    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8342    NewEvents(Poll)
push back event [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Button { button: 0, state: Pressed } })]
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Button { button: 0, state: Pressed } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: MouseInput { device_id: DeviceId(DeviceId), state: Pressed, button: Left, modifiers: (empty) } })
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 2.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 2.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1228.203125, y: 483.3515625 }, modifiers: (empty) } })
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Button { button: 0, state: Released } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: MouseInput { device_id: DeviceId(DeviceId), state: Released, button: Left, modifiers: (empty) } })
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -19.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 13.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-19.0, 13.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1191.671875, y: 508.3359375 }, modifiers: (empty) } })
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    DeviceEvent { device_id: DeviceId(DeviceId), event: Button { button: 0, state: Pressed } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    WindowEvent { window_id: WindowId(Id(140268456159024)), event: MouseInput { device_id: DeviceId(DeviceId), state: Pressed, button: Left, modifiers: (empty) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 2.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 2.0) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1228.203125, y: 483.3515625 }, modifiers: (empty) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    DeviceEvent { device_id: DeviceId(DeviceId), event: Button { button: 0, state: Released } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    WindowEvent { window_id: WindowId(Id(140268456159024)), event: MouseInput { device_id: DeviceId(DeviceId), state: Released, button: Left, modifiers: (empty) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -19.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 13.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-19.0, 13.0) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1191.671875, y: 508.3359375 }, modifiers: (empty) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    MainEventsCleared
app received mouse down
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8343    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8359    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8359    NewEvents(Poll)
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8359    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8359    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8377    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8377    NewEvents(Poll)
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 1.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1188.71875, y: 510.2734375 }, modifiers: (empty) } })
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -2.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-2.0, 1.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1184.6953125, y: 512.6953125 }, modifiers: (empty) } })
queue events []
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1184.6953125, y: 513.1796875 }, modifiers: (empty) } })
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8378    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -1.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8378    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8378    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-1.0, 1.0) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8378    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1188.71875, y: 510.2734375 }, modifiers: (empty) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8378    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -2.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8378    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8378    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-2.0, 1.0) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8378    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1184.6953125, y: 512.6953125 }, modifiers: (empty) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8378    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1184.6953125, y: 513.1796875 }, modifiers: (empty) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8378    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8378    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8396    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8396    NewEvents(Poll)
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8396    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8396    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8417    RedrawEventsCleared
wakeup
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8417    NewEvents(Poll)
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -2.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-2.0, 1.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1181.25, y: 515.6015625 }, modifiers: (empty) } })
queue events [StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -2.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 2.0 } }), StaticEvent(DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-2.0, 2.0) } })]
queue event StaticEvent(WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1176.8203125, y: 518.9921875 }, modifiers: (empty) } })
cleared
ready!
take events
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8418    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -2.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8418    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 1.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8418    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-2.0, 1.0) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8418    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1181.25, y: 515.6015625 }, modifiers: (empty) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8418    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 0, value: -2.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8418    DeviceEvent { device_id: DeviceId(DeviceId), event: Motion { axis: 1, value: 2.0 } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8418    DeviceEvent { device_id: DeviceId(DeviceId), event: MouseMotion { delta: (-2.0, 2.0) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8418    WindowEvent { window_id: WindowId(Id(140268456159024)), event: CursorMoved { device_id: DeviceId(DeviceId), position: PhysicalPosition { x: 1176.8203125, y: 518.9921875 }, modifiers: (empty) } }
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8418    MainEventsCleared
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8418    RedrawRequested(WindowId(Id(140268456159024)))
[2020-02-08T09:32:41Z WARN  skulpin::app::app] EVENT AT 8438    RedrawEventsCleared
wakeup

It looks to me like, when clicking, events stop being emitted for about 100ms.

It looks to me like something isn't right with the delivery of events from NSApplication to the registered callback, which makes me suspect something is wrong with the setup for NSApplication or CFRunLoop. But I'm not familiar enough with the platform to know for certain.

aclysma commented 4 years ago

My guess is that this started along with this overhaul commit: https://github.com/rust-windowing/winit/commit/d5391686ae98914ba54e30d872d0e42b5ab5800c (I didn't verify this, but it's a huge change and fundamentally changes how events are handled on macOS, so I think it's a good possibility)

Before it looks like events were continuously polled by calling appkit::NSApp().nextEventMatchingMask_untilDate_inModedequeue

Now it relies on receiving callbacks from NSApplication, which calls an extern "C" fn send_event which in turn calls maybe_dispatch_device_event(this, event);

pixelprizm commented 4 years ago

Not sure if this is helpful but I checked the Reason Reprocessing library (which in my experience handles mac touchpad input smoothly as I mentioned in my earlier comment) and found that it depends on SDL and internally it calls SDL_PollEvent. Not sure if this is helpful but putting it out there for reference.

(i.e. Reprocessing depends on Reasongl which depends on a fork of TSDL which is a wrapper around SDL, and specifically SDL_PollEvent (appears as "poll_event" in the Reason code) is what kicks off the mouse move events)

aclysma commented 4 years ago

With the disclaimer that I've never written a line of objective C in my life, and that I have no experience working on macOS, I think this is where SDL does their event handling: https://github.com/spurious/SDL-mirror/blob/6b6170caf69b4189c9a9d14fca96e97f09bbcc41/src/video/cocoa/SDL_cocoaevents.m

There is a line here:

NSEvent *event = [NSApp nextEventMatchingMask:NSEventMaskAny untilDate:[NSDate distantPast] inMode:NSDefaultRunLoopMode dequeue:YES ];

Looking at the 0.19 winit code there was something similar with the comment "Wait for the next event. Note that this function blocks during resize."

                // Wait for the next event. Note that this function blocks during resize.
                let ns_event = appkit::NSApp().nextEventMatchingMask_untilDate_inMode_dequeue_(
                    NSEventMask::NSAnyEventMask.bits() | NSEventMask::NSEventMaskPressure.bits(),
                    foundation::NSDate::distantFuture(cocoa::base::nil),
                    foundation::NSDefaultRunLoopMode,
                    cocoa::base::YES);

The second undtilDate was distantFuture in the rust implementation, perhaps if that were distantPast like in SDL, it wouldn't block.

So maybe manually pumping these events is still an option? (Assuming the only reason for changing the way this was handled before was to avoid blocking.)

Also of note, SDL also has this call [NSApp sendEvent:event]; Not sure if that does anything we'd want to do too.

Imberflur commented 4 years ago

Using ControlFlow::Poll, performing sleeping manually in MainEventCleared we see a pattern where the MainEventCleared occurs in pairs without any intervening motion events:

Generating mouse event: (8.000, 0.000)
Generating mouse event: (19.000, -5.000)
[DeviceEvent::MouseMotion(8.000, 0.000)] @ 0.193 us, 342.641 us after winit created
[DeviceEvent::MouseMotion(19.000, -5.000)] @ 41.391 us, 178.440 us after winit created
[MainEventCleared] @ 50.862 us
[MainEventCleared] @ 34315.527 us
Generating mouse event: (42.000, -8.000)
Generating mouse event: (83.000, -16.000)
[DeviceEvent::MouseMotion(42.000, -8.000)] @ 70504.492 us, 319.739 us after winit created
[DeviceEvent::MouseMotion(83.000, -16.000)] @ 70528.703 us, 153.272 us after winit created
[MainEventCleared] @ 70541.742 us
[MainEventCleared] @ 106441.617 us
Generating mouse event: (80.000, -11.000)
Generating mouse event: (133.000, -14.000)
[DeviceEvent::MouseMotion(80.000, -11.000)] @ 141973.828 us, 366.537 us after winit created
[DeviceEvent::MouseMotion(133.000, -14.000)] @ 141990.969 us, 123.327 us after winit created
[MainEventCleared] @ 141999.312 us
[MainEventCleared] @ 177216.766 us
Generating mouse event: (110.000, -10.000)
Generating mouse event: (189.000, -2.000)
[DeviceEvent::MouseMotion(110.000, -10.000)] @ 213950.781 us, 390.369 us after winit created
[DeviceEvent::MouseMotion(189.000, -2.000)] @ 213971.625 us, 131.365 us after winit created
[MainEventCleared] @ 213983.016 us
[MainEventCleared] @ 249157.875 us
Generating mouse event: (201.000, -4.000)
Generating mouse event: (316.000, -15.000)
[DeviceEvent::MouseMotion(201.000, -4.000)] @ 285859.250 us, 464.474 us after winit created
[DeviceEvent::MouseMotion(316.000, -15.000)] @ 285882.094 us, 134.143 us after winit created
[MainEventCleared] @ 285893.969 us
[MainEventCleared] @ 321141.406 us
Generating mouse event: (311.000, -13.000)
Generating mouse event: (192.000, -14.000)
[DeviceEvent::MouseMotion(311.000, -13.000)] @ 359207.062 us, 532.341 us after winit created
[DeviceEvent::MouseMotion(192.000, -14.000)] @ 359241.375 us, 186.857 us after winit created
[MainEventCleared] @ 359253.594 us

Code here: https://github.com/Imberflur/winit/blob/04ab898d0939752df709c403c382838c207ea0e4/examples/mouse_test.rs

Imberflur commented 4 years ago

Polling twice appears to workaround this issue (ie only running update code, sleeping, etc every other MainEventCleared)

slmjkdbtl commented 4 years ago

@Imberflur That's a valid workaround for now, thanks!

photex commented 4 years ago

Just chiming in that I am seeing noticeable lag on Windows 10 (nvidia and intel integrated gpus).

photex commented 4 years ago

In my case at least, I ran my app with Tracy and discovered that due to driver differences between each machine, the time to get the next swapchain texture was "fixed" on one machine to 16ms, but totally unbounded on another. As a result, what I thought was lag was actually just a bug in my handling of input events which causes them to be framerate dependent.

My apologies!

bjorn1004 commented 1 year ago

I discovered what I think is the same bug on windows 10 and I think the reason is a high mouse polling rate. I own a mouse that has a configurable polling rate, and on higher rates the screen will completely freeze when I move the mouse around rapidly, but on lower rates there are no issues

log at 500Hz MainEventsCleared RedrawRequested CursorMoved MainEventsCleared RedrawRequested CursorMoved MainEventsCleared RedrawRequested CursorMoved CursorMoved MainEventsCleared RedrawRequested CursorMoved

log at 1000Hz MainEventsCleared RedrawRequested CursorMoved CursorMoved CursorMoved MainEventsCleared RedrawRequested CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved

log at 8000hz, at this point the application freezes completely when I rapidly move the mouse CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved CursorMoved

rumbogs commented 1 year ago

Any updates on this one? It's been 2 years...

froody commented 1 year ago

@rumbogs I ran into a similar issue, have you tried sampling the app (using Activity Monitor -> Sample App)? I have a vulkan-based app and found it was spending most of the time blocking the main thread waiting for [CAMetalLayer nextDrawable]. I was seeing up to 1 second delay before my app responed to mouse clicks. I fixed it by:

  1. Moving all rendering to a separate thread
  2. Sending winit events from the main thread to the rendering thread via a mpsc channel
  3. On the rendering thread, slurp all the events into a vec, and then only perform one RedrawRequested per batch of events. This made my app super responsive to all mouse input
gRichardson108 commented 1 year ago

Having a similar issue on Windows. I implemented a fly-camera, but when I move the mouse, the game basically freezes or stutters. Moving the camera with keyboard controls works fine. When I print the events, I get a ton of DeviceEvents with the deltas only ever maxing out at 1.0, ie:

DeviceEvent { device_id: DeviceId(DeviceId(65595)), event: Motion { axis: 0, value: 1.0 } }
DeviceEvent { device_id: DeviceId(DeviceId(65595)), event: MouseMotion { delta: (1.0, 0.0) } }

I'll have like 200 of these events if I move the mouse quickly before I get one MainEventsCleared event. Seems like my event loop spends all of its time clearing the device events, so it takes too long to generate MainEventsCleared for me to have a good framerate while moving the mouse. Hopefully there's something silly I'm missing here.

I'm on winit 0.27.5, via glutin.

RandomInsano commented 10 months ago

I've seen a few workarounds by using MainEventsCleared (one in this thread, one here).

It looks like in 0.29.6 that's no longer available. What's the workaround these days? It seems completely gone (I've checked WindowEvent just in case).

I'm coming from a big code migration from SDL2 to save binary space so this development is pretty disappointing. I'm also on macOS 12.7.2

kchibisov commented 10 months ago

Draw from RedrawRequested or trigger it from AboutToWait. There's also an option to try figure out what is laggy (since I can't repro that) and fix.

RandomInsano commented 10 months ago

Yup, that did it. For future generations what I was doing was rendering every iteration of the run() event handler. This also had the effect of creating extreme input lag on Linux the longer the program ran. I'm guessing because event processing was being slowed down by rendering each frame?

The Winit system deduplicates RedrawRequested events from request_redraw().

Thanks for the speedy reply here! Hopefully this helps others.

kchibisov commented 10 months ago

I'm guessing because event processing was being slowed down by rendering each frame?

I mean you tried to render for each event comming, so if moving mouse will generate 100 events you need to render 100 frames to keep up, usually you do mini-batch or draw from e.g. event when going back to sleep without events, like AboutToWait.

RandomInsano commented 10 months ago

Absolutely! It's a facepalming-level mistake 😅. I'm just a bit surprised the event queue didn't throw some sort of error but I guess the event queue silently throws things away which would mean the heavier producers of events like mice would get pruned out more often?

kchibisov commented 10 months ago

It depends on the platform, on Wayland you'll eventually be killed because you overflow the socket on the server. X11 indefinitely buffers so you'll eventually process all the events.

aevyrie commented 10 months ago

I think I've hit this in bevy, I noticed this after switching to macOS. Here is the most illustrative log I've been able to produce:

INFO mouse_input_events: Frame 602
INFO mouse_input_events: MouseMotion { delta: Vec2(-36.0, -2.0) }
INFO mouse_input_events: MouseMotion { delta: Vec2(-35.0, -2.0) }
INFO mouse_input_events: Frame 603
INFO mouse_input_events: MouseMotion { delta: Vec2(-20.0, -2.0) }
INFO mouse_input_events: Frame 604
INFO mouse_input_events: Frame 605
INFO mouse_input_events: Frame 606
INFO mouse_input_events: MouseMotion { delta: Vec2(-31.0, -1.0) }
INFO mouse_input_events: MouseMotion { delta: Vec2(-29.0, -1.0) }
INFO mouse_input_events: Frame 607
INFO mouse_input_events: Frame 608
INFO mouse_input_events: Frame 609
INFO mouse_input_events: Frame 610
INFO mouse_input_events: Frame 611
INFO mouse_input_events: Frame 612
INFO mouse_input_events: Frame 613
INFO mouse_input_events: Frame 614
INFO mouse_input_events: Frame 615
INFO mouse_input_events: Frame 616
INFO mouse_input_events: Frame 617
INFO mouse_input_events: Frame 618
INFO mouse_input_events: Frame 619
INFO mouse_input_events: Frame 620
INFO mouse_input_events: Frame 621
INFO mouse_input_events: Frame 622
INFO mouse_input_events: Frame 623
INFO mouse_input_events: Frame 624
INFO mouse_input_events: MouseButtonInput { button: Left, state: Pressed, window: 0v0 }
INFO mouse_input_events: Frame 625
INFO mouse_input_events: Frame 626
INFO mouse_input_events: Frame 627
INFO mouse_input_events: Frame 628
INFO mouse_input_events: MouseMotion { delta: Vec2(-38.0, 0.0) }
INFO mouse_input_events: Frame 629
INFO mouse_input_events: MouseButtonInput { button: Left, state: Pressed, window: 0v0 }
INFO mouse_input_events: MouseMotion { delta: Vec2(-390.0, -2.0) }
INFO mouse_input_events: MouseMotion { delta: Vec2(-194.0, -2.0) }
INFO mouse_input_events: Frame 630
INFO mouse_input_events: Frame 631
INFO mouse_input_events: Frame 632
INFO mouse_input_events: MouseMotion { delta: Vec2(-75.0, -1.0) }
INFO mouse_input_events: MouseMotion { delta: Vec2(-78.0, -3.0) }
INFO mouse_input_events: Frame 633
INFO mouse_input_events: MouseMotion { delta: Vec2(-68.0, -1.0) }
INFO mouse_input_events: Frame 634
INFO mouse_input_events: MouseMotion { delta: Vec2(-75.0, -1.0) }

Somewhere around frame 607 is where the left mouse button is being pressed, however instead we see a huge gap in events until frame 624, where the press is registered, then another 4 frames until a small delta is received, then the release event is received, and finally, on frame 629 we see two huge mouse deltas show up, about 10x larger than normal. This is where the inputs "catch up" after the hitch.

I noticed the issue is nonexistent when running without vsync, so effectively polling winit at 1,000 fps, so it seems there is some amount of event loop polls (>2) you need to do to grab the missing inputs.

aevyrie commented 10 months ago

Based on previous comments (https://github.com/rust-windowing/winit/issues/1418#issuecomment-596936884), I tried the approach of only running application updates once every 2 MainEventsCleared. This helped, but did not fix it. I had to bump this up to one app update for every 20 MainEventsCleared to make the stutter imperceptible.

kchibisov commented 10 months ago

Have you tried running updates once per render operation which you throttle by either vsync, timer targeting refresh rate, or similar? MainEventsCleared could happen a lot per single frame thus if you do heavy updates on it you clearly will get input lag.

aevyrie commented 10 months ago

A bevy game/application's update runs after processing all winit events and the MainEventsCleared event is reached.

MainEventsCleared could happen a lot per single frame thus if you do heavy updates on it you clearly will get input lag.

Why would this be happening a lot per frame? The docs say:

Emitted when all of the event loop's input events have been processed and redraw processing is about to begin. [...] Programs that draw graphics continuously, like most games, can render here unconditionally for simplicity.

kchibisov commented 10 months ago

input, but how input events are being delivered is up to underlying windowing system. On macOS it may happen more than it should, since it's a synthetic concept, and that was also a reason we removed MainEventsCleared all together from 0.29 series.

aevyrie commented 10 months ago

input, but how input events are being delivered is up to underlying windowing system.

Sorry, I don't understand. Is there documentation I could read about this change?

RandomInsano commented 10 months ago

Not sure about docs, but it’s true that when the window is hidden or minimized the loop runs very quickly consuming 100% of a core. I do put a synthetic 100ms sleep in that case and track that state with the Occluded event.I should calculate frame rate at some point, but it does seem to be artificially throttled by OpenGL already. CPU load is 10% of an M1 efficiency core which is what I was getting with SDL2 so personally I’ll dig in more if/when I need to.On Dec 28, 2023, at 10:29 PM, Aevyrie @.***> wrote: A bevy game/application runs after processing all winit events and the MainEventsCleared event is reached.

MainEventsCleared could happen a lot per single frame thus if you do heavy updates on it you clearly will get input lag.

Why would this be happening a lot per frame? The docs say:

Emitted when all of the event loop's input events have been processed and redraw processing is about to begin. [...] Programs that draw graphics continuously, like most games, can render here unconditionally for simplicity.

—Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you commented.Message ID: @.***>

kchibisov commented 10 months ago

CPU load is 10% of an M1 efficiency core which is what I was getting with SDL2 so personally I’ll dig in more if/when I need to.On Dec 28, 2023, at 10:29 PM, Aevyrie @.***> wrote:

Maybe you can just set the polling mode to Wait and then wait until you're not Occluded anymore (if you really want to go back to Polling)? Like winit is designed for GUIs in mind so having a busy loop is really odd compared to SDL.

aevyrie commented 10 months ago

Looking at the latest docs, I see https://docs.rs/winit/latest/winit/event/enum.Event.html#variant.AboutToWait

Most applications shouldn’t need to hook into this event since there is no real relationship between how often the event loop needs to wake up and the dispatching of any specific events.

High frequency event sources, such as input devices could potentially lead to lots of wake ups and also lots of corresponding AboutToWait events.

Okay, I think this is what @kchibisov is saying about input events.

This is not an ideal event to drive application rendering from and instead applications should render in response to WindowEvent::RedrawRequested events.

Okay, this makes sense. I updated the application update to only run when RedrawRequested is received. However, after doing this, the application hangs. I force the event loop to continue, and I see that RedrawRequested is only ever sent twice - even when resizing the window which the docs suggest should be triggering a redraw.

The winit examples show manually sending window.request_redraw from the AboutToWait event, which seems contradictory to the documentation - it's just extra steps to end up calling app.update when AboutToWait is received.

It's not really clear how we are supposed to be using the eventloop then. My assumption was that it would look something like

  1. Consume all available winit events up to the current time.
  2. Run app.update(), usually limited by vsync to ~16ms.
  3. Repeat

However there does not seem to be a way to say "give me all events I haven't seen since now". Additionally, I don't see how it would help resolve the issue in this ticket, because when pressing LMB on macOS I'm am seeing many frames of delay (i.e. 100 ms) before the mouse motion events are received - and I can't block the game/app waiting for them to show up.

kchibisov commented 10 months ago

The winit examples show manually sending window.request_redraw from the AboutToWait event, which seems contradictory to the documentation - it's just extra steps to end up calling app.update when AboutToWait is received.

you can ask for redraw from the RedrawRequested itself.

However there does not seem to be a way to say "give me all events I haven't seen since now".

you can do mini batching. 100ms sounds insane, do you have the same input lag in e.g. alacritty, it has relatively good loop?

aevyrie commented 10 months ago

you can ask for redraw from the RedrawRequested itself.

I don't understand, why would I request a redraw in response to a redraw?

do you have the same input lag in e.g. alacritty, it has relatively good loop?

Input lag is normally fine, that is not the issue. The issue is only when using LMB on macOS, at which point mouse move events are postponed by about 100ms. Although, it also seems to go away when re-running the event loop repeatedly, so something seems to be wrong in the platform implementation for macOS.

kchibisov commented 10 months ago

I don't understand, why would I request a redraw in response to a redraw?

to contiguously draw?

daxpedda commented 10 months ago

The issue seems to be that there is an expectation to connect some tickrate to Winit, this was done in the past with MainEventsCleared, but this was misleading, hence the removal.

Drawing should be done at RedrawRequested, so if you want to update exactly as fast as you draw, maybe you should do it there. If you want to redraw every frame, as kchibisov said, you should call Window::request_redraw() every frame, so in RedrawRequested, because RedrawRequested is only delivered on request, not by default every frame.

If you want Winit's help to do something like a tickrate, you can use ControlFlow::WaitUntil, but binding it to any other event, e.g. AboutToWait, won't work as those don't happen at a fixed rate or anything like that.

To clarify what AboutToWait means: it just means that there are no further events right now, it does not mean that the next event cycle we are going to draw or that it has any relationship to specific timing or to specific events, you should treat this as completely random, as it depends on user input and such.

I think the documentation around this in Winit is incredibly lackluster and should definitely be improved. In the meantime, please let us know if there is anything else unclear here.

Imberflur commented 9 months ago

From this discussion, I'm a bit confused about what exactly AboutToWait is or isn't promising...

E.g. naively, I would expect that if there are some events being steadily generated, then longer delays before returning to winit eventually lead to more events clustered before the next AboutToWait. Is this generally the case or could AboutToWait be inserted between every event no matter what the delay before returning to winit is?

Is it not possible to use ControlFlow::Poll and have a point to manually sleep at without returning control to winit during the sleep?

I realize this would be a bad pattern on the web backend, since we don't want to block the main thread there. For this topic I am interested in the Linux, Macos, and Windows backends.

daxpedda commented 9 months ago

From this discussion, I'm a bit confused about what exactly AboutToWait is or isn't promising...

AboutToWait will be triggered as soon as there are no new events and the event loop is about to block (ergo "wait"). The delay between AboutToWaits could be 10µq or 10s, it only depends if there are new events or not.

E.g. naively, I would expect that if there are some events being steadily generated, then longer delays before returning to winit eventually lead to more events clustered before the next AboutToWait.

This wouldn't happen unless you actually block the event loop like you suggested, but yes, then events would be "clustered" before Winit is able to resume again, fires all "clustered" events and then ends with a AboutToWait when there are no new events.

Is this generally the case or could AboutToWait be inserted between every event no matter what the delay before returning to winit is?

AboutToWait is not inserted between every event. It is only triggered when there are no new events.

Is it not possible to use ControlFlow::Poll and have a point to manually sleep at without returning control to winit during the sleep?

I realize this would be a bad pattern on the web backend, since we don't want to block the main thread there. For this topic I am interested in the Linux, Macos, and Windows backends.

It should be possible, but this isn't only a "bad pattern" on Web, it would be for most platforms (I know it is at least for Linux and MacOS). The event loop does other things in the background that need to be able to run, so blocking the thread would prevent that. I know that on Linux this can lead to outright crashes, on MacOS some things are queued to run on the main thread, which blocking would prevent.

I recommend you to look into ControlFlow::WaitUntil to get the behavior you seek without actually blocking the main thread.

Imberflur commented 9 months ago

Thanks for answering all my questions!

it would be for most platforms (I know it is at least for Linux and MacOS). The event loop does other things in the background that need to be able to run, so blocking the thread would prevent that. I know that on Linux this can lead to outright crashes, on MacOS some things are queued to run on the main thread, which blocking would prevent.

Interesting, there is one thing this makes me curious about. What if my updates take longer than the target tick/frame rate (or my application is trying to run at the maximum possible frame rate) such that there is no time to wait. Would this basically lead to the same issues? (another thing that comes to mind is blocking on VSync)

kchibisov commented 9 months ago

On macOS I'm not sure about that, but on Wayland you'll likely crash as of now if you don't read events for a while and you have input going, like fastly moving a mouse (winit can't do anything about it at all, it's out of our control for now, in the future there will be a way in libwayland to make buffers unbounded, but that's about it).

If your renderer is way too slow, I'd suggest for you to move it into its own thread, and never block the event loop for way to long, and probably have a pure data state which you can update on main and then read and render on other thread.