Bug 1563554

Supressing logging with:

sudo udevadm control -l emerg

does not help. systemd-udevd is still eating CPU. Any hints/fixes would be appreciated :)

Cheers!

Somehow, that doesn't even reduce the logging:

$ journalctl -b --no-pager | grep hid2hci | wc -l
261374

It just won't stop.

I had no trouble in F27, but I don't know if this is a regression.

It seems that there's some loop in udev rule processing. /usr/lib/udev/rules.d/97-hid2hci.rules contains a call to "/sbin/udevadm trigger", so my guess would be that this rule triggers itself over and over. The call to hd2hci that would cause the loop to be broken, fails.

It would be interesting to see what the hid2hci error is. Is the log line truncated like that in the journal? How are you extracting it?

Ah, no, I think this is the complete error:

Apr 05 09:32:23 ankur.pc systemd-udevd[507]: Process 'hid2hci --method=dell --devpath=/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.1/1-1.1.2/1-1.1.2:1.0' failed with exit code 1.


I don't know much about the hw side, but lspci -vv gives me this about what i think is the hw mentioned in the error above (00:1a.0) if that helps:

00:1a.0 USB controller: Intel Corporation 5 Series/3400 Series Chipset USB2 Enhanced Host Controller (rev 06) (prog-if 20 [EHCI])
        Subsystem: Dell Device 0440
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0
        Interrupt: pin A routed to IRQ 16
        Region 0: Memory at fb408000 (32-bit, non-prefetchable) [size=1K]
        Capabilities: [50] Power Management version 2
                Flags: PMEClk- DSI- D1- D2- AuxCurrent=375mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
                Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME-
        Capabilities: [58] Debug port: BAR=1 offset=00a0
        Capabilities: [98] PCI Advanced Features
                AFCap: TP+ FLR+
                AFCtrl: FLR-
                AFStatus: TP-
        Kernel driver in use: ehci-pci


I'm happy to provide more information if you can tell me how to get it :)

Thanks,
Ankur

Created attachment 1417566 [details]
Full journal logs

I've attached the full journal logs. Lots of these lines in journalctl too, for example.

Apr 05 09:45:11 ankur.pc upowerd[20590]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.1/1-1.1.2/1-1.1.2:1.0    

Eventually, I killed systemd-udevd, and then it didn't restart:

Apr 05 09:45:11 ankur.pc systemd[1]: systemd-udevd.service: Service has no hold-off time, scheduling restart.
Apr 05 09:45:11 ankur.pc systemd[1]: systemd-udevd.service: Scheduled restart job, restart counter is at 6.
Apr 05 09:45:11 ankur.pc systemd[1]: Stopped udev Kernel Device Manager.
Apr 05 09:45:11 ankur.pc systemd[1]: systemd-udevd.service: Start request repeated too quickly.
Apr 05 09:45:11 ankur.pc systemd[1]: systemd-udevd.service: Failed with result 'start-limit-hit'.
Apr 05 09:45:11 ankur.pc systemd[1]: Failed to start udev Kernel Device Manager.

And what happens if you run:
/usr/lib/udev/hid2hci --method=dell --devpath=/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.1/1-1.1.2/1-1.1.2:1.0

I'm interested in any error messages from hid2hci itself.

Not much, I'm afraid:

$ sudo /usr/lib/udev/hid2hci --method=dell --devpath=/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.1/1-1.1.2/1-1.1.2:1.0 
error: switching device '/sys//devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.1/1-1.1.2/1-1.1.2:1.0' failed.

I'm still seeing this here. It doesn't affect the machine much after I login and kill systemd-udev manually. I can restart the service and it doesn't go nuts then. However, it hangs up the boot process, which now waits for the whole 2-3 minutes before quitting on this one particular service.

Any ideas towards a workaround maybe? Is it to do with a specific device I'm using for example? (A wireless microsoft keyboard/mouse for example?)

Just upgraded to F29, and still seeing this issue.

I am as seeing this after upgrading to Fedora 29.

194232 messages relating to this in journal in uptime of 55min.

I'll attach a small sample of the output. Laptop is a dell studio 17. I'll also include start of logfile with details of system.

Created attachment 1499960 [details]
output of: journalctl -b0 | tail -20

output of: journalctl -b0 | tail -20

Created attachment 1499975 [details]
First 1200 lines of "journal -b0" from affected system

First 1200 lines of "journal -b0" from affected system

SOLVED conflict with Dell/Broadcom 370 Wireless Bluetooth half card adapter on Dell Studio 1537


To fix issues please consider modifying  /lib/udev/rules.d/97-hid2hci.rules files from:

ATTR{bInterfaceClass}=="03", ATTR{bInterfaceSubClass}=="01", ATTR{bInterfaceProtocol}=="02", \
  ATTRS{bDeviceClass}=="00", ATTRS{idVendor}=="413c", ATTRS{bmAttributes}=="e0", \
  RUN+="hid2hci --method=dell --devpath=%p", ENV{HID2HCI_SWITCH}="1"

to:

ACTION=="add", ATTR{bInterfaceClass}=="03", ATTR{bInterfaceSubClass}=="01", ATTR{bInterfaceProtocol}=="02", \
  ATTRS{bDeviceClass}=="00", ATTRS{idVendor}=="413c", ATTRS{bmAttributes}=="e0", \
  RUN+="hid2hci --method=dell --devpath=%p", ENV{HID2HCI_SWITCH}="1"

Adding:

the ACTION=="add",

to the line fixed my issues with the Dell/Broadcom 370 Wireless Bluetooth half card adapter in my Dell Studio 1537.
Hopefully this fix will be helpful to others.

/lib/udev/rules.d/97-hid2hci.rules is owned by bluez-hid2hci-5.50-6.fc30.x86_64.
Let's reassign.

> To fix issues please consider modifying  /lib/udev/rules.d/97-hid2hci.rules
> files from:
> 
> ATTR{bInterfaceClass}=="03", ATTR{bInterfaceSubClass}=="01",
> ATTR{bInterfaceProtocol}=="02", \
>   ATTRS{bDeviceClass}=="00", ATTRS{idVendor}=="413c",
> ATTRS{bmAttributes}=="e0", \
>   RUN+="hid2hci --method=dell --devpath=%p", ENV{HID2HCI_SWITCH}="1"
> 
> to:
> 
> ACTION=="add", ATTR{bInterfaceClass}=="03", ATTR{bInterfaceSubClass}=="01",
> ATTR{bInterfaceProtocol}=="02", \
>   ATTRS{bDeviceClass}=="00", ATTRS{idVendor}=="413c",
> ATTRS{bmAttributes}=="e0", \
>   RUN+="hid2hci --method=dell --devpath=%p", ENV{HID2HCI_SWITCH}="1"
> 
> Adding:
> 
> the ACTION=="add",
> 
> to the line fixed my issues with the Dell/Broadcom 370 Wireless Bluetooth
> half card adapter in my Dell Studio 1537.

This has fixed the issue for me too on my Dell Vostro 3500. My bluetooth devices:

$ lsusb | grep -i blue
Bus 001 Device 007: ID 413c:8160 Dell Computer Corp. Wireless 365 Bluetooth
Bus 001 Device 003: ID 0a5c:4500 Broadcom Corp. BCM2046B1 USB 2.0 Hub (part of BCM2046 Bluetooth)

I no longer have this hardware and cannot reproduce this issue, so I'll close this bug now. If someone else is seeing it too, please re-open.

bluez-hid2hci still hasn't been updated to reflect the fix as outlined in comment 13, 14, 15. This is a big problem with SilverBlue, since /lib/udev/rules.d/97-hid2hci.rules is on an immutable file system. I really like SilverBlue, but I can't fix this issue anymore. Also documentation on SilverBlue is lacking because it is new. Do I have to create a new RPM and install with rpm-ostree install. Please advise.

Same issue on a Dell Vostro 3300 with Fedora 30... And comment #13 solved my problem again.