Re: btusb "firmware request while host is not available" at resume

From: Gabriel C
Date: Sun Sep 10 2017 - 23:49:57 EST


On 11.09.2017 05:15, Gabriel C wrote:
On 11.09.2017 03:25, Greg Kroah-Hartman wrote:
On Sun, Sep 10, 2017 at 12:26:02PM -0700, Linus Torvalds wrote:
This seems to be a new problem at resume for the Intel btusb driver,
but I'm not seeing anything in that driver itself that looks like a
likely trigger, so I wonder if it's some driver core change, a generic
resume path issue, or a workqueue change that has made it trigger for
me.

It might also just be a timing difference, maybe it's always been there?

Does anybody have any ideas? It does't happen on every resume, and the
machine works despite this (but no bluetooth - the *next* resume might
bring it back, though).

Ah, it's not just me having this problem. I don't see it happening in
4.12, and haven't had the time to bisect it. I seem to be able to
trigger it every suspend/resume cycle, so I don't know if it's a timing
issue.


I see the same problem with QCA hardware.. but a bit different.

On first resume cycle the firmware call is fine but the adapter dies a bit later with :


Â'Bluetooth: hci0: Failed to send body at 4 of 1857 (-110)'

On second resume cycle I hit the trace too.




ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ Linus

--

ÂÂ ACPI: Low-level resume complete
ÂÂ ACPI: EC: EC started
ÂÂ PM: Restoring platform NVS memory
ÂÂ Enabling non-boot CPUs ...
ÂÂ x86: Booting SMP configuration:
ÂÂ smpboot: Booting Node 0 Processor 1 APIC 0x2
ÂÂÂ cache: parent cpu1 should not be sleeping
ÂÂ CPU1 is up
ÂÂ smpboot: Booting Node 0 Processor 2 APIC 0x1
ÂÂÂ cache: parent cpu2 should not be sleeping
ÂÂ CPU2 is up
ÂÂ smpboot: Booting Node 0 Processor 3 APIC 0x3
ÂÂÂ cache: parent cpu3 should not be sleeping
ÂÂ CPU3 is up
ÂÂ ACPI: Waking up from system sleep state S3
ÂÂ ACPI: EC: event unblocked
ÂÂ usb 1-3: reset full-speed USB device number 2 using xhci_hcd
ÂÂ usb 1-4: reset full-speed USB device number 3 using xhci_hcd
ÂÂ usb 1-5: reset high-speed USB device number 4 using xhci_hcd
ÂÂ usb 1-3:1.0: rebind failed: -517
ÂÂ usb 1-3:1.1: rebind failed: -517
ÂÂ Bluetooth: hci0: Bootloader revision 0.0 build 2 week 52 2014
ÂÂ OOM killer enabled.
ÂÂ Restarting tasks ...
ÂÂ Bluetooth: hci0: Device revision is 5
ÂÂ Bluetooth: hci0: Secure boot is enabled
ÂÂ Bluetooth: hci0: OTP lock is enabled
ÂÂ Bluetooth: hci0: API lock is enabled
ÂÂ Bluetooth: hci0: Debug lock is disabled
ÂÂ Bluetooth: hci0: Minimum firmware build 1 week 10 2014
ÂÂ firmware request while host is not available
ÂÂ ------------[ cut here ]------------
ÂÂ WARNING: CPU: 2 PID: 621 at drivers/base/firmware_class.c:1250
_request_firmware+0x460/0x790
ÂÂ CPU: 2 PID: 621 Comm: kworker/u9:2 Not tainted 4.13.0-10313-ge860d2c904d1 #11
ÂÂ Hardware name: Dell Inc. XPS 13 9350/09JHRY, BIOS 1.4.17 05/10/2017
ÂÂ Workqueue: hci0 hci_power_on [bluetooth]
ÂÂ task: ffff8d3767895ac0 task.stack: ffff9d3481efc000
ÂÂ RIP: 0010:_request_firmware+0x460/0x790
ÂÂ Call Trace:
ÂÂÂ request_firmware+0x37/0x50
ÂÂÂ btusb_setup_intel_new+0x227/0x7e0 [btusb]
ÂÂÂ hci_dev_do_open+0x3da/0x570 [bluetooth]
ÂÂÂ hci_power_on+0x52/0x1f0 [bluetooth]
ÂÂÂ process_one_work+0x1db/0x3d0
ÂÂÂ worker_thread+0x47/0x3e0
ÂÂÂ kthread+0x125/0x140
ÂÂÂ ret_from_fork+0x22/0x30
ÂÂ ---[ end trace 007b222491432927 ]---
ÂÂ Bluetooth: hci0: Failed to load Intel firmware file (-112)
ÂÂ [drm] RC6 on
ÂÂ done.
ÂÂ thermal thermal_zone11: failed to read out thermal zone (-5)
ÂÂ PM: suspend exit

Ah, I'll blame Luis for this, I think it might be due to 81f95076281f
("firmware: add sanity check on shutdown/suspend")

Luis, any ideas? I'll try to revert this and try it out tomorrow when
I get a chance.


I can revert it an fire up some testing..


Yes 81f95076281f is to blame.. After reverting it all is fine again.

15 resume cycles on the one laptop , 10 on the other without to hit the trace.

Regards