LinuxLists.cc - bluetooth related firmware loader spew on resume.

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

At Wed, 26 Nov 2014 16:21:49 +0100,
Takashi Iwai wrote:
>
> At Wed, 26 Nov 2014 15:27:57 +0100,
> Oliver Neukum wrote:
> >
> > On Wed, 2014-11-26 at 15:12 +0100, Takashi Iwai wrote:
> > > At Wed, 26 Nov 2014 23:05:20 +0900,
> > > Marcel Holtmann wrote:
> > > >
> > > > Hi Oliver,
> > > >
> > > > >> In order to paper over this, we may also remember the failing firmware
> > > > >> and avoid loading it. This might be an easer way than the endless
> > > > >> fight against UMH race...
> > > > >
> > > > >
> > > > > the full fix would be to implement reset_resume() for btusb.
> > > > > It seems to me that setup() should be split in two methods,
> > > > > one to request the firmware from user space and the second
> > > > > to transfer it to the device. reset_resume() would just need
> > > > > to repeat the second operation.
> > > >
> > > > so when you do hci_register_dev, then hdev->setup is only called once. I really mean only once per lifetime of the hci_dev. So you would need to unregister the hci_dev first before hdev->setup will ever be called again. So I am not sure this is actually the problem here. The problem here is entirely within request_firmware() unless of course we run through the USB probe handlers again. Which I do not see happening here.
> > > >
> > > > And we have hdev->setup this way since normally the Bluetooth devices keep their firmware patches and not forget about them and suspend-resume cycles. If the USB device of course jumps of the bus during it then all bets are off anyway.
> > >
> > > Usually you can avoid unnecessary rebinding when you provide a proper
> > > reset_resume callback. I guess that's what Oliver suggested.
> >
> > Yes, but even in reset_resume() you would need to redo the setup
> > part, as the device lost power. The basic problem of requesting
> > the firmware wouldn't be solved.
>
> Requesting the firmware in the resume path itself is OK. There are
> many drivers doing so. But the primary problem in btusb is that it's
> triggered at the wrong timing. (And the second problem is that the
> firmware loader doesn't cache the non-existing files, so it goes
> through lengthy code paths for reconfirming that the file doesn't
> exist.)

So, below is a quick hack for avoiding the f/w loader activation
during resume. I just compile-tested, so no idea whether it really
works or not.

Takashi

---
diff --git a/drivers/base/firmware_class.c b/drivers/base/firmware_class.c
index 3d785ebb48d3..e928bde45d7d 100644
--- a/drivers/base/firmware_class.c
+++ b/drivers/base/firmware_class.c
@@ -167,6 +167,7 @@ struct fw_name_devm {

#define FW_LOADER_NO_CACHE 0
#define FW_LOADER_START_CACHE 1
+#define FW_LOADER_CACHE_ONLY 2

static int fw_cache_piggyback_on_request(const char *name);

@@ -1112,6 +1113,11 @@ _request_firmware(const struct firmware **firmware_p, const char *name,
if (ret <= 0) /* error or already assigned */
goto out;

+ if (fw_cache.state == FW_LOADER_CACHE_ONLY) {
+ ret = -ENOENT;
+ goto out;
+ }
+
ret = 0;
timeout = firmware_loading_timeout();
if (opt_flags & FW_OPT_NOWAIT) {
@@ -1633,7 +1639,8 @@ static int fw_pm_notify(struct notifier_block *notify_block,
/* stop caching firmware once syscore_suspend is reached */
static int fw_suspend(void)
{
- fw_cache.state = FW_LOADER_NO_CACHE;
+ /* use only cached firmware until fully resumed */
+ fw_cache.state = FW_LOADER_CACHE_ONLY;
return 0;
}

2014-11-27 10:09:54

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

At Thu, 27 Nov 2014 10:46:05 +0100,
Arend van Spriel wrote:
>
> On 11/27/14 10:29, Arend van Spriel wrote:
> > On 11/27/14 10:17, Takashi Iwai wrote:
> >> At Thu, 27 Nov 2014 09:59:12 +0100,
> >> Arend van Spriel wrote:
> >>>
> >>> On 11/26/14 19:13, Takashi Iwai wrote:
> >>>> At Wed, 26 Nov 2014 18:42:46 +0100,
> >>>> Arend van Spriel wrote:
> >>>>>
> >>>>> On 11/26/14 16:27, Takashi Iwai wrote:
> >>>>>> At Wed, 26 Nov 2014 17:26:15 +0200,
> >>>>>> Mihai Donțu wrote:
> >>>>>>>
> >>>>>>> On Wed, 26 Nov 2014 16:19:49 +0100
> >>>>>>> Takashi Iwai<[email protected]> wrote:
> >>>>>>>
> >>>>>>>> At Wed, 26 Nov 2014 16:56:09 +0200,
> >>>>>>>> Mihai Donțu wrote:
> >>>>>>>>>
> >>>>>>>>> On Tue, 11 Nov 2014 13:12:28 -0500 Dave Jones wrote:
> >>>>>>>>>> Since the addition of 10d4c6736ea "Bluetooth: btusb: Add
> >>>>>>>>>> Broadcom patch
> >>>>>>>>>> RAM support", I (and a number of other people[*]) have been
> >>>>>>>>>> seeing
> >>>>>>>>>> this trace on resume from suspend.
> >>>>>>>>>>
> >>>>>>>>>> WARNING: CPU: 1 PID: 8565 at
> >>>>>>>>>> drivers/base/firmware_class.c:1127
> >>>>>>>>>> _request_firmware+0x4c1/0x7c0()
> >>>>>>>>>> CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted
> >>>>>>>>>> 3.17.2-200.fc20.x86_64 #1
> >>>>>>>>>> Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 )
> >>>>>>>>>> 04/30/2013
> >>>>>>>>>> Workqueue: hci0 hci_power_on [bluetooth]
> >>>>>>>>>> 0000000000000000 00000000f52a564b ffff8800a8c63be8
> >>>>>>>>>> ffffffff817271cc
> >>>>>>>>>> 0000000000000000 ffff8800a8c63c20 ffffffff81094ced
> >>>>>>>>>> ffff8800a8c63d10
> >>>>>>>>>> ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08
> >>>>>>>>>> 00000000fffffff5
> >>>>>>>>>> Call Trace:
> >>>>>>>>>> [<ffffffff817271cc>] dump_stack+0x45/0x56
> >>>>>>>>>> [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
> >>>>>>>>>> [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
> >>>>>>>>>> [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
> >>>>>>>>>> [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
> >>>>>>>>>> [<ffffffff814968f1>] request_firmware+0x31/0x50
> >>>>>>>>>> [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
> >>>>>>>>>> [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
> >>>>>>>>>> [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
> >>>>>>>>>> ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
> >>>>>>>>>> Restarting tasks ...
> >>>>>>>>>> [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
> >>>>>>>>>> [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
> >>>>>>>>>> [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
> >>>>>>>>>> [<ffffffff810acc39>] process_one_work+0x149/0x3d0
> >>>>>>>>>> [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
> >>>>>>>>>> [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
> >>>>>>>>>> [<ffffffff810b2318>] kthread+0xd8/0xf0
> >>>>>>>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> >>>>>>>>>> [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
> >>>>>>>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> >>>>>>>>>> ---[ end trace 75a0e9c7f33ebb4c ]---
> >>>>>>>>>> bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will
> >>>>>>>>>> not be loaded
> >>>>>>>>>> Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not
> >>>>>>>>>> found
> >>>>>>>>>>
> >>>>>>>>>>
> >>>>>>>>>> At first I thought it was just over-reaction to the file being
> >>>>>>>>>> missing, but
> >>>>>>>>>> looking at the WARN_ON, it appears that we're trying to invoke
> >>>>>>>>>> the firmware
> >>>>>>>>>> loader before userspace is back up ?
> >>>>>>>>>>
> >>>>>>>>>> In this (and probably other related) kernel,
> >>>>>>>>>> CONFIG_FW_LOADER_USER_HELPER is unset,
> >>>>>>>>>> in case that matters at all.
> >>>>>>>>>>
> >>>>>>>>>> Dave
> >>>>>>>>>>
> >>>>>>>>>> [*] https://bugzilla.kernel.org/show_bug.cgi?id=81821
> >>>>>>>>>> https://bugzilla.redhat.com/show_bug.cgi?id=1133378
> >>>>>>>>>
> >>>>>>>>> I have the following during normal boot:
> >>>>>>>>>
> >>>>>>>>> [ 5.620796] Bluetooth: hci0: read Intel version:
> >>>>>>>>> 370710018002030d00
> >>>>>>>>> [ 5.620822] bluetooth hci0: Direct firmware load for
> >>>>>>>>> intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq failed with error -2
> >>>>>>>>> [ 5.620827] Bluetooth: hci0 failed to open Intel firmware file:
> >>>>>>>>> intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq(-2)
> >>>>>>>>> [ 5.620920] bluetooth hci0: Direct firmware load for
> >>>>>>>>> intel/ibt-hw-37.7.bseq failed with error -2
> >>>>>>>>> [ 5.620922] Bluetooth: hci0 failed to open default Intel fw
> >>>>>>>>> file: intel/ibt-hw-37.7.bseq
> >>>>>>>>> [ 5.629910] EXT4-fs (sda2): mounted filesystem with ordered
> >>>>>>>>> data mode. Opts: (null)
> >>>>>>>>> [ 5.629916] VFS: Mounted root (ext4 filesystem) readonly on
> >>>>>>>>> device 8:2.
> >>>>>>>>>
> >>>>>>>>> The driver is trying to load the firmware before root is
> >>>>>>>>> mounted. Do I
> >>>>>>>>> really need an initramfs?
> >>>>>>>>
> >>>>>>>> If btusb driver is loaded in initrd, you'd need the corresponding
> >>>>>>>> firmware in initrd, too.
> >>>>>>>
> >>>>>>> The driver is built into the kernel and I don't use an initrd. I
> >>>>>>> could
> >>>>>>> probably create one, but it's a bit tricky with UEFI and a tad
> >>>>>>> harder
> >>>>>>> to maintain.
> >>>>>>
> >>>>>> Then you can build the firmware file into kernel, too.
> >>>>>
> >>>>> huh? The whole idea of the firmware API was to keep (often
> >>>>> proprietary)
> >>>>> firmware out of the kernel. Has that strategy been abandoned recently?
> >>>>
> >>>> See CONFIG_EXTRA_FIRMARE. It doesn't mean to include the binary blob
> >>>> into the kernel source tree. It just allows to *build* into your
> >>>> kernel.
>
> So I looked at this Kconfig option and reading the help I came across
> this warning:
>
> """
> WARNING: If you include additional firmware files into your binary
> kernel image that are not available under the terms of the GPL,
> then it may be a violation of the GPL to distribute the resulting
> image since it combines both GPL and non-GPL work. You should
> consult a lawyer of your own before distributing such an image.
> """
>
> This is exactly what I meant, by "(often proprietary) firmware". So we
> should conclude that if a device needs proprietary firmware it can not
> be built-in the kernel if intended for distribution.

Well, that's why I've repeatedly written it's for *building* the
kernel. Building a kernel in such a way and using it is no problem.
The problem happens only when you distribute it. So, this doesn't
apply to the distro kernels, of course. Think separately between
build and distribution.

In Michai's case, he's certainly building the kernel manually (that's
why btusb is built-in, which usually isn't so on distro kernels).

Takashi

2014-11-27 09:46:05

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

On 11/27/14 10:29, Arend van Spriel wrote:
> On 11/27/14 10:17, Takashi Iwai wrote:
>> At Thu, 27 Nov 2014 09:59:12 +0100,
>> Arend van Spriel wrote:
>>>
>>> On 11/26/14 19:13, Takashi Iwai wrote:
>>>> At Wed, 26 Nov 2014 18:42:46 +0100,
>>>> Arend van Spriel wrote:
>>>>>
>>>>> On 11/26/14 16:27, Takashi Iwai wrote:
>>>>>> At Wed, 26 Nov 2014 17:26:15 +0200,
>>>>>> Mihai Donțu wrote:
>>>>>>>
>>>>>>> On Wed, 26 Nov 2014 16:19:49 +0100
>>>>>>> Takashi Iwai<[email protected]> wrote:
>>>>>>>
>>>>>>>> At Wed, 26 Nov 2014 16:56:09 +0200,
>>>>>>>> Mihai Donțu wrote:
>>>>>>>>>
>>>>>>>>> On Tue, 11 Nov 2014 13:12:28 -0500 Dave Jones wrote:
>>>>>>>>>> Since the addition of 10d4c6736ea "Bluetooth: btusb: Add
>>>>>>>>>> Broadcom patch
>>>>>>>>>> RAM support", I (and a number of other people[*]) have been
>>>>>>>>>> seeing
>>>>>>>>>> this trace on resume from suspend.
>>>>>>>>>>
>>>>>>>>>> WARNING: CPU: 1 PID: 8565 at
>>>>>>>>>> drivers/base/firmware_class.c:1127
>>>>>>>>>> _request_firmware+0x4c1/0x7c0()
>>>>>>>>>> CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted
>>>>>>>>>> 3.17.2-200.fc20.x86_64 #1
>>>>>>>>>> Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 )
>>>>>>>>>> 04/30/2013
>>>>>>>>>> Workqueue: hci0 hci_power_on [bluetooth]
>>>>>>>>>> 0000000000000000 00000000f52a564b ffff8800a8c63be8
>>>>>>>>>> ffffffff817271cc
>>>>>>>>>> 0000000000000000 ffff8800a8c63c20 ffffffff81094ced
>>>>>>>>>> ffff8800a8c63d10
>>>>>>>>>> ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08
>>>>>>>>>> 00000000fffffff5
>>>>>>>>>> Call Trace:
>>>>>>>>>> [<ffffffff817271cc>] dump_stack+0x45/0x56
>>>>>>>>>> [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
>>>>>>>>>> [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
>>>>>>>>>> [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
>>>>>>>>>> [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
>>>>>>>>>> [<ffffffff814968f1>] request_firmware+0x31/0x50
>>>>>>>>>> [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
>>>>>>>>>> [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
>>>>>>>>>> [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
>>>>>>>>>> ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
>>>>>>>>>> Restarting tasks ...
>>>>>>>>>> [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
>>>>>>>>>> [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
>>>>>>>>>> [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
>>>>>>>>>> [<ffffffff810acc39>] process_one_work+0x149/0x3d0
>>>>>>>>>> [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
>>>>>>>>>> [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
>>>>>>>>>> [<ffffffff810b2318>] kthread+0xd8/0xf0
>>>>>>>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
>>>>>>>>>> [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
>>>>>>>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
>>>>>>>>>> ---[ end trace 75a0e9c7f33ebb4c ]---
>>>>>>>>>> bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will
>>>>>>>>>> not be loaded
>>>>>>>>>> Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not
>>>>>>>>>> found
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> At first I thought it was just over-reaction to the file being
>>>>>>>>>> missing, but
>>>>>>>>>> looking at the WARN_ON, it appears that we're trying to invoke
>>>>>>>>>> the firmware
>>>>>>>>>> loader before userspace is back up ?
>>>>>>>>>>
>>>>>>>>>> In this (and probably other related) kernel,
>>>>>>>>>> CONFIG_FW_LOADER_USER_HELPER is unset,
>>>>>>>>>> in case that matters at all.
>>>>>>>>>>
>>>>>>>>>> Dave
>>>>>>>>>>
>>>>>>>>>> [*] https://bugzilla.kernel.org/show_bug.cgi?id=81821
>>>>>>>>>> https://bugzilla.redhat.com/show_bug.cgi?id=1133378
>>>>>>>>>
>>>>>>>>> I have the following during normal boot:
>>>>>>>>>
>>>>>>>>> [ 5.620796] Bluetooth: hci0: read Intel version:
>>>>>>>>> 370710018002030d00
>>>>>>>>> [ 5.620822] bluetooth hci0: Direct firmware load for
>>>>>>>>> intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq failed with error -2
>>>>>>>>> [ 5.620827] Bluetooth: hci0 failed to open Intel firmware file:
>>>>>>>>> intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq(-2)
>>>>>>>>> [ 5.620920] bluetooth hci0: Direct firmware load for
>>>>>>>>> intel/ibt-hw-37.7.bseq failed with error -2
>>>>>>>>> [ 5.620922] Bluetooth: hci0 failed to open default Intel fw
>>>>>>>>> file: intel/ibt-hw-37.7.bseq
>>>>>>>>> [ 5.629910] EXT4-fs (sda2): mounted filesystem with ordered
>>>>>>>>> data mode. Opts: (null)
>>>>>>>>> [ 5.629916] VFS: Mounted root (ext4 filesystem) readonly on
>>>>>>>>> device 8:2.
>>>>>>>>>
>>>>>>>>> The driver is trying to load the firmware before root is
>>>>>>>>> mounted. Do I
>>>>>>>>> really need an initramfs?
>>>>>>>>
>>>>>>>> If btusb driver is loaded in initrd, you'd need the corresponding
>>>>>>>> firmware in initrd, too.
>>>>>>>
>>>>>>> The driver is built into the kernel and I don't use an initrd. I
>>>>>>> could
>>>>>>> probably create one, but it's a bit tricky with UEFI and a tad
>>>>>>> harder
>>>>>>> to maintain.
>>>>>>
>>>>>> Then you can build the firmware file into kernel, too.
>>>>>
>>>>> huh? The whole idea of the firmware API was to keep (often
>>>>> proprietary)
>>>>> firmware out of the kernel. Has that strategy been abandoned recently?
>>>>
>>>> See CONFIG_EXTRA_FIRMARE. It doesn't mean to include the binary blob
>>>> into the kernel source tree. It just allows to *build* into your
>>>> kernel.

So I looked at this Kconfig option and reading the help I came across
this warning:

"""
WARNING: If you include additional firmware files into your binary
kernel image that are not available under the terms of the GPL,
then it may be a violation of the GPL to distribute the resulting
image since it combines both GPL and non-GPL work. You should
consult a lawyer of your own before distributing such an image.
"""

This is exactly what I meant, by "(often proprietary) firmware". So we
should conclude that if a device needs proprietary firmware it can not
be built-in the kernel if intended for distribution.

Regards,
Arend

>>> I see. Thanks for the info. I still do not understand the resume
>>> scenario. I though firmware api did some sort of caching of the firmware
>>> images.
>>
>> My theory is that this is triggered when the firmware file doesn't
>> exist. Then it's neither remembered nor cached, so it's retried in
>> the resume path. But the information is missing, so I cannot say
>> surely about it.
>
> Agree. So the same warning should have occurred upon system boot. Maybe
> Mihai can confirm that.
>
> Regards,
> Arend
>
>>
>> Takashi
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/

2014-11-27 09:29:14

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

On 11/27/14 10:17, Takashi Iwai wrote:
> At Thu, 27 Nov 2014 09:59:12 +0100,
> Arend van Spriel wrote:
>>
>> On 11/26/14 19:13, Takashi Iwai wrote:
>>> At Wed, 26 Nov 2014 18:42:46 +0100,
>>> Arend van Spriel wrote:
>>>>
>>>> On 11/26/14 16:27, Takashi Iwai wrote:
>>>>> At Wed, 26 Nov 2014 17:26:15 +0200,
>>>>> Mihai Donțu wrote:
>>>>>>
>>>>>> On Wed, 26 Nov 2014 16:19:49 +0100
>>>>>> Takashi Iwai<[email protected]> wrote:
>>>>>>
>>>>>>> At Wed, 26 Nov 2014 16:56:09 +0200,
>>>>>>> Mihai Donțu wrote:
>>>>>>>>
>>>>>>>> On Tue, 11 Nov 2014 13:12:28 -0500 Dave Jones wrote:
>>>>>>>>> Since the addition of 10d4c6736ea "Bluetooth: btusb: Add Broadcom patch
>>>>>>>>> RAM support", I (and a number of other people[*]) have been seeing
>>>>>>>>> this trace on resume from suspend.
>>>>>>>>>
>>>>>>>>> WARNING: CPU: 1 PID: 8565 at drivers/base/firmware_class.c:1127 _request_firmware+0x4c1/0x7c0()
>>>>>>>>> CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted 3.17.2-200.fc20.x86_64 #1
>>>>>>>>> Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 ) 04/30/2013
>>>>>>>>> Workqueue: hci0 hci_power_on [bluetooth]
>>>>>>>>> 0000000000000000 00000000f52a564b ffff8800a8c63be8 ffffffff817271cc
>>>>>>>>> 0000000000000000 ffff8800a8c63c20 ffffffff81094ced ffff8800a8c63d10
>>>>>>>>> ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08 00000000fffffff5
>>>>>>>>> Call Trace:
>>>>>>>>> [<ffffffff817271cc>] dump_stack+0x45/0x56
>>>>>>>>> [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
>>>>>>>>> [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
>>>>>>>>> [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
>>>>>>>>> [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
>>>>>>>>> [<ffffffff814968f1>] request_firmware+0x31/0x50
>>>>>>>>> [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
>>>>>>>>> [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
>>>>>>>>> [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
>>>>>>>>> ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
>>>>>>>>> Restarting tasks ...
>>>>>>>>> [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
>>>>>>>>> [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
>>>>>>>>> [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
>>>>>>>>> [<ffffffff810acc39>] process_one_work+0x149/0x3d0
>>>>>>>>> [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
>>>>>>>>> [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
>>>>>>>>> [<ffffffff810b2318>] kthread+0xd8/0xf0
>>>>>>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
>>>>>>>>> [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
>>>>>>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
>>>>>>>>> ---[ end trace 75a0e9c7f33ebb4c ]---
>>>>>>>>> bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
>>>>>>>>> Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> At first I thought it was just over-reaction to the file being missing, but
>>>>>>>>> looking at the WARN_ON, it appears that we're trying to invoke the firmware
>>>>>>>>> loader before userspace is back up ?
>>>>>>>>>
>>>>>>>>> In this (and probably other related) kernel, CONFIG_FW_LOADER_USER_HELPER is unset,
>>>>>>>>> in case that matters at all.
>>>>>>>>>
>>>>>>>>> Dave
>>>>>>>>>
>>>>>>>>> [*] https://bugzilla.kernel.org/show_bug.cgi?id=81821
>>>>>>>>> https://bugzilla.redhat.com/show_bug.cgi?id=1133378
>>>>>>>>
>>>>>>>> I have the following during normal boot:
>>>>>>>>
>>>>>>>> [ 5.620796] Bluetooth: hci0: read Intel version: 370710018002030d00
>>>>>>>> [ 5.620822] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq failed with error -2
>>>>>>>> [ 5.620827] Bluetooth: hci0 failed to open Intel firmware file: intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq(-2)
>>>>>>>> [ 5.620920] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.bseq failed with error -2
>>>>>>>> [ 5.620922] Bluetooth: hci0 failed to open default Intel fw file: intel/ibt-hw-37.7.bseq
>>>>>>>> [ 5.629910] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
>>>>>>>> [ 5.629916] VFS: Mounted root (ext4 filesystem) readonly on device 8:2.
>>>>>>>>
>>>>>>>> The driver is trying to load the firmware before root is mounted. Do I
>>>>>>>> really need an initramfs?
>>>>>>>
>>>>>>> If btusb driver is loaded in initrd, you'd need the corresponding
>>>>>>> firmware in initrd, too.
>>>>>>
>>>>>> The driver is built into the kernel and I don't use an initrd. I could
>>>>>> probably create one, but it's a bit tricky with UEFI and a tad harder
>>>>>> to maintain.
>>>>>
>>>>> Then you can build the firmware file into kernel, too.
>>>>
>>>> huh? The whole idea of the firmware API was to keep (often proprietary)
>>>> firmware out of the kernel. Has that strategy been abandoned recently?
>>>
>>> See CONFIG_EXTRA_FIRMARE. It doesn't mean to include the binary blob
>>> into the kernel source tree. It just allows to *build* into your
>>> kernel.
>>
>> I see. Thanks for the info. I still do not understand the resume
>> scenario. I though firmware api did some sort of caching of the firmware
>> images.
>
> My theory is that this is triggered when the firmware file doesn't
> exist. Then it's neither remembered nor cached, so it's retried in
> the resume path. But the information is missing, so I cannot say
> surely about it.

Agree. So the same warning should have occurred upon system boot. Maybe
Mihai can confirm that.

Regards,
Arend

>
> Takashi

2014-11-27 09:17:17

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

At Thu, 27 Nov 2014 09:59:12 +0100,
Arend van Spriel wrote:
>
> On 11/26/14 19:13, Takashi Iwai wrote:
> > At Wed, 26 Nov 2014 18:42:46 +0100,
> > Arend van Spriel wrote:
> >>
> >> On 11/26/14 16:27, Takashi Iwai wrote:
> >>> At Wed, 26 Nov 2014 17:26:15 +0200,
> >>> Mihai Donțu wrote:
> >>>>
> >>>> On Wed, 26 Nov 2014 16:19:49 +0100
> >>>> Takashi Iwai<[email protected]> wrote:
> >>>>
> >>>>> At Wed, 26 Nov 2014 16:56:09 +0200,
> >>>>> Mihai Donțu wrote:
> >>>>>>
> >>>>>> On Tue, 11 Nov 2014 13:12:28 -0500 Dave Jones wrote:
> >>>>>>> Since the addition of 10d4c6736ea "Bluetooth: btusb: Add Broadcom patch
> >>>>>>> RAM support", I (and a number of other people[*]) have been seeing
> >>>>>>> this trace on resume from suspend.
> >>>>>>>
> >>>>>>> WARNING: CPU: 1 PID: 8565 at drivers/base/firmware_class.c:1127 _request_firmware+0x4c1/0x7c0()
> >>>>>>> CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted 3.17.2-200.fc20.x86_64 #1
> >>>>>>> Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 ) 04/30/2013
> >>>>>>> Workqueue: hci0 hci_power_on [bluetooth]
> >>>>>>> 0000000000000000 00000000f52a564b ffff8800a8c63be8 ffffffff817271cc
> >>>>>>> 0000000000000000 ffff8800a8c63c20 ffffffff81094ced ffff8800a8c63d10
> >>>>>>> ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08 00000000fffffff5
> >>>>>>> Call Trace:
> >>>>>>> [<ffffffff817271cc>] dump_stack+0x45/0x56
> >>>>>>> [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
> >>>>>>> [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
> >>>>>>> [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
> >>>>>>> [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
> >>>>>>> [<ffffffff814968f1>] request_firmware+0x31/0x50
> >>>>>>> [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
> >>>>>>> [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
> >>>>>>> [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
> >>>>>>> ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
> >>>>>>> Restarting tasks ...
> >>>>>>> [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
> >>>>>>> [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
> >>>>>>> [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
> >>>>>>> [<ffffffff810acc39>] process_one_work+0x149/0x3d0
> >>>>>>> [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
> >>>>>>> [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
> >>>>>>> [<ffffffff810b2318>] kthread+0xd8/0xf0
> >>>>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> >>>>>>> [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
> >>>>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> >>>>>>> ---[ end trace 75a0e9c7f33ebb4c ]---
> >>>>>>> bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
> >>>>>>> Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
> >>>>>>>
> >>>>>>>
> >>>>>>> At first I thought it was just over-reaction to the file being missing, but
> >>>>>>> looking at the WARN_ON, it appears that we're trying to invoke the firmware
> >>>>>>> loader before userspace is back up ?
> >>>>>>>
> >>>>>>> In this (and probably other related) kernel, CONFIG_FW_LOADER_USER_HELPER is unset,
> >>>>>>> in case that matters at all.
> >>>>>>>
> >>>>>>> Dave
> >>>>>>>
> >>>>>>> [*] https://bugzilla.kernel.org/show_bug.cgi?id=81821
> >>>>>>> https://bugzilla.redhat.com/show_bug.cgi?id=1133378
> >>>>>>
> >>>>>> I have the following during normal boot:
> >>>>>>
> >>>>>> [ 5.620796] Bluetooth: hci0: read Intel version: 370710018002030d00
> >>>>>> [ 5.620822] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq failed with error -2
> >>>>>> [ 5.620827] Bluetooth: hci0 failed to open Intel firmware file: intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq(-2)
> >>>>>> [ 5.620920] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.bseq failed with error -2
> >>>>>> [ 5.620922] Bluetooth: hci0 failed to open default Intel fw file: intel/ibt-hw-37.7.bseq
> >>>>>> [ 5.629910] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
> >>>>>> [ 5.629916] VFS: Mounted root (ext4 filesystem) readonly on device 8:2.
> >>>>>>
> >>>>>> The driver is trying to load the firmware before root is mounted. Do I
> >>>>>> really need an initramfs?
> >>>>>
> >>>>> If btusb driver is loaded in initrd, you'd need the corresponding
> >>>>> firmware in initrd, too.
> >>>>
> >>>> The driver is built into the kernel and I don't use an initrd. I could
> >>>> probably create one, but it's a bit tricky with UEFI and a tad harder
> >>>> to maintain.
> >>>
> >>> Then you can build the firmware file into kernel, too.
> >>
> >> huh? The whole idea of the firmware API was to keep (often proprietary)
> >> firmware out of the kernel. Has that strategy been abandoned recently?
> >
> > See CONFIG_EXTRA_FIRMARE. It doesn't mean to include the binary blob
> > into the kernel source tree. It just allows to *build* into your
> > kernel.
>
> I see. Thanks for the info. I still do not understand the resume
> scenario. I though firmware api did some sort of caching of the firmware
> images.

My theory is that this is triggered when the firmware file doesn't
exist. Then it's neither remembered nor cached, so it's retried in
the resume path. But the information is missing, so I cannot say
surely about it.

Takashi

2014-11-27 08:59:12

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

On 11/26/14 19:13, Takashi Iwai wrote:
> At Wed, 26 Nov 2014 18:42:46 +0100,
> Arend van Spriel wrote:
>>
>> On 11/26/14 16:27, Takashi Iwai wrote:
>>> At Wed, 26 Nov 2014 17:26:15 +0200,
>>> Mihai Donțu wrote:
>>>>
>>>> On Wed, 26 Nov 2014 16:19:49 +0100
>>>> Takashi Iwai<[email protected]> wrote:
>>>>
>>>>> At Wed, 26 Nov 2014 16:56:09 +0200,
>>>>> Mihai Donțu wrote:
>>>>>>
>>>>>> On Tue, 11 Nov 2014 13:12:28 -0500 Dave Jones wrote:
>>>>>>> Since the addition of 10d4c6736ea "Bluetooth: btusb: Add Broadcom patch
>>>>>>> RAM support", I (and a number of other people[*]) have been seeing
>>>>>>> this trace on resume from suspend.
>>>>>>>
>>>>>>> WARNING: CPU: 1 PID: 8565 at drivers/base/firmware_class.c:1127 _request_firmware+0x4c1/0x7c0()
>>>>>>> CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted 3.17.2-200.fc20.x86_64 #1
>>>>>>> Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 ) 04/30/2013
>>>>>>> Workqueue: hci0 hci_power_on [bluetooth]
>>>>>>> 0000000000000000 00000000f52a564b ffff8800a8c63be8 ffffffff817271cc
>>>>>>> 0000000000000000 ffff8800a8c63c20 ffffffff81094ced ffff8800a8c63d10
>>>>>>> ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08 00000000fffffff5
>>>>>>> Call Trace:
>>>>>>> [<ffffffff817271cc>] dump_stack+0x45/0x56
>>>>>>> [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
>>>>>>> [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
>>>>>>> [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
>>>>>>> [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
>>>>>>> [<ffffffff814968f1>] request_firmware+0x31/0x50
>>>>>>> [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
>>>>>>> [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
>>>>>>> [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
>>>>>>> ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
>>>>>>> Restarting tasks ...
>>>>>>> [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
>>>>>>> [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
>>>>>>> [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
>>>>>>> [<ffffffff810acc39>] process_one_work+0x149/0x3d0
>>>>>>> [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
>>>>>>> [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
>>>>>>> [<ffffffff810b2318>] kthread+0xd8/0xf0
>>>>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
>>>>>>> [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
>>>>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
>>>>>>> ---[ end trace 75a0e9c7f33ebb4c ]---
>>>>>>> bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
>>>>>>> Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
>>>>>>>
>>>>>>>
>>>>>>> At first I thought it was just over-reaction to the file being missing, but
>>>>>>> looking at the WARN_ON, it appears that we're trying to invoke the firmware
>>>>>>> loader before userspace is back up ?
>>>>>>>
>>>>>>> In this (and probably other related) kernel, CONFIG_FW_LOADER_USER_HELPER is unset,
>>>>>>> in case that matters at all.
>>>>>>>
>>>>>>> Dave
>>>>>>>
>>>>>>> [*] https://bugzilla.kernel.org/show_bug.cgi?id=81821
>>>>>>> https://bugzilla.redhat.com/show_bug.cgi?id=1133378
>>>>>>
>>>>>> I have the following during normal boot:
>>>>>>
>>>>>> [ 5.620796] Bluetooth: hci0: read Intel version: 370710018002030d00
>>>>>> [ 5.620822] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq failed with error -2
>>>>>> [ 5.620827] Bluetooth: hci0 failed to open Intel firmware file: intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq(-2)
>>>>>> [ 5.620920] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.bseq failed with error -2
>>>>>> [ 5.620922] Bluetooth: hci0 failed to open default Intel fw file: intel/ibt-hw-37.7.bseq
>>>>>> [ 5.629910] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
>>>>>> [ 5.629916] VFS: Mounted root (ext4 filesystem) readonly on device 8:2.
>>>>>>
>>>>>> The driver is trying to load the firmware before root is mounted. Do I
>>>>>> really need an initramfs?
>>>>>
>>>>> If btusb driver is loaded in initrd, you'd need the corresponding
>>>>> firmware in initrd, too.
>>>>
>>>> The driver is built into the kernel and I don't use an initrd. I could
>>>> probably create one, but it's a bit tricky with UEFI and a tad harder
>>>> to maintain.
>>>
>>> Then you can build the firmware file into kernel, too.
>>
>> huh? The whole idea of the firmware API was to keep (often proprietary)
>> firmware out of the kernel. Has that strategy been abandoned recently?
>
> See CONFIG_EXTRA_FIRMARE. It doesn't mean to include the binary blob
> into the kernel source tree. It just allows to *build* into your
> kernel.

I see. Thanks for the info. I still do not understand the resume
scenario. I though firmware api did some sort of caching of the firmware
images.

Regards,
Arend

2014-11-26 18:13:50

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

At Wed, 26 Nov 2014 18:42:46 +0100,
Arend van Spriel wrote:
>
> On 11/26/14 16:27, Takashi Iwai wrote:
> > At Wed, 26 Nov 2014 17:26:15 +0200,
> > Mihai Donțu wrote:
> >>
> >> On Wed, 26 Nov 2014 16:19:49 +0100
> >> Takashi Iwai<[email protected]> wrote:
> >>
> >>> At Wed, 26 Nov 2014 16:56:09 +0200,
> >>> Mihai Donțu wrote:
> >>>>
> >>>> On Tue, 11 Nov 2014 13:12:28 -0500 Dave Jones wrote:
> >>>>> Since the addition of 10d4c6736ea "Bluetooth: btusb: Add Broadcom patch
> >>>>> RAM support", I (and a number of other people[*]) have been seeing
> >>>>> this trace on resume from suspend.
> >>>>>
> >>>>> WARNING: CPU: 1 PID: 8565 at drivers/base/firmware_class.c:1127 _request_firmware+0x4c1/0x7c0()
> >>>>> CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted 3.17.2-200.fc20.x86_64 #1
> >>>>> Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 ) 04/30/2013
> >>>>> Workqueue: hci0 hci_power_on [bluetooth]
> >>>>> 0000000000000000 00000000f52a564b ffff8800a8c63be8 ffffffff817271cc
> >>>>> 0000000000000000 ffff8800a8c63c20 ffffffff81094ced ffff8800a8c63d10
> >>>>> ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08 00000000fffffff5
> >>>>> Call Trace:
> >>>>> [<ffffffff817271cc>] dump_stack+0x45/0x56
> >>>>> [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
> >>>>> [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
> >>>>> [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
> >>>>> [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
> >>>>> [<ffffffff814968f1>] request_firmware+0x31/0x50
> >>>>> [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
> >>>>> [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
> >>>>> [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
> >>>>> ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
> >>>>> Restarting tasks ...
> >>>>> [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
> >>>>> [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
> >>>>> [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
> >>>>> [<ffffffff810acc39>] process_one_work+0x149/0x3d0
> >>>>> [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
> >>>>> [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
> >>>>> [<ffffffff810b2318>] kthread+0xd8/0xf0
> >>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> >>>>> [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
> >>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> >>>>> ---[ end trace 75a0e9c7f33ebb4c ]---
> >>>>> bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
> >>>>> Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
> >>>>>
> >>>>>
> >>>>> At first I thought it was just over-reaction to the file being missing, but
> >>>>> looking at the WARN_ON, it appears that we're trying to invoke the firmware
> >>>>> loader before userspace is back up ?
> >>>>>
> >>>>> In this (and probably other related) kernel, CONFIG_FW_LOADER_USER_HELPER is unset,
> >>>>> in case that matters at all.
> >>>>>
> >>>>> Dave
> >>>>>
> >>>>> [*] https://bugzilla.kernel.org/show_bug.cgi?id=81821
> >>>>> https://bugzilla.redhat.com/show_bug.cgi?id=1133378
> >>>>
> >>>> I have the following during normal boot:
> >>>>
> >>>> [ 5.620796] Bluetooth: hci0: read Intel version: 370710018002030d00
> >>>> [ 5.620822] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq failed with error -2
> >>>> [ 5.620827] Bluetooth: hci0 failed to open Intel firmware file: intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq(-2)
> >>>> [ 5.620920] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.bseq failed with error -2
> >>>> [ 5.620922] Bluetooth: hci0 failed to open default Intel fw file: intel/ibt-hw-37.7.bseq
> >>>> [ 5.629910] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
> >>>> [ 5.629916] VFS: Mounted root (ext4 filesystem) readonly on device 8:2.
> >>>>
> >>>> The driver is trying to load the firmware before root is mounted. Do I
> >>>> really need an initramfs?
> >>>
> >>> If btusb driver is loaded in initrd, you'd need the corresponding
> >>> firmware in initrd, too.
> >>
> >> The driver is built into the kernel and I don't use an initrd. I could
> >> probably create one, but it's a bit tricky with UEFI and a tad harder
> >> to maintain.
> >
> > Then you can build the firmware file into kernel, too.
>
> huh? The whole idea of the firmware API was to keep (often proprietary)
> firmware out of the kernel. Has that strategy been abandoned recently?

See CONFIG_EXTRA_FIRMARE. It doesn't mean to include the binary blob
into the kernel source tree. It just allows to *build* into your
kernel.

Takashi

2014-11-26 17:42:46

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

On 11/26/14 16:27, Takashi Iwai wrote:
> At Wed, 26 Nov 2014 17:26:15 +0200,
> Mihai Donțu wrote:
>>
>> On Wed, 26 Nov 2014 16:19:49 +0100
>> Takashi Iwai<[email protected]> wrote:
>>
>>> At Wed, 26 Nov 2014 16:56:09 +0200,
>>> Mihai Donțu wrote:
>>>>
>>>> On Tue, 11 Nov 2014 13:12:28 -0500 Dave Jones wrote:
>>>>> Since the addition of 10d4c6736ea "Bluetooth: btusb: Add Broadcom patch
>>>>> RAM support", I (and a number of other people[*]) have been seeing
>>>>> this trace on resume from suspend.
>>>>>
>>>>> WARNING: CPU: 1 PID: 8565 at drivers/base/firmware_class.c:1127 _request_firmware+0x4c1/0x7c0()
>>>>> CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted 3.17.2-200.fc20.x86_64 #1
>>>>> Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 ) 04/30/2013
>>>>> Workqueue: hci0 hci_power_on [bluetooth]
>>>>> 0000000000000000 00000000f52a564b ffff8800a8c63be8 ffffffff817271cc
>>>>> 0000000000000000 ffff8800a8c63c20 ffffffff81094ced ffff8800a8c63d10
>>>>> ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08 00000000fffffff5
>>>>> Call Trace:
>>>>> [<ffffffff817271cc>] dump_stack+0x45/0x56
>>>>> [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
>>>>> [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
>>>>> [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
>>>>> [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
>>>>> [<ffffffff814968f1>] request_firmware+0x31/0x50
>>>>> [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
>>>>> [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
>>>>> [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
>>>>> ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
>>>>> Restarting tasks ...
>>>>> [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
>>>>> [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
>>>>> [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
>>>>> [<ffffffff810acc39>] process_one_work+0x149/0x3d0
>>>>> [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
>>>>> [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
>>>>> [<ffffffff810b2318>] kthread+0xd8/0xf0
>>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
>>>>> [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
>>>>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
>>>>> ---[ end trace 75a0e9c7f33ebb4c ]---
>>>>> bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
>>>>> Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
>>>>>
>>>>>
>>>>> At first I thought it was just over-reaction to the file being missing, but
>>>>> looking at the WARN_ON, it appears that we're trying to invoke the firmware
>>>>> loader before userspace is back up ?
>>>>>
>>>>> In this (and probably other related) kernel, CONFIG_FW_LOADER_USER_HELPER is unset,
>>>>> in case that matters at all.
>>>>>
>>>>> Dave
>>>>>
>>>>> [*] https://bugzilla.kernel.org/show_bug.cgi?id=81821
>>>>> https://bugzilla.redhat.com/show_bug.cgi?id=1133378
>>>>
>>>> I have the following during normal boot:
>>>>
>>>> [ 5.620796] Bluetooth: hci0: read Intel version: 370710018002030d00
>>>> [ 5.620822] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq failed with error -2
>>>> [ 5.620827] Bluetooth: hci0 failed to open Intel firmware file: intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq(-2)
>>>> [ 5.620920] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.bseq failed with error -2
>>>> [ 5.620922] Bluetooth: hci0 failed to open default Intel fw file: intel/ibt-hw-37.7.bseq
>>>> [ 5.629910] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
>>>> [ 5.629916] VFS: Mounted root (ext4 filesystem) readonly on device 8:2.
>>>>
>>>> The driver is trying to load the firmware before root is mounted. Do I
>>>> really need an initramfs?
>>>
>>> If btusb driver is loaded in initrd, you'd need the corresponding
>>> firmware in initrd, too.
>>
>> The driver is built into the kernel and I don't use an initrd. I could
>> probably create one, but it's a bit tricky with UEFI and a tad harder
>> to maintain.
>
> Then you can build the firmware file into kernel, too.

huh? The whole idea of the firmware API was to keep (often proprietary)
firmware out of the kernel. Has that strategy been abandoned recently?

Regards,
Arend

> Takashi
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/

2014-11-26 15:27:31

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

At Wed, 26 Nov 2014 17:26:15 +0200,
Mihai Donțu wrote:
>
> On Wed, 26 Nov 2014 16:19:49 +0100
> Takashi Iwai <[email protected]> wrote:
>
> > At Wed, 26 Nov 2014 16:56:09 +0200,
> > Mihai Donțu wrote:
> > >
> > > On Tue, 11 Nov 2014 13:12:28 -0500 Dave Jones wrote:
> > > > Since the addition of 10d4c6736ea "Bluetooth: btusb: Add Broadcom patch
> > > > RAM support", I (and a number of other people[*]) have been seeing
> > > > this trace on resume from suspend.
> > > >
> > > > WARNING: CPU: 1 PID: 8565 at drivers/base/firmware_class.c:1127 _request_firmware+0x4c1/0x7c0()
> > > > CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted 3.17.2-200.fc20.x86_64 #1
> > > > Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 ) 04/30/2013
> > > > Workqueue: hci0 hci_power_on [bluetooth]
> > > > 0000000000000000 00000000f52a564b ffff8800a8c63be8 ffffffff817271cc
> > > > 0000000000000000 ffff8800a8c63c20 ffffffff81094ced ffff8800a8c63d10
> > > > ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08 00000000fffffff5
> > > > Call Trace:
> > > > [<ffffffff817271cc>] dump_stack+0x45/0x56
> > > > [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
> > > > [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
> > > > [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
> > > > [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
> > > > [<ffffffff814968f1>] request_firmware+0x31/0x50
> > > > [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
> > > > [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
> > > > [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
> > > > ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
> > > > Restarting tasks ...
> > > > [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
> > > > [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
> > > > [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
> > > > [<ffffffff810acc39>] process_one_work+0x149/0x3d0
> > > > [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
> > > > [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
> > > > [<ffffffff810b2318>] kthread+0xd8/0xf0
> > > > [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> > > > [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
> > > > [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> > > > ---[ end trace 75a0e9c7f33ebb4c ]---
> > > > bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
> > > > Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
> > > >
> > > >
> > > > At first I thought it was just over-reaction to the file being missing, but
> > > > looking at the WARN_ON, it appears that we're trying to invoke the firmware
> > > > loader before userspace is back up ?
> > > >
> > > > In this (and probably other related) kernel, CONFIG_FW_LOADER_USER_HELPER is unset,
> > > > in case that matters at all.
> > > >
> > > > Dave
> > > >
> > > > [*] https://bugzilla.kernel.org/show_bug.cgi?id=81821
> > > > https://bugzilla.redhat.com/show_bug.cgi?id=1133378
> > >
> > > I have the following during normal boot:
> > >
> > > [ 5.620796] Bluetooth: hci0: read Intel version: 370710018002030d00
> > > [ 5.620822] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq failed with error -2
> > > [ 5.620827] Bluetooth: hci0 failed to open Intel firmware file: intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq(-2)
> > > [ 5.620920] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.bseq failed with error -2
> > > [ 5.620922] Bluetooth: hci0 failed to open default Intel fw file: intel/ibt-hw-37.7.bseq
> > > [ 5.629910] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
> > > [ 5.629916] VFS: Mounted root (ext4 filesystem) readonly on device 8:2.
> > >
> > > The driver is trying to load the firmware before root is mounted. Do I
> > > really need an initramfs?
> >
> > If btusb driver is loaded in initrd, you'd need the corresponding
> > firmware in initrd, too.
>
> The driver is built into the kernel and I don't use an initrd. I could
> probably create one, but it's a bit tricky with UEFI and a tad harder
> to maintain.

Then you can build the firmware file into kernel, too.

Takashi

2014-11-26 15:26:15

by Mihai Donțu

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

On Wed, 26 Nov 2014 16:19:49 +0100
Takashi Iwai <[email protected]> wrote:

> At Wed, 26 Nov 2014 16:56:09 +0200,
> Mihai Don=C8=9Bu wrote:
> >=20
> > On Tue, 11 Nov 2014 13:12:28 -0500 Dave Jones wrote:
> > > Since the addition of 10d4c6736ea "Bluetooth: btusb: Add Broadcom pat=
ch
> > > RAM support", I (and a number of other people[*]) have been seeing
> > > this trace on resume from suspend.
> > >=20
> > > WARNING: CPU: 1 PID: 8565 at drivers/base/firmware_class.c:1127 _requ=
est_firmware+0x4c1/0x7c0()
> > > CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted 3.17.2-200.fc20.x86_=
64 #1
> > > Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 ) 04/30/20=
13
> > > Workqueue: hci0 hci_power_on [bluetooth]
> > > 0000000000000000 00000000f52a564b ffff8800a8c63be8 ffffffff817271cc
> > > 0000000000000000 ffff8800a8c63c20 ffffffff81094ced ffff8800a8c63d10
> > > ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08 00000000fffffff5
> > > Call Trace:
> > > [<ffffffff817271cc>] dump_stack+0x45/0x56
> > > [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
> > > [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
> > > [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
> > > [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
> > > [<ffffffff814968f1>] request_firmware+0x31/0x50
> > > [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
> > > [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
> > > [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
> > > ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
> > > Restarting tasks ...=20
> > > [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
> > > [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
> > > [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
> > > [<ffffffff810acc39>] process_one_work+0x149/0x3d0
> > > [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
> > > [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
> > > [<ffffffff810b2318>] kthread+0xd8/0xf0
> > > [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> > > [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
> > > [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> > > ---[ end trace 75a0e9c7f33ebb4c ]---
> > > bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be l=
oaded
> > > Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
> > >=20
> > >=20
> > > At first I thought it was just over-reaction to the file being missin=
g, but
> > > looking at the WARN_ON, it appears that we're trying to invoke the fi=
rmware
> > > loader before userspace is back up ?
> > >=20
> > > In this (and probably other related) kernel, CONFIG_FW_LOADER_USER_HE=
LPER is unset,
> > > in case that matters at all.
> > >=20
> > > Dave
> > >=20
> > > [*] https://bugzilla.kernel.org/show_bug.cgi?id=3D81821
> > > https://bugzilla.redhat.com/show_bug.cgi?id=3D1133378
> >=20
> > I have the following during normal boot:
> >=20
> > [ 5.620796] Bluetooth: hci0: read Intel version: 370710018002030d00
> > [ 5.620822] bluetooth hci0: Direct firmware load for intel/ibt-hw-37=
.7.10-fw-1.80.2.3.d.bseq failed with error -2
> > [ 5.620827] Bluetooth: hci0 failed to open Intel firmware file: inte=
l/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq(-2)
> > [ 5.620920] bluetooth hci0: Direct firmware load for intel/ibt-hw-37=
.7.bseq failed with error -2
> > [ 5.620922] Bluetooth: hci0 failed to open default Intel fw file: in=
tel/ibt-hw-37.7.bseq
> > [ 5.629910] EXT4-fs (sda2): mounted filesystem with ordered data mod=
e. Opts: (null)
> > [ 5.629916] VFS: Mounted root (ext4 filesystem) readonly on device 8=
:2.
> >=20
> > The driver is trying to load the firmware before root is mounted. Do I
> > really need an initramfs?
>=20
> If btusb driver is loaded in initrd, you'd need the corresponding
> firmware in initrd, too.

The driver is built into the kernel and I don't use an initrd. I could
probably create one, but it's a bit tricky with UEFI and a tad harder
to maintain.

--=20
Mihai Don=C8=9Bu

2014-11-26 15:21:49

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

At Wed, 26 Nov 2014 15:27:57 +0100,
Oliver Neukum wrote:
>
> On Wed, 2014-11-26 at 15:12 +0100, Takashi Iwai wrote:
> > At Wed, 26 Nov 2014 23:05:20 +0900,
> > Marcel Holtmann wrote:
> > >
> > > Hi Oliver,
> > >
> > > >> In order to paper over this, we may also remember the failing firmware
> > > >> and avoid loading it. This might be an easer way than the endless
> > > >> fight against UMH race...
> > > >
> > > >
> > > > the full fix would be to implement reset_resume() for btusb.
> > > > It seems to me that setup() should be split in two methods,
> > > > one to request the firmware from user space and the second
> > > > to transfer it to the device. reset_resume() would just need
> > > > to repeat the second operation.
> > >
> > > so when you do hci_register_dev, then hdev->setup is only called once. I really mean only once per lifetime of the hci_dev. So you would need to unregister the hci_dev first before hdev->setup will ever be called again. So I am not sure this is actually the problem here. The problem here is entirely within request_firmware() unless of course we run through the USB probe handlers again. Which I do not see happening here.
> > >
> > > And we have hdev->setup this way since normally the Bluetooth devices keep their firmware patches and not forget about them and suspend-resume cycles. If the USB device of course jumps of the bus during it then all bets are off anyway.
> >
> > Usually you can avoid unnecessary rebinding when you provide a proper
> > reset_resume callback. I guess that's what Oliver suggested.
>
> Yes, but even in reset_resume() you would need to redo the setup
> part, as the device lost power. The basic problem of requesting
> the firmware wouldn't be solved.

Requesting the firmware in the resume path itself is OK. There are
many drivers doing so. But the primary problem in btusb is that it's
triggered at the wrong timing. (And the second problem is that the
firmware loader doesn't cache the non-existing files, so it goes
through lengthy code paths for reconfirming that the file doesn't
exist.)

Takashi

2014-11-26 15:19:49

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

At Wed, 26 Nov 2014 16:56:09 +0200,
Mihai Donțu wrote:
>
> On Tue, 11 Nov 2014 13:12:28 -0500 Dave Jones wrote:
> > Since the addition of 10d4c6736ea "Bluetooth: btusb: Add Broadcom patch
> > RAM support", I (and a number of other people[*]) have been seeing
> > this trace on resume from suspend.
> >
> > WARNING: CPU: 1 PID: 8565 at drivers/base/firmware_class.c:1127 _request_firmware+0x4c1/0x7c0()
> > CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted 3.17.2-200.fc20.x86_64 #1
> > Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 ) 04/30/2013
> > Workqueue: hci0 hci_power_on [bluetooth]
> > 0000000000000000 00000000f52a564b ffff8800a8c63be8 ffffffff817271cc
> > 0000000000000000 ffff8800a8c63c20 ffffffff81094ced ffff8800a8c63d10
> > ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08 00000000fffffff5
> > Call Trace:
> > [<ffffffff817271cc>] dump_stack+0x45/0x56
> > [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
> > [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
> > [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
> > [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
> > [<ffffffff814968f1>] request_firmware+0x31/0x50
> > [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
> > [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
> > [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
> > ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
> > Restarting tasks ...
> > [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
> > [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
> > [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
> > [<ffffffff810acc39>] process_one_work+0x149/0x3d0
> > [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
> > [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
> > [<ffffffff810b2318>] kthread+0xd8/0xf0
> > [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> > [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
> > [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> > ---[ end trace 75a0e9c7f33ebb4c ]---
> > bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
> > Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
> >
> >
> > At first I thought it was just over-reaction to the file being missing, but
> > looking at the WARN_ON, it appears that we're trying to invoke the firmware
> > loader before userspace is back up ?
> >
> > In this (and probably other related) kernel, CONFIG_FW_LOADER_USER_HELPER is unset,
> > in case that matters at all.
> >
> > Dave
> >
> > [*] https://bugzilla.kernel.org/show_bug.cgi?id=81821
> > https://bugzilla.redhat.com/show_bug.cgi?id=1133378
>
> I have the following during normal boot:
>
> [ 5.620796] Bluetooth: hci0: read Intel version: 370710018002030d00
> [ 5.620822] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq failed with error -2
> [ 5.620827] Bluetooth: hci0 failed to open Intel firmware file: intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq(-2)
> [ 5.620920] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.bseq failed with error -2
> [ 5.620922] Bluetooth: hci0 failed to open default Intel fw file: intel/ibt-hw-37.7.bseq
> [ 5.629910] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
> [ 5.629916] VFS: Mounted root (ext4 filesystem) readonly on device 8:2.
>
> The driver is trying to load the firmware before root is mounted. Do I
> really need an initramfs?

If btusb driver is loaded in initrd, you'd need the corresponding
firmware in initrd, too.

Takashi

2014-11-26 14:56:09

by Mihai Donțu

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

On Tue, 11 Nov 2014 13:12:28 -0500 Dave Jones wrote:
> Since the addition of 10d4c6736ea "Bluetooth: btusb: Add Broadcom patch
> RAM support", I (and a number of other people[*]) have been seeing
> this trace on resume from suspend.
>=20
> WARNING: CPU: 1 PID: 8565 at drivers/base/firmware_class.c:1127 _request_=
firmware+0x4c1/0x7c0()
> CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted 3.17.2-200.fc20.x86_64 #1
> Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 ) 04/30/2013
> Workqueue: hci0 hci_power_on [bluetooth]
> 0000000000000000 00000000f52a564b ffff8800a8c63be8 ffffffff817271cc
> 0000000000000000 ffff8800a8c63c20 ffffffff81094ced ffff8800a8c63d10
> ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08 00000000fffffff5
> Call Trace:
> [<ffffffff817271cc>] dump_stack+0x45/0x56
> [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
> [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
> [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
> [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
> [<ffffffff814968f1>] request_firmware+0x31/0x50
> [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
> [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
> [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
> ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
> Restarting tasks ...=20
> [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
> [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
> [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
> [<ffffffff810acc39>] process_one_work+0x149/0x3d0
> [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
> [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
> [<ffffffff810b2318>] kthread+0xd8/0xf0
> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> ---[ end trace 75a0e9c7f33ebb4c ]---
> bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
> Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
>=20
>=20
> At first I thought it was just over-reaction to the file being missing, b=
ut
> looking at the WARN_ON, it appears that we're trying to invoke the firmwa=
re
> loader before userspace is back up ?
>=20
> In this (and probably other related) kernel, CONFIG_FW_LOADER_USER_HELPER=
is unset,
> in case that matters at all.
>=20
> Dave
>=20
> [*] https://bugzilla.kernel.org/show_bug.cgi?id=3D81821
> https://bugzilla.redhat.com/show_bug.cgi?id=3D1133378

I have the following during normal boot:

[ 5.620796] Bluetooth: hci0: read Intel version: 370710018002030d00
[ 5.620822] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.1=
0-fw-1.80.2.3.d.bseq failed with error -2
[ 5.620827] Bluetooth: hci0 failed to open Intel firmware file: intel/ib=
t-hw-37.7.10-fw-1.80.2.3.d.bseq(-2)
[ 5.620920] bluetooth hci0: Direct firmware load for intel/ibt-hw-37.7.b=
seq failed with error -2
[ 5.620922] Bluetooth: hci0 failed to open default Intel fw file: intel/=
ibt-hw-37.7.bseq
[ 5.629910] EXT4-fs (sda2): mounted filesystem with ordered data mode. O=
pts: (null)
[ 5.629916] VFS: Mounted root (ext4 filesystem) readonly on device 8:2.

The driver is trying to load the firmware before root is mounted. Do I
really need an initramfs?

Thanks,

--=20
Mihai Don=C8=9Bu

2014-11-26 14:38:16

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

On Wed, 2014-11-26 at 15:31 +0100, Takashi Iwai wrote:

> Yes, that's what I mentioned in my reply. But, actually more puzzling
> is that the WARNING shouldn't have been triggered at all. That is,
> something is still racy there, so we'd need to fix it.

Did it trigger before khubd was replaced by a work queue?

Regards
Oliver

2014-11-26 14:31:57

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

At Wed, 26 Nov 2014 15:23:20 +0100,
Oliver Neukum wrote:
>
> On Wed, 2014-11-26 at 11:53 +0100, Takashi Iwai wrote:
> > At Wed, 26 Nov 2014 11:43:36 +0100,
> > Oliver Neukum wrote:
> > >
> > > On Wed, 2014-11-26 at 11:31 +0100, Takashi Iwai wrote:
> > > > At Wed, 26 Nov 2014 11:10:23 +0100,
> > > > Oliver Neukum wrote:
> > > > >
> > > > > On Wed, 2014-11-26 at 09:52 +0100, Takashi Iwai wrote:
> > > > > > At Wed, 26 Nov 2014 14:15:27 +0900,
> > > > >
> > > > > > In order to paper over this, we may also remember the failing firmware
> > > > > > and avoid loading it. This might be an easer way than the endless
> > > > > > fight against UMH race...
> > > > >
> > > > > Hi,
> > > > >
> > > > > the full fix would be to implement reset_resume() for btusb.
> > > > > It seems to me that setup() should be split in two methods,
> > > > > one to request the firmware from user space and the second
> > > > > to transfer it to the device. reset_resume() would just need
> > > > > to repeat the second operation.
> > > >
> > > > I'm not against it, but one slight drawback is that you'll have to
> > > > remember the firmware content to transfer by the driver itself in this
> > > > scenario. In the firmware loader framework, the content is re-read
> > > > at resume so that the largish content isn't kept unnecessarily during
> > > > the whole operation.
> > >
> > > That isn't a drawback but an advantage. Firmware for devices that
> > > do power management needs to be in RAM. The right time to free it
> > > is in disconnect(). But why does that mean that the driver has to
> > > manage the firmware? Can't the firmware layer do it?
> >
> > The f/w loader remembers the f/w names of the successful loads, and
> > retries to load them automatically at the suspend time. But it
> > doesn't remember/cache the failed loads. So, when the driver retires
>
> Two issues
>
> 1. the firmware may be added later. So we could only record the name,
> not the result of the query.

It records only the name. The content is cached only between suspend
and resume. But this reminds me that it's also a problem when the
firmware file on disk is replaced after the driver is loaded. Then
the firmware content differs from what the driver had.

> 2. a driver may query several firmwares in turn to find its firmware

Right, and this kind of behavior hits the problem.

> It seems to me that a firmware that will be needed again should
> just not be evicted from RAM.
>
> > request_firmware() for a non-existing file in the resume path, it
> > actually reaches to the f/w loading part again unexpectedly.
>
> And that is probably a bug. We just cannot request a firmware during
> resumption. On anything but a leave node it is potentially deadly.

Yes, that's what I mentioned in my reply. But, actually more puzzling
is that the WARNING shouldn't have been triggered at all. That is,
something is still racy there, so we'd need to fix it.

Of course, robustifying the firmware loader itself is another good
thing.

Takashi

2014-11-26 14:27:57

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

On Wed, 2014-11-26 at 15:12 +0100, Takashi Iwai wrote:
> At Wed, 26 Nov 2014 23:05:20 +0900,
> Marcel Holtmann wrote:
> >
> > Hi Oliver,
> >
> > >> In order to paper over this, we may also remember the failing firmware
> > >> and avoid loading it. This might be an easer way than the endless
> > >> fight against UMH race...
> > >
> > >
> > > the full fix would be to implement reset_resume() for btusb.
> > > It seems to me that setup() should be split in two methods,
> > > one to request the firmware from user space and the second
> > > to transfer it to the device. reset_resume() would just need
> > > to repeat the second operation.
> >
> > so when you do hci_register_dev, then hdev->setup is only called once. I really mean only once per lifetime of the hci_dev. So you would need to unregister the hci_dev first before hdev->setup will ever be called again. So I am not sure this is actually the problem here. The problem here is entirely within request_firmware() unless of course we run through the USB probe handlers again. Which I do not see happening here.
> >
> > And we have hdev->setup this way since normally the Bluetooth devices keep their firmware patches and not forget about them and suspend-resume cycles. If the USB device of course jumps of the bus during it then all bets are off anyway.
>
> Usually you can avoid unnecessary rebinding when you provide a proper
> reset_resume callback. I guess that's what Oliver suggested.

Yes, but even in reset_resume() you would need to redo the setup
part, as the device lost power. The basic problem of requesting
the firmware wouldn't be solved.

Regards
Oliver

2014-11-26 14:23:20

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

On Wed, 2014-11-26 at 11:53 +0100, Takashi Iwai wrote:
> At Wed, 26 Nov 2014 11:43:36 +0100,
> Oliver Neukum wrote:
> >
> > On Wed, 2014-11-26 at 11:31 +0100, Takashi Iwai wrote:
> > > At Wed, 26 Nov 2014 11:10:23 +0100,
> > > Oliver Neukum wrote:
> > > >
> > > > On Wed, 2014-11-26 at 09:52 +0100, Takashi Iwai wrote:
> > > > > At Wed, 26 Nov 2014 14:15:27 +0900,
> > > >
> > > > > In order to paper over this, we may also remember the failing firmware
> > > > > and avoid loading it. This might be an easer way than the endless
> > > > > fight against UMH race...
> > > >
> > > > Hi,
> > > >
> > > > the full fix would be to implement reset_resume() for btusb.
> > > > It seems to me that setup() should be split in two methods,
> > > > one to request the firmware from user space and the second
> > > > to transfer it to the device. reset_resume() would just need
> > > > to repeat the second operation.
> > >
> > > I'm not against it, but one slight drawback is that you'll have to
> > > remember the firmware content to transfer by the driver itself in this
> > > scenario. In the firmware loader framework, the content is re-read
> > > at resume so that the largish content isn't kept unnecessarily during
> > > the whole operation.
> >
> > That isn't a drawback but an advantage. Firmware for devices that
> > do power management needs to be in RAM. The right time to free it
> > is in disconnect(). But why does that mean that the driver has to
> > manage the firmware? Can't the firmware layer do it?
>
> The f/w loader remembers the f/w names of the successful loads, and
> retries to load them automatically at the suspend time. But it
> doesn't remember/cache the failed loads. So, when the driver retires

Two issues

1. the firmware may be added later. So we could only record the name,
not the result of the query.
2. a driver may query several firmwares in turn to find its firmware

It seems to me that a firmware that will be needed again should
just not be evicted from RAM.

> request_firmware() for a non-existing file in the resume path, it
> actually reaches to the f/w loading part again unexpectedly.

And that is probably a bug. We just cannot request a firmware during
resumption. On anything but a leave node it is potentially deadly.

Regards
Oliver

2014-11-26 14:16:35

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

On Wed, 2014-11-26 at 23:05 +0900, Marcel Holtmann wrote:
> Hi Oliver,
>
> >> In order to paper over this, we may also remember the failing firmware
> >> and avoid loading it. This might be an easer way than the endless
> >> fight against UMH race...
> >
> >
> > the full fix would be to implement reset_resume() for btusb.
> > It seems to me that setup() should be split in two methods,
> > one to request the firmware from user space and the second
> > to transfer it to the device. reset_resume() would just need
> > to repeat the second operation.
>
> so when you do hci_register_dev, then hdev->setup is only called once. I really mean only once per lifetime of the hci_dev. So you would need to unregister the hci_dev first before hdev->setup will ever be called again. So I am not sure this is actually the problem here. The problem here is entirely within request_firmware() unless of course we run through the USB probe handlers again. Which I do not see happening here.

It seems most likely to me that probing is indeed done again.
btusb does not implement reset_resume(). If power goes away
as is usual on S3/4 the device is reenumerated. The original
trace has a call to btusb_setup_bcm_patchram().
What else could be happening?

Regards
Oliver

2014-11-26 14:12:07

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

At Wed, 26 Nov 2014 23:05:20 +0900,
Marcel Holtmann wrote:
>
> Hi Oliver,
>
> >> In order to paper over this, we may also remember the failing firmware
> >> and avoid loading it. This might be an easer way than the endless
> >> fight against UMH race...
> >
> >
> > the full fix would be to implement reset_resume() for btusb.
> > It seems to me that setup() should be split in two methods,
> > one to request the firmware from user space and the second
> > to transfer it to the device. reset_resume() would just need
> > to repeat the second operation.
>
> so when you do hci_register_dev, then hdev->setup is only called once. I really mean only once per lifetime of the hci_dev. So you would need to unregister the hci_dev first before hdev->setup will ever be called again. So I am not sure this is actually the problem here. The problem here is entirely within request_firmware() unless of course we run through the USB probe handlers again. Which I do not see happening here.
>
> And we have hdev->setup this way since normally the Bluetooth devices keep their firmware patches and not forget about them and suspend-resume cycles. If the USB device of course jumps of the bus during it then all bets are off anyway.

Usually you can avoid unnecessary rebinding when you provide a proper
reset_resume callback. I guess that's what Oliver suggested.

Takashi

2014-11-26 14:08:22

by Marcel Holtmann

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

Hi Takashi,

>>>> On Wed, 2014-11-26 at 09:52 +0100, Takashi Iwai wrote:
>>>>> At Wed, 26 Nov 2014 14:15:27 +0900,
>>>>
>>>>> In order to paper over this, we may also remember the failing firmware
>>>>> and avoid loading it. This might be an easer way than the endless
>>>>> fight against UMH race...
>>>>
>>>> Hi,
>>>>
>>>> the full fix would be to implement reset_resume() for btusb.
>>>> It seems to me that setup() should be split in two methods,
>>>> one to request the firmware from user space and the second
>>>> to transfer it to the device. reset_resume() would just need
>>>> to repeat the second operation.
>>>
>>> I'm not against it, but one slight drawback is that you'll have to
>>> remember the firmware content to transfer by the driver itself in this
>>> scenario. In the firmware loader framework, the content is re-read
>>> at resume so that the largish content isn't kept unnecessarily during
>>> the whole operation.
>>
>> That isn't a drawback but an advantage. Firmware for devices that
>> do power management needs to be in RAM. The right time to free it
>> is in disconnect(). But why does that mean that the driver has to
>> manage the firmware? Can't the firmware layer do it?
>
> The f/w loader remembers the f/w names of the successful loads, and
> retries to load them automatically at the suspend time. But it
> doesn't remember/cache the failed loads. So, when the driver retires
> request_firmware() for a non-existing file in the resume path, it
> actually reaches to the f/w loading part again unexpectedly.

I think this should be indeed fixed. The firmware loader needs to remember the information. Since sometimes the firmware is optional. No point in re-loading it. And realistically, if the firmware was not present before suspend, it will not magically appear during resume.

Regards

Marcel

2014-11-26 14:05:20

by Marcel Holtmann

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

Hi Oliver,

>> In order to paper over this, we may also remember the failing firmware
>> and avoid loading it. This might be an easer way than the endless
>> fight against UMH race...
>
>
> the full fix would be to implement reset_resume() for btusb.
> It seems to me that setup() should be split in two methods,
> one to request the firmware from user space and the second
> to transfer it to the device. reset_resume() would just need
> to repeat the second operation.

so when you do hci_register_dev, then hdev->setup is only called once. I really mean only once per lifetime of the hci_dev. So you would need to unregister the hci_dev first before hdev->setup will ever be called again. So I am not sure this is actually the problem here. The problem here is entirely within request_firmware() unless of course we run through the USB probe handlers again. Which I do not see happening here.

And we have hdev->setup this way since normally the Bluetooth devices keep their firmware patches and not forget about them and suspend-resume cycles. If the USB device of course jumps of the bus during it then all bets are off anyway.

Regards

Marcel

2014-11-26 10:53:46

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

At Wed, 26 Nov 2014 11:43:36 +0100,
Oliver Neukum wrote:
>
> On Wed, 2014-11-26 at 11:31 +0100, Takashi Iwai wrote:
> > At Wed, 26 Nov 2014 11:10:23 +0100,
> > Oliver Neukum wrote:
> > >
> > > On Wed, 2014-11-26 at 09:52 +0100, Takashi Iwai wrote:
> > > > At Wed, 26 Nov 2014 14:15:27 +0900,
> > >
> > > > In order to paper over this, we may also remember the failing firmware
> > > > and avoid loading it. This might be an easer way than the endless
> > > > fight against UMH race...
> > >
> > > Hi,
> > >
> > > the full fix would be to implement reset_resume() for btusb.
> > > It seems to me that setup() should be split in two methods,
> > > one to request the firmware from user space and the second
> > > to transfer it to the device. reset_resume() would just need
> > > to repeat the second operation.
> >
> > I'm not against it, but one slight drawback is that you'll have to
> > remember the firmware content to transfer by the driver itself in this
> > scenario. In the firmware loader framework, the content is re-read
> > at resume so that the largish content isn't kept unnecessarily during
> > the whole operation.
>
> That isn't a drawback but an advantage. Firmware for devices that
> do power management needs to be in RAM. The right time to free it
> is in disconnect(). But why does that mean that the driver has to
> manage the firmware? Can't the firmware layer do it?

The f/w loader remembers the f/w names of the successful loads, and
retries to load them automatically at the suspend time. But it
doesn't remember/cache the failed loads. So, when the driver retires
request_firmware() for a non-existing file in the resume path, it
actually reaches to the f/w loading part again unexpectedly.

Takashi

2014-11-26 10:43:36

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

On Wed, 2014-11-26 at 11:31 +0100, Takashi Iwai wrote:
> At Wed, 26 Nov 2014 11:10:23 +0100,
> Oliver Neukum wrote:
> >
> > On Wed, 2014-11-26 at 09:52 +0100, Takashi Iwai wrote:
> > > At Wed, 26 Nov 2014 14:15:27 +0900,
> >
> > > In order to paper over this, we may also remember the failing firmware
> > > and avoid loading it. This might be an easer way than the endless
> > > fight against UMH race...
> >
> > Hi,
> >
> > the full fix would be to implement reset_resume() for btusb.
> > It seems to me that setup() should be split in two methods,
> > one to request the firmware from user space and the second
> > to transfer it to the device. reset_resume() would just need
> > to repeat the second operation.
>
> I'm not against it, but one slight drawback is that you'll have to
> remember the firmware content to transfer by the driver itself in this
> scenario. In the firmware loader framework, the content is re-read
> at resume so that the largish content isn't kept unnecessarily during
> the whole operation.

That isn't a drawback but an advantage. Firmware for devices that
do power management needs to be in RAM. The right time to free it
is in disconnect(). But why does that mean that the driver has to
manage the firmware? Can't the firmware layer do it?

You just cannot keep a device operational seamlessly if you request
firmware on resume. We could in theory use a notification queue
running while user space is operational if you really want to save
a little RAM.

Regards
Oliver

2014-11-26 10:31:43

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

At Wed, 26 Nov 2014 11:10:23 +0100,
Oliver Neukum wrote:
>
> On Wed, 2014-11-26 at 09:52 +0100, Takashi Iwai wrote:
> > At Wed, 26 Nov 2014 14:15:27 +0900,
>
> > In order to paper over this, we may also remember the failing firmware
> > and avoid loading it. This might be an easer way than the endless
> > fight against UMH race...
>
> Hi,
>
> the full fix would be to implement reset_resume() for btusb.
> It seems to me that setup() should be split in two methods,
> one to request the firmware from user space and the second
> to transfer it to the device. reset_resume() would just need
> to repeat the second operation.

I'm not against it, but one slight drawback is that you'll have to
remember the firmware content to transfer by the driver itself in this
scenario. In the firmware loader framework, the content is re-read
at resume so that the largish content isn't kept unnecessarily during
the whole operation.

Takashi

2014-11-26 10:10:23

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

On Wed, 2014-11-26 at 09:52 +0100, Takashi Iwai wrote:
> At Wed, 26 Nov 2014 14:15:27 +0900,

> In order to paper over this, we may also remember the failing firmware
> and avoid loading it. This might be an easer way than the endless
> fight against UMH race...

Hi,

the full fix would be to implement reset_resume() for btusb.
It seems to me that setup() should be split in two methods,
one to request the firmware from user space and the second
to transfer it to the device. reset_resume() would just need
to repeat the second operation.

Regards
Oliver

2014-11-26 08:52:54

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

At Wed, 26 Nov 2014 14:15:27 +0900,
Marcel Holtmann wrote:
>
> Hi Takashi,
>
> >> Since the addition of 10d4c6736ea "Bluetooth: btusb: Add Broadcom patch
> >> RAM support", I (and a number of other people[*]) have been seeing
> >> this trace on resume from suspend.
> >>
> >> WARNING: CPU: 1 PID: 8565 at drivers/base/firmware_class.c:1127 _request_firmware+0x4c1/0x7c0()
> >> CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted 3.17.2-200.fc20.x86_64 #1
> >> Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 ) 04/30/2013
> >> Workqueue: hci0 hci_power_on [bluetooth]
> >> 0000000000000000 00000000f52a564b ffff8800a8c63be8 ffffffff817271cc
> >> 0000000000000000 ffff8800a8c63c20 ffffffff81094ced ffff8800a8c63d10
> >> ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08 00000000fffffff5
> >> Call Trace:
> >> [<ffffffff817271cc>] dump_stack+0x45/0x56
> >> [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
> >> [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
> >> [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
> >> [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
> >> [<ffffffff814968f1>] request_firmware+0x31/0x50
> >> [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
> >> [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
> >> [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
> >> ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
> >> Restarting tasks ...
> >> [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
> >> [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
> >> [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
> >> [<ffffffff810acc39>] process_one_work+0x149/0x3d0
> >> [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
> >> [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
> >> [<ffffffff810b2318>] kthread+0xd8/0xf0
> >> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> >> [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
> >> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
> >> ---[ end trace 75a0e9c7f33ebb4c ]---
> >> bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
> >> Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
> >>
> >>
> >> At first I thought it was just over-reaction to the file being missing, but
> >> looking at the WARN_ON, it appears that we're trying to invoke the firmware
> >> loader before userspace is back up ?
> >>
> >> In this (and probably other related) kernel, CONFIG_FW_LOADER_USER_HELPER is unset,
> >> in case that matters at all.
> >
> > If it's the case where no matching firmware file is present, the patch
> > below might help. It's only compile-tested.
> >
> >
> > Takashi
> >
> > -- 8< --
> > From: Takashi Iwai <[email protected]>
> > Subject: [PATCH] btusb: Give up firmware loading once when failed
> >
> > Otherwise it may trigger request_firmware() for the non-existing file
> > in the resume path, resulting in a warning. For the success paths,
> > calling request_firmware() is fine, as it's cached properly at
> > suspend. The problem is only for the error paths.
> >
> > Signed-off-by: Takashi Iwai <[email protected]>
> > ---
> > drivers/bluetooth/btusb.c | 2 ++
> > 1 file changed, 2 insertions(+)
> >
> > diff --git a/drivers/bluetooth/btusb.c b/drivers/bluetooth/btusb.c
> > index edfc17bfcd44..62d8e23fd3cb 100644
> > --- a/drivers/bluetooth/btusb.c
> > +++ b/drivers/bluetooth/btusb.c
> > @@ -1569,6 +1569,7 @@ static int btusb_setup_intel(struct hci_dev *hdev)
> > if (!fw) {
> > kfree_skb(skb);
> > btusb_check_bdaddr_intel(hdev);
> > + hdev->setup = NULL;
> > return 0;
> > }
> > fw_ptr = fw->data;
> > @@ -1756,6 +1757,7 @@ static int btusb_setup_bcm_patchram(struct hci_dev *hdev)
> > ret = request_firmware(&fw, fw_name, &hdev->dev);
> > if (ret < 0) {
> > BT_INFO("%s: BCM: patch %s not found", hdev->name, fw_name);
> > + hdev->setup = NULL;
> > return 0;
> > }
>
> the hdev->setup callback is only called once for each new device found. This means that setting it back to NULL from the its own handler is not making any difference.

Indeed. I misread the messages.

> Also the problem is that hdev->setup is really there to load firmware. Devices might work without the firmware, but then they run off an old ROM firmware which is not a good idea in most cases. So we can not just close our eyes and hope for the best. The firmware should really be loaded.
>
> I think the problem is that the devices physically disappear from the USB bus during suspend and will show up as a newly attached device after resume. So we have the cold plug case here. And there we need to firmware. Plain and simple. As stated above hdev->setup is only after run once. The only way to run it a second time is by unplugging and replugging the device. A BIOS that takes the power of the Bluetooth USB device is essentially simulating this behavior.
>
> We are seeing a hci_power_on call since that is triggered exactly once when the device is plugged in. If we wanted to be super smart, then we could delay that initial call until the first userspace opens any Bluetooth socket. In theory that would work, but could be also way to complicated to realized. However it would mean the initial firmware loading and setup of the device is delayed until bluetoothd has been started. For bluetoothd this will be not a problem since it can handle hotplug of Bluetooth controllers, but for all other command line tools it might be a real problem.

Actually, there are a few other issues behind the scene:

- This warning happens only when the firmware loading fails.
If the firmware was successfully loaded *before* suspend, the f/w
loader retries to load the firmware and cache it at suspend and use
it at resume in return.

- The usermodehelper_read_trylock() should be blocked at resume, but
by some reason it didn't work.
I thought I closed the race in the commit 4320f6b1d9db, but it seems
incomplete or yet buggy. Hmm..

In order to paper over this, we may also remember the failing firmware
and avoid loading it. This might be an easer way than the endless
fight against UMH race...

Takashi

2014-11-26 05:15:27

by Marcel Holtmann

[permalink] [raw]

Subject: Re: bluetooth related firmware loader spew on resume.

Hi Takashi,

>> Since the addition of 10d4c6736ea "Bluetooth: btusb: Add Broadcom patch
>> RAM support", I (and a number of other people[*]) have been seeing
>> this trace on resume from suspend.
>>
>> WARNING: CPU: 1 PID: 8565 at drivers/base/firmware_class.c:1127 _request_firmware+0x4c1/0x7c0()
>> CPU: 1 PID: 8565 Comm: kworker/u17:0 Not tainted 3.17.2-200.fc20.x86_64 #1
>> Hardware name: LENOVO 2356JK8/2356JK8, BIOS G7ET94WW (2.54 ) 04/30/2013
>> Workqueue: hci0 hci_power_on [bluetooth]
>> 0000000000000000 00000000f52a564b ffff8800a8c63be8 ffffffff817271cc
>> 0000000000000000 ffff8800a8c63c20 ffffffff81094ced ffff8800a8c63d10
>> ffff8801365ddf00 ffff8801387b4b00 ffff8800a8c63d08 00000000fffffff5
>> Call Trace:
>> [<ffffffff817271cc>] dump_stack+0x45/0x56
>> [<ffffffff81094ced>] warn_slowpath_common+0x7d/0xa0
>> [<ffffffff81094e1a>] warn_slowpath_null+0x1a/0x20
>> [<ffffffff814965c1>] _request_firmware+0x4c1/0x7c0
>> [<ffffffff8137b9b9>] ? snprintf+0x49/0x70
>> [<ffffffff814968f1>] request_firmware+0x31/0x50
>> [<ffffffffa0943bf3>] btusb_setup_bcm_patchram+0x83/0x550 [btusb]
>> [<ffffffff8148ecf6>] ? rpm_idle+0xd6/0x2b0
>> [<ffffffffa0649051>] hci_dev_do_open+0xe1/0xa60 [bluetooth]
>> ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
>> Restarting tasks ...
>> [<ffffffff810bcb3d>] ? ttwu_do_activate.constprop.90+0x5d/0x70
>> [<ffffffffa064a1c0>] hci_power_on+0x40/0x1e0 [bluetooth]
>> [<ffffffff810f53fb>] ? lock_timer_base.isra.34+0x2b/0x50
>> [<ffffffff810acc39>] process_one_work+0x149/0x3d0
>> [<ffffffff810ad2bb>] worker_thread+0x11b/0x490
>> [<ffffffff810ad1a0>] ? rescuer_thread+0x2e0/0x2e0
>> [<ffffffff810b2318>] kthread+0xd8/0xf0
>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
>> [<ffffffff8172e7bc>] ret_from_fork+0x7c/0xb0
>> [<ffffffff810b2240>] ? kthread_create_on_node+0x190/0x190
>> ---[ end trace 75a0e9c7f33ebb4c ]---
>> bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
>> Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
>>
>>
>> At first I thought it was just over-reaction to the file being missing, but
>> looking at the WARN_ON, it appears that we're trying to invoke the firmware
>> loader before userspace is back up ?
>>
>> In this (and probably other related) kernel, CONFIG_FW_LOADER_USER_HELPER is unset,
>> in case that matters at all.
>
> If it's the case where no matching firmware file is present, the patch
> below might help. It's only compile-tested.
>
>
> Takashi
>
> -- 8< --
> From: Takashi Iwai <[email protected]>
> Subject: [PATCH] btusb: Give up firmware loading once when failed
>
> Otherwise it may trigger request_firmware() for the non-existing file
> in the resume path, resulting in a warning. For the success paths,
> calling request_firmware() is fine, as it's cached properly at
> suspend. The problem is only for the error paths.
>
> Signed-off-by: Takashi Iwai <[email protected]>
> ---
> drivers/bluetooth/btusb.c | 2 ++
> 1 file changed, 2 insertions(+)
>
> diff --git a/drivers/bluetooth/btusb.c b/drivers/bluetooth/btusb.c
> index edfc17bfcd44..62d8e23fd3cb 100644
> --- a/drivers/bluetooth/btusb.c
> +++ b/drivers/bluetooth/btusb.c
> @@ -1569,6 +1569,7 @@ static int btusb_setup_intel(struct hci_dev *hdev)
> if (!fw) {
> kfree_skb(skb);
> btusb_check_bdaddr_intel(hdev);
> + hdev->setup = NULL;
> return 0;
> }
> fw_ptr = fw->data;
> @@ -1756,6 +1757,7 @@ static int btusb_setup_bcm_patchram(struct hci_dev *hdev)
> ret = request_firmware(&fw, fw_name, &hdev->dev);
> if (ret < 0) {
> BT_INFO("%s: BCM: patch %s not found", hdev->name, fw_name);
> + hdev->setup = NULL;
> return 0;
> }

the hdev->setup callback is only called once for each new device found. This means that setting it back to NULL from the its own handler is not making any difference.

Also the problem is that hdev->setup is really there to load firmware. Devices might work without the firmware, but then they run off an old ROM firmware which is not a good idea in most cases. So we can not just close our eyes and hope for the best. The firmware should really be loaded.

I think the problem is that the devices physically disappear from the USB bus during suspend and will show up as a newly attached device after resume. So we have the cold plug case here. And there we need to firmware. Plain and simple. As stated above hdev->setup is only after run once. The only way to run it a second time is by unplugging and replugging the device. A BIOS that takes the power of the Bluetooth USB device is essentially simulating this behavior.

We are seeing a hci_power_on call since that is triggered exactly once when the device is plugged in. If we wanted to be super smart, then we could delay that initial call until the first userspace opens any Bluetooth socket. In theory that would work, but could be also way to complicated to realized. However it would mean the initial firmware loading and setup of the device is delayed until bluetoothd has been started. For bluetoothd this will be not a problem since it can handle hotplug of Bluetooth controllers, but for all other command line tools it might be a real problem.

Regards

Marcel

2014-11-25 16:40:47