Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
slmjkdbtl opened this issue Jan 24, 2020 · 40 comments
Open
Labels
B - bug Dang, that shouldn't have happened C - needs investigation Issue must be confirmed and researched DS - macos H - help wanted Someone please save us

Comments

@slmjkdbtl
Copy link
Contributor

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
Copy link

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

@goddessfreya goddessfreya added DS - macos H - help wanted Someone please save us C - needs investigation Issue must be confirmed and researched B - bug Dang, that shouldn't have happened labels Jan 26, 2020
@aclysma
Copy link

aclysma commented Jan 29, 2020

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

aclysma/skulpin#31

@pixelprizm
Copy link

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
Copy link
Contributor Author

@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
Copy link

aclysma commented Feb 8, 2020

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
Copy link

aclysma commented Feb 9, 2020

My guess is that this started along with this overhaul commit: d539168 (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_inMode_dequeue_

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
Copy link

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
Copy link

aclysma commented Feb 14, 2020

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
Copy link
Contributor

Imberflur commented Mar 10, 2020

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
Copy link
Contributor

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

@slmjkdbtl
Copy link
Contributor Author

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

@photex
Copy link

photex commented Jun 28, 2020

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

@photex
Copy link

photex commented Jun 29, 2020

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
Copy link

bjorn1004 commented Dec 22, 2022

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
Copy link

rumbogs commented Jan 31, 2023

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

@froody
Copy link

froody commented Feb 9, 2023

@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
Copy link

gRichardson108 commented Apr 20, 2023

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
Copy link

RandomInsano commented Dec 25, 2023

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
Copy link
Member

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
Copy link

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
Copy link
Member

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
Copy link

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
Copy link
Member

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
Copy link

aevyrie commented Dec 29, 2023

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
Copy link

aevyrie commented Dec 29, 2023

Based on previous comments (#1418 (comment)), 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
Copy link
Member

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
Copy link

aevyrie commented Dec 29, 2023

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
Copy link
Member

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
Copy link

aevyrie commented Dec 29, 2023

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
Copy link

RandomInsano commented Dec 29, 2023 via email

@kchibisov
Copy link
Member

kchibisov commented Dec 29, 2023

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
Copy link

aevyrie commented Dec 29, 2023

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
Copy link
Member

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
Copy link

aevyrie commented Dec 29, 2023

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
Copy link
Member

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

to contiguously draw?

@daxpedda
Copy link
Member

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
Copy link
Contributor

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
Copy link
Member

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
Copy link
Contributor

Imberflur commented Jan 23, 2024

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
Copy link
Member

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
B - bug Dang, that shouldn't have happened C - needs investigation Issue must be confirmed and researched DS - macos H - help wanted Someone please save us
Development

No branches or pull requests