Bug 203741

Created attachment 282985 [details]
dmesg

See the 3 min delay for the devs coming on-line

Created attachment 282987 [details]
journalctl -b | grep -iE "kernel|udev"

Created attachment 282989 [details]
lsmod before devs

[Quote=Hans]
Can you please run lsmod *before* the devices show up in dmesg and
again after they show up and include the output of both commands in
the bug.[/quote]

I had to find an old wired keyboard to get this.  And also, my comment in the email regarding Plasma5 was incorrect.  After getting to Plasma DE, waiting for the devs to come online, they are then available to the Desktop.

Created attachment 282991 [details]
lsmod after

Ok, so for some reason the modprobe of the 2 modules for the mouse and keyboard is taking very long, looking at the 2 lsmods:

--- Download/lsmod-before.log   2019-06-03 11:22:19.084063223 +0200
+++ Download/lsmod-after.log    2019-06-03 11:22:20.580077384 +0200
@@ -1,10 +1,13 @@
 Module                  Size  Used by
+hid_logitech_hidpp     45056  0
+joydev                 28672  0
+hid_logitech_dj        28672  0
 af_packet              53248  2
 scsi_transport_iscsi   122880  1
 msr                    16384  0

In our email exchange you said you can build your own kernels, can you try reverting these 2 commits:

git revert 4ceabaf79
git revert a025a18fe

Besides making changes to the logitech code I also submitted 2 patches to
optimize HID driver loading, but these 2 seem to be causing problems for various users.

I expect reverting these 2 to get rid of the delay.

After booting a 5.2 kernel with these 2 reverts, can you please do:

dmesg > dmesg.log

And attach the new dmesg.log here?

I've another request, what is the setting of the CONFIG_RANDOM_TRUST_CPU Kconfig option in the .config file for your kernel?

If that is not set, it would also be interesting to try setting that to Y and see if that fixes the delay without needing to revert those 2 patches.

CONFIG_RANDOM_TRUST_CPU is set to Y for my current kernel 5.2RC2.

(In reply to Mike Noe from comment #7)
> CONFIG_RANDOM_TRUST_CPU is set to Y for my current kernel 5.2RC2.

Ok, so that is not the problem then, too bad (it was a bit of a long shot anyways).

Created attachment 283053 [details]
dmesg after reverting two commits

Well, yes, you called it right.  I took linus/master (RC3) and reverted those two commits and now USB devs (keyboard/mouse) are all working as expected, no delay after boot.

FWIW, I'm running MSI Tomahawk/AM4/Ryzen5

Thanks, the dmesg looks good, logitech-dj still loads as expected.

Can you do:

cat /proc/sys/kernel/modprobe

And paste the output?  we are still trying to find out why those 2 commits are causing problems for some users, while they work fine for others (including for both me and Benjamin who both have tested them extensively).

/sbin/modprobe

(In reply to Mike Noe from comment #11)
> /sbin/modprobe

Ok, so nothing special there.

Similar problem here, with kernel 5.2rc2 from opensuse HEAD, only it takes "just" 30 seconds to initialize:

[Thu May 30 08:29:20 2019] random: crng init done
[Thu May 30 08:29:20 2019] random: 7 urandom warning(s) missed due to ratelimiting
... 30 seconds wait ...
[Thu May 30 08:29:51 2019] input: Logitech USB Receiver as /devices/pci0000:00/0000:00:02.0/usb2/2-3/2-3:1.0/0003:046D:C517.0001/input/input5
[Thu May 30 08:29:51 2019] hid-generic 0003:046D:C517.0001: input,hidraw0: USB HID v1.10 Keyboard [Logitech USB Receiver] on usb-0000:00:02.0-3/input0
[Thu May 30 08:29:51 2019] input: Logitech USB Receiver Mouse as /devices/pci0000:00/0000:00:02.0/usb2/2-3/2-3:1.1/0003:046D:C517.0002/input/input6
[Thu May 30 08:29:51 2019] input: Logitech USB Receiver Consumer Control as /devices/pci0000:00/0000:00:02.0/usb2/2-3/2-3:1.1/0003:046D:C517.0002/input/input7
[Thu May 30 08:29:51 2019] input: Logitech USB Receiver System Control as /devices/pci0000:00/0000:00:02.0/usb2/2-3/2-3:1.1/0003:046D:C517.0002/input/input8
[Thu May 30 08:29:51 2019] hid-generic 0003:046D:C517.0002: input,hiddev96,hidraw1: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:02.0-3/input1
[Thu May 30 08:29:51 2019] usbcore: registered new interface driver usbhid [Thu May 30 08:29:51 2019] usbhid: USB HID core driver
[Thu May 30 08:29:51 2019] logitech-djreceiver 0003:046D:C517.0001: hidraw0:USB HID v1.10 Keyboard [Logitech USB Receiver] on usb-0000:00:02.0-3/input0
[Thu May 30 08:29:51 2019] systemd-journald[217]: Received SIGTERM from PID 1 (systemd).
[Thu May 30 08:29:51 2019] logitech-djreceiver 0003:046D:C517.0002:hiddev96,hidraw1: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:02.0-3/input1
[Thu May 30 08:29:51 2019] logitech-djreceiver 0003:046D:C517.0002: device of type 27 Mhz (0x02) connected on slot 1
[Thu May 30 08:29:51 2019] logitech-djreceiver 0003:046D:C517.0002: device of type 27 Mhz (0x02) connected on slot 3
[Thu May 30 08:29:51 2019] printk: systemd: 12 output lines suppressed due to ratelimiting
[Thu May 30 08:29:53 2019] logitech-hidpp-device 0003:046D:000A.0003: HID++ 1.0 device connected.
[Thu May 30 08:29:53 2019] input: Logitech Wireless Mouse PID:000a as /devices/pci0000:00/0000:00:02.0/usb2/2-3/2-3:1.1/0003:046D:C517.0002/0003:046D:000A.0003 input/input11
[Thu May 30 08:29:53 2019] logitech-hidpp-device 0003:046D:000A.0003: input,hidraw2: USB HID v1.11 Mouse [Logitech Wireless Mouse PID:000a] on usb-0000:00:02.0-3/input1:1
[Thu May 30 08:29:53 2019] logitech-hidpp-device 0003:046D:005E.0004: HID++ 1.0 device connected. 
[Thu May 30 08:29:53 2019] input: Logitech Wireless Keyboard PID:005e as /devices/pci0000:00/0000:00:02.0/usb2/2-3/2-3:1.1/0003:046D:C517.0002/0003:046D:005E.0004/input/input12
[Thu May 30 08:29:53 2019] logitech-hidpp-device 0003:046D:005E.0004: input,hidraw3: USB HID v1.11 Keyboard [Logitech Wireless Keyboard PID:005e] on usb-0000:00:02.0-3/input1:3


Motherboard is Gigabyte 970-GAMING, Logitech device is Cordless Desktop 650.

Have the same problem. My Logitech M325 mouse starts working after a delay of 2-3 minutes if hot plugged into running laptop. OR and WILL cause the 2-3 minutes delay if I turn on my laptop with a receiver plugged in. If it is not plugged kernel starts without a delay.

(In reply to Hans de Goede from comment #5)
> Ok, so for some reason the modprobe of the 2 modules for the mouse and
> keyboard is taking very long, looking at the 2 lsmods:
> 
> --- Download/lsmod-before.log   2019-06-03 11:22:19.084063223 +0200
> +++ Download/lsmod-after.log    2019-06-03 11:22:20.580077384 +0200
> @@ -1,10 +1,13 @@
>  Module                  Size  Used by
> +hid_logitech_hidpp     45056  0
> +joydev                 28672  0
> +hid_logitech_dj        28672  0
>  af_packet              53248  2
>  scsi_transport_iscsi   122880  1
>  msr                    16384  0
> 
> In our email exchange you said you can build your own kernels, can you try
> reverting these 2 commits:
> 
> git revert 4ceabaf79
> git revert a025a18fe
> 

I can confirm that reverting those commits solve my problem described at 
https://bugzilla.kernel.org/show_bug.cgi?id=203807

The 2 reverts fixing this are queued up for merging in: https://git.kernel.org/pub/scm/linux/kernel/git/hid/hid.git/log/?h=for-5.2/fixes

So they should show up in an upcoming 5.2-rc# release.

(In reply to Hans de Goede from comment #16)
> The 2 reverts fixing this are queued up for merging in:
> https://git.kernel.org/pub/scm/linux/kernel/git/hid/hid.git/log/?h=for-5.2/
> fixes
> 
> So they should show up in an upcoming 5.2-rc# release.

5.2-rc5 works like a charm

Thanks for cooperation
Elimar

Working on 5.2-rc5 too. Also, first time I can see any kind of battery status for my (old) Logitech Desktop, however inaccurate may it be (in sysfs I can find only High and Low values, while KDE battery monitor jumps from 70% when idle to 10% when typing more than a few characters, then back to 70%. I was sooooo happy when first "Low keyboard battery" notification jumped out - Windows did that back in 1990's, but after a few minutes had to reduce it's sensitivity to <10% because it was annoying. Did not have time to try new batteries, maybe tomorrow). 
I'll have to wait until one of the batteries goes dead to see what will it say then...

Thank you, and keep up the good work!