Message-ID: <ZuB3omUkdUHLggYu@mdpsys.co.uk>
Date: Tue, 10 Sep 2024 18:09:05 +0100
From: Marc Payne <marc.payne@...sys.co.uk>
To: Hao Qin <hao.qin@...iatek.com>
Cc: Chris Lu <chris.lu@...iatek.com>, Sean Wang <sean.wang@...iatek.com>,
	Deren Wu <deren.Wu@...iatek.com>,
	Aaron Hou <aaron.hou@...iatek.com>,
	Steve Lee <steve.lee@...iatek.com>,
	Marcel Holtmann <marcel@...tmann.org>,
	Johan Hedberg <johan.hedberg@...il.com>,
	Luiz Von Dentz <luiz.dentz@...il.com>,
	linux-bluetooth <linux-bluetooth@...r.kernel.org>,
	linux-kernel <linux-kernel@...r.kernel.org>,
	linux-mediatek <linux-mediatek@...ts.infradead.org>
Subject: Re: [PATCH] Bluetooth: btmtk: Remove resetting mt7921 before
 downloading the fw

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@...iatek.com>
> ---
>  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@mdpsys.co.uk/]

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

Powered by blists - more mailing lists