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

Keyboard/mouse not working after reboot on arch based distros #197

Closed
saikat0511 opened this issue Oct 22, 2021 · 33 comments
Closed

Keyboard/mouse not working after reboot on arch based distros #197

saikat0511 opened this issue Oct 22, 2021 · 33 comments

Comments

@saikat0511
Copy link

Installed key-mapper-git from AUR. After setting it up and rebooting the mouse doesn't work. It starts working after couple of minutes but then the keyboard stops working. Uninstalling the package fixes the issue.

Both manjaro and endeavouros show this behavior. I am using KDE.

Attaching a journalctl log if that helps...
eos-log-tool.log

@sezanzeb
Copy link
Owner

sezanzeb commented Oct 22, 2021

Are you able to reproduce the problem by running the service manually?

sudo systemctl stop key-mapper && sudo systemctl disable key-mapper would stop it and it won't start automatically at boot anymore

then run sudo key-mapper-service -d in a console in order to get some debug logs. Keep this running. Once you open the gui tool after that and start the injection you should be able to see more logs in the console.

Once the problem is reproduced please share the logs. If you want to avoid sharing everything you typed in here, you can remove all lines saying SPAM keycode_mapper.py. "SPAM" lines that appear after the problem is reproduced might be interesting though.

@sezanzeb
Copy link
Owner

The mouse you are trying to map is the "Logitech M585/M590", right? And it seems to be a bluetooth mouse?

@sezanzeb
Copy link
Owner

sezanzeb commented Oct 22, 2021

The output of xinput might be useful from

  1. when key-mapper is not running
  2. when key-mapper is working correctly
  3. when key-mapper starts having the problem

@saikat0511
Copy link
Author

saikat0511 commented Oct 22, 2021

The mouse you are trying to map is the "Logitech M585/M590", right? And it seems to be a bluetooth mouse?

yes, and yes. It don't think it matters tho because it works fine with key-mapper when I use it on ubuntu based distros

sudo systemctl stop key-mapper && sudo systemctl disable key-mapper would stop it and it won't start automatically at boot anymore

It doesn't seem to work. After reboot systemctl status shows disabled but Mouse KB still stop working. (Seems like the problem isn't with key-mapper but something else?)

xinput output seems interesting. Mouse disappears from the output when it stops working, reappears when when it starts working again but the keyboard disappears as it stops working (had to use onscreen keyboard to use the terminal)

When mouse stops working after reboot:

⎡ Virtual core pointer                          id=2    [master pointer  (3)]
⎜   ↳ Virtual core XTEST pointer                id=4    [slave  pointer  (2)]
⎜   ↳ Wacom HID 5218 Finger                     id=15   [slave  pointer  (2)]
⎣ Virtual core keyboard                         id=3    [master keyboard (2)]
    ↳ Virtual core XTEST keyboard               id=5    [slave  keyboard (3)]
    ↳ Power Button                              id=6    [slave  keyboard (3)]
    ↳ Video Bus                                 id=7    [slave  keyboard (3)]
    ↳ Video Bus                                 id=8    [slave  keyboard (3)]
    ↳ Power Button                              id=9    [slave  keyboard (3)]
    ↳ Lid Switch                                id=10   [slave  keyboard (3)]
    ↳ Sleep Button                              id=11   [slave  keyboard (3)]
    ↳ Ideapad extra buttons                     id=12   [slave  keyboard (3)]
    ↳ AT Translated Set 2 keyboard              id=13   [slave  keyboard (3)]    <<< keyboard is fine, but mouse not listed
    ↳ Wacom HID 5218 Pen                        id=14   [slave  keyboard (3)]

Note that the keyboard is listed and working at this point in time, but the mouse and touchpad are not. (touchscreen and pen are not affected)

After couple of minutes mouse and touchpad start working again, but keyboard stops working and disappears from xinput output:

⎡ Virtual core pointer                          id=2    [master pointer  (3)]
⎜   ↳ Virtual core XTEST pointer                id=4    [slave  pointer  (2)]
⎜   ↳ Wacom HID 5218 Finger                     id=15   [slave  pointer  (2)]
⎜   ↳ MSFT0001:00 04F3:3140 Mouse               id=6    [slave  pointer  (2)]    <<<
⎜   ↳ MSFT0001:00 04F3:3140 Touchpad            id=8    [slave  pointer  (2)]    <<<
⎜   ↳ Logitech M585/M590                        id=10   [slave  pointer  (2)]    <<< mouse and touchpad are back, but keyboard is gone
⎣ Virtual core keyboard                         id=3    [master keyboard (2)]
    ↳ Virtual core XTEST keyboard               id=5    [slave  keyboard (3)]
    ↳ Video Bus                                 id=7    [slave  keyboard (3)]
    ↳ Wacom HID 5218 Pen                        id=14   [slave  keyboard (3)]
    ↳ Integrated Camera: Integrated C           id=9    [slave  keyboard (3)]
    ↳ Logitech M585/M590 

@saikat0511
Copy link
Author

saikat0511 commented Oct 22, 2021

Another thing I noticed is that during installation I get this in between the logs:

Created symlink /etc/systemd/system/key-mapper.service → /usr/lib/systemd/system/key-mapper.service.
Created symlink /etc/systemd/system/default.target.wants/key-mapper.service → /usr/lib/systemd/system/key-mapper.service.
Job for key-mapper.service failed because the control process exited with error code.
See "systemctl status key-mapper.service" and "journalctl -xeu key-mapper.service" for details.
error: command failed to execute correctly

After installation completes running systemctl status key-mapper.service show the following:

× key-mapper.service - Service to inject keycodes without the GUI application
     Loaded: loaded (/usr/lib/systemd/system/key-mapper.service; enabled; vendor preset: disabled)
     Active: failed (Result: exit-code) since Fri 2021-10-22 16:51:14 IST; 54s ago
   Main PID: 5804 (code=exited, status=1/FAILURE)
        CPU: 204ms

Oct 22 16:51:14 81x1 key-mapper-service[5804]: Optional `xmodmap` command not found. This is not critical.
Oct 22 16:51:14 81x1 key-mapper-service[5804]: This output is also stored in "/var/log/key-mapper"
Oct 22 16:51:14 81x1 key-mapper-service[5804]: Logging to "/var/log/key-mapper"
Oct 22 16:51:14 81x1 key-mapper-service[5804]: key-mapper-service 1.2.1 38ba5ab8b971c5d1f50106f47262724f354dbb71 https://github.com/sezanzeb/key-mapper
Oct 22 16:51:14 81x1 key-mapper-service[5804]: python-evdev 1.4.0
Oct 22 16:51:14 81x1 key-mapper-service[5804]: ERROR: Is the service already running? (g-dbus-error-quark: GDBus.Error:org.freedesktop.DBus.Error.AccessDenied: Connection ":1.69" is not allowed to own the service "keymapper.Control" due to security policies in the configuration file (9))
Oct 22 16:51:14 81x1 key-mapper-service[5804]: Stopping all injections
Oct 22 16:51:14 81x1 systemd[1]: key-mapper.service: Main process exited, code=exited, status=1/FAILURE
Oct 22 16:51:14 81x1 systemd[1]: key-mapper.service: Failed with result 'exit-code'.
Oct 22 16:51:14 81x1 systemd[1]: Failed to start Service to inject keycodes without the GUI application.

At this point key-mapper along with mouse and keyboard all work fine, until I reboot after which the issue happens. That error seems useful.

@saikat0511
Copy link
Author

Running sudo key-mapper-service -d for the first time gave me the following error:

Traceback (most recent call last):
  File "/usr/bin/key-mapper-service", line 28, in <module>
    from keymapper.logger import update_verbosity, log_info, \
  File "/usr/lib/python3.9/site-packages/keymapper/logger.py", line 29, in <module>
    import pkg_resources
ModuleNotFoundError: No module named 'pkg_resources'

Did a quick google search and fixed it by installing python-setuptools

After a reboot mouse, touchpad, touchscreen and pen were not working (key-mapper was disabled in systemctl). Ran the command and got the following:

2105 0.03973 DEBUG groups.py:335: Discovering device paths
2105 0.04028 SPAM groups.py:367: Found "3_1133_16491_usb-0000:00:14.0-4", "/dev/input/event16", "Logitech Wireless Device PID:406b Mouse", type: mouse
2105 0.04067 SPAM groups.py:367: Found "3_1133_16491_usb-0000:00:14.0-4", "/dev/input/event7", "Logitech Wireless Device PID:406b Keyboard", type: keyboard
2105 0.04228 SPAM groups.py:367: Found "24_1386_21016_i2c-WACF2200:00", "/dev/input/event9", "Wacom HID 5218 Finger", type: touchpad
2105 0.04271 SPAM groups.py:367: Found "24_1386_21016_i2c-WACF2200:00", "/dev/input/event8", "Wacom HID 5218 Pen", type: graphics-tablet
2105 0.04312 SPAM groups.py:367: Found "24_1267_12608_i2c-MSFT0001:00", "/dev/input/event19", "MSFT0001:00 04F3:3140 Touchpad", type: touchpad
2105 0.04353 SPAM groups.py:367: Found "24_1267_12608_i2c-MSFT0001:00", "/dev/input/event18", "MSFT0001:00 04F3:3140 Mouse", type: mouse
2105 0.04370 SPAM groups.py:367: Found "25_0_6_LNXVIDEO", "/dev/input/event15", "Video Bus", type: unknown
2105 0.04384 SPAM groups.py:367: Found "25_0_6_LNXVIDEO", "/dev/input/event14", "Video Bus", type: unknown
2105 0.04412 SPAM groups.py:367: Found "25_0_0_ideapad", "/dev/input/event5", "Ideapad extra buttons", type: unknown
2105 0.04447 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event4", "AT Translated Set 2 keyboard", type: keyboard
2105 0.04501 SPAM groups.py:367: Found "25_0_3_PNP0C0E", "/dev/input/event2", "Sleep Button", type: unknown
2105 0.04611 INFO groups.py:438: Found "Logitech Wireless Device PID:406b Mouse", "Wacom HID 5218 Pen", "MSFT0001:00 04F3:3140 Mouse", "Video Bus", "Ideapad extra buttons", "AT Translated Set 2 keyboard", "Sleep Button"
2105 0.04764 DEBUG system_mapping.py:64: Gathering available keycodes
2105 0.05107 DEBUG system_mapping.py:86: Writing "/home/saikat/.config/key-mapper/xmodmap.json"
2105 0.05236 SPAM shared_dict.py:58: Starting SharedDict process
2129 0.05387 SPAM shared_dict.py:64: SharedDict process started
2105 0.05477 INFO logger.py:203: This output is also stored in "/var/log/key-mapper"
2105 0.05507 INFO logger.py:219: Logging to "/var/log/key-mapper"
2105 0.05515 INFO logger.py:163: key-mapper-service 1.2.1 38ba5ab8b971c5d1f50106f47262724f354dbb71 https://github.com/sezanzeb/key-mapper
2105 0.05532 INFO logger.py:168: python-evdev 1.4.0
2105 0.05540 WARNING logger.py:171: Debug level will log all your keystrokes! Do not post this output in the internet if you typed in sensitive or private information with your device!
2105 0.05551 DEBUG daemon.py:147: Creating daemon
2105 0.05963 DEBUG daemon.py:220: Running daemon

When the mouse started working and keyboard stopped working, the following lines appeared in the teminal:

2105 82.1154 INFO daemon.py:334: Request to autoload for "Logitech Wireless Device PID:406b Mouse"
2105 82.1156 DEBUG daemon.py:338: Tried to autoload "Logitech Wireless Device PID:406b Mouse" without configuring the daemon first via set_config_dir.
2105 82.1842 INFO daemon.py:334: Request to autoload for "MSFT0001:00 04F3:3140 Mouse"
2105 82.1844 DEBUG daemon.py:338: Tried to autoload "MSFT0001:00 04F3:3140 Mouse" without configuring the daemon first via set_config_dir.
2105 82.6549 INFO daemon.py:334: Request to autoload for "Wacom HID 5218 Pen"
2105 82.6551 DEBUG daemon.py:338: Tried to autoload "Wacom HID 5218 Pen" without configuring the daemon first via set_config_dir.
2105 82.8321 INFO daemon.py:334: Request to autoload for "Wacom HID 5218 Pen"
2105 82.8323 DEBUG daemon.py:338: Tried to autoload "Wacom HID 5218 Pen" without configuring the daemon first via set_config_dir.
2105 83.9779 INFO daemon.py:334: Request to autoload for "Logitech M585/M590"
2105 83.9781 DEBUG daemon.py:338: Tried to autoload "Logitech M585/M590" without configuring the daemon first via set_config_dir.
2105 84.4055 INFO daemon.py:334: Request to autoload for "Logitech M585/M590"
2105 84.4056 DEBUG daemon.py:338: Tried to autoload "Logitech M585/M590" without configuring the daemon first via set_config_dir.

Waited for another half hour, nothing else got logged

@sezanzeb
Copy link
Owner

sezanzeb commented Oct 22, 2021

I just added python-setuptools to the dependencies in the AUR package, thanks

It doesn't seem to work. After reboot systemctl status shows disabled but Mouse KB still stop working. (Seems like the problem isn't with key-mapper but something else?)

You can verify if it is really stopped by checking ps -aux | grep key-mapper, or via key-mapper-control --command hello

Note, that the user interface starts a service process if it is not found running

@saikat0511
Copy link
Author

After disabling the service and reboot, output of key-mapper-control --command hello is:
ERROR: Service not running? g-dbus-error-quark: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name keymapper.Control was not provided by any .service files (2)

While the mouse remains non fuctional the output of ps -aux | grep key-mapper is:

root         347  2.1  0.2 472088 32184 ?        S    19:02   0:00 /usr/bin/python3 /bin/key-mapper-control --command autoload --device /dev/input/event2
root         351  2.1  0.2 406552 32100 ?        S    19:02   0:00 /usr/bin/python3 /bin/key-mapper-control --command autoload --device /dev/input/event3
root         352  2.1  0.2 537624 32108 ?        S    19:02   0:00 /usr/bin/python3 /bin/key-mapper-control --command autoload --device /dev/input/event1
root         357  2.0  0.2 865304 32232 ?        S    19:02   0:00 /usr/bin/python3 /bin/key-mapper-control --command autoload --device /dev/input/event0
root         481  1.9  0.2 799768 32384 ?        S    19:02   0:00 /usr/bin/python3 /bin/key-mapper-control --command autoload --device /dev/input/event4
root         773  2.0  0.2 472084 32320 ?        S    19:02   0:00 /usr/bin/python3 /bin/key-mapper-control --command autoload --device /dev/input/event13
root         796  2.1  0.2 472088 32464 ?        S    19:02   0:00 /usr/bin/python3 /bin/key-mapper-control --command autoload --device /dev/input/event6
root         809  2.2  0.2 537624 32540 ?        S    19:02   0:00 /usr/bin/python3 /bin/key-mapper-control --command autoload --device /dev/input/event15
root         829  2.1  0.2 537624 32456 ?        S    19:02   0:00 /usr/bin/python3 /bin/key-mapper-control --command autoload --device /dev/input/event7
myname      2514  0.0  0.0   6504  2444 pts/0    S+   19:02   0:00 grep key-mapper

Once the mouse and other input devices start working and keyboard stops working the output of the same is:

root        2602  0.1  0.2 119564 32336 ?        S    19:05   0:00 /usr/bin/python3 /bin/key-mapper-control --command autoload --device /dev/input/event6
myname      2890  0.0  0.0   6504  2440 pts/0    S+   19:08   0:00 grep key-mapper

Also this issue seems random. Sometimes after reboot all devices works as expected and nothing goes wrong :/

@sezanzeb
Copy link
Owner

sezanzeb commented Oct 22, 2021

After a reboot mouse, touchpad, touchscreen and pen were not working (key-mapper was disabled in systemctl). Ran the command and got the following:

If the command doesn't exit right away it probably means it wasn't running before

When the mouse started working and keyboard stopped working, the following lines appeared in the teminal:

This is caused by key-mappers udev rule https://github.com/sezanzeb/key-mapper/blob/clean-history-main/data/key-mapper.rules

i.e. something is causing your devices to disconnect and reconnect or something

Tried to autoload "Wacom HID 5218 Pen" without configuring the daemon first via set_config_dir.

I just pushed changes to main that avoid this problem when the gui connects to the service, or when it is run via sudo on its own

@sezanzeb
Copy link
Owner

sezanzeb commented Oct 22, 2021

So

  • service not running, key-mapper installed: issues
  • service running, key-mapper installed: issues
  • service not running, key-mapper uninstalled: no issues

did I get that right?

Are you still having issues if you run sudo mv /usr/lib/udev/rules.d/key-mapper.rules /usr/lib/udev/rules.d/key-mapper.rules.old to disable key-mappers udev rule? That would mean you have to start the injections yourself via the gui or key-mapper-control.

@saikat0511
Copy link
Author

running sudo mv /usr/lib/udev/rules.d/key-mapper.rules /usr/lib/udev/rules.d/key-mapper.rules.old seems to have fixed the issue. Rebooted multiple times to verify, working as expected. Thanks!

That would mean you have to start the injections yourself via the gui or key-mapper-control

I am not sure what do you mean by that. Autoload is still working.

@sezanzeb
Copy link
Owner

Autoload is still working

probably because of https://github.com/sezanzeb/key-mapper/blob/clean-history-main/data/key-mapper-autoload.desktop, which triggers autoloading on login, I forgot about that one.

If you unplug your device and plug it back in, the preset won't be applied though. Having udev rules seemed to be required to make it work with bluetooth devices in at least one case.

@saikat0511
Copy link
Author

yeah presets aren't applied after replugging the device. I can live with that tho, I dont usually disconnect my mouse.

Any clue why is this only happening on arch based distros? I have been using key-mapper on many debian/ubuntu based distros and it has been worked flawlessly on the same system.

@sezanzeb
Copy link
Owner

no idea unfortunately.

Maybe you could try to compare/upgrade kernel, systemd and libevdev versions

@Liniya
Copy link

Liniya commented Nov 4, 2021

I'm also on Manjaro KDE, and it displays a bit different symptoms for me. Fairly often after a reboot, sound would be disabled for a couple of minutes (the speaker icon in the task panel is crossed out), then it is enabled by itself displaying the name of the sound card briefly, and at the same moment, an error like this appears in the logs:

Nov 04 09:18:13 hostname systemd-udevd[378]: event18: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event18' [777] timed out after 2min 59s, killing
Nov 04 09:18:13 hostname systemd-udevd[332]: event18: Worker [378] processing SEQNUM=4133 killed
Nov 04 09:18:13 hostname systemd-udevd[332]: event18: Worker [378] failed

Sometimes this doesn't happen and it seems fine. It's completely random. Likewise for the remapped buttons, most of the time they do work regardless of whether this error appears, but sometimes they do stop (either after a reboot, or after this error appears, I think) and I need to open the key-mapper menu and re-apply the preset.

For now, I've tried to apply the fix mentioned here with renaming udev rules file to .old, and so far I'm not seeing this error after 3 reboots.

@sezanzeb
Copy link
Owner

sezanzeb commented Nov 4, 2021

I just added timeouts to the key-mapper-control calls that are much shorter than the udev timeout. Does that improve anything for you?

@Liniya
Copy link

Liniya commented Nov 4, 2021

I've reinstalled the AUR package, and likewise, not seeing this error so far after 3 reboots. I'll see how it goes and report back if it happens again. Thanks.

@Liniya
Copy link

Liniya commented Nov 8, 2021

Well, it seems this has started again, after working for a couple of days without errors. Here's the first one, from yesterday:

Nov 07 08:39:47 hostname systemd-udevd[358]: event13: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event13' [716] timed out after 2min 59s, killing
Nov 07 08:39:47 hostname systemd-udevd[331]: event13: Worker [358] processing SEQNUM=4144 killed
Nov 07 08:39:47 hostname systemd-udevd[331]: event13: Worker [358] failed

And two from today. Strangely the 'spawned process' line referring specifically to key-mapper is not present in the 1st one:

Nov 08 07:13:06 hostname systemd-udevd[332]: event15: Worker [347] processing SEQNUM=4129 killed
Nov 08 07:13:06 hostname systemd-udevd[332]: event15: Worker [347] failed
Nov 08 11:09:09 hostname systemd-udevd[377]: event17: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event17' [778] timed out after 2min 59s, killing
Nov 08 11:09:09 hostname systemd-udevd[333]: event17: Worker [377] processing SEQNUM=4163 killed
Nov 08 11:09:09 hostname systemd-udevd[333]: event17: Worker [377] failed

There was no problem with the mapped buttons regardless of these errors, at least today (wasn't able to check yesterday).

For now, I will probably try that udev renaming fix again and run it like that for a while, to try and see if there's something else there at play.

@sezanzeb
Copy link
Owner

sezanzeb commented Nov 8, 2021

Since it is still timing out the timeout is apparently not happening when communicating with the service, but maybe rather when connecting to it.

Apparently bus.get (https://github.com/sezanzeb/key-mapper/blob/main/keymapper/daemon.py#L186) also supports a timeout (see https://github.com/LEW21/pydbus/blob/cc407c8b1d25b7e28a6d661a29f9e661b1c9b964/pydbus/proxy.py)

I don't know when I'll be able to test and push a change (I'm not at home right now and am super busy), but if you have time maybe you'll find out that using interface = bus.get(BUS_NAME, timeout=10) helps in the meantime.

@Liniya
Copy link

Liniya commented Nov 9, 2021

I added that edit to daemon.py (in two places as there was one more similar line below). Unfortunately, it didn't help, I'm still getting that error at random. Additionally, I got the following error once after a power loss. The mapped keys didn't work at that time.

Nov 09 19:49:44 hostname systemd[1]: key-mapper.service: start operation timed out. Terminating.
Nov 09 19:49:44 hostname systemd[1]: key-mapper.service: Failed with result 'timeout'.
Nov 09 19:49:44 hostname systemd[1]: Failed to start Service to inject keycodes without the GUI application.

@sezanzeb
Copy link
Owner

sezanzeb commented Nov 9, 2021

Thanks for trying!

what does systemctl status key-mapper yield after booting? Is there anything interesting in /var/log/key-mapper?

In order to debug this we would have to find the place where it hangs until udev times out. I'm not sure how to proceed

@Liniya
Copy link

Liniya commented Nov 12, 2021

Okay, this error wasn't showing itself for some time, but today's one seemed somewhat 'big' so here's the report.

Upon booting at first, the sound icon was crossed out as usual in these cases. At this time there was nothing of interest yet in the journal (journalctl -b -p4).
Mapped keys did NOT work. Status of key-mapper.service was shown as follows:

● key-mapper.service - Service to inject keycodes without the GUI application
     Loaded: loaded (/usr/lib/systemd/system/key-mapper.service; enabled; vendor preset: disabled)
     Active: activating (start) since Fri 2021-11-12 11:07:53 MSK; 22s ago
   Main PID: 585 (key-mapper-serv)
      Tasks: 1 (limit: 38400)
     Memory: 19.0M
        CPU: 192ms
     CGroup: /system.slice/key-mapper.service
             └─585 /usr/bin/python3 /usr/bin/key-mapper-service

cat /var/log/key-mapper displayed the following (probably referring to some previous boot launch?):

key-mapper-service 1.2.1 1d79ad369b021512f4991974787a4443ef8d18fd https://github.com/sezanzeb/key-mapper
python-evdev 1.4.0
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
Request to autoload for "Razer Razer DeathAdder Essential"
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
Request to autoload for "Razer Razer DeathAdder Essential"
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
Request to autoload for "Razer Razer DeathAdder Essential"
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
Request to autoload for "Razer Razer DeathAdder Essential"
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
Request to autoload for "Razer Razer DeathAdder Essential"
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
Request to autoload for "Razer Razer DeathAdder Essential"
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
Loaded config from "/home/hikaru/.config/key-mapper/config.json"
Loaded config from "/home/hikaru/.config/key-mapper/config.json"
Stopping all injections
Loaded config from "/home/hikaru/.config/key-mapper/config.json"
Loaded config from "/home/hikaru/.config/key-mapper/config.json"
Autoloading for all devices
Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
Autoloading for "Razer Razer DeathAdder Essential"
Loading preset from "/home/hikaru/.config/key-mapper/presets/Razer Razer DeathAdder Essential/MyMouseKeyPreset.json"
Starting injecting the mapping for "Razer Razer DeathAdder Essential"
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist
�[31mERROR�[0m: "/root/.config/key-mapper/config.json" does not exist

After a couple of minutes, sound came back on, and status of key-mapper.service was shown as follows:

× key-mapper.service - Service to inject keycodes without the GUI application
     Loaded: loaded (/usr/lib/systemd/system/key-mapper.service; enabled; vendor preset: disabled)
     Active: failed (Result: timeout) since Fri 2021-11-12 11:09:22 MSK; 25s ago
    Process: 585 ExecStart=/usr/bin/key-mapper-service (code=killed, signal=TERM)
   Main PID: 585 (code=killed, signal=TERM)
        CPU: 194ms

At the same time, a whole lot of errors appeared in the log:

Nov 12 11:09:22 hikaru-pc systemd[1]: key-mapper.service: start operation timed out. Terminating.
Nov 12 11:09:22 hikaru-pc systemd[1]: key-mapper.service: Failed with result 'timeout'.
Nov 12 11:09:22 hikaru-pc systemd[1]: Failed to start Service to inject keycodes without the GUI application.
Nov 12 11:10:53 hikaru-pc systemd-udevd[354]: event16: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event16' [815] timed out after 2min 59s, killing
Nov 12 11:10:53 hikaru-pc systemd-udevd[351]: event11: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event11' [674] timed out after 2min 59s, killing
Nov 12 11:10:53 hikaru-pc systemd-udevd[389]: event18: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event18' [859] timed out after 2min 59s, killing
Nov 12 11:10:53 hikaru-pc systemd-udevd[352]: event14: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event14' [723] timed out after 2min 59s, killing
Nov 12 11:10:53 hikaru-pc systemd-udevd[379]: event17: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event17' [799] timed out after 2min 59s, killing
Nov 12 11:10:53 hikaru-pc systemd-udevd[367]: event0: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event0' [548] timed out after 2min 59s, killing
Nov 12 11:10:53 hikaru-pc systemd-udevd[363]: event8: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event8' [666] timed out after 2min 59s, killing
Nov 12 11:10:53 hikaru-pc systemd-udevd[349]: event13: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event13' [728] timed out after 2min 59s, killing
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event1: Worker [368] processing SEQNUM=3029 killed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event18: Worker [389] processing SEQNUM=4141 killed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event16: Worker [354] processing SEQNUM=4137 killed
Nov 12 11:10:53 hikaru-pc systemd-udevd[378]: event7: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event7' [678] timed out after 2min 59s, killing
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event17: Worker [379] processing SEQNUM=4139 killed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event0: Worker [367] processing SEQNUM=3193 killed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event13: Worker [349] processing SEQNUM=4117 killed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event14: Worker [352] processing SEQNUM=4133 killed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event11: Worker [351] processing SEQNUM=4103 killed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event7: Worker [378] processing SEQNUM=4028 killed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event8: Worker [363] processing SEQNUM=4097 killed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event1: Worker [368] failed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event0: Worker [367] failed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event16: Worker [354] failed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event13: Worker [349] failed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event8: Worker [363] failed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event17: Worker [379] failed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event18: Worker [389] failed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event7: Worker [378] failed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event14: Worker [352] failed
Nov 12 11:10:53 hikaru-pc systemd-udevd[334]: event11: Worker [351] failed

Afterwards, trying systemctl start key-mapper.service:

● key-mapper.service - Service to inject keycodes without the GUI application
     Loaded: loaded (/usr/lib/systemd/system/key-mapper.service; enabled; vendor preset: disabled)
     Active: active (running) since Fri 2021-11-12 11:14:16 MSK; 5s ago
   Main PID: 2306 (key-mapper-serv)
      Tasks: 4 (limit: 38400)
     Memory: 25.6M
        CPU: 161ms
     CGroup: /system.slice/key-mapper.service
             ├─2306 /usr/bin/python3 /usr/bin/key-mapper-service
             └─2329 /usr/bin/python3 /usr/bin/key-mapper-service

cat /var/log/key-mapper displayed just this:

key-mapper-service 1.2.1 1d79ad369b021512f4991974787a4443ef8d18fd https://github.com/sezanzeb/key-mapper
python-evdev 1.4.0

Mapped keys still did NOT work. At last, I had to open the key-mapper window and apply the preset again. The keys started working again, and key-mapper log became this:

key-mapper-service 1.2.1 1d79ad369b021512f4991974787a4443ef8d18fd https://github.com/sezanzeb/key-mapper
python-evdev 1.4.0
Loaded config from "/home/hikaru/.config/key-mapper/config.json"
Loaded config from "/home/hikaru/.config/key-mapper/config.json"
Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
Loading preset from "/home/hikaru/.config/key-mapper/presets/Razer Razer DeathAdder Essential/MyMouseKeyPreset.json"
Starting injecting the mapping for "Razer Razer DeathAdder Essential"
ERROR: "/root/.config/key-mapper/config.json" does not exist
ERROR: "/root/.config/key-mapper/config.json" does not exist
ERROR: "/root/.config/key-mapper/config.json" does not exist

Other than that, I had boots with everything working normally, as well as boots with only the 'worker killed' error messages in the log (no specific references to key-mapper, as stated above). I've found that in the latter case, the mapped keys were working normally as well.

@sezanzeb
Copy link
Owner

yeah presets aren't applied after replugging the device

so if you do that with the udev rule in place, does autoloading work after plugging in the mouse?

@sezanzeb
Copy link
Owner

sezanzeb commented Nov 14, 2021

Please install the backage from the AUR again and try to reboot.

Debug logs for the udev rule are now written to /var/log/key-mapper-control, this might help to find the issue

@Liniya
Copy link

Liniya commented Nov 16, 2021

From today (the keys did work in the end):

journalctl -b -p4

Nov 16 06:05:03 hikaru-pc systemd-udevd[373]: event19: Spawned process '/bin/key-mapper-control --command autoload --device /dev/input/event19 -d' [747] timed out after 2min 59s>
Nov 16 06:05:03 hikaru-pc systemd-udevd[330]: event19: Worker [373] processing SEQNUM=4146 killed
Nov 16 06:05:03 hikaru-pc systemd-udevd[330]: event19: Worker [373] failed

cat /var/log/key-mapper-control

739 0.12298 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential Keyboard", type: keyboard
530 0.72742 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
530 0.72939 SPAM shared_dict.py:58: Starting SharedDict process
1333 0.73212 SPAM shared_dict.py:64: SharedDict process started
530 0.73822 INFO daemon.py:190: Connected to the service
530 0.73837 ERROR key-mapper-control:104: unknown device "/dev/input/event0"
1333 0.73912 SPAM shared_dict.py:68: SharedDict got ('stop',)
739 0.17932 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
707 0.17672 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
739 0.17956 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
707 0.17700 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
739 0.18000 INFO groups.py:438: Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
707 0.17750 INFO groups.py:438: Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
739 0.18139 DEBUG system_mapping.py:64: Gathering available keycodes
707 0.17880 DEBUG system_mapping.py:64: Gathering available keycodes
739 0.18361 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
707 0.18119 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
739 0.18475 SPAM shared_dict.py:58: Starting SharedDict process
707 0.18248 SPAM shared_dict.py:58: Starting SharedDict process
1384 0.18628 SPAM shared_dict.py:64: SharedDict process started
1385 0.18411 SPAM shared_dict.py:64: SharedDict process started
739 0.19040 INFO daemon.py:190: Connected to the service
739 0.19050 ERROR key-mapper-control:104: unknown device "/dev/input/event20"
707 0.18805 INFO daemon.py:190: Connected to the service
707 0.18815 ERROR key-mapper-control:104: unknown device "/dev/input/event18"
1384 0.20717 SPAM shared_dict.py:68: SharedDict got ('stop',)
1385 0.20462 SPAM shared_dict.py:68: SharedDict got ('stop',)
747 0.15805 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event6", "Razer Razer DeathAdder Essential", type: keyboard
---
1507 0.01165 DEBUG logger.py:199: Started debug logs at: 2021-11-16 06:02:03.888778
1507 0.01171 DEBUG key-mapper-control:243: Call for "['/bin/key-mapper-control', '--command', 'autoload', '--device', '/dev/input/mice', '-d']"
1507 0.05149 DEBUG groups.py:335: Discovering device paths
1507 0.05249 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event5", "Razer Razer DeathAdder Essential", type: keyboard
1507 0.05300 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential", type: keyboard
1507 0.08100 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
1507 0.08262 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
1507 0.08312 INFO groups.py:438: Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
1507 0.08465 DEBUG system_mapping.py:64: Gathering available keycodes
1507 0.08663 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
1507 0.08770 SPAM shared_dict.py:58: Starting SharedDict process
1533 0.08915 SPAM shared_dict.py:64: SharedDict process started
1507 0.09260 INFO daemon.py:190: Connected to the service
1507 0.09269 ERROR key-mapper-control:104: unknown device "/dev/input/mice"
---
1508 0.01159 DEBUG logger.py:199: Started debug logs at: 2021-11-16 06:02:03.991593
1508 0.01165 DEBUG key-mapper-control:243: Call for "['/bin/key-mapper-control', '--command', 'autoload', '--device', '/dev/input/event6', '-d']"
1508 0.04975 DEBUG groups.py:335: Discovering device paths
1508 0.05082 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event5", "Razer Razer DeathAdder Essential", type: keyboard
1508 0.07209 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential", type: keyboard
1533 0.17538 SPAM shared_dict.py:68: SharedDict got ('stop',)
---
1512 0.01198 DEBUG logger.py:199: Started debug logs at: 2021-11-16 06:02:04.073295
1512 0.01203 DEBUG key-mapper-control:243: Call for "['/bin/key-mapper-control', '--command', 'autoload', '--device', '/dev/input/event4', '-d']"
1508 0.12833 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
1508 0.13087 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
1512 0.05021 DEBUG groups.py:335: Discovering device paths
1508 0.13160 INFO groups.py:438: Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
1508 0.13343 DEBUG system_mapping.py:64: Gathering available keycodes
1508 0.13661 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
1508 0.13781 SPAM shared_dict.py:58: Starting SharedDict process
1562 0.13974 SPAM shared_dict.py:64: SharedDict process started
1508 0.14301 INFO daemon.py:190: Connected to the service
1508 0.14310 ERROR key-mapper-control:104: unknown device "/dev/input/event6"
---
1537 0.01173 DEBUG logger.py:199: Started debug logs at: 2021-11-16 06:02:04.128729
1537 0.01178 DEBUG key-mapper-control:243: Call for "['/bin/key-mapper-control', '--command', 'autoload', '--device', '/dev/input/event5', '-d']"
1512 0.07368 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event5", "Razer Razer DeathAdder Essential", type: keyboard
1512 0.07406 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential", type: keyboard
1512 0.07426 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
1512 0.07575 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
1512 0.07620 INFO groups.py:438: Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
1512 0.07738 DEBUG system_mapping.py:64: Gathering available keycodes
1512 0.07939 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
1512 0.08047 SPAM shared_dict.py:58: Starting SharedDict process
1586 0.08192 SPAM shared_dict.py:64: SharedDict process started
1562 0.16607 SPAM shared_dict.py:68: SharedDict got ('stop',)
1512 0.08545 INFO daemon.py:190: Connected to the service
1512 0.08554 INFO key-mapper-control:142: Autoloading /dev/input/event4
1537 0.05011 DEBUG groups.py:335: Discovering device paths
---
1540 0.01165 DEBUG logger.py:199: Started debug logs at: 2021-11-16 06:02:04.177713
1540 0.01170 DEBUG key-mapper-control:243: Call for "['/bin/key-mapper-control', '--command', 'autoload', '--device', '/dev/input/event3', '-d']"
1537 0.06665 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event5", "Razer Razer DeathAdder Essential", type: keyboard
1537 0.06704 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential", type: keyboard
1586 0.15361 SPAM shared_dict.py:68: SharedDict got ('stop',)
1540 0.04962 DEBUG groups.py:335: Discovering device paths
1537 0.12792 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
1537 0.13003 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
1537 0.13077 INFO groups.py:438: Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
1537 0.13211 DEBUG system_mapping.py:64: Gathering available keycodes
1537 0.13455 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
1537 0.13626 SPAM shared_dict.py:58: Starting SharedDict process
1615 0.13858 SPAM shared_dict.py:64: SharedDict process started
1540 0.09223 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event5", "Razer Razer DeathAdder Essential", type: keyboard
1540 0.09260 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential", type: keyboard
1540 0.09279 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
1537 0.14222 INFO daemon.py:190: Connected to the service
1537 0.14231 INFO key-mapper-control:142: Autoloading /dev/input/event5
1540 0.09440 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
1540 0.09484 INFO groups.py:438: Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
1540 0.09604 DEBUG system_mapping.py:64: Gathering available keycodes
1615 0.14673 SPAM shared_dict.py:68: SharedDict got ('stop',)
1540 0.09810 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
1540 0.09920 SPAM shared_dict.py:58: Starting SharedDict process
1639 0.10091 SPAM shared_dict.py:64: SharedDict process started
1540 0.10500 INFO daemon.py:190: Connected to the service
1540 0.10511 INFO key-mapper-control:142: Autoloading /dev/input/event3
1639 0.16890 SPAM shared_dict.py:68: SharedDict got ('stop',)
---
1647 0.01172 DEBUG logger.py:199: Started debug logs at: 2021-11-16 06:02:04.543897
1647 0.01177 DEBUG key-mapper-control:243: Call for "['/bin/key-mapper-control', '--command', 'autoload', '--device', '/dev/input/event5', '-d']"
1647 0.04995 DEBUG groups.py:335: Discovering device paths
1647 0.05095 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event5", "Razer Razer DeathAdder Essential", type: keyboard
1647 0.05148 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential", type: keyboard
1647 0.05173 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
1647 0.07032 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
1647 0.07093 INFO groups.py:438: Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
1647 0.07199 DEBUG system_mapping.py:64: Gathering available keycodes
1647 0.07521 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
1647 0.07700 SPAM shared_dict.py:58: Starting SharedDict process
1674 0.07869 SPAM shared_dict.py:64: SharedDict process started
1647 0.08228 INFO daemon.py:190: Connected to the service
1647 0.08237 INFO key-mapper-control:142: Autoloading /dev/input/event5
---
1649 0.01158 DEBUG logger.py:199: Started debug logs at: 2021-11-16 06:02:04.644600
1649 0.01163 DEBUG key-mapper-control:243: Call for "['/bin/key-mapper-control', '--command', 'autoload', '--device', '/dev/input/event4', '-d']"
1649 0.04900 DEBUG groups.py:335: Discovering device paths
1649 0.04960 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event5", "Razer Razer DeathAdder Essential", type: keyboard
1649 0.04993 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential", type: keyboard
1674 0.15275 SPAM shared_dict.py:68: SharedDict got ('stop',)
---
1672 0.01168 DEBUG logger.py:199: Started debug logs at: 2021-11-16 06:02:04.730002
1672 0.01174 DEBUG key-mapper-control:243: Call for "['/bin/key-mapper-control', '--command', 'autoload', '--device', '/dev/input/event3', '-d']"
1649 0.10520 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
1649 0.10711 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
1649 0.10767 INFO groups.py:438: Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
1649 0.10882 DEBUG system_mapping.py:64: Gathering available keycodes
1649 0.11130 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
1649 0.11285 SPAM shared_dict.py:58: Starting SharedDict process
1708 0.11478 SPAM shared_dict.py:64: SharedDict process started
1649 0.11803 INFO daemon.py:190: Connected to the service
1649 0.11812 INFO key-mapper-control:142: Autoloading /dev/input/event4
1672 0.05007 DEBUG groups.py:335: Discovering device paths
1672 0.05093 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event5", "Razer Razer DeathAdder Essential", type: keyboard
1672 0.05130 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential", type: keyboard
1672 0.05151 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
1708 0.16191 SPAM shared_dict.py:68: SharedDict got ('stop',)
1672 0.07693 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
1672 0.07745 INFO groups.py:438: Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
1672 0.07873 DEBUG system_mapping.py:64: Gathering available keycodes
1672 0.08118 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
1672 0.08240 SPAM shared_dict.py:58: Starting SharedDict process
1741 0.08427 SPAM shared_dict.py:64: SharedDict process started
1672 0.08813 INFO daemon.py:190: Connected to the service
1672 0.08826 INFO key-mapper-control:142: Autoloading /dev/input/event3
1741 0.14672 SPAM shared_dict.py:68: SharedDict got ('stop',)
---
1773 0.01146 DEBUG logger.py:199: Started debug logs at: 2021-11-16 06:02:05.014982
1773 0.01151 DEBUG key-mapper-control:243: Call for "['/bin/key-mapper-control', '--command', 'autoload', '--device', '/dev/input/mouse0', '-d']"
1773 0.04893 DEBUG groups.py:335: Discovering device paths
1773 0.04993 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event5", "Razer Razer DeathAdder Essential", type: keyboard
1773 0.05045 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential", type: keyboard
1773 0.05452 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
1773 0.05623 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
1773 0.05669 INFO groups.py:438: Found "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
1773 0.05781 DEBUG system_mapping.py:64: Gathering available keycodes
1773 0.06007 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
1773 0.06113 SPAM shared_dict.py:58: Starting SharedDict process
1800 0.06258 SPAM shared_dict.py:64: SharedDict process started
1773 0.06690 INFO daemon.py:190: Connected to the service
1773 0.06704 ERROR key-mapper-control:104: unknown device "/dev/input/mouse0"
1800 0.15811 SPAM shared_dict.py:68: SharedDict got ('stop',)
---
2163 0.01354 DEBUG logger.py:199: Started debug logs at: 2021-11-16 06:02:06.795503
2163 0.01362 DEBUG key-mapper-control:243: Call for "['/bin/key-mapper-control', '--command', 'autoload', '--device', '/dev/input/event6', '-d']"
2163 0.05699 DEBUG groups.py:335: Discovering device paths
2163 0.05763 SPAM groups.py:367: Found "3_1_1_key-mapper", "/dev/input/event21", "key-mapper Razer Razer DeathAdder Essential forwarded", type: mouse
2163 0.05796 SPAM groups.py:367: Found "3_1_1_key-mapper", "/dev/input/event6", "key-mapper Razer Razer DeathAdder Essential mapped", type: unknown
2163 0.05832 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event5", "Razer Razer DeathAdder Essential", type: keyboard
2163 0.05866 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential", type: keyboard
2163 0.05887 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
2163 0.06058 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
2163 0.06104 INFO groups.py:438: Found "key-mapper Razer Razer DeathAdder Essential mapped", "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
2163 0.06226 DEBUG system_mapping.py:64: Gathering available keycodes
2163 0.06507 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
2163 0.06627 SPAM shared_dict.py:58: Starting SharedDict process
2201 0.06804 SPAM shared_dict.py:64: SharedDict process started
2163 0.07147 INFO daemon.py:190: Connected to the service
2163 0.07155 INFO key-mapper-control:142: Autoloading /dev/input/event6
---
2165 0.01202 DEBUG logger.py:199: Started debug logs at: 2021-11-16 06:02:06.860476
2165 0.01207 DEBUG key-mapper-control:243: Call for "['/bin/key-mapper-control', '--command', 'autoload', '--device', '/dev/input/mouse1', '-d']"
2165 0.05100 DEBUG groups.py:335: Discovering device paths
2165 0.05189 SPAM groups.py:367: Found "3_1_1_key-mapper", "/dev/input/event21", "key-mapper Razer Razer DeathAdder Essential forwarded", type: mouse
2165 0.05209 SPAM groups.py:367: Found "3_1_1_key-mapper", "/dev/input/event6", "key-mapper Razer Razer DeathAdder Essential mapped", type: unknown
2165 0.05241 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event5", "Razer Razer DeathAdder Essential", type: keyboard
2165 0.05277 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential", type: keyboard
2165 0.05295 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
2201 0.13317 SPAM shared_dict.py:68: SharedDict got ('stop',)
2165 0.06758 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
---
2165 0.06805 INFO groups.py:438: Found "key-mapper Razer Razer DeathAdder Essential mapped", "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
2175 0.01179 DEBUG logger.py:199: Started debug logs at: 2021-11-16 06:02:06.916560
2175 0.01184 DEBUG key-mapper-control:243: Call for "['/bin/key-mapper-control', '--command', 'autoload', '--device', '/dev/input/event21', '-d']"
2165 0.06925 DEBUG system_mapping.py:64: Gathering available keycodes
2165 0.07125 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
2165 0.07233 SPAM shared_dict.py:58: Starting SharedDict process
2230 0.07393 SPAM shared_dict.py:64: SharedDict process started
2165 0.07784 INFO daemon.py:190: Connected to the service
2165 0.07793 ERROR key-mapper-control:104: unknown device "/dev/input/mouse1"
2175 0.05150 DEBUG groups.py:335: Discovering device paths
2175 0.05212 SPAM groups.py:367: Found "3_1_1_key-mapper", "/dev/input/event21", "key-mapper Razer Razer DeathAdder Essential forwarded", type: mouse
2175 0.05231 SPAM groups.py:367: Found "3_1_1_key-mapper", "/dev/input/event6", "key-mapper Razer Razer DeathAdder Essential mapped", type: unknown
2175 0.05254 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event5", "Razer Razer DeathAdder Essential", type: keyboard
2175 0.05288 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event4", "Razer Razer DeathAdder Essential", type: keyboard
2175 0.05311 SPAM groups.py:367: Found "3_5426_110_usb-0000:0a:00.3-3", "/dev/input/event3", "Razer Razer DeathAdder Essential", type: mouse
2230 0.15364 SPAM shared_dict.py:68: SharedDict got ('stop',)
2175 0.09865 SPAM groups.py:367: Found "17_1_1_isa0060", "/dev/input/event2", "AT Translated Set 2 keyboard", type: keyboard
2175 0.09940 INFO groups.py:438: Found "key-mapper Razer Razer DeathAdder Essential mapped", "Razer Razer DeathAdder Essential", "AT Translated Set 2 keyboard"
2175 0.10122 DEBUG system_mapping.py:64: Gathering available keycodes
2175 0.10346 INFO system_mapping.py:78: Optional `xmodmap` command not found. This is not critical.
2175 0.10459 SPAM shared_dict.py:58: Starting SharedDict process
2261 0.10610 SPAM shared_dict.py:64: SharedDict process started
2175 0.10984 INFO daemon.py:190: Connected to the service
2175 0.10992 INFO key-mapper-control:142: Autoloading /dev/input/event21
2261 0.16356 SPAM shared_dict.py:68: SharedDict got ('stop',)

sezanzeb added a commit that referenced this issue Nov 20, 2021
@sezanzeb
Copy link
Owner

sezanzeb commented Nov 20, 2021

Hey, thanks for trying.

It keeps 1000 lines now instead of only 200 and logs if the command finished. Can you please reinstall from the latest source and try to reproduce the problem again?

I'll work on avoiding starting the SharedDict if it is not needed

@sezanzeb
Copy link
Owner

sezanzeb commented Nov 20, 2021

That was really easy actually, the log output should be cleaner now. There is also a very slim chance that the SharedDict might have caused the trouble because of all the multiprocessing and ipc stuff.

@sezanzeb
Copy link
Owner

sezanzeb commented Nov 21, 2021

Device info is now lazy-loaded. This keeps the log shorter and avoids more unnecessary potential for bugs for key-mapper-control.

I'm really looking forward to knowing how all of that affects the issue

If you still have problems, journalctl -g key-mapper | tail -n 1000 gives more interesting information

@saikat0511
Copy link
Author

I can still see many errors in /var/log/key-mapper and /var/log/key-mapper-control but everything works as expected now. Autoload works and all input devices are working fine after reboot!

@sezanzeb
Copy link
Owner

sezanzeb commented Nov 22, 2021

Nice, can you please post those errors anyway? ERROR key-mapper-control:104: unknown device logs are not critical, don't worry about those

@saikat0511
Copy link
Author

saikat0511 commented Nov 22, 2021

/var/log/key-mapper

key-mapper-service 1.2.1 6484ab4972845224e591ec16fb6fdcc9a70b500d https://github.com/sezanzeb/key-mapper
python-evdev 1.4.0
Request to autoload for "AT Translated Set 2 keyboard"
ERROR: Request to autoload "AT Translated Set 2 keyboard" before a user told the service about their session using set_config_dir
Request to autoload for "Logitech Wireless Device PID:406b Mouse"
ERROR: Request to autoload "Logitech Wireless Device PID:406b Mouse" before a user told the service about their session using set_config_dir
Request to autoload for "Video Bus"
ERROR: Request to autoload "Video Bus" before a user told the service about their session using set_config_dir
Request to autoload for "Video Bus"
ERROR: Request to autoload "Video Bus" before a user told the service about their session using set_config_dir
Request to autoload for "Wacom HID 5218 Pen"
ERROR: Request to autoload "Wacom HID 5218 Pen" before a user told the service about their session using set_config_dir
Request to autoload for "Sleep Button"
ERROR: Request to autoload "Sleep Button" before a user told the service about their session using set_config_dir
Request to autoload for "Wacom HID 5218 Pen"
ERROR: Request to autoload "Wacom HID 5218 Pen" before a user told the service about their session using set_config_dir
Request to autoload for "MSFT0001:00 04F3:3140 Mouse"
ERROR: Request to autoload "MSFT0001:00 04F3:3140 Mouse" before a user told the service about their session using set_config_dir
Request to autoload for "Ideapad extra buttons"
ERROR: Request to autoload "Ideapad extra buttons" before a user told the service about their session using set_config_dir
Request to autoload for "MSFT0001:00 04F3:3140 Mouse"
ERROR: Request to autoload "MSFT0001:00 04F3:3140 Mouse" before a user told the service about their session using set_config_dir
Request to autoload for "MSFT0001:00 04F3:3140 Mouse"
ERROR: Request to autoload "MSFT0001:00 04F3:3140 Mouse" before a user told the service about their session using set_config_dir
Request to autoload for "MSFT0001:00 04F3:3140 Mouse"
ERROR: Request to autoload "MSFT0001:00 04F3:3140 Mouse" before a user told the service about their session using set_config_dir
Request to autoload for "Logitech M585/M590"
ERROR: Request to autoload "Logitech M585/M590" before a user told the service about their session using set_config_dir
Request to autoload for "Video Bus"
ERROR: Request to autoload "Video Bus" before a user told the service about their session using set_config_dir
Request to autoload for "Video Bus"
ERROR: Request to autoload "Video Bus" before a user told the service about their session using set_config_dir
Request to autoload for "Wacom HID 5218 Pen"
ERROR: Request to autoload "Wacom HID 5218 Pen" before a user told the service about their session using set_config_dir
Request to autoload for "Wacom HID 5218 Pen"
ERROR: Request to autoload "Wacom HID 5218 Pen" before a user told the service about their session using set_config_dir
Request to autoload for "MSFT0001:00 04F3:3140 Mouse"
ERROR: Request to autoload "MSFT0001:00 04F3:3140 Mouse" before a user told the service about their session using set_config_dir
Request to autoload for "MSFT0001:00 04F3:3140 Mouse"
ERROR: Request to autoload "MSFT0001:00 04F3:3140 Mouse" before a user told the service about their session using set_config_dir
Request to autoload for "Logitech M585/M590"
ERROR: Request to autoload "Logitech M585/M590" before a user told the service about their session using set_config_dir
Loaded config from "/home/saikat/.config/key-mapper/config.json"
Loaded config from "/home/saikat/.config/key-mapper/config.json"
Stopping all injections
Loaded config from "/home/saikat/.config/key-mapper/config.json"
Loaded config from "/home/saikat/.config/key-mapper/config.json"
Autoloading for all devices
Found "Logitech M585/M590", "Video Bus", "Wacom HID 5218 Pen", "MSFT0001:00 04F3:3140 Mouse", "Ideapad extra buttons", "AT Translated Set 2 keyboard", "Sleep Button"
Autoloading for "Logitech M585/M590"
Loading preset from "/home/saikat/.config/key-mapper/presets/Logitech M585/M590/genshin-impact.json"
Optional `xmodmap` command not found. This is not critical.
Starting injecting the mapping for "Logitech M585/M590"
WARNING: Failed to get ABS info of "device /dev/input/event10, name "Logitech M585/M590", phys "usb-0000:00:14.0-5/input2:1"" for key 0: {0: [0, 1, 2, 3, 4, 17, 20], 1: [1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50, 51, 52, 53, 54, 55, 56, 57, 58, 59, 60, 61, 62, 63, 64, 65, 66, 67, 68, 69, 70, 71, 72, 73, 74, 75, 76, 77, 78, 79, 80, 81, 82, 83, 85, 86, 87, 88, 89, 90, 91, 92, 93, 94, 95, 96, 97, 98, 99, 100, 102, 103, 104, 105, 106, 107, 108, 109, 110, 111, 113, 114, 115, 116, 117, 119, 120, 121, 122, 123, 124, 125, 126, 127, 128, 129, 130, 131, 132, 133, 134, 135, 136, 137, 138, 139, 140, 142, 143, 144, 150, 152, 155, 156, 158, 159, 161, 163, 164, 165, 166, 167, 168, 169, 171, 172, 173, 174, 176, 177, 178, 179, 180, 181, 182, 183, 184, 185, 186, 187, 188, 189, 190, 191, 192, 193, 194, 206, 207, 208, 209, 210, 212, 216, 217, 219, 223, 224, 225, 228, 229, 230, 231, 232, 233, 234, 235, 240, 241, 244, 256, 272, 273, 274, 275, 276, 277, 278, 279, 280, 281, 282, 283, 284, 285, 286, 287, 353, 354, 358, 362, 366, 370, 372, 374, 375, 376, 377, 378, 379, 380, 381, 383, 384, 386, 387, 389, 392, 393, 396, 397, 398, 399, 400, 401, 402, 403, 405, 407, 408, 409, 410, 412, 416, 417, 418, 419, 420, 421, 422, 423, 424, 425, 426, 427, 428, 429, 430, 431, 432, 433, 439, 442, 576, 577, 578, 579, 580, 581, 582, 583, 584, 585, 592, 593, 608, 609, 610, 611, 612, 613], 2: [0, 1, 6, 8, 11, 12], 3: [(32, AbsInfo(value=0, min=1, max=767, fuzz=0, flat=0, resolution=0))], 4: [4], 17: [0, 1, 2, 3, 4]}

/var/log/key-mapper-control
Just a couple of ERROR key-mapper-control:102: Unknown device

@sezanzeb
Copy link
Owner

sezanzeb commented Nov 22, 2021

ERROR: Request to autoload "AT Translated Set 2 keyboard" before a user told the service about their session using set_config_dir

This is usually happening before a user logged in. udev tells the service about an input device at boot time, but the service doesn't know yet where to look for a configuration. Maybe I can avoid those dbus calls alltogether somehow by checking if any user is logged in first via https://stackoverflow.com/a/14319024/4417769 or something

Of course doing that would also avoid the original issue completely, but making key-mapper-control calls more stable and easier to debug didn't hurt as well. I'll push more changes maybe tomorrow

@sezanzeb
Copy link
Owner

Pushed final changes. If you still have more problems feel free to comment here, I'll close it for now

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants