Bug#764263: linux-image-3.16-2-amd64: WARNING at drivers/base/firmware_class.c:1109 _request_firmware+0x521/0xaf0() [btusb?]

classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|

Bug#764263: linux-image-3.16-2-amd64: WARNING at drivers/base/firmware_class.c:1109 _request_firmware+0x521/0xaf0() [btusb?]

Julien Cristau-6
Package: src:linux
Version: 3.16.3-2
Severity: normal

Hi,

I get the following trace in my kernel log, which I don't think I've
seen in pre-3.16 versions:

Sep 29 19:12:49 betterave kernel: [ 7696.920600] PM: resume of devices complete after 508.149 msecs
Sep 29 19:12:49 betterave kernel: [ 7696.921181] ------------[ cut here ]------------
Sep 29 19:12:49 betterave kernel: [ 7696.921188] WARNING: CPU: 2 PID: 3533 at /build/linux-P15SNz/linux-3.16.3/drivers/base/firmware_class.c:1109 _request_firmware+0x521/0xaf0()
Sep 29 19:12:49 betterave kernel: [ 7696.921282] Modules linked in: ctr ccm bnep binfmt_misc nfsd auth_rpcgss oid_registry nfs_acl nfs lockd fscache sunrpc nls_utf8 nls_cp437 vfat fat snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic joydev arc4 iwldvm ecb mac80211 x86_pkg_temp_thermal intel_powerclamp intel_rapl btusb coretemp bluetooth kvm_intel kvm 6lowpan_iphc crc32_pclmul ghash_clmulni_intel iTCO_wdt aesni_intel iTCO_vendor_support aes_x86_64 lrw gf128mul glue_helper iwlwifi evdev snd_hda_intel efi_pstore ablk_helper psmouse snd_hda_controller cryptd i915 snd_hda_codec cfg80211 serio_raw snd_hwdep snd_pcm efivars pcspkr thinkpad_acpi snd_timer nvram wmi snd drm_kms_helper ac soundcore i2c_i801 tpm_tis mei_me drm rfkill shpchp i2c_algo_bit lpc_ich tpm battery mei video i2c_core mfd_core button processor loop fuse parport_pc ppdev lp parport autofs4 ext4 crc16 mbcache jbd2 dm_mod sg sd_mod crc_t10dif crct10dif_generic ahci crct10dif_pclmul crct10dif_common libahci crc32c_intel ehci_pci ehci_hcd xhci_hcd libata sdhci_pci sdhci scsi_mod mmc_core e1000e usbcore usb_common ptp pps_core thermal thermal_sys
Sep 29 19:12:49 betterave kernel: [ 7696.921326] ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
Sep 29 19:12:49 betterave kernel: [ 7696.921327]
Sep 29 19:12:49 betterave kernel: [ 7696.921329] PM: Finishing wakeup.
Sep 29 19:12:49 betterave kernel: [ 7696.921333] CPU: 2 PID: 3533 Comm: kworker/u17:0 Not tainted 3.16-2-amd64 #1 Debian 3.16.3-2
Sep 29 19:12:49 betterave kernel: [ 7696.921338] Restarting tasks ...
Sep 29 19:12:49 betterave kernel: [ 7696.921338] Hardware name: LENOVO 2324CTO/2324CTO, BIOS G2ET92WW (2.52 ) 02/22/2013
Sep 29 19:12:49 betterave kernel: [ 7696.921353] Workqueue: hci0 hci_power_on [bluetooth]
Sep 29 19:12:49 betterave kernel: [ 7696.921362]  0000000000000009 ffffffff81506188 0000000000000000 ffffffff81065707
Sep 29 19:12:49 betterave kernel: [ 7696.921365]  ffff880214b3fd48 ffff880201fe6d80 ffff880201c25e80 ffff8800d4797600
Sep 29 19:12:49 betterave kernel: [ 7696.921371]  ffff880214b3fd40 ffffffff813af2b1 ffff0004ff102100 ffff8800d57bdab8
Sep 29 19:12:49 betterave kernel: [ 7696.921377] Call Trace:
Sep 29 19:12:49 betterave kernel: [ 7696.921386]  [<ffffffff81506188>] ? dump_stack+0x41/0x51
Sep 29 19:12:49 betterave kernel: [ 7696.921394]  [<ffffffff81065707>] ? warn_slowpath_common+0x77/0x90
Sep 29 19:12:49 betterave kernel: [ 7696.921400]  [<ffffffff813af2b1>] ? _request_firmware+0x521/0xaf0
Sep 29 19:12:49 betterave kernel: [ 7696.921405]  [<ffffffff813af8ac>] ? request_firmware+0x2c/0x40
Sep 29 19:12:49 betterave kernel: [ 7696.921412]  [<ffffffffa065f895>] ? btusb_setup_bcm_patchram+0x85/0x430 [btusb]
Sep 29 19:12:49 betterave kernel: [ 7696.921419]  [<ffffffff813a663a>] ? rpm_check_suspend_allowed+0x6a/0xc0
Sep 29 19:12:49 betterave kernel: [ 7696.921428]  [<ffffffff813a7359>] ? __pm_runtime_idle+0x69/0x80
Sep 29 19:12:49 betterave kernel: [ 7696.921439]  [<ffffffffa060991d>] ? hci_dev_do_open+0x25d/0x920 [bluetooth]
Sep 29 19:12:49 betterave kernel: [ 7696.921446]  [<ffffffff8109bd4f>] ? enqueue_task_fair+0x2cf/0xe20
Sep 29 19:12:49 betterave kernel: [ 7696.921454]  [<ffffffff8101b89d>] ? native_sched_clock+0x2d/0x80
Sep 29 19:12:49 betterave kernel: [ 7696.921465]  [<ffffffffa060a5dc>] ? hci_power_on+0x2c/0x170 [bluetooth]
Sep 29 19:12:49 betterave kernel: [ 7696.921473]  [<ffffffff81092064>] ? ttwu_do_wakeup+0x14/0xd0
Sep 29 19:12:49 betterave kernel: [ 7696.921482]  [<ffffffff8107f4a2>] ? process_one_work+0x172/0x420
Sep 29 19:12:49 betterave kernel: [ 7696.921488]  [<ffffffff8107fb35>] ? worker_thread+0x115/0x520
Sep 29 19:12:49 betterave kernel: [ 7696.921494]  [<ffffffff8107fa20>] ? rescuer_thread+0x2d0/0x2d0
Sep 29 19:12:49 betterave kernel: [ 7696.921500]  [<ffffffff81085dcd>] ? kthread+0xbd/0xe0
Sep 29 19:12:49 betterave kernel: [ 7696.921507]  [<ffffffff81085d10>] ? kthread_create_on_node+0x180/0x180
Sep 29 19:12:49 betterave kernel: [ 7696.921513]  [<ffffffff8150c1bc>] ? ret_from_fork+0x7c/0xb0
Sep 29 19:12:49 betterave kernel: [ 7696.921519]  [<ffffffff81085d10>] ? kthread_create_on_node+0x180/0x180
Sep 29 19:12:49 betterave kernel: [ 7696.921522] ---[ end trace 6e5c53426f331854 ]---
Sep 29 19:12:49 betterave kernel: [ 7696.921528] bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
Sep 29 19:12:49 betterave kernel: [ 7696.921534] Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
Sep 29 19:12:49 betterave kernel: [ 7696.928553] ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: Unable to dock!
Sep 29 19:12:49 betterave kernel: [ 7696.929287] done.

Cheers,
Julien

-- Package-specific info:
** Version:
Linux version 3.16-2-amd64 ([hidden email]) (gcc version 4.8.3 (Debian 4.8.3-11) ) #1 SMP Debian 3.16.3-2 (2014-09-20)

** Command line:
BOOT_IMAGE=/vmlinuz-3.16-2-amd64 root=/dev/mapper/betterave-root ro quiet

** Tainted: W (512)
 * Taint on warning.

** Kernel log:
[31336.082638] kvm: enabling virtualization on CPU2
[31336.084873] Intel pstate controlling: cpu 2
[31336.084921] CPU2 is up
[31336.084980] smpboot: Booting Node 0 Processor 3 APIC 0x3
[31336.096303] kvm: enabling virtualization on CPU3
[31336.098547] Intel pstate controlling: cpu 3
[31336.098596] CPU3 is up
[31336.101569] ACPI: Waking up from system sleep state S3
[31336.184160] xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI
[31336.184259] sdhci-pci 0000:02:00.0: MMC controller base frequency changed to 50Mhz.
[31336.184390] ehci-pci 0000:00:1a.0: System wakeup disabled by ACPI
[31336.185239] ehci-pci 0000:00:1d.0: System wakeup disabled by ACPI
[31336.185688] PM: noirq resume of devices complete after 16.951 msecs
[31336.186069] PM: early resume of devices complete after 0.342 msecs
[31336.186290] e1000e 0000:00:19.0: System wakeup disabled by ACPI
[31336.186371] mei_me 0000:00:16.0: irq 40 for MSI/MSI-X
[31336.187433] snd_hda_intel 0000:00:1b.0: irq 43 for MSI/MSI-X
[31336.199850] sd 0:0:0:0: [sda] Starting disk
[31336.219857] tpm_tis 00:05: TPM is disabled/deactivated (0x6)
[31336.304709] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
[31336.396094] usb 3-1.4: reset full-speed USB device number 3 using ehci-pci
[31336.520038] ata5: SATA link down (SStatus 0 SControl 300)
[31336.528043] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[31336.528815] ata1.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
[31336.528818] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
[31336.529024] ata1.00: supports DRM functions and may not be fully accessible
[31336.529145] ata1.00: failed to get NCQ Send/Recv Log Emask 0x1
[31336.534680] ata1.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
[31336.534683] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
[31336.534861] ata1.00: supports DRM functions and may not be fully accessible
[31336.534979] ata1.00: failed to get NCQ Send/Recv Log Emask 0x1
[31336.535047] ata1.00: configured for UDMA/133
[31336.536066] ata2: SATA link down (SStatus 0 SControl 300)
[31336.690732] PM: resume of devices complete after 504.327 msecs
[31336.691246] ------------[ cut here ]------------
[31336.691252] WARNING: CPU: 3 PID: 11762 at /build/linux-P15SNz/linux-3.16.3/drivers/base/firmware_class.c:1109 _request_firmware+0x521/0xaf0()
[31336.691337] Modules linked in: ctr ccm binfmt_misc bnep arc4 iwldvm mac80211 snd_hda_codec_hdmi iwlwifi snd_hda_codec_realtek snd_hda_codec_generic cfg80211 iTCO_wdt iTCO_vendor_support joydev nfsd auth_rpcgss oid_registry nfs_acl nfs lockd fscache sunrpc nls_utf8 nls_cp437 vfat fat x86_pkg_temp_thermal intel_powerclamp intel_rapl coretemp kvm_intel kvm crc32_pclmul ghash_clmulni_intel ecb btusb bluetooth 6lowpan_iphc aesni_intel aes_x86_64 lrw gf128mul glue_helper ablk_helper cryptd evdev efi_pstore psmouse serio_raw pcspkr efivars i2c_i801 snd_hda_intel snd_hda_controller snd_hda_codec snd_hwdep snd_pcm snd_timer lpc_ich mfd_core shpchp thinkpad_acpi i915 wmi nvram snd soundcore drm_kms_helper rfkill drm ac battery tpm_tis tpm i2c_algo_bit mei_me i2c_core mei video button processor loop fuse parport_pc ppdev lp parport autofs4 ext4 crc16 mbcache jbd2 dm_mod sg sd_mod crc_t10dif crct10dif_generic ahci libahci crct10dif_pclmul crct10dif_common crc32c_intel libata scsi_mod sdhci_pci sdhci ehci_pci mmc_core ehci_hcd xhci_hcd e1000e ptp pps_core usbcore usb_common thermal thermal_sys
[31336.691381] ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: docking
[31336.691385] CPU: 3 PID: 11762 Comm: kworker/u17:0 Not tainted 3.16-2-amd64 #1 Debian 3.16.3-2
[31336.691386] PM: Finishing wakeup.
[31336.691388] Hardware name: LENOVO 2324CTO/2324CTO, BIOS G2ET92WW (2.52 ) 02/22/2013
[31336.691404] Restarting tasks ...
[31336.691407] Workqueue: hci0 hci_power_on [bluetooth]
[31336.691415]  0000000000000009 ffffffff81506188 0000000000000000 ffffffff81065707
[31336.691418]  ffff88017e933d48 ffff8800d5437080 ffff880213845b80 ffff880215521400
[31336.691423]  ffff88017e933d40 ffffffff813af2b1 ffff0004ff102100 ffff8800d5d25ab8
[31336.691428] Call Trace:
[31336.691437]  [<ffffffff81506188>] ? dump_stack+0x41/0x51
[31336.691444]  [<ffffffff81065707>] ? warn_slowpath_common+0x77/0x90
[31336.691449]  [<ffffffff813af2b1>] ? _request_firmware+0x521/0xaf0
[31336.691454]  [<ffffffff813af8ac>] ? request_firmware+0x2c/0x40
[31336.691462]  [<ffffffffa0576895>] ? btusb_setup_bcm_patchram+0x85/0x430 [btusb]
[31336.691469]  [<ffffffff813a663a>] ? rpm_check_suspend_allowed+0x6a/0xc0
[31336.691474]  [<ffffffff813a7359>] ? __pm_runtime_idle+0x69/0x80
[31336.691485]  [<ffffffffa064491d>] ? hci_dev_do_open+0x25d/0x920 [bluetooth]
[31336.691492]  [<ffffffff8109bd4f>] ? enqueue_task_fair+0x2cf/0xe20
[31336.691499]  [<ffffffff8101b89d>] ? native_sched_clock+0x2d/0x80
[31336.691510]  [<ffffffffa06455dc>] ? hci_power_on+0x2c/0x170 [bluetooth]
[31336.691516]  [<ffffffff81092064>] ? ttwu_do_wakeup+0x14/0xd0
[31336.691523]  [<ffffffff8107f4a2>] ? process_one_work+0x172/0x420
[31336.691528]  [<ffffffff8107fb35>] ? worker_thread+0x115/0x520
[31336.691534]  [<ffffffff8107fa20>] ? rescuer_thread+0x2d0/0x2d0
[31336.691540]  [<ffffffff81085dcd>] ? kthread+0xbd/0xe0
[31336.691545]  [<ffffffff81085d10>] ? kthread_create_on_node+0x180/0x180
[31336.691550]  [<ffffffff8150c1bc>] ? ret_from_fork+0x7c/0xb0
[31336.691555]  [<ffffffff81085d10>] ? kthread_create_on_node+0x180/0x180
[31336.691558] ---[ end trace 79c0a83b3ce31f49 ]---
[31336.691563] bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
[31336.691568] Bluetooth: hci0: BCM: patch brcm/BCM20702A0-0a5c-21e6.hcd not found
[31336.693771] ACPI: \_SB_.PCI0.LPC_.EC__.BAT1: Unable to dock!
[31336.693792] done.
[31336.831158] e1000e: eth0 NIC Link is Down
[31336.832066] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[31336.954028] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
[31337.056439] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
[31337.056751] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[31337.057963] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[31337.064700] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
[31337.151125] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[31338.177132] [drm] Enabling RC6 states: RC6 on, RC6p on, RC6pp off
[31340.508805] wlan0: authenticate with 72:0b:95:89:af:30
[31340.508813] wlan0: capabilities/regulatory prevented using AP HT/VHT configuration, downgraded
[31340.512860] wlan0: send auth to 72:0b:95:89:af:30 (try 1/3)
[31340.516670] wlan0: authenticated
[31340.519168] wlan0: associate with 72:0b:95:89:af:30 (try 1/3)
[31340.529712] wlan0: RX AssocResp from 72:0b:95:89:af:30 (capab=0x411 status=0 aid=4)
[31340.551097] wlan0: associated
[31340.551131] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[32853.608307] SGI XFS with ACLs, security attributes, realtime, large block/inode numbers, no debug enabled
[32853.621076] JFS: nTxBlock = 8192, nTxLock = 65536
[32853.635596] ntfs: driver 2.1.30 [Flags: R/W MODULE].
[32853.653019] QNX4 filesystem 0.2.3 registered.
[32853.731026] raid6: sse2x1    6351 MB/s
[32853.799070] raid6: sse2x2    9750 MB/s
[32853.867108] raid6: sse2x4   12576 MB/s
[32853.867109] raid6: using algorithm sse2x4 (12576 MB/s)
[32853.867111] raid6: using ssse3x2 recovery algorithm
[32853.867989] xor: automatically using best checksumming function:
[32853.907132]    avx       : 23369.000 MB/sec
[32853.934711] Btrfs loaded

** Model information
sys_vendor: LENOVO
product_name: 2324CTO
product_version: ThinkPad X230
chassis_vendor: LENOVO
chassis_version: Not Available
bios_vendor: LENOVO
bios_version: G2ET92WW (2.52 )
board_vendor: LENOVO
board_name: 2324CTO
board_version: Win8 Pro DPK TPG

** Loaded modules:
btrfs
xor
raid6_pq
ufs
qnx4
hfsplus
hfs
minix
ntfs
msdos
jfs
xfs
libcrc32c
ctr
ccm
binfmt_misc
bnep
arc4
iwldvm
mac80211
snd_hda_codec_hdmi
iwlwifi
snd_hda_codec_realtek
snd_hda_codec_generic
cfg80211
iTCO_wdt
iTCO_vendor_support
joydev
nfsd
auth_rpcgss
oid_registry
nfs_acl
nfs
lockd
fscache
sunrpc
nls_utf8
nls_cp437
vfat
fat
x86_pkg_temp_thermal
intel_powerclamp
intel_rapl
coretemp
kvm_intel
kvm
crc32_pclmul
ghash_clmulni_intel
ecb
btusb
bluetooth
6lowpan_iphc
aesni_intel
aes_x86_64
lrw
gf128mul
glue_helper
ablk_helper
cryptd
evdev
efi_pstore
psmouse
serio_raw
pcspkr
efivars
i2c_i801
snd_hda_intel
snd_hda_controller
snd_hda_codec
snd_hwdep
snd_pcm
snd_timer
lpc_ich
mfd_core
shpchp
thinkpad_acpi
i915
wmi
nvram
snd
soundcore
drm_kms_helper
rfkill
drm
ac
battery
tpm_tis
tpm
i2c_algo_bit
mei_me
i2c_core
mei
video
button
processor
loop
fuse
parport_pc
ppdev
lp
parport
autofs4
ext4
crc16
mbcache
jbd2
dm_mod
sg
sd_mod
crc_t10dif
crct10dif_generic
ahci
libahci
crct10dif_pclmul
crct10dif_common
crc32c_intel
libata
scsi_mod
sdhci_pci
sdhci
ehci_pci
mmc_core
ehci_hcd
xhci_hcd
e1000e
ptp
pps_core
usbcore
usb_common
thermal
thermal_sys

** PCI devices:
00:00.0 Host bridge [0600]: Intel Corporation 3rd Gen Core processor DRAM Controller [8086:0154] (rev 09)
        Subsystem: Lenovo Device [17aa:21fa]
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort+ >SERR- <PERR- INTx-
        Latency: 0
        Capabilities: <access denied>
        Kernel driver in use: ivb_uncore

00:02.0 VGA compatible controller [0300]: Intel Corporation 3rd Gen Core processor Graphics Controller [8086:0166] (rev 09) (prog-if 00 [VGA controller])
        Subsystem: Lenovo Device [17aa:21fa]
        Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
        Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0
        Interrupt: pin A routed to IRQ 44
        Region 0: Memory at f0000000 (64-bit, non-prefetchable) [size=4M]
        Region 2: Memory at e0000000 (64-bit, prefetchable) [size=256M]
        Region 4: I/O ports at 5000 [size=64]
        Expansion ROM at <unassigned> [disabled]
        Capabilities: <access denied>
        Kernel driver in use: i915

00:14.0 USB controller [0c03]: Intel Corporation 7 Series/C210 Series Chipset Family USB xHCI Host Controller [8086:1e31] (rev 04) (prog-if 30 [XHCI])
        Subsystem: Lenovo Device [17aa:21fa]
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
        Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0
        Interrupt: pin A routed to IRQ 41
        Region 0: Memory at f2520000 (64-bit, non-prefetchable) [size=64K]
        Capabilities: <access denied>
        Kernel driver in use: xhci_hcd

00:16.0 Communication controller [0780]: Intel Corporation 7 Series/C210 Series Chipset Family MEI Controller #1 [8086:1e3a] (rev 04)
        Subsystem: Lenovo Device [17aa:21fa]
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0
        Interrupt: pin A routed to IRQ 40
        Region 0: Memory at f2535000 (64-bit, non-prefetchable) [size=16]
        Capabilities: <access denied>
        Kernel driver in use: mei_me

00:16.3 Serial controller [0700]: Intel Corporation 7 Series/C210 Series Chipset Family KT Controller [8086:1e3d] (rev 04) (prog-if 02 [16550])
        Subsystem: Lenovo Device [17aa:21fa]
        Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap+ 66MHz+ UDF- FastB2B+ ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0
        Interrupt: pin B routed to IRQ 19
        Region 0: I/O ports at 50b0 [size=8]
        Region 1: Memory at f253c000 (32-bit, non-prefetchable) [size=4K]
        Capabilities: <access denied>
        Kernel driver in use: serial

00:19.0 Ethernet controller [0200]: Intel Corporation 82579LM Gigabit Network Connection [8086:1502] (rev 04)
        Subsystem: Lenovo Device [17aa:21f3]
        Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0
        Interrupt: pin A routed to IRQ 45
        Region 0: Memory at f2500000 (32-bit, non-prefetchable) [size=128K]
        Region 1: Memory at f253b000 (32-bit, non-prefetchable) [size=4K]
        Region 2: I/O ports at 5080 [size=32]
        Capabilities: <access denied>
        Kernel driver in use: e1000e

00:1a.0 USB controller [0c03]: Intel Corporation 7 Series/C210 Series Chipset Family USB Enhanced Host Controller #2 [8086:1e2d] (rev 04) (prog-if 20 [EHCI])
        Subsystem: Lenovo Device [17aa:21fa]
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0
        Interrupt: pin A routed to IRQ 16
        Region 0: Memory at f253a000 (32-bit, non-prefetchable) [size=1K]
        Capabilities: <access denied>
        Kernel driver in use: ehci-pci

00:1b.0 Audio device [0403]: Intel Corporation 7 Series/C210 Series Chipset Family High Definition Audio Controller [8086:1e20] (rev 04)
        Subsystem: Lenovo Device [17aa:21fa]
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Interrupt: pin A routed to IRQ 43
        Region 0: Memory at f2530000 (64-bit, non-prefetchable) [size=16K]
        Capabilities: <access denied>
        Kernel driver in use: snd_hda_intel

00:1c.0 PCI bridge [0604]: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 1 [8086:1e10] (rev c4) (prog-if 00 [Normal decode])
        Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Bus: primary=00, secondary=02, subordinate=02, sec-latency=0
        I/O behind bridge: 00004000-00004fff
        Memory behind bridge: f1d00000-f24fffff
        Prefetchable memory behind bridge: 00000000f0400000-00000000f0bfffff
        Secondary status: 66MHz- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- <SERR- <PERR-
        BridgeCtl: Parity- SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
                PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
        Capabilities: <access denied>
        Kernel driver in use: pcieport

00:1c.1 PCI bridge [0604]: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 2 [8086:1e12] (rev c4) (prog-if 00 [Normal decode])
        Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Bus: primary=00, secondary=03, subordinate=03, sec-latency=0
        Memory behind bridge: f1c00000-f1cfffff
        Secondary status: 66MHz- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- <SERR- <PERR-
        BridgeCtl: Parity- SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
                PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
        Capabilities: <access denied>
        Kernel driver in use: pcieport

00:1c.2 PCI bridge [0604]: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 3 [8086:1e14] (rev c4) (prog-if 00 [Normal decode])
        Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Bus: primary=00, secondary=04, subordinate=0b, sec-latency=0
        I/O behind bridge: 00003000-00003fff
        Memory behind bridge: f1400000-f1bfffff
        Prefetchable memory behind bridge: 00000000f0c00000-00000000f13fffff
        Secondary status: 66MHz- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- <SERR- <PERR-
        BridgeCtl: Parity- SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
                PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
        Capabilities: <access denied>
        Kernel driver in use: pcieport

00:1d.0 USB controller [0c03]: Intel Corporation 7 Series/C210 Series Chipset Family USB Enhanced Host Controller #1 [8086:1e26] (rev 04) (prog-if 20 [EHCI])
        Subsystem: Lenovo Device [17aa:21fa]
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0
        Interrupt: pin A routed to IRQ 23
        Region 0: Memory at f2539000 (32-bit, non-prefetchable) [size=1K]
        Capabilities: <access denied>
        Kernel driver in use: ehci-pci

00:1f.0 ISA bridge [0601]: Intel Corporation QM77 Express Chipset LPC Controller [8086:1e55] (rev 04)
        Subsystem: Lenovo Device [17aa:21fa]
        Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0
        Capabilities: <access denied>
        Kernel driver in use: lpc_ich

00:1f.2 SATA controller [0106]: Intel Corporation 7 Series Chipset Family 6-port SATA Controller [AHCI mode] [8086:1e03] (rev 04) (prog-if 01 [AHCI 1.0])
        Subsystem: Lenovo Device [17aa:21fa]
        Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
        Status: Cap+ 66MHz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0
        Interrupt: pin B routed to IRQ 42
        Region 0: I/O ports at 50a8 [size=8]
        Region 1: I/O ports at 50bc [size=4]
        Region 2: I/O ports at 50a0 [size=8]
        Region 3: I/O ports at 50b8 [size=4]
        Region 4: I/O ports at 5060 [size=32]
        Region 5: Memory at f2538000 (32-bit, non-prefetchable) [size=2K]
        Capabilities: <access denied>
        Kernel driver in use: ahci

00:1f.3 SMBus [0c05]: Intel Corporation 7 Series/C210 Series Chipset Family SMBus Controller [8086:1e22] (rev 04)
        Subsystem: Lenovo Device [17aa:21fa]
        Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap- 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Interrupt: pin C routed to IRQ 18
        Region 0: Memory at f2534000 (64-bit, non-prefetchable) [size=256]
        Region 4: I/O ports at efa0 [size=32]
        Kernel driver in use: i801_smbus

02:00.0 System peripheral [0880]: Ricoh Co Ltd MMC/SD Host Controller [1180:e822] (rev 07) (prog-if 01)
        Subsystem: Lenovo Device [17aa:21fa]
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Interrupt: pin A routed to IRQ 16
        Region 0: Memory at f1d00000 (32-bit, non-prefetchable) [size=256]
        Capabilities: <access denied>
        Kernel driver in use: sdhci-pci

03:00.0 Network controller [0280]: Intel Corporation Centrino Advanced-N 6205 [Taylor Peak] [8086:0085] (rev 34)
        Subsystem: Intel Corporation Centrino Advanced-N 6205 AGN [8086:1311]
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Interrupt: pin A routed to IRQ 46
        Region 0: Memory at f1c00000 (64-bit, non-prefetchable) [size=8K]
        Capabilities: <access denied>
        Kernel driver in use: iwlwifi


** USB devices:
Bus 004 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 004 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 003 Device 003: ID 0a5c:21e6 Broadcom Corp. BCM20702 Bluetooth 4.0 [ThinkPad]
Bus 003 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub


-- System Information:
Debian Release: jessie/sid
  APT prefers testing
  APT policy: (900, 'testing'), (500, 'stable-updates'), (500, 'unstable'), (500, 'stable'), (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 3.16-2-amd64 (SMP w/4 CPU cores)
Locale: LANG=en_US.utf8, LC_CTYPE=fr_FR.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash

Versions of packages linux-image-3.16-2-amd64 depends on:
ii  debconf [debconf-2.0]                   1.5.53
ii  initramfs-tools [linux-initramfs-tool]  0.116
ii  kmod                                    18-3
ii  linux-base                              3.5
ii  module-init-tools                       18-3

Versions of packages linux-image-3.16-2-amd64 recommends:
ii  firmware-linux-free  3.3

Versions of packages linux-image-3.16-2-amd64 suggests:
pn  debian-kernel-handbook     <none>
pn  grub-pc | extlinux | lilo  <none>
pn  linux-doc-3.16             <none>

Versions of packages linux-image-3.16-2-amd64 is related to:
pn  firmware-atheros        <none>
pn  firmware-bnx2           <none>
pn  firmware-bnx2x          <none>
pn  firmware-brcm80211      <none>
pn  firmware-intelwimax     <none>
pn  firmware-ipw2x00        <none>
pn  firmware-ivtv           <none>
ii  firmware-iwlwifi        0.43
pn  firmware-libertas       <none>
pn  firmware-linux          <none>
pn  firmware-linux-nonfree  <none>
pn  firmware-myricom        <none>
pn  firmware-netxen         <none>
pn  firmware-qlogic         <none>
pn  firmware-ralink         <none>
pn  firmware-realtek        <none>
pn  xen-hypervisor          <none>

-- debconf information:
  linux-image-3.16-2-amd64/postinst/depmod-error-initrd-3.16-2-amd64: false
  linux-image-3.16-2-amd64/prerm/removing-running-kernel-3.16-2-amd64: true
  linux-image-3.16-2-amd64/postinst/mips-initrd-3.16-2-amd64:

signature.asc (836 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Bug#764263: linux-image-3.16-2-amd64: WARNING at drivers/base/firmware_class.c:1109 _request_firmware+0x521/0xaf0() [btusb?]

Ben Hutchings-3
On Mon, 2014-10-06 at 20:15 +0200, Julien Cristau wrote:

> Package: src:linux
> Version: 3.16.3-2
> Severity: normal
>
> Hi,
>
> I get the following trace in my kernel log, which I don't think I've
> seen in pre-3.16 versions:
>
> Sep 29 19:12:49 betterave kernel: [ 7696.920600] PM: resume of devices complete after 508.149 msecs
> Sep 29 19:12:49 betterave kernel: [ 7696.921181] ------------[ cut here ]------------
> Sep 29 19:12:49 betterave kernel: [ 7696.921188] WARNING: CPU: 2 PID: 3533 at /build/linux-P15SNz/linux-3.16.3/drivers/base/firmware_class.c:1109 _request_firmware+0x521/0xaf0()
[...]
> Sep 29 19:12:49 betterave kernel: [ 7696.921405]  [<ffffffff813af8ac>] ? request_firmware+0x2c/0x40
> Sep 29 19:12:49 betterave kernel: [ 7696.921412]  [<ffffffffa065f895>] ? btusb_setup_bcm_patchram+0x85/0x430 [btusb]
> Sep 29 19:12:49 betterave kernel: [ 7696.921419]  [<ffffffff813a663a>] ? rpm_check_suspend_allowed+0x6a/0xc0
[...]
> Sep 29 19:12:49 betterave kernel: [ 7696.921528] bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
[...]

This means: btusb tries to load firmware during its resume operation,
when userland is not yet available.  This doesn't work if firmware
loading depends on the userland firmware agent.

The warning won't appear if the firmware is installed in the usual
place, as direct loading will work.  And the firmware agent is npw
deprecated and not even enabled in Debian kernels.  We could remove this
warning, but it would be papering over a driver bug.

Ben.

--
Ben Hutchings
The program is absolutely right; therefore, the computer must be wrong.

signature.asc (828 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Bug#764263: linux-image-3.16-2-amd64: WARNING at drivers/base/firmware_class.c:1109 _request_firmware+0x521/0xaf0() [btusb?]

Bjørn Mork
In reply to this post by Julien Cristau-6
Ben Hutchings <[hidden email]> writes:

> On Mon, 2014-10-06 at 20:15 +0200, Julien Cristau wrote:
>> Package: src:linux
>> Version: 3.16.3-2
>> Severity: normal
>>
>> Hi,
>>
>> I get the following trace in my kernel log, which I don't think I've
>> seen in pre-3.16 versions:
>>
>> Sep 29 19:12:49 betterave kernel: [ 7696.920600] PM: resume of devices complete after 508.149 msecs
>> Sep 29 19:12:49 betterave kernel: [ 7696.921181] ------------[ cut here ]------------
>> Sep 29 19:12:49 betterave kernel: [ 7696.921188] WARNING: CPU: 2 PID: 3533 at /build/linux-P15SNz/linux-3.16.3/drivers/base/firmware_class.c:1109 _request_firmware+0x521/0xaf0()
> [...]
>> Sep 29 19:12:49 betterave kernel: [ 7696.921405]  [<ffffffff813af8ac>] ? request_firmware+0x2c/0x40
>> Sep 29 19:12:49 betterave kernel: [ 7696.921412]  [<ffffffffa065f895>] ? btusb_setup_bcm_patchram+0x85/0x430 [btusb]
>> Sep 29 19:12:49 betterave kernel: [ 7696.921419]  [<ffffffff813a663a>] ? rpm_check_suspend_allowed+0x6a/0xc0
> [...]
>> Sep 29 19:12:49 betterave kernel: [ 7696.921528] bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
> [...]
>
> This means: btusb tries to load firmware during its resume operation,
> when userland is not yet available.  This doesn't work if firmware
> loading depends on the userland firmware agent.
>
> The warning won't appear if the firmware is installed in the usual
> place, as direct loading will work.  And the firmware agent is npw
> deprecated and not even enabled in Debian kernels.  We could remove this
> warning, but it would be papering over a driver bug.

Are you sure about this?  FWIW I've occasionally seen similar warnings
from another btusb device with firmware (using kernels I've built
myself, so not reported here of course). And I haven't really bothered to
look at the root cause before, so I haven't reported it upstream either.

But looking at _request_firmware() now it seems to me that this warning
is triggered _before_ we attempt any direct loading:


_request_firmware(const struct firmware **firmware_p, const char *name,
                  struct device *device, unsigned int opt_flags)
{

..
        if (opt_flags & FW_OPT_NOWAIT) {
                timeout = usermodehelper_read_lock_wait(timeout);
                if (!timeout) {
                        dev_dbg(device, "firmware: %s loading timed out\n",
                                name);
                        ret = -EBUSY;
                        goto out;
                }
        } else {
                ret = usermodehelper_read_trylock();
                if (WARN_ON(ret)) {
                        dev_err(device, "firmware: %s will not be loaded\n",
                                name);
                        goto out;
                }
        }

        ret = fw_get_filesystem_firmware(device, fw->priv);

 

That's the WARN_ON() we are hitting, as can be seen by the error message
following the warning.  So we fail to get the usermodehelper read lock
(why do we need that?) and bail out before even attempting the direct
loading.

I will not claim I understand any of this.  But the warning is
definitely triggered on some resumes, with firmware in the usual place
and without the firmware agent being enabled.


Bjørn


--
To UNSUBSCRIBE, email to [hidden email]
with a subject of "unsubscribe". Trouble? Contact [hidden email]

Reply | Threaded
Open this post in threaded view
|

Bug#764263: linux-image-3.16-2-amd64: WARNING at drivers/base/firmware_class.c:1109 _request_firmware+0x521/0xaf0() [btusb?]

Darshaka Pathirana-2
Hi,

I know, this is a very old bug report but as I am still running
Debian/jessie (and others might too), I thought my findings would
still be helpful and/or lead to closing this bug.

On 10/07/2014 09:18 AM, Bjørn Mork wrote:

> Ben Hutchings <[hidden email]> writes:
>> On Mon, 2014-10-06 at 20:15 +0200, Julien Cristau wrote:
>>> Package: src:linux
>>> Version: 3.16.3-2
>>> Severity: normal
>>>
>>> Hi,
>>>
>>> I get the following trace in my kernel log, which I don't think I've
>>> seen in pre-3.16 versions:
>>>
>>> Sep 29 19:12:49 betterave kernel: [ 7696.920600] PM: resume of devices complete after 508.149 msecs
>>> Sep 29 19:12:49 betterave kernel: [ 7696.921181] ------------[ cut here ]------------
>>> Sep 29 19:12:49 betterave kernel: [ 7696.921188] WARNING: CPU: 2 PID: 3533 at /build/linux-P15SNz/linux-3.16.3/drivers/base/firmware_class.c:1109 _request_firmware+0x521/0xaf0()
>> [...]
>>> Sep 29 19:12:49 betterave kernel: [ 7696.921405]  [<ffffffff813af8ac>] ? request_firmware+0x2c/0x40
>>> Sep 29 19:12:49 betterave kernel: [ 7696.921412]  [<ffffffffa065f895>] ? btusb_setup_bcm_patchram+0x85/0x430 [btusb]
>>> Sep 29 19:12:49 betterave kernel: [ 7696.921419]  [<ffffffff813a663a>] ? rpm_check_suspend_allowed+0x6a/0xc0
>> [...]
>>> Sep 29 19:12:49 betterave kernel: [ 7696.921528] bluetooth hci0: firmware: brcm/BCM20702A0-0a5c-21e6.hcd will not be loaded
>> [...]
>>
>> This means: btusb tries to load firmware during its resume operation,
>> when userland is not yet available.  This doesn't work if firmware
>> loading depends on the userland firmware agent.
>>
>> The warning won't appear if the firmware is installed in the usual
>> place, as direct loading will work.  And the firmware agent is npw
>> deprecated and not even enabled in Debian kernels.  We could remove this
>> warning, but it would be papering over a driver bug.
>
> Are you sure about this?  FWIW I've occasionally seen similar warnings
> from another btusb device with firmware (using kernels I've built
> myself, so not reported here of course). And I haven't really bothered to
> look at the root cause before, so I haven't reported it upstream either.
> [...]
I also got this kernel backtrace log, especially after resume from
suspend. So I tested the following configurations:

* Kernel: 3.16.43-2+deb8u2 / without firmware
* Kernel: 3.16.43-2+deb8u2 / with firmware
* Kernel: 4.9.30-2+deb9u2~bpo8+1 / without firmware
* Kernel: 4.9.30-2+deb9u2~bpo8+1 / with firmware

Finding the correct firmware is a complete different story (see
my comments in #801084 for details) but I only got the kernel
backtrace log with the first configuration (Kernel: 3.16.43-2+deb8u2 /
without firmware).

So I think this issue is fixed in the jessie-backports kernel.

If you need more information on this, please let me know. If Julien
can confirm that the kernel log is not shown with the new kernel
version, this bug can be closed.

Regards,
 - Darsha


signature.asc (836 bytes) Download Attachment