Minor init annoyance with Logitech G900 Gaming Mouse

Minor init annoyance with Logitech G900 Gaming Mouse

[Fabrizio Pelosi]

Hello, 
I'm having a minor annoyance with my Logitech G900 Gaming Mouse 
since a long time and only now I've decided to report it.

I'm running ArchLinux (amd64) with kernel `7.1.8.arch1-3`.
Mouse firmware is the latest available.

The mouse is a wired / wireless gaming mouse. 
It can work via USB directly or via its own receiver. 
It has a switch on the bottom (the part that touches the flat surface): 
when OFF it doesn't work even via USB.

The issue is that if you switch the mouse ON and wait one second or two before 
putting it down, it works correctly. 
If you happen to put it down too fast, instead, it may happen that you need to 
wait ~31 seconds before it starts to work. 
Also there are differences between the two cases in `dmesg`. You can see them 
in the `g900_journal` section below.
When it works, the mouse is renamed to "Logitech Heat Gaming Mouse G900" 
(with "Heat") and the line "HID++ 4.2 device connected" appears; 
when it doesn't it doesn't get renamed (it remains "Logitech Gaming Mouse G900")
and there's NO line "HID++ 4.2 device connected".

This issue may also happen if the mouse is ON and the PC is rebooted. 
It seems it causes a delay in the initrd with systemd trying to stop 
"Rule-based Manager for Device Events and Files". 
Ultimately it works (but it takes a bit longer than 31 seconds it seems) 
but if I switch the mouse OFF, it seems it exits as soon as I do it.
You can see the `journalctl` log in the `g900_initrd` section below.

I have captured a USB capture with `dumpcap` (the capture is related to 
the `g900_journal` section below). 
I can provide it as an attachment, if needed (it's less than 60 KiB).

These are the steps to try to reproduce the issue:

1. Run `dmesg -w`
2. Pick up the mouse and switch it ON.
3. Put it down on a surface as fast as possible (so that it starts to send 
   pointer events, maybe)
4. Watch `dmesg -w` and see that there's a delay of 31s before the mouse 
   fully works.

I can try to test a patch on the `drivers/hid/hid-logitech-hidpp.c` module, 
if needed (but I can't guarantee I'll be able to since it'll be my 
first time doing it).

Thanks,
Fabrizio.

====== g900_journal ======

ago 13 10:03:36 tesx-pc kernel: usb 7-4: USB disconnect, device number 4

# --- waiting before putting the mouse down after turning it on ---

ago 13 10:03:43 tesx-pc kernel: usb 7-4: new full-speed USB device number 5 using xhci_hcd
ago 13 10:03:43 tesx-pc kernel: usb 7-4: New USB device found, idVendor=046d, idProduct=c081, bcdDevice= 1.03
ago 13 10:03:43 tesx-pc kernel: usb 7-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
ago 13 10:03:43 tesx-pc kernel: usb 7-4: Product: Gaming Mouse G900
ago 13 10:03:43 tesx-pc kernel: usb 7-4: Manufacturer: Logitech
ago 13 10:03:43 tesx-pc kernel: usb 7-4: SerialNumber: 0E6C36503233
ago 13 10:03:43 tesx-pc kernel: input: Logitech Gaming Mouse G900 as /devices/pci0000:00/0000:00:08.1/0000:0e:00.3/usb7/7-4/7-4:1.0/0003:046D:C081.0009/input/input33
ago 13 10:03:43 tesx-pc kernel: logitech-hidpp-device 0003:046D:C081.0009: input,hidraw6: USB HID v1.11 Mouse [Logitech Gaming Mouse G900] on usb-0000:0e:00.3-4/input0
ago 13 10:03:43 tesx-pc kernel: input: Logitech Heat Gaming Mouse G900 as /devices/pci0000:00/0000:00:08.1/0000:0e:00.3/usb7/7-4/7-4:1.1/0003:046D:C081.000A/input/input34
ago 13 10:03:43 tesx-pc kernel: logitech-hidpp-device 0003:046D:C081.000A: input,hiddev99,hidraw7: USB HID v1.11 Keyboard [Logitech Heat Gaming Mouse G900] on usb-0000:0e:00.3-4/input1
ago 13 10:03:43 tesx-pc kernel: logitech-hidpp-device 0003:046D:C081.000A: HID++ 4.2 device connected.
ago 13 10:03:43 tesx-pc mtp-probe[4632]: checking bus 7, device 5: "/sys/devices/pci0000:00/0000:00:08.1/0000:0e:00.3/usb7/7-4"
ago 13 10:03:43 tesx-pc mtp-probe[4632]: bus: 7, device: 5 was not an MTP device
ago 13 10:03:43 tesx-pc systemd-logind[983]: Watching system buttons on /dev/input/event28 (Logitech Heat Gaming Mouse G900)
ago 13 10:03:43 tesx-pc mtp-probe[4675]: checking bus 7, device 5: "/sys/devices/pci0000:00/0000:00:08.1/0000:0e:00.3/usb7/7-4"
ago 13 10:03:43 tesx-pc mtp-probe[4675]: bus: 7, device: 5 was not an MTP device
ago 13 10:03:47 tesx-pc kernel: usb 7-4: USB disconnect, device number 5

# --- putting the mouse down right after turning it on (it doesn't happen always) ---

ago 13 10:03:50 tesx-pc kernel: usb 7-4: new full-speed USB device number 6 using xhci_hcd
ago 13 10:03:50 tesx-pc kernel: usb 7-4: New USB device found, idVendor=046d, idProduct=c081, bcdDevice= 1.03
ago 13 10:03:50 tesx-pc kernel: usb 7-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
ago 13 10:03:50 tesx-pc kernel: usb 7-4: Product: Gaming Mouse G900
ago 13 10:03:50 tesx-pc kernel: usb 7-4: Manufacturer: Logitech
ago 13 10:03:50 tesx-pc kernel: usb 7-4: SerialNumber: 0E6C36503233
ago 13 10:03:50 tesx-pc kernel: input: Logitech Gaming Mouse G900 as /devices/pci0000:00/0000:00:08.1/0000:0e:00.3/usb7/7-4/7-4:1.0/0003:046D:C081.000B/input/input35
ago 13 10:03:50 tesx-pc kernel: logitech-hidpp-device 0003:046D:C081.000B: input,hidraw6: USB HID v1.11 Mouse [Logitech Gaming Mouse G900] on usb-0000:0e:00.3-4/input0

# 31s later (it seems the delay is fixed)...

ago 13 10:04:21 tesx-pc kernel: input: Logitech Gaming Mouse G900 as /devices/pci0000:00/0000:00:08.1/0000:0e:00.3/usb7/7-4/7-4:1.1/0003:046D:C081.000C/input/input36
ago 13 10:04:21 tesx-pc kernel: logitech-hidpp-device 0003:046D:C081.000C: input,hiddev99,hidraw7: USB HID v1.11 Keyboard [Logitech Gaming Mouse G900] on usb-0000:0e:00.3-4/input1
ago 13 10:04:37 tesx-pc mtp-probe[4724]: checking bus 7, device 6: "/sys/devices/pci0000:00/0000:00:08.1/0000:0e:00.3/usb7/7-4"
ago 13 10:04:37 tesx-pc mtp-probe[4724]: bus: 7, device: 6 was not an MTP device
ago 13 10:04:37 tesx-pc systemd-logind[983]: Watching system buttons on /dev/input/event28 (Logitech Gaming Mouse G900)
ago 13 10:04:37 tesx-pc mtp-probe[4767]: checking bus 7, device 6: "/sys/devices/pci0000:00/0000:00:08.1/0000:0e:00.3/usb7/7-4"
ago 13 10:04:37 tesx-pc mtp-probe[4767]: bus: 7, device: 6 was not an MTP device

# The line "HID++ 4.2 device connected." is missing
# and the device didn't change name to "Logitech Heat Gaming Mouse G900" ("Heat" is missing)

====== g900_initrd ======

ago 11 12:05:13 archlinux systemd[1]: Stopping Rule-based Manager for Device Events and Files...

[...]

ago 11 12:05:47 archlinux kernel: input: Logitech Gaming Mouse G900 as /devices/pci0000:00/0000:00:08.1/0000:0e:00.3/usb7/7-4/7-4:1.1/0003:046D:C081.0008/input/input12
ago 11 12:05:47 archlinux kernel: logitech-hidpp-device 0003:046D:C081.0008: input,hiddev99,hidraw7: USB HID v1.11 Keyboard [Logitech Gaming Mouse G900] on usb-0000:0e:00.3-4/input1
ago 11 12:06:00 archlinux kernel: usb 7-4: USB disconnect, device number 4
ago 11 12:06:02 archlinux systemd[1]: systemd-udevd.service: Deactivated successfully.
ago 11 12:06:02 archlinux systemd[1]: Stopped Rule-based Manager for Device Events and Files.
ago 11 12:06:02 archlinux systemd[1]: systemd-udevd.service: Consumed 4.881s CPU time over 50.277s wall clock time, 48.5M memory peak.
ago 11 12:06:02 archlinux systemd[1]: systemd-udevd-control.socket: Deactivated successfully.
ago 11 12:06:02 archlinux systemd[1]: Closed udev Control Socket.
ago 11 12:06:02 archlinux systemd[1]: Starting Cleanup udev Database...
ago 11 12:06:02 archlinux systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.
ago 11 12:06:02 archlinux systemd[1]: Stopped Create Static Device Nodes in /dev.
ago 11 12:06:02 archlinux systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.
ago 11 12:06:02 archlinux systemd[1]: Finished Cleanup udev Database.
ago 11 12:06:02 archlinux systemd[1]: Reached target Switch Root.
ago 11 12:06:02 archlinux systemd[1]: Starting Switch Root...
ago 11 12:06:02 archlinux systemd[1]: Switching root.