Message-ID: <76922517-7497-48b5-a581-d1290d413604@molgen.mpg.de>
Date: Wed, 21 Aug 2024 07:27:04 +0200
From: Paul Menzel <pmenzel@...gen.mpg.de>
To: Marc Payne <marc.payne@...sys.co.uk>, Hao Qin <hao.qin@...iatek.com>,
 Sean Wang <sean.wang@...iatek.com>, Chris Lu <chris.lu@...iatek.com>
Cc: Marcel Holtmann <marcel@...tmann.org>,
 Luiz Augusto von Dentz <luiz.dentz@...il.com>,
 linux-bluetooth@...r.kernel.org, linux-kernel@...r.kernel.org,
 linux-mediatek@...ts.infradead.org, regressions@...ts.linux.dev
Subject: Re: [REGRESSION] [BISECTED] btusb: driver fails to initialize
 MT7921AUN on v6.11-rc4

[Cc: +Marcel, +Luiz]

#regzbot ^introduced: ccfc8948d7e4


Dear Marc,


Thank you for your report and bisecting the issue. I just add the 
maintainers, and tell regzbot about it.


Kind regards,

Paul


Am 20.08.24 um 20:35 schrieb Marc Payne:
> Hello,
> 
> I'm testing v6.11-rc4 and the btusb driver fails to properly initialize my
> MT7921AUN-based Alfa Networks AWUS036AXML:
> 
> [   63.896319] usb 4-3.1.2: new SuperSpeed USB device number 4 using xhci_hcd
> [   63.915436] usb 4-3.1.2: New USB device found, idVendor=0e8d, idProduct=7961, bcdDevice= 1.00
> [   63.915450] usb 4-3.1.2: New USB device strings: Mfr=6, Product=7, SerialNumber=8
> [   63.915455] usb 4-3.1.2: Product: Wireless_Device
> [   63.915459] usb 4-3.1.2: Manufacturer: MediaTek Inc.
> [   63.915461] usb 4-3.1.2: SerialNumber: 000000000
> [   69.146856] Bluetooth: hci1: Failed to write uhw reg(-110)
> [   69.149213] Bluetooth: hci1: HW/SW Version: 0x008a008a, Build Time: 20240716151445
> [   78.530621] usb 4-3.1.2: Failed to suspend device, error -110
> [   88.553074] Bluetooth: hci1: Execution of wmt command timed out
> [   88.553097] Bluetooth: hci1: Failed to send wmt patch dwnld (-110)
> [   88.553186] Bluetooth: hci1: Failed to set up firmware (-110)
> [   88.553193] Bluetooth: hci1: HCI Enhanced Setup Synchronous Connection command is advertised, but not supported.
> [   90.899462] usb 4-3.1.2: Failed to suspend device, error -110
> 
> I have bisected the issue down to the following commit:
> 
>      ccfc8948d7e4 ("Bluetooth: btusb: mediatek: reset the controller before downloading the fw")
> 
> The commit does not revert cleanly due to refactoring in subsequent commits but
> removing the relevant ten lines of code allows the driver to initialize the
> device correctly, albeit with some failures and 'Mediatek coredump' errors
> followed by an additional reset. Interestingly, after the reset the device is
> now showing as hci2 rather than hci1, suggesting an HCI device registration
> issue... Bluetooth devices are able to pair and connect as expected:
> 
> [   77.765047] usb 4-3.1.2: new SuperSpeed USB device number 4 using xhci_hcd
> [   77.785044] usb 4-3.1.2: New USB device found, idVendor=0e8d, idProduct=7961, bcdDevice= 1.00
> [   77.785063] usb 4-3.1.2: New USB device strings: Mfr=6, Product=7, SerialNumber=8
> [   77.785069] usb 4-3.1.2: Product: Wireless_Device
> [   77.785073] usb 4-3.1.2: Manufacturer: MediaTek Inc.
> [   77.785077] usb 4-3.1.2: SerialNumber: 000000000
> [   77.807685] Bluetooth: hci1: HW/SW Version: 0x008a008a, Build Time: 20240716151445
> [   80.570163] Bluetooth: hci1: Device setup in 2710186 usecs
> [   80.570173] Bluetooth: hci1: HCI Enhanced Setup Synchronous Connection command is advertised, but not supported.
> [   81.871516] Bluetooth: hci1: Mediatek coredump end
> [   82.734805] Bluetooth: hci1: Opcode 0x0c03 failed: -110
> [   82.754807] Bluetooth: hci1: Mediatek coredump end
> [   84.868215] Bluetooth: hci1: Failed to read MSFT supported features (-110)
> [   87.001566] Bluetooth: hci1: AOSP get vendor capabilities (-110)
> [   92.292375] usb 4-3.1.2: reset SuperSpeed USB device number 4 using xhci_hcd
> [   92.385619] usb 4-3.1.2: reset SuperSpeed USB device number 4 using xhci_hcd
> [   92.406786] Bluetooth: hci2: HW/SW Version: 0x008a008a, Build Time: 20240716151445
> [   94.920337] Bluetooth: hci2: Device setup in 2455839 usecs
> [   94.920343] Bluetooth: hci2: HCI Enhanced Setup Synchronous Connection command is advertised, but not supported.
> [   94.994480] Bluetooth: hci2: AOSP extensions version v1.00
> [   94.994494] Bluetooth: hci2: AOSP quality report is supported
> [   94.995001] Bluetooth: MGMT ver 1.23
> 
> However, when disconnecting the AWUS036AXML device I get an Oops in
> the hci_unregister_dev function, again indicating an issue with HCI registration
> which was not present in the 6.10 kernel versions:
> 
> [ 1210.222351] usb 4-3.1.2: USB disconnect, device number 4
> [ 1210.271146] Oops: general protection fault, probably for non-canonical address 0xdead000000000122: 0000 [#1] PREEMPT SMP NOPTI
> [ 1210.271166] CPU: 2 UID: 0 PID: 2275 Comm: kworker/2:1 Not tainted 6.11.0-rc4-dirty #67 a319890a1bc323fc297a70bfc980897913c059f7
> [ 1210.271178] Hardware name: Intel(R) Client Systems NUC12WSHi7/NUC12WSBi7, BIOS WSADL357.0088.2023.0505.1623 05/05/2023
> [ 1210.271183] Workqueue: usb_hub_wq hub_event
> [ 1210.271200] RIP: 0010:hci_unregister_dev+0x45/0x1f0 [bluetooth]
> [ 1210.271292] Code: 89 ef e8 0e c4 ca dc f0 80 8b e9 0e 00 00 08 48 89 ef e8 6e b1 ca dc 48 c7 c7 68 70 44 c1 e8 82 12 cb dc 48 8b 43 08 48 8b 13 <48> 3b 18 0f 85 35 c8 06 00 48 3b 5a 08 0f 85 2b c8 06 00 48 89 42
> [ 1210.271297] RSP: 0018:ffffbb3b0661bb98 EFLAGS: 00010246
> [ 1210.271305] RAX: dead000000000122 RBX: ffff97bc8f92e000 RCX: 0000000000000000
> [ 1210.271310] RDX: dead000000000100 RSI: ffff97bc8ba8b610 RDI: ffffffffc1447068
> [ 1210.271314] RBP: ffff97bc8f92e4d0 R08: ffff97bc8424b5c0 R09: 00000000802a0026
> [ 1210.271318] R10: 00000000802a0026 R11: 0000000000000001 R12: ffff97bc8f92e000
> [ 1210.271323] R13: ffffffffc12ff278 R14: ffffffffc12ff278 R15: ffff97bcf25acc50
> [ 1210.271327] FS:  0000000000000000(0000) GS:ffff97cbd7300000(0000) knlGS:0000000000000000
> [ 1210.271332] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1210.271337] CR2: 0000285c01b10000 CR3: 00000003d6e22000 CR4: 0000000000f50ef0
> [ 1210.271342] PKRU: 55555554
> [ 1210.271346] Call Trace:
> [ 1210.271352]  <TASK>
> [ 1210.271359]  ? __die_body.cold+0x19/0x27
> [ 1210.271371]  ? die_addr+0x3c/0x60
> [ 1210.271378]  ? exc_general_protection+0x17d/0x400
> [ 1210.271391]  ? asm_exc_general_protection+0x26/0x30
> [ 1210.271403]  ? hci_unregister_dev+0x45/0x1f0 [bluetooth ffdb4fb65cead032fbb8f4718e5d0aa7b94d492f]
> [ 1210.271479]  ? hci_unregister_dev+0x3e/0x1f0 [bluetooth ffdb4fb65cead032fbb8f4718e5d0aa7b94d492f]
> [ 1210.271551]  btusb_disconnect+0x67/0x170 [btusb ce322bda915639979ec31f72a2b85eb752188d36]
> [ 1210.271563]  usb_unbind_interface+0x90/0x290
> [ 1210.271576]  device_release_driver_internal+0x19c/0x200
> [ 1210.271589]  bus_remove_device+0xc6/0x130
> [ 1210.271599]  device_del+0x161/0x3e0
> [ 1210.271608]  ? kobject_put+0xa0/0x1d0
> [ 1210.271617]  usb_disable_device+0x104/0x220
> [ 1210.271627]  usb_disconnect+0xe6/0x2e0
> [ 1210.271637]  hub_event+0x7f9/0x19d0
> [ 1210.271648]  ? __schedule+0x3dd/0x1520
> [ 1210.271656]  process_one_work+0x17b/0x330
> [ 1210.271667]  worker_thread+0x2d2/0x400
> [ 1210.271676]  ? __pfx_worker_thread+0x10/0x10
> [ 1210.271684]  kthread+0xcf/0x100
> [ 1210.271695]  ? __pfx_kthread+0x10/0x10
> [ 1210.271705]  ret_from_fork+0x31/0x50
> [ 1210.271711]  ? __pfx_kthread+0x10/0x10
> [ 1210.271720]  ret_from_fork_asm+0x1a/0x30
> [ 1210.271732]  </TASK>
> [ 1210.271735] Modules linked in: mt792x_usb mt7921_common mt792x_lib mt76_connac_lib mt76_usb mt76 ccm option usb_wwan rndis_host uhid cmac algif_hash algif_skcipher af_alg bnep vfat fat cdc_ether usbnet intel_rapl_msr intel_rapl_common intel_uncore_frequency intel_uncore_frequency_common snd_sof_pci_intel_tgl snd_sof_pci_intel_cnl iwlmvm snd_sof_intel_hda_generic soundwire_intel soundwire_cadence snd_sof_intel_hda_common x86_pkg_temp_thermal intel_powerclamp snd_sof_intel_hda_mlink snd_sof_intel_hda coretemp snd_sof_pci snd_sof_xtensa_dsp kvm_intel snd_sof r8152 mii snd_sof_utils mac80211 libphy snd_soc_hdac_hda kvm snd_soc_acpi_intel_match soundwire_generic_allocation snd_soc_acpi soundwire_bus snd_soc_avs snd_hda_codec_hdmi snd_soc_hda_codec snd_hda_ext_core snd_hda_codec_realtek snd_soc_core snd_hda_codec_generic snd_hda_scodec_component crct10dif_pclmul crc32_pclmul polyval_clmulni snd_compress polyval_generic ac97_bus libarc4 ghash_clmulni_intel snd_pcm_dmaengine sha512_ssse3 sha256_ssse3 snd_hda_intel sha1_ssse3
> [ 1210.271851]  aesni_intel btusb snd_intel_dspcfg snd_intel_sdw_acpi gf128mul iwlwifi snd_hda_codec btrtl crypto_simd cryptd btintel tps6598x btbcm typec snd_hda_core btmtk rapl cfg80211 roles mei_pxp mei_hdcp snd_hwdep intel_cstate ee1004 bluetooth igc snd_pcm spi_nor intel_uncore ov13858 mei_me snd_timer thunderbolt v4l2_fwnode snd ptp mei i2c_i801 v4l2_async wdat_wdt mtd pcspkr intel_lpss_pci wmi_bmof pps_core i2c_smbus intel_lpss videodev soundcore i2c_mux rfkill idma64 intel_pmc_core mousedev igen6_edac joydev serial_multi_instantiate intel_vsec mc pmt_telemetry acpi_pad acpi_tad pinctrl_tigerlake pmt_class mac_hid i2c_dev dm_mod sg crypto_user loop nfnetlink ip_tables x_tables ext4 crc32c_generic crc16 mbcache jbd2 xe drm_ttm_helper gpu_sched drm_suballoc_helper drm_gpuvm drm_exec i915 hid_generic usbhid i2c_algo_bit drm_buddy ttm intel_gtt nvme drm_display_helper nvme_core video spi_intel_pci cec xhci_pci crc32c_intel nvme_auth spi_intel xhci_pci_renesas wmi
> [ 1210.271992] ---[ end trace 0000000000000000 ]---
> [ 1210.271996] RIP: 0010:hci_unregister_dev+0x45/0x1f0 [bluetooth]
> [ 1210.272061] Code: 89 ef e8 0e c4 ca dc f0 80 8b e9 0e 00 00 08 48 89 ef e8 6e b1 ca dc 48 c7 c7 68 70 44 c1 e8 82 12 cb dc 48 8b 43 08 48 8b 13 <48> 3b 18 0f 85 35 c8 06 00 48 3b 5a 08 0f 85 2b c8 06 00 48 89 42
> [ 1210.272066] RSP: 0018:ffffbb3b0661bb98 EFLAGS: 00010246
> [ 1210.272071] RAX: dead000000000122 RBX: ffff97bc8f92e000 RCX: 0000000000000000
> [ 1210.272075] RDX: dead000000000100 RSI: ffff97bc8ba8b610 RDI: ffffffffc1447068
> [ 1210.272078] RBP: ffff97bc8f92e4d0 R08: ffff97bc8424b5c0 R09: 00000000802a0026
> [ 1210.272082] R10: 00000000802a0026 R11: 0000000000000001 R12: ffff97bc8f92e000
> [ 1210.272085] R13: ffffffffc12ff278 R14: ffffffffc12ff278 R15: ffff97bcf25acc50
> [ 1210.272088] FS:  0000000000000000(0000) GS:ffff97cbd7300000(0000) knlGS:0000000000000000
> [ 1210.272092] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1210.272096] CR2: 0000285c01b10000 CR3: 00000003d6e22000 CR4: 0000000000f50ef0
> [ 1210.272099] PKRU: 55555554
> [ 1210.272102] note: kworker/2:1[2275] exited with preempt_count 1
> 
> 
> The kworker exiting obviously means that the kernel no longer responds to events
> on any of the USB ports...
> 
> I hope you can track down the issue, let me know if you need any additional
> details.
> 
> Regards,
> 
> Marc

Powered by blists - more mailing lists