swhkd icon indicating copy to clipboard operation
swhkd copied to clipboard

Published 20 hours ago • verified publisher icon waycrate

`swhkd` does not process hotkeys of newly connected devices

Open ajanon opened this issue 3 years ago • 14 comments
trafficstars

Version Information:

  • Linux arch-dktp-alexis 5.19.6-arch1-1 #1 SMP PREEMPT_DYNAMIC Wed, 31 Aug 2022 22:09:40 +0000 x86_64 GNU/Linux
  • swhkd 1.2.1 (installed from the swhkd-git AUR package)

Describe the bug: swhkd does not register hotkeys from a newly connected keyboard (or disconnected then reconnected).

Expected behavior: swhkd should be able to register hotkeys on a newly connected keyboard.

Actual behavior: swhkd does not grab newly connected devices and thus cannot handle their keypresses events.

To Reproduce: Start swhkd. Connect a keyboard (or disconnect yours before reconnecting it). Hotkeys will not work.

Additional information: This can probably be solved using udev, with either the udev crate or tokio-udev crate.

My attempts at implementing this (the same content is also in the [wip] commits of each branch):

  • Using the tokio-udev crate (udev_async branch):

    This does not work as-is. Unfortunately, sometimes udev events get 'stuck' and only processed after another batch of events comes in. In practice, this translates to e.g. a batch of 'Add' events (after connecting a device) only passed to the application loop after a batch of 'Remove' events (after disconnecting the same device for instance).

  • Using the udev crate iterators wrapped in a tokio stream (udev_sync branch):

    This does not work as-is, as the MonitorSocket Iterator may return None when no udev events are available. tokio stops listening after the first None received from the stream, which means that events are not listened to at all.

  • Using the udev crate with a busy loop (udev_sync_busy branch):

    At the cost of an always busy thread, this does receive all udev events in a timely manner.

The busy loop is the only one which is working, but also the worst performance-wise. See this one more as a proof of concept.

ajanon avatar Sep 14 '22 09:09 ajanon

MWE for each implementation

Each exemple prints events from the 'input' subsystem as they are received. Each log is prefixed by a basic timestamp to highlight the difference between the actual physical event and the time it is passed to the application.

Busy loop

use std::error::Error;
use std::time::{SystemTime, UNIX_EPOCH};
use tokio::select;
use tokio_stream::StreamExt;
use udev::MonitorBuilder;

#[tokio::main]
async fn main() -> Result<(), Box<dyn Error>> {
    let mut udev = tokio_stream::iter(MonitorBuilder::new()?.match_subsystem("input")?.listen()?);
    loop {
        select! {
            udev_item = udev.next() => {
                if udev_item.is_none() {
                    continue;
                }
                let event = udev_item.unwrap();
                println!("[{:?}] '{:?}' event - devnode: {:?}",
                         SystemTime::now().duration_since(UNIX_EPOCH)?.as_secs(),
                         event.event_type(),
                         event.devnode());
            }
        }
    }
}

On my computer, when disconnecting and reconnecting my keyboard, this gives:

[1663146489] 'Remove' event - devnode: Some("/dev/input/event3") [1663146489] 'Remove' event - devnode: None [1663146489] 'Remove' event - devnode: Some("/dev/input/event5") [1663146489] 'Remove' event - devnode: None [1663146489] 'Remove' event - devnode: Some("/dev/input/event6") [1663146489] 'Remove' event - devnode: None [1663146489] 'Remove' event - devnode: Some("/dev/input/event7") [1663146489] 'Remove' event - devnode: None [1663146489] 'Remove' event - devnode: Some("/dev/input/event8") [1663146489] 'Remove' event - devnode: None [1663146491] 'Add' event - devnode: None [1663146491] 'Add' event - devnode: None [1663146491] 'Add' event - devnode: None [1663146491] 'Add' event - devnode: None [1663146491] 'Add' event - devnode: None [1663146491] 'Add' event - devnode: Some("/dev/input/event5") [1663146491] 'Add' event - devnode: Some("/dev/input/event7") [1663146491] 'Add' event - devnode: Some("/dev/input/event6") [1663146491] 'Add' event - devnode: Some("/dev/input/event8") [1663146491] 'Add' event - devnode: Some("/dev/input/event3")

Sync loop

Replace the inner loop with:

        select! {
            Some(event) = udev.next() => {
                println!("[{:?}] '{:?}' event - devnode: {:?}",
                         SystemTime::now().duration_since(UNIX_EPOCH)?.as_secs(),
                         event.event_type(),
                         event.devnode());
            }
            else => {}
        }

This does work in this example, but events are ignored when trying the same thing in swhkd. I think this is because the stream is ignored by tokio on the first None it returns.

Async

use std::error::Error;
use std::time::{SystemTime, UNIX_EPOCH};
use tokio::select;
use tokio_stream::StreamExt;
use tokio_udev::{AsyncMonitorSocket, MonitorBuilder};

#[tokio::main]
async fn main() -> Result<(), Box<dyn Error>> {
    let mut udev = AsyncMonitorSocket::new(MonitorBuilder::new()?.match_subsystem("input")?.listen()?)?;
    loop {
        select! {
            Some(Ok(event)) = udev.next() => {
                println!("[{:?}] '{:?}' event - devnode: {:?}",
                         SystemTime::now().duration_since(UNIX_EPOCH)?.as_secs(),
                         event.event_type(),
                         event.devnode());
            }
        }
    }
}

For two disconnections/reconnections, this gives me (late events in bold):

[1663146903] 'Remove' event - devnode: Some("/dev/input/event3") [1663146903] 'Remove' event - devnode: None [1663146903] 'Remove' event - devnode: Some("/dev/input/event5") [1663146903] 'Remove' event - devnode: None [1663146903] 'Remove' event - devnode: Some("/dev/input/event6") [1663146903] 'Remove' event - devnode: None [1663146903] 'Remove' event - devnode: Some("/dev/input/event7") [1663146903] 'Remove' event - devnode: Some("/dev/input/event8") [1663146903] 'Remove' event - devnode: None [1663146919] 'Remove' event - devnode: None [1663146919] 'Add' event - devnode: None [1663146919] 'Add' event - devnode: None [1663146919] 'Add' event - devnode: None [1663146919] 'Add' event - devnode: None [1663146919] 'Add' event - devnode: None [1663146919] 'Add' event - devnode: Some("/dev/input/event6") [1663146919] 'Add' event - devnode: Some("/dev/input/event8") [1663146919] 'Add' event - devnode: Some("/dev/input/event5") [1663146919] 'Add' event - devnode: Some("/dev/input/event7") [1663146925] 'Add' event - devnode: Some("/dev/input/event3") [1663146925] 'Remove' event - devnode: Some("/dev/input/event3") [1663146925] 'Remove' event - devnode: None [1663146925] 'Remove' event - devnode: Some("/dev/input/event5") [1663146925] 'Remove' event - devnode: None [1663146925] 'Remove' event - devnode: Some("/dev/input/event6") [1663146925] 'Remove' event - devnode: None [1663146925] 'Remove' event - devnode: Some("/dev/input/event7") [1663146925] 'Remove' event - devnode: None [1663146925] 'Remove' event - devnode: Some("/dev/input/event8") [1663146932] 'Remove' event - devnode: None [1663146932] 'Add' event - devnode: None [1663146932] 'Add' event - devnode: None [1663146932] 'Add' event - devnode: None [1663146932] 'Add' event - devnode: None [1663146932] 'Add' event - devnode: None [1663146932] 'Add' event - devnode: Some("/dev/input/event6") [1663146932] 'Add' event - devnode: Some("/dev/input/event8") [1663146932] 'Add' event - devnode: Some("/dev/input/event5")

Please note that here, the input which is the actual keyboard is /dev/input/event3 but it is passed to the application only after it has been removed again.

I do not understand why this happens. The most I was able to understand was that the stream sometimes got 'stuck' on Poll::Pending as if no new events were available (but there actually was).

Running udevadm monitor -s input at the same time shows events in real time with no lag, as the busy loop does. I was not able to track this issue further for now.

ajanon avatar Sep 14 '22 09:09 ajanon

I looked into solving my issue with udev, but if anyone has any other idea, I can also take a shot at it !

ajanon avatar Sep 14 '22 09:09 ajanon

Wow! Impressive bug report and you have my respect for putting in the time to not only investigate the issue but also to propose possible changes ❤️. The implementations look interesting, I'm not too familiar with udev but I just had one question, can udev detect the type of device that we're dealing with? this can help another bug where mice are picked up as keyboards sometimes.

Shinyzenith avatar Sep 16 '22 08:09 Shinyzenith

Apart from that, this looks good, I'll review it in depth once I'm done with relocating!

Shinyzenith avatar Sep 16 '22 08:09 Shinyzenith

I did some digging and found out that we don't need to create a new MonitorSocket from MonitorBuilder::new()?....listen(). We can create this builder once globally and then just poll the socket. Although this too is inefficient, it's...not as bad 🤣.

Shinyzenith avatar Sep 19 '22 03:09 Shinyzenith

can udev detect the type of device that we're dealing with? this can help another bug where mice are picked up as keyboards sometimes.

Maybe?

Take a look at https://wiki.ubuntu.com/X/InputConfiguration#Device_classification: udev classifies devices when detected. With some basic testing on my side, it seems that my keyboard is indeed detected as ID_INPUT_KEYBOARD and my mouse as ID_INPUT_MOUSE... and also ID_INPUT_KEYOARD. My mouse is connected through a Logitech receiver which works for both their mice and keyboards, so it advertises for both (even though I do not have one of their keyboards). This may be better than the current keyboard detection, but it may still yield false positives.

A basic implementation could be:

// or tokio_udev
let mut udev_scan = udev::Enumerator::new()?;
udev_scan.match_subsystem("input")?;
udev_scan.match_property("ID_INPUT_KEYBOARD", "1")?;
let keyboard_devices = udev_scan.scan_devices()?
    .map(|dev| dev.devnode().map(|path| path.to_owned()))
    .flatten()
    .map(evdev::Device::open)
    .flatten()
    .collect::<Vec<_>>();

This works with some basic testing. I could implement a PR for that if you'd like!

To be honest, I think it would be better to fix #131 rather than detecting keyboards: if swhkd could properly re-emit events from all kinds of devices, there would be no need to only grab keyboards, right?

ajanon avatar Sep 19 '22 09:09 ajanon

I did some digging and found out that we don't need to create a new MonitorSocket from MonitorBuilder::new()?....listen(). We can create this builder once globally and then just poll the socket. Although this too is inefficient, it's...not as bad :rofl:.

Is it that bad? Isn't the socket only created once anyway? What does it change to create first the builder?

ajanon avatar Sep 19 '22 09:09 ajanon

I did some digging and found out that we don't need to create a new MonitorSocket from MonitorBuilder::new()?....listen(). We can create this builder once globally and then just poll the socket. Although this too is inefficient, it's...not as bad :rofl:.

Is it that bad? Isn't the socket only created once anyway? What does it change to create first the builder?

It's probably not too different but why perform extra computation when we can just poll the socket descriptor?

Shinyzenith avatar Sep 19 '22 10:09 Shinyzenith

To be honest, I think it would be better to fix #131 rather than detecting keyboards: if swhkd could properly re-emit events from all kinds of devices, there would be no need to only grab keyboards, right?

Okay! it's cool that udev can detect these things for me, intruiging. However I think you're correct, we can drop this task from udev entirely and just implement good mouse support too. I have attempted this in an open pr but failed eventually, would you like to try your hand at it? I'll help as much as I can.

Also I've been meaning to ask, would you like to join us as a maintainer? I've noticed that you have great debugging skills along with good problem solving skills.

Shinyzenith avatar Sep 19 '22 10:09 Shinyzenith

I have time this weekend to work on the udev problem! I'll go ahead and start on a patch asap. PS: Cleared up some unnecessary messages.

Shinyzenith avatar Oct 26 '22 19:10 Shinyzenith

I have reported this issue to tokio-udev upstream: https://github.com/jeandudey/tokio-udev/issues/17 Hopefully they can help us!

ajanon avatar Dec 18 '22 10:12 ajanon

https://app.bountysource.com/issues/118215631-swhkd-does-not-process-hotkeys-of-newly-connected-devices

If anyone is interested!

Shinyzenith avatar Mar 20 '23 13:03 Shinyzenith

The latest updates in the tokio_udev repo make it possible to detect added/removed devices.

This is implemented in the udev_async branch.

I will be waiting for a release of tokio_udev before creating a PR for it.

ajanon avatar May 28 '23 12:05 ajanon

https://github.com/jeandudey/tokio-udev/issues/19

Shinyzenith avatar May 28 '23 16:05 Shinyzenith

@ajanon I tested the udev_async branch and it seems that sometimes, the code seems to panic. I am yet to find the triggering cause. I'll paste the logs below:

[2023-05-30T03:18:22Z INFO  swhkd] Device 'SINO WEALTH Gaming KB ' removed
[2023-05-30T03:18:22Z INFO  swhkd] Device 'SINO WEALTH Gaming KB  Keyboard' removed
thread 'main' panicked at 'index out of bounds: the len is 1 but the index is 2', swhkd/src/daemon.rs:331:43
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

Shinyzenith avatar May 29 '23 21:05 Shinyzenith

Here are the steps I found to reliably reproduce the issue. I have an external keyboard connected to my laptop. Upon disconnecting my external keyboard and attempting to press just a modifier key ( in this case, Super ) It causes swhkd to crash. It seems to be crashing on the keyboard_stream_map match.

Shinyzenith avatar May 29 '23 21:05 Shinyzenith

When running from the main branch swhkd doesn't give any error but it doesn't seem to accept keyboard events any longer. When running from the udev_async branch I get the same error as @Shinyzenith .

[2023-06-03T15:31:04Z INFO  swhkd] Device 'Gaming keyboard' removed
[2023-06-03T15:31:04Z INFO  swhkd] Device 'Gaming keyboard' removed
[2023-06-03T15:31:04Z INFO  swhkd] Device 'Gaming keyboard' removed
thread 'main' panicked at 'removal index (is 3) should be < len (is 1)', swhkd/src/daemon.rs:318:49
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Aborted

CluelessTechnologist avatar Jun 03 '23 16:06 CluelessTechnologist

Is this still an issue?

I wanted to look into it because of the bounty but I can't reproduce the issue with the udev_async head. I can plug and unplug my USB keyboard freely and swhkd seems to cope just fine.

(Incidentally I am doing this on a setup where no commands are actually run, on any hotkey swhkd prints "failed to send command through ipc". swhkd can't find the socket created by swhkd for reasons unclear to me. But that can't be the reason for the error not happening to me, can it?)

ConcurrentCrab avatar Jul 15 '23 20:07 ConcurrentCrab

I have detailed the steps to a crash issue two comments above. Can you reproduce that?

Shinyzenith avatar Jul 15 '23 20:07 Shinyzenith

I have detailed the steps to a crash issue two comments above. Can you reproduce that?

I can connect and disconnect the USB keyboard, and pressing super in both states, on both keyboards (obvs on the external only when connected), makes swhkd log the key. Using any combinations involving super also are logged fine (though the commands not executed, as I mentioned above).

The only combination in my config is a Super + l. I don't think the configured combinations should be relevant to the location of the crash either, however.

Here are the steps I found to reliably reproduce the issue. I have an external keyboard connected to my laptop. Upon disconnecting my external keyboard and attempting to press just a modifier key ( in this case, Super ) It causes swhkd to crash. It seems to be crashing on the keyboard_stream_map match.

Am I missing something?

ConcurrentCrab avatar Jul 15 '23 21:07 ConcurrentCrab

Fixed the socket issue with commands, it was just polkit being weird like always. still can't reproduce the crash.

Wow, that's some main(). Looking at it, I might have some theories, even if I can't reproduce it personally. Is it alright if I make some educated-guess changes and ask any of you (who suffer from the crash) to test?

ConcurrentCrab avatar Jul 15 '23 22:07 ConcurrentCrab

Still don't face the issue, but I came up with some theories and made some fixes to obvious problems: https://github.com/ConcurrentCrab/swhkd/tree/udev_async https://github.com/waycrate/swhkd/pull/216

@Shinyzenith and others: can you test and see if these fixes work for you?

ConcurrentCrab avatar Jul 16 '23 11:07 ConcurrentCrab

Still don't face the issue, but I came up with some theories and made some fixes to obvious problems: https://github.com/ConcurrentCrab/swhkd/tree/udev_async #216

Nice, seems to be working now. Great job!

[2023-07-18T20:11:23Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event2' removed
[2023-07-18T20:11:23Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event3' removed
[2023-07-18T20:11:23Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event4' removed
[2023-07-18T20:11:23Z INFO  swhkd] Device 'Logitech Gaming Mouse G502 Keyboard' at '/dev/input/event1' removed
[2023-07-18T20:11:31Z ERROR swhkd] Could not open evdev device at /dev/input/mouse0: Inappropriate ioctl for device (os error 25)
[2023-07-18T20:11:31Z DEBUG swhkd] Keyboard: Logitech Gaming Mouse G502 Keyboard
[2023-07-18T20:11:31Z INFO  swhkd] Device 'Logitech Gaming Mouse G502 Keyboard' at '/dev/input/event1' added.
[2023-07-18T20:11:31Z DEBUG swhkd] Keyboard: Gaming keyboard
[2023-07-18T20:11:31Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event2' added.
[2023-07-18T20:11:31Z DEBUG swhkd] Keyboard: Gaming keyboard
[2023-07-18T20:11:31Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event3' added.
[2023-07-18T20:11:31Z DEBUG swhkd] Keyboard: Gaming keyboard
[2023-07-18T20:11:31Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event4' added.
[2023-07-18T20:11:31Z TRACE swhkd] Other: Logitech Gaming Mouse G502

CluelessTechnologist avatar Jul 18 '23 20:07 CluelessTechnologist

Fixed the socket issue with commands, it was just polkit being weird like always. still can't reproduce the crash.

Wow, that's some main(). Looking at it, I might have some theories, even if I can't reproduce it personally. Is it alright if I make some educated-guess changes and ask any of you (who suffer from the crash) to test?

Sorry for the late reply. I'm more than happy to do some more testing. Yeah the main() needs cleanup...a lot of it.

Shinyzenith avatar Jul 19 '23 19:07 Shinyzenith

I'll review the PR and get that going.

Shinyzenith avatar Jul 19 '23 19:07 Shinyzenith

I have merged the pr sent by @ConcurrentCrab. Just to be sure @CluelessTechnologist would you mind testing the latest HEAD of udev branch once more? If all is good to go, I'll merge.

Shinyzenith avatar Jul 19 '23 20:07 Shinyzenith

I have merged the pr sent by @ConcurrentCrab. Just to be sure @CluelessTechnologist would you mind testing the latest HEAD of udev branch once more? If all is good to go, I'll merge.

Sure. Just tested the latest commit from udev branch. Happy to report that it's still working:

[2023-07-19T22:49:04Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event2' removed
[2023-07-19T22:49:04Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event3' removed
[2023-07-19T22:49:04Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event4' removed
[2023-07-19T22:49:04Z INFO  swhkd] Device 'Logitech Gaming Mouse G502 Keyboard' at '/dev/input/event1' removed
[2023-07-19T22:49:11Z ERROR swhkd] Could not open evdev device at /dev/input/mouse0: Inappropriate ioctl for device (os error 25)
[2023-07-19T22:49:11Z DEBUG swhkd] Keyboard: Gaming keyboard
[2023-07-19T22:49:11Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event2' added.
[2023-07-19T22:49:11Z DEBUG swhkd] Keyboard: Gaming keyboard
[2023-07-19T22:49:11Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event4' added.
[2023-07-19T22:49:11Z DEBUG swhkd] Keyboard: Gaming keyboard
[2023-07-19T22:49:11Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event3' added.
[2023-07-19T22:49:11Z DEBUG swhkd] Keyboard: Logitech Gaming Mouse G502 Keyboard
[2023-07-19T22:49:11Z INFO  swhkd] Device 'Logitech Gaming Mouse G502 Keyboard' at '/dev/input/event1' added.
[2023-07-19T22:49:11Z TRACE swhkd] Other: Logitech Gaming Mouse G502

CluelessTechnologist avatar Jul 19 '23 22:07 CluelessTechnologist

@CluelessTechnologist I made some minor changes and force pushed. Would you mind testing the branch head one last time? My apologies. After that it'll be ready for merge.

Shinyzenith avatar Jul 20 '23 14:07 Shinyzenith

@CluelessTechnologist I made some minor changes and force pushed. Would you mind testing the branch head one last time? My apologies. After that it'll be ready for merge.

Okay I pulled the latest commit and recompiled and reinstalled. Still seems to be working:

[2023-07-21T13:44:11Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event2' removed
[2023-07-21T13:44:11Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event3' removed
[2023-07-21T13:44:11Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event4' removed
[2023-07-21T13:44:11Z INFO  swhkd] Device 'Logitech Gaming Mouse G502 Keyboard' at '/dev/input/event1' removed
[2023-07-21T13:44:18Z ERROR swhkd] Could not open evdev device at /dev/input/mouse0: Inappropriate ioctl for device (os error 25)
[2023-07-21T13:44:18Z DEBUG swhkd] Keyboard: Gaming keyboard
[2023-07-21T13:44:18Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event2' added.
[2023-07-21T13:44:18Z DEBUG swhkd] Keyboard: Gaming keyboard
[2023-07-21T13:44:18Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event4' added.
[2023-07-21T13:44:18Z DEBUG swhkd] Keyboard: Logitech Gaming Mouse G502 Keyboard
[2023-07-21T13:44:18Z INFO  swhkd] Device 'Logitech Gaming Mouse G502 Keyboard' at '/dev/input/event1' added.
[2023-07-21T13:44:18Z DEBUG swhkd] Keyboard: Gaming keyboard
[2023-07-21T13:44:18Z INFO  swhkd] Device 'Gaming keyboard' at '/dev/input/event3' added.
[2023-07-21T13:44:18Z TRACE swhkd] Other: Logitech Gaming Mouse G502

CluelessTechnologist avatar Jul 21 '23 13:07 CluelessTechnologist

Nice, seems to be working now. Great job!

Awesome! Happy to be of help to y'all, and thanks for the bounty!

@Shinyzenith I can't collect the bounty on bountysource.com until this issue is marked as closed, so I'd really appreciate it if you could close it and test miscelleneous changes afterwards :P

ConcurrentCrab avatar Jul 22 '23 20:07 ConcurrentCrab