Re: [PATCH] Bluetooth: btmtk: Remove resetting mt7921 before downloading the fw

[Chris Lu (陸稚泓)]

On Tue, 2024-09-10 at 18:09 +0100, Marc Payne wrote:

Hi Marc,

Is it possible to provide entire kernel log for further debugging?
(From boot up to issue heppen)

We suspect that the issue occurred event earilier and our controller is
not able to recover itself. Therfore, we need to check if Bluetooth
works as expected in the booting stage.

BRs,
Chris Lu

>  	 
> External email : Please do not click links or open attachments until
> you have verified the sender or the content.
>  Hi,
> 
> The 22/08/2024 13:23, Hao Qin wrote:
> > Remove resetting mt7921 before downloading the fw, as it may cause
> > command timeout when performing the reset.
> > 
> > Signed-off-by: Hao Qin <hao.qin@xxxxxxxxxxxx>
> > ---
> >  drivers/bluetooth/btmtk.c | 4 ++--
> >  1 file changed, 2 insertions(+), 2 deletions(-)
> > 
> > diff --git a/drivers/bluetooth/btmtk.c b/drivers/bluetooth/btmtk.c
> > index 2b7c80043aa2..a46f70135cbd 100644
> > --- a/drivers/bluetooth/btmtk.c
> > +++ b/drivers/bluetooth/btmtk.c
> > @@ -1326,7 +1326,6 @@ int btmtk_usb_setup(struct hci_dev *hdev)
> >  fwname = FIRMWARE_MT7668;
> >  break;
> >  case 0x7922:
> > -case 0x7961:
> >  case 0x7925:
> >  /* Reset the device to ensure it's in the initial state before
> >   * downloading the firmware to ensure.
> > @@ -1334,7 +1333,8 @@ int btmtk_usb_setup(struct hci_dev *hdev)
> >  
> >  if (!test_bit(BTMTK_FIRMWARE_LOADED, &btmtk_data->flags))
> >  btmtk_usb_subsys_reset(hdev, dev_id);
> > -
> > +fallthrough;
> > +case 0x7961:
> >  btmtk_fw_get_filename(fw_bin_name, sizeof(fw_bin_name), dev_id,
> >        fw_version, fw_flavor);
> >  
> > -- 
> > 2.18.0
> > 
> 
> [Original regression report
> 
https://lore.kernel.org/linux-bluetooth/ZsTh7Jyug7MbZsLE@xxxxxxxxxxxx/
> ]
> 
> Thanks for the patch, I have tested it on top of v6.11-rc7 and can
> confirm
> that it resolves the initial command timeout issue.
> 
> Unfortunately, when using the latest firmware version 20240826151221
> from the
> linux-firmware repo I'm still seeing "Mediatek coredump end" errors
> followed by MSFT and AOSP errors. The device then appears
> unresponsive
> and the kernel eventually gives up attempting to enumerate:
> 
> [  230.042936] usb 4-3.2: new SuperSpeed USB device number 4 using
> xhci_hcd
> [  230.065228] usb 4-3.2: New USB device found, idVendor=0e8d,
> idProduct=7961, bcdDevice= 1.00
> [  230.065237] usb 4-3.2: New USB device strings: Mfr=6, Product=7,
> SerialNumber=8
> [  230.065240] usb 4-3.2: Product: Wireless_Device
> [  230.065242] usb 4-3.2: Manufacturer: MediaTek Inc.
> [  230.065245] usb 4-3.2: SerialNumber: 000000000
> [  230.101915] Bluetooth: hci2: HW/SW Version: 0x008a008a, Build
> Time: 20240826151221
> [  233.005938] Bluetooth: hci2: Device setup in 2862056 usecs
> [  233.005983] Bluetooth: hci2: HCI Enhanced Setup Synchronous
> Connection command is advertised, but not supported.
> [  234.306071] Bluetooth: hci2: Mediatek coredump end
> [  235.092729] Bluetooth: hci2: Opcode 0x0c03 failed: -110
> [  235.192772] Bluetooth: hci2: Mediatek coredump end
> [  237.226157] Bluetooth: hci2: Failed to read MSFT supported
> features (-110)
> [  239.359435] Bluetooth: hci2: AOSP get vendor capabilities (-110)
> [  244.479726] usb 4-3.2: Disable of device-initiated U1 failed.
> [  249.599598] usb 4-3.2: Disable of device-initiated U2 failed.
> [  259.839215] Bluetooth: hci2: Failed to write uhw reg(-110)
> [  259.839240] usb 4-3.2: Disable of device-initiated U1 failed.
> [  264.959343] usb 4-3.2: Disable of device-initiated U2 failed.
> [  270.079038] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  275.412299] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  275.618812] usb 4-3.2: device not accepting address 4, error -62
> [  280.958852] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  286.292034] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  286.498618] usb 4-3.2: device not accepting address 4, error -62
> [  291.838759] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  297.172018] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  297.378477] usb 4-3.2: device not accepting address 4, error -62
> [  302.718497] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  308.051867] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  308.258345] usb 4-3.2: device not accepting address 4, error -62
> [  308.260253] usb 4-3.2: USB disconnect, device number 4
> [  313.598307] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  318.931586] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  319.138278] usb 4-3.2: device not accepting address 5, error -62
> [  324.478224] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  329.811444] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  330.018032] usb 4-3.2: device not accepting address 6, error -62
> [  330.018489] usb 4-3-port2: attempt power cycle
> [  336.211505] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  341.544640] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  341.751239] usb 4-3.2: device not accepting address 7, error -62
> [  347.091375] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  352.424563] xhci_hcd 0000:00:14.0: Timeout while waiting for setup
> device command
> [  352.631136] usb 4-3.2: device not accepting address 8, error -62
> [  352.631538] usb 4-3-port2: unable to enumerate USB device
> 
> 
> Interestingly, if I revert back to an known-good firmware version
> 20231025113744 along with your patch, the device enumerates and works
> fine:
> 
> [ 4001.366725] usb 4-1: new SuperSpeed USB device number 4 using
> xhci_hcd
> [ 4001.385840] usb 4-1: New USB device found, idVendor=0e8d,
> idProduct=7961, bcdDevice= 1.00
> [ 4001.385855] usb 4-1: New USB device strings: Mfr=6, Product=7,
> SerialNumber=8
> [ 4001.385860] usb 4-1: Product: Wireless_Device
> [ 4001.385863] usb 4-1: Manufacturer: MediaTek Inc.
> [ 4001.385867] usb 4-1: SerialNumber: 000000000
> [ 4001.398010] Bluetooth: hci1: HW/SW Version: 0x008a008a, Build
> Time: 20231025113744
> [ 4004.275656] Bluetooth: hci1: Device setup in 2812288 usecs
> [ 4004.275661] Bluetooth: hci1: HCI Enhanced Setup Synchronous
> Connection command is advertised, but not supported.
> [ 4004.355137] Bluetooth: hci1: AOSP extensions version v0.96
> [ 4004.355156] Bluetooth: hci1: AOSP quality report is not supported
> [ 4004.355698] Bluetooth: MGMT ver 1.23
> 
> But if I then disconnect it, I get the Oops that I shared in my
> original
> regression report:
> 
> [ 4043.436215] usb 4-1: USB disconnect, device number 4
> [ 4043.437308] Oops: general protection fault, probably for non-
> canonical address 0xdead000000000122: 0000 [#1] PREEMPT SMP NOPTI
> [ 4043.437332] CPU: 2 UID: 0 PID: 3698 Comm: kworker/2:0 Not tainted
> 6.11.0-rc7-00001-g0e2ad6528188-dirty #71
> d90fb9085e2a0686ac48ebcc408d97b104c6fbf1
> [ 4043.437352] Hardware name: Intel(R) Client Systems
> NUC12WSHi7/NUC12WSBi7, BIOS WSADL357.0088.2023.0505.1623 05/05/2023
> [ 4043.437361] Workqueue: usb_hub_wq hub_event
> [ 4043.437386] RIP: 0010:hci_unregister_dev+0x45/0x1f0 [bluetooth]
> [ 4043.437548] Code: 89 ef e8 ae d4 5c c1 f0 80 8b e9 0e 00 00 08 48
> 89 ef e8 0e c2 5c c1 48 c7 c7 68 60 52 c1 e8 22 23 5d c1 48 8b 43 08
> 48 8b 13 <48> 3b 18 0f 85 f5 c7 06 00 48 3b 5a 08 0f 85 eb c7 06 00
> 48 89 42
> [ 4043.437560] RSP: 0018:ffffa10f4ae43b98 EFLAGS: 00010246
> [ 4043.437574] RAX: dead000000000122 RBX: ffff8cf86c160000 RCX:
> 0000000000000000
> [ 4043.437585] RDX: dead000000000100 RSI: ffff8cf7b7d16c50 RDI:
> ffffffffc1526068
> [ 4043.437594] RBP: ffff8cf86c1604d0 R08: 0000000000000000 R09:
> ffff8cf7401d8e10
> [ 4043.437602] R10: ffffa10f4ae43ba0 R11: ffffa10f4ae43ba8 R12:
> ffff8cf86c160000
> [ 4043.437610] R13: ffffffffc1416278 R14: ffffffffc1416278 R15:
> ffff8cf7f8d73850
> [ 4043.437620] FS:  0000000000000000(0000) GS:ffff8d0697300000(0000)
> knlGS:0000000000000000
> [ 4043.437632] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 4043.437641] CR2: 00007f98d66dc000 CR3: 0000000131124000 CR4:
> 0000000000f50ef0
> [ 4043.437651] PKRU: 55555554
> [ 4043.437658] Call Trace:
> [ 4043.437670]  <TASK>
> [ 4043.437680]  ? __die_body.cold+0x19/0x27
> [ 4043.437700]  ? die_addr+0x3c/0x60
> [ 4043.437716]  ? exc_general_protection+0x17d/0x400
> [ 4043.437738]  ? asm_exc_general_protection+0x26/0x30
> [ 4043.437760]  ? hci_unregister_dev+0x45/0x1f0 [bluetooth
> 6dca047d1088401e195d97746b2b4936e5756d61]
> [ 4043.437930]  ? hci_unregister_dev+0x3e/0x1f0 [bluetooth
> 6dca047d1088401e195d97746b2b4936e5756d61]
> [ 4043.438080]  btusb_disconnect+0x67/0x170 [btusb
> 5bf8186d9cab4c5be1762247dadb6753a7c72a7f]
> [ 4043.438108]  usb_unbind_interface+0x90/0x290
> [ 4043.438130]  device_release_driver_internal+0x19c/0x200
> [ 4043.438150]  bus_remove_device+0xc6/0x130
> [ 4043.438166]  device_del+0x161/0x3e0
> [ 4043.438182]  ? kobject_put+0xa0/0x1d0
> [ 4043.438196]  usb_disable_device+0x104/0x220
> [ 4043.438213]  usb_disconnect+0xe6/0x2e0
> [ 4043.438231]  hub_event+0x7f9/0x19d0
> [ 4043.438250]  ? __pm_runtime_suspend+0x47/0xc0
> [ 4043.438269]  process_one_work+0x17b/0x330
> [ 4043.438287]  worker_thread+0x2c6/0x3f0
> [ 4043.438304]  ? __pfx_worker_thread+0x10/0x10
> [ 4043.438318]  kthread+0xcf/0x100
> [ 4043.438337]  ? __pfx_kthread+0x10/0x10
> [ 4043.438354]  ret_from_fork+0x31/0x50
> [ 4043.438367]  ? __pfx_kthread+0x10/0x10
> [ 4043.438382]  ret_from_fork_asm+0x1a/0x30
> [ 4043.438403]  </TASK>
> [ 4043.438408] Modules linked in: uhid mt792x_usb mt7921_common
> mt792x_lib mt76_connac_lib mt76_usb mt76 ccm option usb_wwan cmac
> algif_hash algif_skcipher af_alg sr_mod cdrom bnep mousedev joydev
> vfat fat snd_sof_pci_intel_tgl snd_sof_pci_intel_cnl intel_rapl_msr
> snd_sof_intel_hda_generic intel_rapl_common soundwire_intel
> intel_uncore_frequency soundwire_cadence
> intel_uncore_frequency_common snd_sof_intel_hda_common
> snd_sof_intel_hda_mlink snd_sof_intel_hda snd_sof_pci
> snd_sof_xtensa_dsp snd_sof iwlmvm snd_sof_utils snd_soc_hdac_hda
> snd_soc_acpi_intel_match soundwire_generic_allocation snd_soc_acpi
> soundwire_bus snd_soc_avs r8152 x86_pkg_temp_thermal intel_powerclamp
> libphy snd_soc_hda_codec coretemp mac80211 snd_hda_ext_core kvm_intel
> snd_soc_core snd_hda_codec_hdmi cdc_ether hid_generic uas usbnet
> snd_hda_codec_realtek snd_compress kvm usb_storage mii usbhid
> snd_hda_codec_generic ac97_bus snd_pcm_dmaengine
> snd_hda_scodec_component snd_hda_intel libarc4 snd_intel_dspcfg btusb
> crct10dif_pclmul snd_intel_sdw_acpi
> [ 4043.438617]  crc32_pclmul iwlwifi btrtl snd_hda_codec
> polyval_clmulni btintel polyval_generic btbcm ghash_clmulni_intel
> sha512_ssse3 btmtk tps6598x sha256_ssse3 snd_hda_core typec
> sha1_ssse3 cfg80211 bluetooth aesni_intel snd_hwdep roles gf128mul
> crypto_simd snd_pcm cryptd mei_hdcp mei_pxp rapl ee1004 ov13858
> snd_timer intel_cstate igc spi_nor intel_uncore i2c_i801 thunderbolt
> snd v4l2_fwnode mei_me v4l2_async ptp wdat_wdt i2c_smbus mtd pcspkr
> wmi_bmof intel_lpss_pci videodev mei pps_core soundcore
> intel_pmc_core i2c_mux intel_lpss rfkill idma64 igen6_edac intel_vsec
> serial_multi_instantiate mc pmt_telemetry pinctrl_tigerlake pmt_class
> acpi_pad acpi_tad 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 i2c_algo_bit drm_buddy ttm nvme intel_gtt drm_display_helper
> nvme_core spi_intel_pci cec xhci_pci crc32c_intel spi_intel nvme_auth
> xhci_pci_renesas video wmi
> [ 4043.438898] ---[ end trace 0000000000000000 ]---
> [ 4043.438905] RIP: 0010:hci_unregister_dev+0x45/0x1f0 [bluetooth]
> [ 4043.439039] Code: 89 ef e8 ae d4 5c c1 f0 80 8b e9 0e 00 00 08 48
> 89 ef e8 0e c2 5c c1 48 c7 c7 68 60 52 c1 e8 22 23 5d c1 48 8b 43 08
> 48 8b 13 <48> 3b 18 0f 85 f5 c7 06 00 48 3b 5a 08 0f 85 eb c7 06 00
> 48 89 42
> [ 4043.439048] RSP: 0018:ffffa10f4ae43b98 EFLAGS: 00010246
> [ 4043.439058] RAX: dead000000000122 RBX: ffff8cf86c160000 RCX:
> 0000000000000000
> [ 4043.439065] RDX: dead000000000100 RSI: ffff8cf7b7d16c50 RDI:
> ffffffffc1526068
> [ 4043.439072] RBP: ffff8cf86c1604d0 R08: 0000000000000000 R09:
> ffff8cf7401d8e10
> [ 4043.439078] R10: ffffa10f4ae43ba0 R11: ffffa10f4ae43ba8 R12:
> ffff8cf86c160000
> [ 4043.439085] R13: ffffffffc1416278 R14: ffffffffc1416278 R15:
> ffff8cf7f8d73850
> [ 4043.439091] FS:  0000000000000000(0000) GS:ffff8d0697300000(0000)
> knlGS:0000000000000000
> [ 4043.439100] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 4043.439108] CR2: 00007f98d66dc000 CR3: 0000000131124000 CR4:
> 0000000000f50ef0
> [ 4043.439116] PKRU: 55555554
> [ 4043.439122] note: kworker/2:0[3698] exited with preempt_count 1
> 
> So, in summary, it looks as though there are two issues here:
> 
> 1. The latest firmware does not seem to work well with this chipset,
>    perhaps it is crashing after loading?
> 2. The Oops in the hci_unregister_dev function suggests some HCI
>    registration bug.
> 
> Let me know if I can provide any further assistance.
> 
> Regards,
> 
> Marc
>