Bug 216885 - HID++ Logitech G903 generates full scroll wheel events with every hi-res tick when attached via USB
Summary: HID++ Logitech G903 generates full scroll wheel events with every hi-res tick...
Status: RESOLVED CODE_FIX
Alias: None
Product: Drivers
Classification: Unclassified
Component: Input Devices (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: drivers_input-devices
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2023-01-04 20:37 UTC by David Roth
Modified: 2023-03-01 14:01 UTC (History)
8 users (show)

See Also:
Kernel Version: 6.1.2
Tree: Mainline
Subsystem:
Regression: Yes


Attachments
Libinput record with G903 attached directly to USB (93.09 KB, text/plain)
2023-01-04 20:37 UTC, David Roth
Details
Patch adding a kernel param for disabling querying and a quirk for G903 HERO (1.87 KB, patch)
2023-01-09 16:44 UTC, David Roth
Details | Diff
hid-recorder showing the issue (104.46 KB, text/plain)
2023-01-16 16:19 UTC, David Roth
Details
hid-recorder without the issue (58.75 KB, text/plain)
2023-01-16 16:20 UTC, David Roth
Details
Hid-recording with issue - 2nd Person - Logitech G903 - Wired (3.10 KB, text/plain)
2023-01-18 14:21 UTC, Linus
Details
Hid-recording with issue - 2nd Person - Logitech G903 - Wireless (3.89 KB, text/plain)
2023-01-18 14:21 UTC, Linus
Details
Hid-recording without issue - 2nd Person - Logitech G903 - Wired (680 bytes, text/plain)
2023-01-18 14:22 UTC, Linus
Details
Hid-recording without issue - 2nd Person - Logitech G903 - Wireless (1.15 KB, text/plain)
2023-01-18 14:22 UTC, Linus
Details
solaar show run for G903 in good state (3.44 KB, text/plain)
2023-01-26 14:49 UTC, Tobias Klausmann
Details
solaar show run for mouse in bad state (3.44 KB, text/plain)
2023-01-26 14:51 UTC, Tobias Klausmann
Details
hidpp-hires-scroll-stock-test-v1.patch (7.72 KB, patch)
2023-02-02 12:19 UTC, Bastien Nocera
Details | Diff
debug log (2.51 KB, text/plain)
2023-02-02 13:09 UTC, Tobias Klausmann
Details
0001-HID-logitech-Disable-hi-res-scrolling-on-USB.patch (1.46 KB, patch)
2023-02-03 00:27 UTC, Bastien Nocera
Details | Diff

Description David Roth 2023-01-04 20:37:22 UTC
Created attachment 303526 [details]
Libinput record with G903 attached directly to USB

Since https://lore.kernel.org/linux-input/20220914132146.6435-1-hadess@hadess.net/T/#u my Logitech G903 has gained hi res support. While normally a good thing, it seems that in this case it leads to generating one normal REL_WHEEL with each REL_WHEEL_HI_RES event instead of just a couple of REL_WHEEL_HI_RES, followed by the standard REL_WHEEL once a notch/tick is reached. This leads to overly sensitive scrolling and makes the wheel basically useless.

Interestingly this only happens when the mouse is connected directly via cable (PID:0xC091) and not via the Lightspeed wireless dongle (PID:0x4087) where it will lead to correctly applying the times 8 multiplier and the relevant set of HI_RES and REL_WHEEL event once a notch is reached.

I originally thought about patching the module/adding a param to simple disable high res support in general, assuming this might be something people might want to configure, but seeing that this can be "fixed" that way I decided to hold off on the thought.

However it seems like we'd need to trade one set of quirks for another, so not sure what the correct approach might be.

I'll attach some libinput debug logs when the issue happens.
Comment 1 Linus 2023-01-06 17:05:54 UTC
Encountered the same issue. I usually use the mouse wireless, so I didn't notice it at first. Wireless also has weird behaviour btw. It causes applications to not notice a change in direction most of the time:

 -> Scroll up one step: Recognized
 -> Scroll up one step: Recognized
 -> Scroll down one step: NOT Recognized
 -> Scroll down one step: Recognized

(same the other way around)

I documented the issue already here: https://www.reddit.com/r/linux_gaming/comments/1032x5q/linux_61_update_screws_up_the_mouse_wheel_of_my/

The post contains some logs which show evtest output for scroll up + down in both the old state and new one in both wired and wireless mode. I hope this helps in tracking it down.

The file links from the post:
 - Kernel 6.0 (old working state)
   - Wireless (USB Dongle): https://haste.cosmos-ink.net/ilypefymex.log
   - Wired: https://haste.cosmos-ink.net/aqutucufuw.log
 - Kernel 6.1 (new broken state)
   - Wireless (USB Dongle): https://haste.cosmos-ink.net/lasunyjape.log
   - Wired: https://haste.cosmos-ink.net/tekijabimi.log

Those are using my G903 where I each time just scrolled up one step and one down afterwards.
Comment 2 Linus 2023-01-06 17:08:34 UTC
Seems most but not all models are affected. The previous mentioned reddit post (https://www.reddit.com/r/linux_gaming/comments/1032x5q/linux_61_update_screws_up_the_mouse_wheel_of_my/) had two other people respond:

DarkeoX: Has a Logitech G Pro, uses KDE+Wayland and didn't notice any behaviour changes.

eruanttien: Has the same issue on his Logitech G403.

So seems some, but not all, Logitech models are affected.
Comment 3 David Roth 2023-01-09 16:44:52 UTC
Created attachment 303559 [details]
Patch adding a kernel param for disabling querying and a quirk for G903 HERO

FWIW here's a minimal patch, to implement both of my original suggestions, works for me
Comment 4 Bastien Nocera 2023-01-16 15:29:22 UTC
David, Linus, can you please use hid-recorder to capture the output from the device? In a working, and non-working state would be best. That will allow to reproduce the problem locally.

Peter, do you know whether that could be a libinput, or toolkit problem?
Comment 5 David Roth 2023-01-16 16:19:43 UTC
Created attachment 303615 [details]
hid-recorder showing the issue

Sure, as far as i know libinput record should also grab the raw device inputs, but I replicated it now through hid-recorder as well
Comment 6 David Roth 2023-01-16 16:20:57 UTC
Created attachment 303616 [details]
hid-recorder without the issue
Comment 7 David B. 2023-01-18 09:49:53 UTC
Hi, 

i have the same issue with a Logitech Anywhere MX mouse in wireless mode with kernel 6.1.6.
Comment 8 David Roth 2023-01-18 09:54:55 UTC
FWIW just from looking at these files (I might be bad at interpreting the format though) it doesn't appear that the generated events are per se any different, but if high-res is explicitly enabled as provided by your commit the wheel simply freaks out completely and gets way too sensitive (I can shake the mouse in the air and the jitter on the wheel will generate scroll events) - so this might be a firmware quirk we can't do much about on kernel/linux side - I could try to boot Windows and check whether a firmware update is available that might fix that, I somewhat doubt that though
Comment 9 Linus 2023-01-18 14:21:58 UTC
Created attachment 303620 [details]
Hid-recording with issue - 2nd Person - Logitech G903 - Wired
Comment 10 Linus 2023-01-18 14:21:59 UTC
Created attachment 303621 [details]
Hid-recording with issue - 2nd Person - Logitech G903 - Wireless
Comment 11 Linus 2023-01-18 14:22:01 UTC
Created attachment 303622 [details]
Hid-recording without issue - 2nd Person - Logitech G903 - Wired
Comment 12 Linus 2023-01-18 14:22:02 UTC
Created attachment 303623 [details]
Hid-recording without issue - 2nd Person - Logitech G903 - Wireless
Comment 13 Linus 2023-01-18 14:30:49 UTC
Also added some recordings of mine. With issue is kernel 6.1.1-1-MANJARO and without issue is kernel 6.0.15-1-MANJARO.

In those recordings i tried to distinctively scroll up down and up. I scrolled 3 steps in one direction, 3 steps in the other one and again 3 steps in the first direction. I think I didn't keep the starting direction the same, so the direction might be reversed in some recordings which is not a software bug but my fault.

Btw is hidraw a lower level than evdev/input? At least in my evtest recordings the issue was easily visible. The mouse would generate an ordinary REL_WHEEL event for each REL_WHEEL_HI_RES one and also be very sensitive.

Do the changes publish in 6.1 configure the mouse or tell it to be hi-res in some other way? Is there some command to show general device information like the firmware version?
Comment 14 Linus 2023-01-18 14:38:47 UTC
While just switching from 6.1 (nonworking) back to 6.0, I also noticed that the very fast scrolling I had with 6.1 in wired mode was present in wireless mode somehow.

So this confirms that indeed there must be some setting sent to the mouse firmware which causes it to generate these unexpected events. Plugging USB Wireless Dongle out and back in caused the mouse to revert to the working state again.
Comment 15 David B. 2023-01-19 10:43:09 UTC
Today I realise that the problem has magically disappeared for me. Same setup (and kernel version) as yesterday, but there was an update for libinput from version 1.22.0 to 1.22.1. Perhaps this fix the problem!? Can anybody confirm this?
Comment 16 David Roth 2023-01-19 13:14:11 UTC
(In reply to David B. from comment #15)
> Today I realise that the problem has magically disappeared for me. Same
> setup (and kernel version) as yesterday, but there was an update for
> libinput from version 1.22.0 to 1.22.1. Perhaps this fix the problem!? Can
> anybody confirm this?

There's nothing in that version difference that would have any effect on this https://gitlab.freedesktop.org/libinput/libinput/-/compare/1.22.0...1.22.1
Comment 17 Linus 2023-01-19 14:17:34 UTC
Does it re-appear when you re-plug your Mouse (USB / USB Dongle) or turn the mouse of and on again?

I had the opposite problem, where it would sometimes remember the state set by the previous kernel and have the weird behaviour continue on 6.0 until I re-plugged the usb dongle. Maybe it somehow didn't change the HI-Res state in the mouse firmware (at least as far as I understand it).
Comment 18 David B. 2023-01-19 15:59:45 UTC
(In reply to David Roth from comment #16)
> (In reply to David B. from comment #15)
> > Today I realise that the problem has magically disappeared for me. Same
> > setup (and kernel version) as yesterday, but there was an update for
> > libinput from version 1.22.0 to 1.22.1. Perhaps this fix the problem!? Can
> > anybody confirm this?
> 
> There's nothing in that version difference that would have any effect on
> this
> https://gitlab.freedesktop.org/libinput/libinput/-/compare/1.22.0...1.22.1

You're right, I was on the wrong track. Even with an older version, the mouse wheel works as it should.
Comment 19 David B. 2023-01-19 16:02:55 UTC
(In reply to Linus from comment #17)
> Does it re-appear when you re-plug your Mouse (USB / USB Dongle) or turn the
> mouse of and on again?
> 
> I had the opposite problem, where it would sometimes remember the state set
> by the previous kernel and have the weird behaviour continue on 6.0 until I
> re-plugged the usb dongle. Maybe it somehow didn't change the HI-Res state
> in the mouse firmware (at least as far as I understand it).

Turn mouse off/on or unplug/plug makes no difference to me. 
Currently it just works...
Btw: I use a fully updated Fedora 37
Comment 20 Peter Hutterer 2023-01-24 02:00:09 UTC
> Peter, do you know whether that could be a libinput, or toolkit problem?

Apologies for the delay, this fell through the gaps. The libinput record output in comment #0 shows that the kernel events are correctly paired as if the device didn't have hi-res scrolling, each wheel event is a hires event of 120. So there's no multiplier set in the kernel.

libinput hasn't had any changes to wheel behaviour in a while, so updates to libinput won't make a difference here, this is a kernel issue.

The hid-recorder output doesn't change - that's expected since the values don't really change, just the frequency of how often they're reported.

IIRC when you plug the mouse in and the multiplier is set, a message to that effect should be printed by the kernel:  hid_dbg(hidpp->hid_dev, "wheel multiplier = %d\n", multiplier); Does that show up in your case? Or only if it works? 

(Or maybe this device usese a different driver altogether, I haven't sufficiently kept track of this, sorry).
Comment 21 David Roth 2023-01-24 13:37:28 UTC
Thanks for getting back to this

(In reply to Peter Hutterer from comment #20)

> IIRC when you plug the mouse in and the multiplier is set, a message to that
> effect should be printed by the kernel:  hid_dbg(hidpp->hid_dev, "wheel
> multiplier = %d\n", multiplier); Does that show up in your case? Or only if
> it works? 

That shows up in both cases (... of course only if debug logging is enabled) and when it does it leads to the faulty behavior for the connected case and works fine wirelessly (wirelessly it does correctly do high-res events 8 times followed by the notch tick):

[ 4381.371067] logitech-hidpp-device 0003:046D:C091.0010: HID++ 4.2 device connected.
[ 4381.418934] logitech-hidpp-device 0003:046D:C091.0010: Detected HID++ 2.0 hi-res scroll wheel
[ 4381.434062] logitech-hidpp-device 0003:046D:C091.0010: wheel multiplier = 8


As for keeping track - since I'm not that versed with general kernel dev (yet) - is it OK to keep responding here or should this be posted directly to some mailing list or so?

With the patch in comment #3 these do of course not show up anymore and the issue is "solved" since the relevant queries don't happen.
Comment 22 Linus 2023-01-24 15:14:49 UTC
> That shows up in both cases (... of course only if debug logging is enabled)
> and when it does it leads to the faulty behavior for the connected case and
> works fine wirelessly (wirelessly it does correctly do high-res events 8
> times followed by the notch tick):


In the wireless case, while not scrolling too fast, it seems to have the bug where it skips a tick when direction is reversed though. So while tick intervals are in theory correct, it's still faulty. That's how I initially noticed it. The reddit link above had me describe it in more detail i think.


Also not really versed with kernel dev yet. I have contributed via mailing lists twice so far, but it usually was pretty slow to get things done for me and I don't actively monitor the kernel mailinglist rn. If there is testing needed, feel free to let me know though.
Comment 23 Tobias Klausmann 2023-01-26 10:13:50 UTC
I have the same problem with a G903 (I only use it wired). I have chosen to blacklist `hid_logitech_hidpp.ko` for now which is easier than patching (and I don't use the hires stuff anyway). I can provide logs and testing as needed.
Comment 24 Bastien Nocera 2023-01-26 14:31:39 UTC
Can someone please attach the output of "solaar show" to this bug with the mouse connected? It doesn't need to be with one of the problematic kernels. You might need to run "solaar" as root.
Comment 25 Tobias Klausmann 2023-01-26 14:49:16 UTC
Created attachment 303651 [details]
solaar show run for G903 in good state

Attached solaar show for when the system is in good state. Will add bad state in a moment.
Comment 26 Tobias Klausmann 2023-01-26 14:51:46 UTC
Created attachment 303652 [details]
solaar show run for mouse in bad state

And here's the same command, but with the mouse in bad state.
Comment 27 Bastien Nocera 2023-01-26 16:27:24 UTC
The 0x2121 feature seems to get enabled correctly, with the correct multiplier (8).

So the problem is probably somewhere in the hidpp_scroll_counter_handle_scroll() codepath, either a bug in the function itself, or the fact that hidpp_event() gets called for more than just wheel events despite the contents of hidpp_usages[].

If someone wants to debug, they can make hidpp_event() show the page and usage fields of the hid_field struct, description for the values are in hid-debug.c.

I'll try to figure out how to get access to a supported device, or use hid-recorder to replay the existing captures.
Comment 28 Tobias Klausmann 2023-01-26 16:41:01 UTC
I can hack the kernel code, but I don't know which fields of hid_field are interesting. It's also been a while since I did such hacking, is dprintk still the done thing?
Comment 29 Bastien Nocera 2023-02-02 12:18:48 UTC
I bought a G903 second-hand, but there are multiple models of the G903, and this model (M-R0068) doesn't support hi-res scrolling, only the refreshed model (M-R0081) does.

Attached below will be a patch that adds debug to try and track down the problem. Please compile a kernel with this patch, and make sure to enable CONFIF_DYNAMIC_DEBUG when you do.

Boot your machine with the mouse turned off. As root, enable debug in the Logitech driver:
echo 'file hid-logitech-hidpp.c +p' > /sys/kernel/debug/dynamic_debug/control

Verify that you're running the correct kernel by checking:
# grep -i passing /sys/kernel/debug/dynamic_debug/control 
drivers/hid/hid-logitech-hidpp.c:3801 [hid_logitech_hidpp]hidpp_event =p "Passing scroll event as low-res (reason: %s)\n"
drivers/hid/hid-logitech-hidpp.c:3807 [hid_logitech_hidpp]hidpp_event =p "Passing hi-res scroll event (value %d)\n"

Then, turn on the mouse, and capture the journalctl output once you can reproduce the problem, and attach it here.

If I can't find anything wrong for those devices, I'll use the logs to create a blocklist and stop the G903 from using the hi-res scroll wheel functionality.

If the problem happens on other devices (I've seen the G403 mentioned), please apply the patch, and post logs too.
Comment 30 Bastien Nocera 2023-02-02 12:19:43 UTC
Created attachment 303677 [details]
hidpp-hires-scroll-stock-test-v1.patch

Apply with "git am".

Make sure to enable CONFIG_DYNAMIC_DEBUG.
Comment 31 Tobias Klausmann 2023-02-02 13:09:24 UTC
Created attachment 303678 [details]
debug log

Log from patched v6.2-rc6 kernel. HIDPP is built-in (not a module). Nothing else showed up in syslog/journal or kmesg.
Comment 32 Bastien Nocera 2023-02-02 13:17:18 UTC
(In reply to Tobias Klausmann from comment #31)
> Created attachment 303678 [details]
> debug log
> 
> Log from patched v6.2-rc6 kernel. HIDPP is built-in (not a module). Nothing
> else showed up in syslog/journal or kmesg.

Did you verify:
# grep -i passing /sys/kernel/debug/dynamic_debug/control 
?

I have no idea whether dynamic debug works with the driver builtin. It should show stuff like:
Feb 02 12:03:26 classic kernel: logitech-hidpp-device 0003:046D:406D.0006: Passing hi-res scroll event (value 1)
Feb 02 12:03:26 classic kernel: logitech-hidpp-device 0003:046D:406D.0006: Passing hi-res scroll event (value -1)
Feb 02 12:08:34 classic kernel: logitech-hidpp-device 0003:046D:406D.0006: Passing scroll event as low-res (reason: value is 0)

When using the scroll wheel. If it doesn't, that means that the patch might not having been applied correctly. It's supposed to create 4 new commits in git...
Comment 33 Tobias Klausmann 2023-02-02 13:44:21 UTC
linux ((1de8cbee2e17...)) $ git diff --stat v6.2-rc6
 drivers/hid/hid-core.c           |  9 --------
 drivers/hid/hid-logitech-hidpp.c | 52 ++++++++++++++++++++++++++++++++++++++----
 include/linux/hid.h              |  8 +------
 3 files changed, 49 insertions(+), 20 deletions(-)
linux ((1de8cbee2e17...)) $ git log --oneline |head
1de8cbee2e17 scroll events debug
3bf61ca06c83 HID: logitech-hidpp: Don't parse messages meant for others
ee897dde53fc HID: logitech-hidpp: Add more debug statements
0571314af9fa HID: use standard debug APIs
6d796c50f84c Linux 6.2-rc6
ab072681eabe Merge tag 'irq_urgent_for_v6.2_rc6' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
bc6bc34b1095 Merge tag 'x86_urgent_for_v6.2_rc6' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
linux ((1de8cbee2e17...)) $

This is what I have after git-am'ing the patch linked above.

As for the enabling echo, I did that, but didn't get anything with grep _until after the module was loaded,_ hence me doing a second try with the driver built-in. After a modprobe (mouse still off) and echo  I got the expected lines back on grep. So I tried again, this time not hand-loading the mdoule but letting the USB device appearing cause a load. No difference. Here's how that looked:

root@motoko:~# grep -i passing /sys/kernel/debug/dynamic_debug/control 
root@motoko:~# echo 'file hid-logitech-hidpp.c +p' > /sys/kernel/debug/dynamic_debug/control 
root@motoko:~# grep -i passing /sys/kernel/debug/dynamic_debug/control 
[pwoer-on the mouse]
root@motoko:~# grep -i passing /sys/kernel/debug/dynamic_debug/control 
drivers/hid/hid-logitech-hidpp.c:3787 [hid_logitech_hidpp]hidpp_event =_ "Passing scroll event as low-res (reason: %s)\n"
drivers/hid/hid-logitech-hidpp.c:3793 [hid_logitech_hidpp]hidpp_event =_ "Passing hi-res scroll event (value %d)\n"
root@motoko:~#

The messages about scroll events I didn't see anywhere (dmesg, syslog, journalctl -xe -f). Are they maybe too high/low a log level to show up anywhere?
Comment 34 Tobias Klausmann 2023-02-02 13:47:11 UTC
One add'l note: if you'd prefer to do this more sycnrhonously (and not spam this bug), you can find me on the Libera and OFTC networks as Blackb|rd.
Comment 35 Bastien Nocera 2023-02-02 13:50:05 UTC
(In reply to Tobias Klausmann from comment #34)
> One add'l note: if you'd prefer to do this more sycnrhonously (and not spam
> this bug), you can find me on the Libera and OFTC networks as Blackb|rd.

I'm not doing anything special for them to show up in either dmesg or journalctl.

Maybe re-run the echo command to enable the debug after the module is loaded.
Comment 36 Tobias Klausmann 2023-02-02 14:14:03 UTC
I did some more digging on why there are no messages and added this debug line:

@@ -3761,8 +3762,10 @@ static int hidpp_event(struct hid_device *hdev, struct hid_field *field,
        struct hidpp_device *hidpp = hid_get_drvdata(hdev);
        struct hidpp_scroll_counter *counter;
 
-       if (!hidpp)
+       if (!hidpp) {
+               printk("[klausman] hidpp is NULL");
                return 0;
+       }
 
        counter = &hidpp->vertical_wheel_counter;
        /* A scroll event may occur before the multiplier has been retrieved or


And sure enough, that rpintk fires all the time (mouse movement, scroll wheel). So the debug messages further down the file never fire. What this means on the context of the bug, I dunno.
Comment 37 Bastien Nocera 2023-02-02 14:33:21 UTC
(In reply to Tobias Klausmann from comment #36)
> I did some more digging on why there are no messages and added this debug
> line:
> 
> @@ -3761,8 +3762,10 @@ static int hidpp_event(struct hid_device *hdev,
> struct hid_field *field,
>         struct hidpp_device *hidpp = hid_get_drvdata(hdev);
>         struct hidpp_scroll_counter *counter;
>  
> -       if (!hidpp)
> +       if (!hidpp) {
> +               printk("[klausman] hidpp is NULL");
>                 return 0;
> +       }
>  
>         counter = &hidpp->vertical_wheel_counter;
>         /* A scroll event may occur before the multiplier has been retrieved
> or
> 
> 
> And sure enough, that rpintk fires all the time (mouse movement, scroll
> wheel). So the debug messages further down the file never fire. What this
> means on the context of the bug, I dunno.

It means hidpp_validate_device() failed and hid_set_drvdata() was called, see the comment that says:
"Make sure the device is HID++ capable, otherwise treat as generic HID"
or there's a pretty big bug somewhere. Can you add a debug statement there to see if it's taking that path?

Can you please post another log with those debugs? It's unclear to me which device this is happening on, and this is all very weird.
Comment 38 Tobias Klausmann 2023-02-02 15:59:25 UTC
I added more debugging statements in hidpp_probe() and hidpp_validate_device. On device init I get tow devices that have supported_reports=0:

Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.001F: [klausman] supported reports: 0
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.001F: [klausman] After hidpp_validate_device, supported_reports=0
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.001F: [klausman] returning hid_hw_start(hdev, HID_CONNECT_DEFAULT);
Feb 02 16:43:52 motoko kernel: input: Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO as /devices/pci0000:00/0000:00:01.3/0000:02:00.0/usb1/1-7/1-7.1/1-7.1:1.0/0003:046D:C091.001F/input/input54
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.001F: input,hidraw0: USB HID v1.11 Mouse [Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO] on usb-0000:02:00.0-7.1/input0
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0020: [klausman] supported reports: 0
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0020: [klausman] After hidpp_validate_device, supported_reports=0
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0020: [klausman] returning hid_hw_start(hdev, HID_CONNECT_DEFAULT);
Feb 02 16:43:52 motoko kernel: input: Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO as /devices/pci0000:00/0000:00:01.3/0000:02:00.0/usb1/1-7/1-7.1/1-7.1:1.1/0003:046D:C091.0020/input/input55
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0020: input,hidraw1: USB HID v1.11 Keyboard [Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO] on usb-0000:02:00.0-7.1/input1

They all hit the validate call after the comment you mentioned, but supported_reports is 0, so they take the first if-section afyter that (returning hid_hw_start(hdev, HID_CONNECT_DEFAULT);)

I added printk()s to all of the report length cgecks (that lead to goto bad_device). None of them were hit for any of the three calls to that function.

The third device has three reports, so it continues on:

Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0021: [klausman] supported reports: 3
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0021: [klausman] After hidpp_validate_device, supported_reports=3
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0021: [klausman] INIT_WORK(&hidpp->work, delayed_work_cb);

Reaching this point means none of the Quirks sections (half a dozen) were hit (there would be additional log lines).

Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0021: [klausman] hid_device_io_start()

Since we got here, hw start succeeded, as did hw_open,

Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0021: HID++ 4.2 device connected.
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0021: [klausman] hidpp_root_get_protocol_version(hidpp) == 0? connected=1
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0021: [klausman] overwriting name

This means we hit the bottom of the if-block that checks whether the dice is connected properly (hidpp_overwrite_name(hdev);)

Feb 02 16:43:52 motoko kernel: hid_logitech_hidpp: drivers/hid/hid-logitech-hidpp.c: HID++: Got name: Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0021: [klausman] hidpp_connect_event(hidpp);

This means none of the conditional blocks after the protocol_major>=2 check are hit (no wireless, no init fail, not a WTP or G920 quirk device)

Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0021: Detected HID++ 2.0 hi-res scroll wheel
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0021: wheel multiplier = 8
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0021: hiddev0,hidraw2: USB HID v1.11 Device [Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO] on usb-0000:02:00.0-7.1/input2
Feb 02 16:43:52 motoko kernel: logitech-hidpp-device 0003:046D:C091.0021: [klausman] return from hidpp_probe (nofail)

And this means we made it to the non-fail-bottom of the function hidpp_probe(). None of the goto-targets after that are ever triggered.

I am not sure if any of this helps. It sure doesn't look like any errors/failures occur that would explain the bug.

As for hid_set_drvdata, I could not find where that function/macro is defined, so I couldn't add any debug statements to it.
Comment 39 Bastien Nocera 2023-02-02 16:12:40 UTC
(In reply to Tobias Klausmann from comment #38)
> And this means we made it to the non-fail-bottom of the function
> hidpp_probe(). None of the goto-targets after that are ever triggered.

Do you still see hidpp_event() exiting early because hid_get_drvdata() returns NULL? On which device is it? On the same device that has hidpp_validate_device() failing, or on another one? The full log would still be useful.

I wonder if the scroll events happen on a different interface/device to where the HID++ interface is, which would explain all the problems we've seen.

> As for hid_set_drvdata, I could not find where that function/macro is
> defined, so I couldn't add any debug statements to it.

It's defined in include/linux/hid.h.
Comment 40 Tobias Klausmann 2023-02-02 16:40:54 UTC
(In reply to Bastien Nocera from comment #39)
> (In reply to Tobias Klausmann from comment #38)
> > And this means we made it to the non-fail-bottom of the function
> > hidpp_probe(). None of the goto-targets after that are ever triggered.
> 
> Do you still see hidpp_event() exiting early because hid_get_drvdata()
> returns NULL? On which device is it? On the same device that has
> hidpp_validate_device() failing, or on another one? The full log would still
> be useful.
> 
> I wonder if the scroll events happen on a different interface/device to
> where the HID++ interface is, which would explain all the problems we've
> seen.

```
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0028: [klausman] supported reports: 0
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0028: [klausman] After hidpp_validate_device, supported_reports=0
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0028: [klausman] returning hid_hw_start(hdev, HID_CONNECT_DEFAULT);
Feb 02 17:37:37 motoko kernel: input: Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO as /devices/pci0000:00/0000:00:01.3/0000:02:00.0/usb1/1-7/1-7.1/1-7.1:1.0/0003:046D:C091.0028/input/input62
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0028: input,hidraw0: USB HID v1.11 Mouse [Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO] on usb-0000:02:00.0-7.1/input0
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0029: [klausman] supported reports: 0
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0029: [klausman] After hidpp_validate_device, supported_reports=0
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0029: [klausman] returning hid_hw_start(hdev, HID_CONNECT_DEFAULT);
Feb 02 17:37:37 motoko kernel: input: Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO as /devices/pci0000:00/0000:00:01.3/0000:02:00.0/usb1/1-7/1-7.1/1-7.1:1.1/0003:046D:C091.0029/input/input63
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0029: input,hidraw1: USB HID v1.11 Keyboard [Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO] on usb-0000:02:00.0-7.1/input1
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: [klausman] supported reports: 3
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: [klausman] After hidpp_validate_device, supported_reports=3
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: [klausman] INIT_WORK(&hidpp->work, delayed_work_cb);
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: [klausman] hid_device_io_start()
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: HID++ 4.2 device connected.
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: [klausman] hidpp_root_get_protocol_version(hidpp) == 0? connected=1
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: [klausman]in HIDPP_QUIRK_UNIFYING
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: [klausman] overwriting name
Feb 02 17:37:37 motoko kernel: hid_logitech_hidpp: drivers/hid/hid-logitech-hidpp.c: HID++: Got name: Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: [klausman] hidpp_connect_event(hidpp);
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: Detected HID++ 2.0 hi-res scroll wheel
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: wheel multiplier = 8
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: [klausman] modified module active
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: hiddev0,hidraw2: USB HID v1.11 Device [Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO] on usb-0000:02:00.0-7.1/input2
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.002A: [klausman] return from hidpp_unifying_init (nofail)
Feb 02 17:37:37 motoko mtp-probe[73869]: checking bus 1, device 20: "/sys/devices/pci0000:00/0000:00:01.3/0000:02:00.0/usb1/1-7/1-7.1"
Feb 02 17:37:37 motoko mtp-probe[73869]: bus: 1, device: 20 was not an MTP device
Feb 02 17:37:37 motoko systemd-logind[771]: Watching system buttons on /dev/input/event15 (Logitech G903 LIGHTSPEED Wireless Gaming Mouse w/ HERO)
Feb 02 17:37:37 motoko mtp-probe[73892]: checking bus 1, device 20: "/sys/devices/pci0000:00/0000:00:01.3/0000:02:00.0/usb1/1-7/1-7.1"
Feb 02 17:37:37 motoko mtp-probe[73892]: bus: 1, device: 20 was not an MTP device
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0028: [klausman] early exit
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0028: [klausman] early exit
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0028: [klausman] early exit
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0028: [klausman] early exit
Feb 02 17:37:37 motoko kernel: logitech-hidpp-device 0003:046D:C091.0028: [klausman] early exit
```

So it looks like the device that triggers the "early exit" (aka hidpp==NULL) is 0003:046D:C091.0028, one of the two devices that has supported_reports==0. I don't know what exactly that means, but it sounds like the problem you mentioned. I also notice that the early exit message is triggered 8 times for every notch on the wheel, which meshes with the debug dumps we had the other day.
Comment 41 Bastien Nocera 2023-02-03 00:27:59 UTC
Created attachment 303680 [details]
0001-HID-logitech-Disable-hi-res-scrolling-on-USB.patch

This disable hi-res scrolling on those devices, for the stable and development branches, until we implement scroll events through HID++.

Let me know if it works as expected (or as before, rather).
Comment 42 Tobias Klausmann 2023-02-03 08:37:28 UTC
I can confirm that that patch, applied ontop of 6.2-rc6 fixes the problem (`hid_logitech_hidpp.ko` is loaded and there are no special kernel cmdline options). Thanks!
Comment 43 Bastien Nocera 2023-02-03 13:12:51 UTC
(In reply to Bastien Nocera from comment #41)
> Created attachment 303680 [details]
> 0001-HID-logitech-Disable-hi-res-scrolling-on-USB.patch
> 
> This disable hi-res scrolling on those devices, for the stable and
> development branches, until we implement scroll events through HID++.

The bug for tracking the re-enablement of the feature:
https://bugzilla.kernel.org/show_bug.cgi?id=216997
Comment 44 Bastien Nocera 2023-03-01 14:01:55 UTC
Patch was merged upstream.

Note You need to log in before you can comment on or make changes to this bug.