mt7612 suspend/resume issue

From: Oleksandr Natalenko
Date: Thu Jun 18 2020 - 05:06:16 EST


Hello, Lorenzo et al.

I'm using MT7612 mini-PCIE cards as both AP in a home server and as a client in
a laptop. The AP works perfectly (after some fixing from your side; thanks for
that!), and so does the client modulo it has issues during system resume.

So, the card is installed in my aging Dell Vostro 3360. The system always
suspends fine, but on resume this can happen occasionally:

===
Äen 15 20:21:07 spock kernel: mt76x2e 0000:01:00.0: MCU message 2 (seq 11) timed out
Äen 15 20:21:07 spock kernel: mt76x2e 0000:01:00.0: MCU message 30 (seq 12) timed out
Äen 15 20:21:07 spock kernel: mt76x2e 0000:01:00.0: MCU message 30 (seq 13) timed out
Äen 15 20:21:07 spock kernel: mt76x2e 0000:01:00.0: Firmware Version: 0.0.00
Äen 15 20:21:07 spock kernel: mt76x2e 0000:01:00.0: Build: 1
Äen 15 20:21:07 spock kernel: mt76x2e 0000:01:00.0: Build Time: 201507311614____
Äen 15 20:21:07 spock kernel: mt76x2e 0000:01:00.0: Firmware running!
Äen 15 20:21:07 spock kernel: ieee80211 phy0: Hardware restart was requested
Äen 15 20:21:08 spock kernel: mt76x2e 0000:01:00.0: MCU message 2 (seq 1) timed out
Äen 15 20:21:09 spock kernel: mt76x2e 0000:01:00.0: MCU message 30 (seq 2) timed out
Äen 15 20:21:10 spock kernel: mt76x2e 0000:01:00.0: MCU message 30 (seq 3) timed out
Äen 15 20:21:10 spock kernel: mt76x2e 0000:01:00.0: Firmware Version: 0.0.00
Äen 15 20:21:10 spock kernel: mt76x2e 0000:01:00.0: Build: 1
Äen 15 20:21:10 spock kernel: mt76x2e 0000:01:00.0: Build Time: 201507311614____
Äen 15 20:21:10 spock kernel: mt76x2e 0000:01:00.0: Firmware running!
Äen 15 20:21:10 spock kernel: ieee80211 phy0: Hardware restart was requested
Äen 15 20:21:11 spock kernel: mt76x2e 0000:01:00.0: MCU message 31 (seq 5) timed out
Äen 15 20:21:12 spock kernel: mt76x2e 0000:01:00.0: MCU message 31 (seq 6) timed out
Äen 15 20:21:13 spock kernel: mt76x2e 0000:01:00.0: MCU message 31 (seq 7) timed out
Äen 15 20:21:14 spock kernel: mt76x2e 0000:01:00.0: MCU message 31 (seq 8) timed out
Äen 15 20:21:15 spock kernel: mt76x2e 0000:01:00.0: MCU message 31 (seq 9) timed out
Äen 15 20:21:16 spock kernel: mt76x2e 0000:01:00.0: MCU message 31 (seq 10) timed out
Äen 15 20:21:17 spock kernel: mt76x2e 0000:01:00.0: MCU message 31 (seq 11) timed out
Äen 15 20:21:17 spock kernel: mt76x2e 0000:01:00.0: Firmware Version: 0.0.00
Äen 15 20:21:17 spock kernel: mt76x2e 0000:01:00.0: Build: 1
Äen 15 20:21:17 spock kernel: mt76x2e 0000:01:00.0: Build Time: 201507311614____
Äen 15 20:21:17 spock kernel: mt76x2e 0000:01:00.0: Firmware running!
Äen 15 20:21:17 spock kernel: ieee80211 phy0: Hardware restart was requested
Äen 15 20:21:18 spock kernel: ------------[ cut here ]------------
Äen 15 20:21:18 spock kernel: WARNING: CPU: 3 PID: 11956 at net/mac80211/util.c:2270 ieee80211_reconfig+0x234/0x1700 [mac80211]
Äen 15 20:21:18 spock kernel: Modules linked in: pl2303 md4 nls_utf8 cifs dns_resolver fscache libdes cmac ccm bridge stp llc nft_ct nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nf_tables tun nfnetlink msr nls_iso8859_1 nls_cp437 vfat fat snd_hda_codec_hdmi mt76x2e snd_hda_codec_cirrus snd_hda_codec_generic mt76x2_common mt76x02_lib mt76 snd_hda_intel intel_rapl_msr snd_intel_dspcfg mei_hdcp dell_wmi iTCO_wdt mac80211 iTCO_vendor_support intel_rapl_common sparse_keymap wmi_bmof snd_hda_codec x86_pkg_temp_thermal rtsx_usb_ms intel_powerclamp dell_laptop coretemp ledtrig_audio dell_smbios memstick kvm_intel kvm snd_hda_core dell_wmi_descriptor dcdbas snd_hwdep dell_smm_hwmon cfg80211 snd_pcm irqbypass mousedev intel_cstate psmouse joydev intel_uncore intel_rapl_perf input_leds snd_timer i2c_i801 snd mei_me alx rfkill mei libarc4 lpc_ich mdio soundcore battery wmi evdev mac_hid dell_smo8800 ac tcp_bbr crypto_user ip_tables x_tables xfs dm_thin_pool dm_persistent_data dm_bio_prison dm_bufio libcrc32c
Äen 15 20:21:18 spock kernel: crc32c_generic dm_crypt hid_logitech_hidpp hid_logitech_dj hid_generic usbhid hid rtsx_usb_sdmmc mmc_core rtsx_usb dm_mod crct10dif_pclmul crc32_pclmul crc32c_intel raid10 ghash_clmulni_intel serio_raw atkbd libps2 md_mod aesni_intel crypto_simd cryptd glue_helper xhci_pci xhci_hcd ehci_pci ehci_hcd i8042 serio i915 intel_gtt i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops cec rc_core drm agpgart
Äen 15 20:21:18 spock kernel: CPU: 3 PID: 11956 Comm: kworker/3:1 Not tainted 5.7.0-pf2 #1
Äen 15 20:21:18 spock kernel: Hardware name: Dell Inc. Vostro 3360/0F5DWF, BIOS A18 09/25/2013
Äen 15 20:21:18 spock kernel: Workqueue: events_freezable ieee80211_restart_work [mac80211]
Äen 15 20:21:18 spock kernel: RIP: 0010:ieee80211_reconfig+0x234/0x1700 [mac80211]
Äen 15 20:21:18 spock kernel: Code: 83 b8 0b 00 00 83 e0 fd 83 f8 04 74 e6 48 8b 83 90 04 00 00 a8 01 74 db 48 89 de 48 89 ef e8 03 dc fb ff 41 89 c7 85 c0 74 c9 <0f> 0b 48 8b 5b 08 4c 8b 24 24 48 3b 1c 24 75 12 e9 51 fe ff ff 48
Äen 15 20:21:18 spock kernel: RSP: 0018:ffffb803c23ffdf0 EFLAGS: 00010286
Äen 15 20:21:18 spock kernel: RAX: 00000000fffffff0 RBX: ffff9595a7564900 RCX: 0000000000000008
Äen 15 20:21:18 spock kernel: RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000100
Äen 15 20:21:18 spock kernel: RBP: ffff9595a7ec07e0 R08: 0000000000000000 R09: 0000000000000001
Äen 15 20:21:18 spock kernel: R10: 0000000000000001 R11: 0000000000000000 R12: ffff9595a7ec18d0
Äen 15 20:21:18 spock kernel: R13: 00000000ffffffff R14: 0000000000000000 R15: 00000000fffffff0
Äen 15 20:21:18 spock kernel: FS: 0000000000000000(0000) GS:ffff9595af2c0000(0000) knlGS:0000000000000000
Äen 15 20:21:18 spock kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Äen 15 20:21:18 spock kernel: CR2: 000055e56d7de000 CR3: 000000042200a001 CR4: 00000000001706e0
Äen 15 20:21:18 spock kernel: Call Trace:
Äen 15 20:21:18 spock kernel: ieee80211_restart_work+0xb7/0xe0 [mac80211]
Äen 15 20:21:18 spock kernel: process_one_work+0x1d4/0x3c0
Äen 15 20:21:18 spock kernel: worker_thread+0x228/0x470
Äen 15 20:21:18 spock kernel: ? process_one_work+0x3c0/0x3c0
Äen 15 20:21:18 spock kernel: kthread+0x19c/0x1c0
Äen 15 20:21:18 spock kernel: ? __kthread_init_worker+0x30/0x30
Äen 15 20:21:18 spock kernel: ret_from_fork+0x35/0x40
Äen 15 20:21:18 spock kernel: ---[ end trace d8e4d40f48014382 ]---
Äen 15 20:21:18 spock kernel: ------------[ cut here ]------------
Äen 15 20:21:18 spock kernel: wlp1s0: Failed check-sdata-in-driver check, flags: 0x0
Äen 15 20:21:18 spock kernel: WARNING: CPU: 3 PID: 11956 at net/mac80211/driver-ops.h:17 drv_remove_interface+0x11f/0x130 [mac80211]
Äen 15 20:21:18 spock kernel: Modules linked in: pl2303 md4 nls_utf8 cifs dns_resolver fscache libdes cmac ccm bridge stp llc nft_ct nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nf_tables tun nfnetlink msr nls_iso8859_1 nls_cp437 vfat fat snd_hda_codec_hdmi mt76x2e snd_hda_codec_cirrus snd_hda_codec_generic mt76x2_common mt76x02_lib mt76 snd_hda_intel intel_rapl_msr snd_intel_dspcfg mei_hdcp dell_wmi iTCO_wdt mac80211 iTCO_vendor_support intel_rapl_common sparse_keymap wmi_bmof snd_hda_codec x86_pkg_temp_thermal rtsx_usb_ms intel_powerclamp dell_laptop coretemp ledtrig_audio dell_smbios memstick kvm_intel kvm snd_hda_core dell_wmi_descriptor dcdbas snd_hwdep dell_smm_hwmon cfg80211 snd_pcm irqbypass mousedev intel_cstate psmouse joydev intel_uncore intel_rapl_perf input_leds snd_timer i2c_i801 snd mei_me alx rfkill mei libarc4 lpc_ich mdio soundcore battery wmi evdev mac_hid dell_smo8800 ac tcp_bbr crypto_user ip_tables x_tables xfs dm_thin_pool dm_persistent_data dm_bio_prison dm_bufio libcrc32c
Äen 15 20:21:18 spock kernel: crc32c_generic dm_crypt hid_logitech_hidpp hid_logitech_dj hid_generic usbhid hid rtsx_usb_sdmmc mmc_core rtsx_usb dm_mod crct10dif_pclmul crc32_pclmul crc32c_intel raid10 ghash_clmulni_intel serio_raw atkbd libps2 md_mod aesni_intel crypto_simd cryptd glue_helper xhci_pci xhci_hcd ehci_pci ehci_hcd i8042 serio i915 intel_gtt i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops cec rc_core drm agpgart
Äen 15 20:21:18 spock kernel: CPU: 3 PID: 11956 Comm: kworker/3:1 Tainted: G W 5.7.0-pf2 #1
Äen 15 20:21:18 spock kernel: Hardware name: Dell Inc. Vostro 3360/0F5DWF, BIOS A18 09/25/2013
Äen 15 20:21:18 spock kernel: Workqueue: events_freezable ieee80211_restart_work [mac80211]
Äen 15 20:21:18 spock kernel: RIP: 0010:drv_remove_interface+0x11f/0x130 [mac80211]
Äen 15 20:21:18 spock kernel: Code: a0 27 d2 da e9 4b ff ff ff 48 8b 86 78 04 00 00 48 8d b6 98 04 00 00 48 c7 c7 e8 1f f7 c0 48 85 c0 48 0f 45 f0 e8 59 fe db da <0f> 0b 5b 5d 41 5c c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00
Äen 15 20:21:18 spock kernel: RSP: 0018:ffffb803c23ffc80 EFLAGS: 00010282
Äen 15 20:21:18 spock kernel: RAX: 0000000000000000 RBX: ffff9595a7564900 RCX: 0000000000000000
Äen 15 20:21:18 spock kernel: RDX: 0000000000000001 RSI: 0000000000000082 RDI: 00000000ffffffff
Äen 15 20:21:18 spock kernel: RBP: ffff9595a7ec1930 R08: 00000000000004b6 R09: 0000000000000001
Äen 15 20:21:18 spock kernel: R10: 0000000000000001 R11: 0000000000006f08 R12: ffff9595a7ec1000
Äen 15 20:21:18 spock kernel: R13: ffff9595a75654b8 R14: ffff9595a7ec0ca0 R15: ffff9595a7ec07e0
Äen 15 20:21:18 spock kernel: FS: 0000000000000000(0000) GS:ffff9595af2c0000(0000) knlGS:0000000000000000
Äen 15 20:21:18 spock kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Äen 15 20:21:18 spock kernel: CR2: 000055e56d7de000 CR3: 000000042200a001 CR4: 00000000001706e0
Äen 15 20:21:18 spock kernel: Call Trace:
Äen 15 20:21:18 spock kernel: ieee80211_do_stop+0x5af/0x8c0 [mac80211]
Äen 15 20:21:18 spock kernel: ieee80211_stop+0x16/0x20 [mac80211]
Äen 15 20:21:18 spock kernel: __dev_close_many+0xaa/0x120
Äen 15 20:21:18 spock kernel: dev_close_many+0xa1/0x2b0
Äen 15 20:21:18 spock kernel: dev_close+0x6d/0x90
Äen 15 20:21:18 spock kernel: cfg80211_shutdown_all_interfaces+0x71/0xd0 [cfg80211]
Äen 15 20:21:18 spock kernel: ieee80211_reconfig+0xa2/0x1700 [mac80211]
Äen 15 20:21:18 spock kernel: ieee80211_restart_work+0xb7/0xe0 [mac80211]
Äen 15 20:21:18 spock kernel: process_one_work+0x1d4/0x3c0
Äen 15 20:21:18 spock kernel: worker_thread+0x228/0x470
Äen 15 20:21:18 spock kernel: ? process_one_work+0x3c0/0x3c0
Äen 15 20:21:18 spock kernel: kthread+0x19c/0x1c0
Äen 15 20:21:18 spock kernel: ? __kthread_init_worker+0x30/0x30
Äen 15 20:21:18 spock kernel: ret_from_fork+0x35/0x40
Äen 15 20:21:18 spock kernel: ---[ end trace d8e4d40f48014383 ]---
===

The Wi-Fi becomes unusable from this point. If I `modprobe -r` the "mt76x2e" module
after this splat, the system hangs completely.

If the system resumes fine, the resume itself takes quite some time (more than
10 seconds).

I've found a workaround for this, though. It seems the system behaves fine if I
do `modprobe -r mt76x2e` before it goes to sleep, and then `modprobe mt76x2e`
after resume. Also, the resume time improves greatly.

I cannot say if it is some regression or not. I've installed the card
just recently, and used it with v5.7 kernel series only.

Do you have any idea what could go wrong and how to approach the issue?

Thanks.

--
Best regards,
Oleksandr Natalenko (post-factum)
Principal Software Maintenance Engineer