Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

AP stops with mt76x2u: error: mt76x02u_mcu_wait_resp failed with -110 #405

Open
bjlockie opened this issue May 31, 2020 · 86 comments
Open

Comments

@bjlockie
Copy link

bjlockie commented May 31, 2020

My AP usually stops when I update all the packages on my Android phone that were installed via google play.
I tried to reproduce it with iperf (client on my phone and server on my desktop).
It happened once but works alot.
I haven't found a way to reproduce it on demand.
I use a Raspberry Pi4 with an imagebuilder 2020-05-14 build of openwrt
and an Alfa AWUS036ACM (Mediatek MT7612U).
I have it set as a 5GHz access point.

I found this bug report that might be related:
mt76x2u mac specific condition occurred #403

# dmesg
[1461031.326341] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110

After remove and insert USB device:

# dmesg
[1461528.333182] usb 2-1: USB disconnect, device number 14
[1461528.555583] mt76x2u 2-1:1.0: mac specific condition occurred
[1461528.665062] mt76x2u 2-1:1.0: mac specific condition occurred
[1461528.765063] mt76x2u 2-1:1.0: timed out waiting for pending tx
[1461528.771773] br-lan: port 2(wlan12) entered disabled state
[1461528.782735] device wlan12 left promiscuous mode
[1461528.787501] br-lan: port 2(wlan12) entered disabled state
[1461530.265357] usb 2-1: new SuperSpeed Gen 1 USB device number 15 using xhci_hcd
[1461530.290773] usb 2-1: New USB device found, idVendor=0e8d, idProduct=7612, bcdDevice= 1.00
[1461530.299179] usb 2-1: New USB device strings: Mfr=2, Product=3, SerialNumber=4
[1461530.306529] usb 2-1: Product: Wireless 
[1461530.310568] usb 2-1: Manufacturer: MediaTek Inc.
[1461530.315387] usb 2-1: SerialNumber: 000000000
[1461530.453673] usb 2-1: reset SuperSpeed Gen 1 USB device number 15 using xhci_hcd
[1461530.483230] mt76x2u 2-1:1.0: ASIC revision: 76120044
[1461530.521613] mt76x2u 2-1:1.0: ROM patch build: 20141115060606a
[1461530.696481] mt76x2u 2-1:1.0: Firmware Version: 0.0.00
[1461530.701755] mt76x2u 2-1:1.0: Build: 1
[1461530.705606] mt76x2u 2-1:1.0: Build Time: 201507311614____
[1461531.521298] ieee80211 phy13: Selected rate control algorithm 'minstrel_ht'

I reset USB device from Luci and it works.

Any ideas on how to reproduce it?

@amk316
Copy link

amk316 commented Jun 2, 2020

[ 12.917747] mt7615e 0000:02:00.0: Invalid firmware
5.4.42+2020-05-30-85c51608-2
RE650 AP stop working!!!

@bjlockie
Copy link
Author

bjlockie commented Jun 2, 2020

I wasn't even using it and it died again.

Tue Jun  2 01:53:03 2020 kern.err kernel: [1581056.533998] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Tue Jun  2 01:53:24 2020 daemon.notice hostapd: wlan13: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Tue Jun  2 01:58:27 2020 daemon.info hostapd: wlan13: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)

@bjlockie
Copy link
Author

bjlockie commented Jun 2, 2020

[ 12.917747] mt7615e 0000:02:00.0: Invalid firmware
5.4.42+2020-05-30-85c51608-2
RE650 AP stop working!!!

Sorry I don't understand.
Are you saying I need to install firmware?

@bjlockie
Copy link
Author

bjlockie commented Jun 2, 2020

I upgraded to 2020-06-02.

Firmware Version: OpenWrt SNAPSHOT r13427-a47acae319 / LuCI Master git-20.154.25027-09014e0
Kernel Version: 5.4.42

@bjlockie
Copy link
Author

bjlockie commented Jun 3, 2020

It happened again but it seems to have more information in the system log.
It upgraded 1 thing from Google Play automatically overnight so I think it was that.

Wed Jun  3 06:42:20 2020 kern.err kernel: [53501.400415] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Wed Jun  3 06:42:45 2020 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Wed Jun  3 06:48:59 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 07:00:08 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 07:07:37 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 07:13:52 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 07:21:26 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 07:28:25 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 07:35:56 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 07:44:52 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 07:51:31 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 08:01:38 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 08:10:34 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 08:14:16 2020 daemon.notice netifd: Internet (906): udhcpc: sending renew to 7.127.0.77
Wed Jun  3 08:17:17 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 08:23:52 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 08:32:18 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 08:38:59 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 08:48:24 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 09:01:17 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 09:09:50 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 09:16:33 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 09:24:27 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 09:31:12 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 09:37:30 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 09:46:33 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Jun  3 10:02:02 2020 kern.info kernel: [65483.010128] usb 2-1: USB disconnect, device number 2
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.020039] ------------[ cut here ]------------
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.027262] STA xx:xx:xx:xx:xx:xx AC 2 txq pending airtime underflow: 4294967192, 104
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.027336] WARNING: CPU: 0 PID: 0 at backports-5.7-rc3-1/net/mac80211/sta_info.c:1929 ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.051406] Modules linked in: pppoe ppp_async iptable_nat brcmfmac xt_state xt_nat xt_conntrack xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT pppox ppp_generic nf_nat nf_flow_table_hw nf_flow_table nf_conntrack_rtcache nf_conntrack_netlink nf_conntrack mt76x2u mt76x2e mt76x2_common mt76x02_usb mt76x02_lib mt7603e mt76_usb mt76 mac80211 ipt_REJECT cfg80211 xt_time xt_tcpudp xt_multiport xt_mark xt_mac xt_limit xt_comment xt_TCPMSS xt_LOG usbnet usbhid slhc r8152 nfnetlink nf_reject_ipv4 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_filter ip_tables hid_generic crc_ccitt compat brcmutil snd_bcm2835(C) hid evdev ledtrig_heartbeat nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 snd_rawmidi snd_seq_device snd_pcm_oss snd_pcm_dmaengine snd_pcm snd_timer snd_mixer_oss snd_hwdep snd_compress snd soundcore nls_utf8 vfat fat nls_iso8859_1 nls_cp437
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.141794] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G         C        5.4.42 #0
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.151052] Hardware name: Raspberry Pi 4 Model B Rev 1.1 (DT)
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.158817] pstate: 60400005 (nZCv daif +PAN -UAO)
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.165514] pc : ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.174486] lr : ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.183421] sp : ffffffc010003cc0
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.188605] x29: ffffffc010003cc0 x28: ffffff8038504980
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.195800] x27: ffffff8038503bf8 x26: ffffffc0100a6a34
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.202991] x25: ffffff8037462128 x24: 0000000000000000
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.210171] x23: 00000000ffffff98 x22: 0000000000000002
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.217270] x21: ffffff80368345d8 x20: 0000000000000068
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.224424] x19: ffffff8038500fe0 x18: 0000000000000000
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.231558] x17: 0000000000000000 x16: ffffffc0136c8b98
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.238677] x15: 0000000000000020 x14: 363934393234203a
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.245785] x13: 776f6c667265646e x12: 7520656d69747269
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.252887] x11: 6120676e69646e65 x10: 7020717874203220
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.260004] x9 : 43412032663a3738 x8 : 3a63393a61633a39
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.267064] x7 : 633a656120415453 x6 : ffffffc010a001a9
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.274175] x5 : 00ffffffffffffff x4 : 0000000000000000
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.281278] x3 : 0000000000000000 x2 : 00000000ffffffff
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.288381] x1 : ffffffc02a811000 x0 : 0000000000000049
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.295458] Call trace:
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.299652]  ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.308135]  ieee80211_report_low_ack+0x1fc/0x490 [mac80211]
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.315540]  ieee80211_free_txskb+0x18/0x30 [mac80211]
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.322407]  mt76_tx_complete_skb+0xd0/0xe8 [mt76]
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.328912]  mt76x02u_tx_complete_skb+0x6c/0x80 [mt76x02_usb]
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.336351]  mt76u_queues_deinit+0x288/0xbc8 [mt76_usb]
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.343276]  tasklet_action_common.isra.19+0xac/0x150
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.349965]  tasklet_action+0x24/0x30
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.355317]  __do_softirq+0x11c/0x230
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.360664]  irq_exit+0x9c/0xb8
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.365400]  __handle_domain_irq+0x64/0xb8
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.371184]  gic_handle_irq+0x5c/0xb8
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.376503]  el1_irq+0xf0/0x1c0
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.381250]  arch_cpu_idle+0x10/0x18
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.386465]  do_idle+0x1e4/0x258
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.391334]  cpu_startup_entry+0x24/0x28
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.396903]  rest_init+0xb0/0xbc
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.401758]  arch_call_rest_init+0xc/0x14
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.407406]  start_kernel+0x3c4/0x3dc
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.412689] ---[ end trace eb48540368ce9fe8 ]---
Wed Jun  3 10:02:02 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Wed Jun  3 10:02:02 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Wed Jun  3 10:02:02 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Wed Jun  3 10:02:02 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Wed Jun  3 10:02:02 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Wed Jun  3 10:02:02 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Wed Jun  3 10:02:02 2020 kern.err kernel: [65483.636559] mt76x2u 2-1:1.0: mac specific condition occurred
Wed Jun  3 10:02:02 2020 kern.err kernel: [65483.746033] mt76x2u 2-1:1.0: mac specific condition occurred
Wed Jun  3 10:02:02 2020 kern.err kernel: [65483.846021] mt76x2u 2-1:1.0: timed out waiting for pending tx
Wed Jun  3 10:02:02 2020 daemon.notice netifd: Network device 'wlan0' link is down
Wed Jun  3 10:02:02 2020 kern.info kernel: [65483.854466] br-lan: port 2(wlan0) entered disabled state
Wed Jun  3 10:02:02 2020 kern.info kernel: [65483.864692] device wlan0 left promiscuous mode
Wed Jun  3 10:02:02 2020 kern.info kernel: [65483.870325] br-lan: port 2(wlan0) entered disabled state
Wed Jun  3 10:02:02 2020 daemon.err hostapd: Failed to set beacon parameters
Wed Jun  3 10:02:02 2020 daemon.notice hostapd: wlan0: INTERFACE-DISABLED
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.959048] ------------[ cut here ]------------
Wed Jun  3 10:02:02 2020 kern.warn kernel: [65483.966472] Have pending ack frames!
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65483.972689] WARNING: CPU: 0 PID: 4020 at backports-5.7-rc3-1/net/mac80211/main.c:1396 ieee80211_free_hw+0xe8/0xf0 [mac80211]
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65483.985440] Modules linked in: pppoe ppp_async iptable_nat brcmfmac xt_state xt_nat xt_conntrack xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT pppox ppp_generic nf_nat nf_flow_table_hw nf_flow_table nf_conntrack_rtcache nf_conntrack_netlink nf_conntrack mt76x2u mt76x2e mt76x2_common mt76x02_usb mt76x02_lib mt7603e mt76_usb mt76 mac80211 ipt_REJECT cfg80211 xt_time xt_tcpudp xt_multiport xt_mark xt_mac xt_limit xt_comment xt_TCPMSS xt_LOG usbnet usbhid slhc r8152 nfnetlink nf_reject_ipv4 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_filter ip_tables hid_generic crc_ccitt compat brcmutil snd_bcm2835(C) hid evdev ledtrig_heartbeat nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 snd_rawmidi snd_seq_device snd_pcm_oss snd_pcm_dmaengine snd_pcm snd_timer snd_mixer_oss snd_hwdep snd_compress snd soundcore nls_utf8 vfat fat nls_iso8859_1 nls_cp437
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.072074] CPU: 0 PID: 4020 Comm: kworker/0:1 Tainted: G        WC        5.4.42 #0
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.080956] Hardware name: Raspberry Pi 4 Model B Rev 1.1 (DT)
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.087936] Workqueue: usb_hub_wq hub_event
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.093241] pstate: 40400005 (nZcv daif +PAN -UAO)
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.099132] pc : ieee80211_free_hw+0xe8/0xf0 [mac80211]
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.105469] lr : ieee80211_free_hw+0xe8/0xf0 [mac80211]
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.111788] sp : ffffffc0159539e0
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.116166] x29: ffffffc0159539e0 x28: 0000000000000000
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.122590] x27: ffffffc008a79000 x26: ffffff80393c88a0
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.129015] x25: ffffff80393c8800 x24: ffffff8038502610
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.135422] x23: ffffffc0089919a8 x22: 0000000000000000
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.141850] x21: 000000007fffffff x20: 0000000000000000
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.148274] x19: ffffff8039852e00 x18: 0000000000000000
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.154701] x17: 0000000000000000 x16: ffffffc0136c8b98
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.161119] x15: 0000000000000020 x14: 0000000000001c80
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.167491] x13: 0000000000000000 x12: 0000000000000001
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.173914] x11: 00000000ffffffff x10: ffffff80391933b0
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.180324] x9 : ffffff80391933b0 x8 : 0000000000000001
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.186738] x7 : 0000000000000008 x6 : 0000000000000001
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.193136] x5 : 0000000000000000 x4 : 0000000000000000
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.199527] x3 : 0000000000000000 x2 : ffffff803b199258
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.205924] x1 : ffffffc02a811000 x0 : 0000000000000018
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.212314] Call trace:
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.215801]  ieee80211_free_hw+0xe8/0xf0 [mac80211]
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.221741]  idr_for_each+0x54/0xd0
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.226291]  ieee80211_free_hw+0x34/0xf0 [mac80211]
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.232228]  0xffffffc008a760dc
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.236424]  usb_unbind_interface+0x6c/0x210
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.241742]  device_release_driver_internal+0xf0/0x1b8
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.247939]  device_release_driver+0x14/0x20
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.253272]  bus_remove_device+0x118/0x128
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.258430]  device_del+0x144/0x338
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.262974]  usb_disable_device+0x8c/0x1d0
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.268130]  usb_disconnect+0xb4/0x2d8
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.272940]  hub_event+0xbc4/0x11e8
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.277500]  process_one_work+0x1ec/0x378
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.282534]  worker_thread+0x48/0x4d0
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.287267]  kthread+0x120/0x128
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.291570]  ret_from_fork+0x10/0x18
Wed Jun  3 10:02:03 2020 kern.warn kernel: [65484.296208] ---[ end trace eb48540368ce9fe9 ]---
Wed Jun  3 10:02:05 2020 kern.info kernel: [65486.974381] usb 2-1: new SuperSpeed Gen 1 USB device number 4 using xhci_hcd
Wed Jun  3 10:02:06 2020 kern.info kernel: [65487.003789] usb 2-1: New USB device found, idVendor=0e8d, idProduct=7612, bcdDevice= 1.00
Wed Jun  3 10:02:06 2020 kern.info kernel: [65487.014636] usb 2-1: New USB device strings: Mfr=2, Product=3, SerialNumber=4
Wed Jun  3 10:02:06 2020 kern.info kernel: [65487.024455] usb 2-1: Product: Wireless
Wed Jun  3 10:02:06 2020 kern.info kernel: [65487.030947] usb 2-1: Manufacturer: MediaTek Inc.
Wed Jun  3 10:02:06 2020 kern.info kernel: [65487.038213] usb 2-1: SerialNumber: 000000000
Wed Jun  3 10:02:06 2020 kern.info kernel: [65487.178836] usb 2-1: reset SuperSpeed Gen 1 USB device number 4 using xhci_hcd
Wed Jun  3 10:02:06 2020 kern.info kernel: [65487.208279] mt76x2u 2-1:1.0: ASIC revision: 76120044
Wed Jun  3 10:02:06 2020 kern.info kernel: [65487.249563] mt76x2u 2-1:1.0: ROM patch build: 20141115060606a
Wed Jun  3 10:02:06 2020 kern.info kernel: [65487.426434] mt76x2u 2-1:1.0: Firmware Version: 0.0.00
Wed Jun  3 10:02:06 2020 kern.info kernel: [65487.433997] mt76x2u 2-1:1.0: Build: 1
Wed Jun  3 10:02:06 2020 kern.info kernel: [65487.438686] mt76x2u 2-1:1.0: Build Time: 201507311614____
Wed Jun  3 10:02:07 2020 kern.debug kernel: [65488.249894] ieee80211 phy2: Selected rate control algorithm 'minstrel_ht'
Wed Jun  3 10:02:07 2020 daemon.notice hostapd: wlan0: INTERFACE-ENABLED
Wed Jun  3 10:02:12 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:02:38 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:02:42 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:02:42 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:02:43 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:02:43 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:02:46 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:03 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:03 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:12 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:12 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:12 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:23 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:23 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:25 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:25 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:25 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:42 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:42 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:42 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:42 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:42 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:03:43 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:04:11 2020 daemon.err uhttpd[808]: luci: accepted login on /admin/network/wireless for root from 192.168.1.12
Wed Jun  3 10:04:12 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:04:12 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:04:22 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:04:22 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:04:22 2020 daemon.notice hostapd: handle_probe_req: send failed
Wed Jun  3 10:04:22 2020 daemon.notice hostapd: Remove interface 'wlan0'
Wed Jun  3 10:04:22 2020 daemon.notice hostapd: wlan0: interface state ENABLED->DISABLED
Wed Jun  3 10:04:22 2020 daemon.notice hostapd: wlan0: AP-DISABLED
Wed Jun  3 10:04:22 2020 daemon.notice hostapd: wlan0: CTRL-EVENT-TERMINATING
Wed Jun  3 10:04:22 2020 daemon.notice hostapd: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
Wed Jun  3 10:04:22 2020 daemon.notice hostapd: nl80211: Failed to remove interface wlan0 from bridge br-lan: Invalid argument
Wed Jun  3 10:04:23 2020 daemon.notice hostapd: Configuration file: /var/run/hostapd-phy2.conf (phy wlan2) --> new PHY
Wed Jun  3 10:04:23 2020 kern.info kernel: [65624.862262] br-lan: port 2(wlan2) entered blocking state
Wed Jun  3 10:04:23 2020 kern.info kernel: [65624.869687] br-lan: port 2(wlan2) entered disabled state
Wed Jun  3 10:04:23 2020 kern.info kernel: [65624.869970] device wlan2 entered promiscuous mode
Wed Jun  3 10:04:23 2020 daemon.notice hostapd: wlan2: interface state UNINITIALIZED->HT_SCAN
Wed Jun  3 10:04:23 2020 daemon.notice netifd: radio1 (4220): WARNING (wireless_add_process): executable path /usr/sbin/wpad does not match process  path (/proc/exe)
Wed Jun  3 10:04:23 2020 daemon.notice netifd: radio1 (4220): Command failed: Invalid argument
Wed Jun  3 10:04:26 2020 kern.info kernel: [65627.007180] IPv6: ADDRCONF(NETDEV_CHANGE): wlan2: link becomes ready
Wed Jun  3 10:04:26 2020 kern.info kernel: [65627.015609] br-lan: port 2(wlan2) entered blocking state
Wed Jun  3 10:04:26 2020 kern.info kernel: [65627.022483] br-lan: port 2(wlan2) entered forwarding state
Wed Jun  3 10:04:26 2020 daemon.notice netifd: Network device 'wlan2' link is up
Wed Jun  3 10:04:26 2020 daemon.notice hostapd: wlan2: interface state HT_SCAN->ENABLED
Wed Jun  3 10:04:26 2020 daemon.notice hostapd: wlan2: AP-ENABLED
Wed Jun  3 10:04:56 2020 daemon.info hostapd: wlan2: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Wed Jun  3 10:04:57 2020 daemon.info hostapd: wlan2: STA xx:xx:xx:xx:xx:xx IEEE 802.11: associated (aid 1)
Wed Jun  3 10:04:57 2020 daemon.notice hostapd: wlan2: AP-STA-CONNECTED xx:xx:xx:xx:xx:xx
Wed Jun  3 10:04:57 2020 daemon.info hostapd: wlan2: STA xx:xx:xx:xx:xx:xx WPA: pairwise key handshake completed (RSN)
Powered by LuCI Master (git-20.154.25027-09014e0) / OpenWrt

Kernel log:

[53501.400415] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110
[65483.010128] usb 2-1: USB disconnect, device number 2
[65483.020039] ------------[ cut here ]------------
[65483.027262] STA xx:xx:xx:xx:xx:xx AC 2 txq pending airtime underflow: 4294967192, 104
[65483.027336] WARNING: CPU: 0 PID: 0 at backports-5.7-rc3-1/net/mac80211/sta_info.c:1929 ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
[65483.051406] Modules linked in: pppoe ppp_async iptable_nat brcmfmac xt_state xt_nat xt_conntrack xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT pppox ppp_generic nf_nat nf_flow_table_hw nf_flow_table nf_conntrack_rtcache nf_conntrack_netlink nf_conntrack mt76x2u mt76x2e mt76x2_common mt76x02_usb mt76x02_lib mt7603e mt76_usb mt76 mac80211 ipt_REJECT cfg80211 xt_time xt_tcpudp xt_multiport xt_mark xt_mac xt_limit xt_comment xt_TCPMSS xt_LOG usbnet usbhid slhc r8152 nfnetlink nf_reject_ipv4 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_filter ip_tables hid_generic crc_ccitt compat brcmutil snd_bcm2835(C) hid evdev ledtrig_heartbeat nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 snd_rawmidi snd_seq_device snd_pcm_oss snd_pcm_dmaengine snd_pcm snd_timer snd_mixer_oss snd_hwdep snd_compress snd soundcore nls_utf8 vfat fat nls_iso8859_1 nls_cp437
[65483.141794] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G         C        5.4.42 #0
[65483.151052] Hardware name: Raspberry Pi 4 Model B Rev 1.1 (DT)
[65483.158817] pstate: 60400005 (nZCv daif +PAN -UAO)
[65483.165514] pc : ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
[65483.174486] lr : ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
[65483.183421] sp : ffffffc010003cc0
[65483.188605] x29: ffffffc010003cc0 x28: ffffff8038504980 
[65483.195800] x27: ffffff8038503bf8 x26: ffffffc0100a6a34 
[65483.202991] x25: ffffff8037462128 x24: 0000000000000000 
[65483.210171] x23: 00000000ffffff98 x22: 0000000000000002 
[65483.217270] x21: ffffff80368345d8 x20: 0000000000000068 
[65483.224424] x19: ffffff8038500fe0 x18: 0000000000000000 
[65483.231558] x17: 0000000000000000 x16: ffffffc0136c8b98 
[65483.238677] x15: 0000000000000020 x14: 363934393234203a 
[65483.245785] x13: 776f6c667265646e x12: 7520656d69747269 
[65483.252887] x11: 6120676e69646e65 x10: 7020717874203220 
[65483.260004] x9 : 43412032663a3738 x8 : 3a63393a61633a39 
[65483.267064] x7 : 633a656120415453 x6 : ffffffc010a001a9 
[65483.274175] x5 : 00ffffffffffffff x4 : 0000000000000000 
[65483.281278] x3 : 0000000000000000 x2 : 00000000ffffffff 
[65483.288381] x1 : ffffffc02a811000 x0 : 0000000000000049 
[65483.295458] Call trace:
[65483.299652]  ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
[65483.308135]  ieee80211_report_low_ack+0x1fc/0x490 [mac80211]
[65483.315540]  ieee80211_free_txskb+0x18/0x30 [mac80211]
[65483.322407]  mt76_tx_complete_skb+0xd0/0xe8 [mt76]
[65483.328912]  mt76x02u_tx_complete_skb+0x6c/0x80 [mt76x02_usb]
[65483.336351]  mt76u_queues_deinit+0x288/0xbc8 [mt76_usb]
[65483.343276]  tasklet_action_common.isra.19+0xac/0x150
[65483.349965]  tasklet_action+0x24/0x30
[65483.355317]  __do_softirq+0x11c/0x230
[65483.360664]  irq_exit+0x9c/0xb8
[65483.365400]  __handle_domain_irq+0x64/0xb8
[65483.371184]  gic_handle_irq+0x5c/0xb8
[65483.376503]  el1_irq+0xf0/0x1c0
[65483.381250]  arch_cpu_idle+0x10/0x18
[65483.386465]  do_idle+0x1e4/0x258
[65483.391334]  cpu_startup_entry+0x24/0x28
[65483.396903]  rest_init+0xb0/0xbc
[65483.401758]  arch_call_rest_init+0xc/0x14
[65483.407406]  start_kernel+0x3c4/0x3dc
[65483.412689] ---[ end trace eb48540368ce9fe8 ]---
[65483.636559] mt76x2u 2-1:1.0: mac specific condition occurred
[65483.746033] mt76x2u 2-1:1.0: mac specific condition occurred
[65483.846021] mt76x2u 2-1:1.0: timed out waiting for pending tx
[65483.854466] br-lan: port 2(wlan0) entered disabled state
[65483.864692] device wlan0 left promiscuous mode
[65483.870325] br-lan: port 2(wlan0) entered disabled state
[65483.959048] ------------[ cut here ]------------
[65483.966472] Have pending ack frames!
[65483.972689] WARNING: CPU: 0 PID: 4020 at backports-5.7-rc3-1/net/mac80211/main.c:1396 ieee80211_free_hw+0xe8/0xf0 [mac80211]
[65483.985440] Modules linked in: pppoe ppp_async iptable_nat brcmfmac xt_state xt_nat xt_conntrack xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT pppox ppp_generic nf_nat nf_flow_table_hw nf_flow_table nf_conntrack_rtcache nf_conntrack_netlink nf_conntrack mt76x2u mt76x2e mt76x2_common mt76x02_usb mt76x02_lib mt7603e mt76_usb mt76 mac80211 ipt_REJECT cfg80211 xt_time xt_tcpudp xt_multiport xt_mark xt_mac xt_limit xt_comment xt_TCPMSS xt_LOG usbnet usbhid slhc r8152 nfnetlink nf_reject_ipv4 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_filter ip_tables hid_generic crc_ccitt compat brcmutil snd_bcm2835(C) hid evdev ledtrig_heartbeat nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 snd_rawmidi snd_seq_device snd_pcm_oss snd_pcm_dmaengine snd_pcm snd_timer snd_mixer_oss snd_hwdep snd_compress snd soundcore nls_utf8 vfat fat nls_iso8859_1 nls_cp437
[65484.072074] CPU: 0 PID: 4020 Comm: kworker/0:1 Tainted: G        WC        5.4.42 #0
[65484.080956] Hardware name: Raspberry Pi 4 Model B Rev 1.1 (DT)
[65484.087936] Workqueue: usb_hub_wq hub_event
[65484.093241] pstate: 40400005 (nZcv daif +PAN -UAO)
[65484.099132] pc : ieee80211_free_hw+0xe8/0xf0 [mac80211]
[65484.105469] lr : ieee80211_free_hw+0xe8/0xf0 [mac80211]
[65484.111788] sp : ffffffc0159539e0
[65484.116166] x29: ffffffc0159539e0 x28: 0000000000000000 
[65484.122590] x27: ffffffc008a79000 x26: ffffff80393c88a0 
[65484.129015] x25: ffffff80393c8800 x24: ffffff8038502610 
[65484.135422] x23: ffffffc0089919a8 x22: 0000000000000000 
[65484.141850] x21: 000000007fffffff x20: 0000000000000000 
[65484.148274] x19: ffffff8039852e00 x18: 0000000000000000 
[65484.154701] x17: 0000000000000000 x16: ffffffc0136c8b98 
[65484.161119] x15: 0000000000000020 x14: 0000000000001c80 
[65484.167491] x13: 0000000000000000 x12: 0000000000000001 
[65484.173914] x11: 00000000ffffffff x10: ffffff80391933b0 
[65484.180324] x9 : ffffff80391933b0 x8 : 0000000000000001 
[65484.186738] x7 : 0000000000000008 x6 : 0000000000000001 
[65484.193136] x5 : 0000000000000000 x4 : 0000000000000000 
[65484.199527] x3 : 0000000000000000 x2 : ffffff803b199258 
[65484.205924] x1 : ffffffc02a811000 x0 : 0000000000000018 
[65484.212314] Call trace:
[65484.215801]  ieee80211_free_hw+0xe8/0xf0 [mac80211]
[65484.221741]  idr_for_each+0x54/0xd0
[65484.226291]  ieee80211_free_hw+0x34/0xf0 [mac80211]
[65484.232228]  0xffffffc008a760dc
[65484.236424]  usb_unbind_interface+0x6c/0x210
[65484.241742]  device_release_driver_internal+0xf0/0x1b8
[65484.247939]  device_release_driver+0x14/0x20
[65484.253272]  bus_remove_device+0x118/0x128
[65484.258430]  device_del+0x144/0x338
[65484.262974]  usb_disable_device+0x8c/0x1d0
[65484.268130]  usb_disconnect+0xb4/0x2d8
[65484.272940]  hub_event+0xbc4/0x11e8
[65484.277500]  process_one_work+0x1ec/0x378
[65484.282534]  worker_thread+0x48/0x4d0
[65484.287267]  kthread+0x120/0x128
[65484.291570]  ret_from_fork+0x10/0x18
[65484.296208] ---[ end trace eb48540368ce9fe9 ]---
[65486.974381] usb 2-1: new SuperSpeed Gen 1 USB device number 4 using xhci_hcd
[65487.003789] usb 2-1: New USB device found, idVendor=0e8d, idProduct=7612, bcdDevice= 1.00
[65487.014636] usb 2-1: New USB device strings: Mfr=2, Product=3, SerialNumber=4
[65487.024455] usb 2-1: Product: Wireless 
[65487.030947] usb 2-1: Manufacturer: MediaTek Inc.
[65487.038213] usb 2-1: SerialNumber: 000000000
[65487.178836] usb 2-1: reset SuperSpeed Gen 1 USB device number 4 using xhci_hcd
[65487.208279] mt76x2u 2-1:1.0: ASIC revision: 76120044
[65487.249563] mt76x2u 2-1:1.0: ROM patch build: 20141115060606a
[65487.426434] mt76x2u 2-1:1.0: Firmware Version: 0.0.00
[65487.433997] mt76x2u 2-1:1.0: Build: 1
[65487.438686] mt76x2u 2-1:1.0: Build Time: 201507311614____
[65488.249894] ieee80211 phy2: Selected rate control algorithm 'minstrel_ht'
[65624.862262] br-lan: port 2(wlan2) entered blocking state
[65624.869687] br-lan: port 2(wlan2) entered disabled state
[65624.869970] device wlan2 entered promiscuous mode
[65627.007180] IPv6: ADDRCONF(NETDEV_CHANGE): wlan2: link becomes ready
[65627.015609] br-lan: port 2(wlan2) entered blocking state
[65627.022483] br-lan: port 2(wlan2) entered forwarding state

@bjlockie
Copy link
Author

bjlockie commented Jun 5, 2020

It's happening without any app updates on my
phone.

Fri Jun  5 02:46:03 2020 kern.err kernel: [212127.005760] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Fri Jun  5 02:51:13 2020 daemon.info hostapd: wlan3: STA xx:xx:xx:xx:xx:xx WPA: group key handshake failed (RSN) after 4 tries
Fri Jun  5 02:51:13 2020 daemon.notice hostapd: wlan3: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Fri Jun  5 02:51:18 2020 daemon.info hostapd: wlan3: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticatedticated due to local deauth request

@bjlockie
Copy link
Author

bjlockie commented Jun 5, 2020

The "interface" name keeps increasing when I reinsert the USB, it is "wlan4" now.

@bjlockie
Copy link
Author

bjlockie commented Jun 5, 2020

Fri Jun  5 17:54:54 2020 daemon.notice hostapd: wlan4: AP-STA-POLL-OK xx:xx:xx:xx:xx:xx
Fri Jun  5 18:00:09 2020 daemon.notice hostapd: wlan4: AP-STA-POLL-OK xx:xx:xx:xx:xx:xx
Fri Jun  5 18:05:16 2020 daemon.notice hostapd: wlan4: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Fri Jun  5 18:05:16 2020 daemon.info hostapd: wlan4: STA xx:xx:xx:xx:xx:xx IEEE 802.11: disassociated due to inactivity
Fri Jun  5 18:05:17 Fri Jun  5 17:49:53 2020 kern.err kernel: [266357.429448] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Fri Jun  5 17:54:54 2020 daemon.notice hostapd: wlan4: AP-STA-POLL-OK xx:xx:xx:xx:xx:xx
Fri Jun  5 18:00:09 2020 daemon.notice hostapd: wlan4: AP-STA-POLL-OK xx:xx:xx:xx:xx:xx
Fri Jun  5 18:05:16 2020 daemon.notice hostapd: wlan4: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Fri Jun  5 18:05:16 2020 daemon.info hostapd: wlan4: STA xx:xx:xx:xx:xx:xx IEEE 802.11: disassociated due to inactivity
Fri Jun  5 18:05:17 2020 daemon.info hostapd: wlan4: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Fri Jun  5 18:27:22 2020 daemon.err uhttpd[808]: luci: accepted login on /admin/status/dmesg for root from 192.168.1.12 daemon.info hostapd: wlan4: STA xx:xx:xx:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Fri Jun  5 18:27:22 2020 daemon.err uhttpd[808]: luci: accepted login on /admin/status/dmesg for root from 192.168.1.12

@bjlockie
Copy link
Author

bjlockie commented Jun 9, 2020

It lasted longer this time.

Tue Jun 9 14:56:14 2020 kern.err kernel: [80673.191388] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110

I noticed luci still says my cellphone is associated.

@bjlockie
Copy link
Author

bjlockie commented Jun 18, 2020

Raspberry Pi 4 Model B Rev 1.1
OpenWrt SNAPSHOT r13575-d64d5ed142 / LuCI Master git-20.166.62203-d0a2566
Kernel Version 5.4.45

Thu Jun 18 11:06:34 2020 kern.err kernel: [220856.547498] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110

@bjlockie
Copy link
Author

Raspberry Pi 4 Model B Rev 1.1
OpenWrt SNAPSHOT r13600-9a477b833a / LuCI Master git-20.171.38103-40f28a1
Kernel Version 5.4.46
[ 8030.297510] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110
[ 9378.238547] usb 2-1: USB disconnect, device number 2
[ 9378.460929] mt76x2u 2-1:1.0: mac specific condition occurred

I've ordered a powered hub to see if that helps.
I'm sure it related to traffic when it gets too busy.
If I can reproduce it on demand then maybe someone can fix it.

@bjlockie
Copy link
Author

bjlockie commented Jun 23, 2020

Raspberry Pi 4 Model B Rev 1.1
OpenWrt SNAPSHOT r13600-9a477b833a / LuCI Master git-20.171.38103-40f28a1
Kernel Version 5.4.46

Mon Jun 22 22:59:45 2020 kern.err kernel: [199929.561062] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Mon Jun 22 22:59:48 2020 kern.err kernel: [199932.185107] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Mon Jun 22 23:04:57 2020 daemon.notice hostapd: wlan1: AP-STA-POLL-OK xx:xx:xx:xx:xx:xx
Mon Jun 22 23:10:00 2020 daemon.notice hostapd: wlan1: AP-STA-POLL-OK xx:xx:xx:xx:xx:xx
Mon Jun 22 23:12:37 2020 kern.info kernel: [200701.505801] usb 2-1: USB disconnect, device number 4
Mon Jun 22 23:12:38 2020 kern.err kernel: [200701.728157] mt76x2u 2-1:1.0: mac specific condition occurred
Mon Jun 22 23:12:38 2020 kern.err kernel: [200701.837666] mt76x2u 2-1:1.0: mac specific condition occurred
Mon Jun 22 23:12:38 2020 kern.err kernel: [200701.937689] mt76x2u 2-1:1.0: timed out waiting for pending tx
Mon Jun 22 23:12:38 2020 kern.info kernel: [200701.944232] br-lan: port 2(wlan1) entered disabled state
Mon Jun 22 23:12:38 2020 daemon.notice netifd: Network device 'wlan1' link is down
Mon Jun 22 23:12:38 2020 kern.info kernel: [200701.955483] device wlan1 left promiscuous mode
Mon Jun 22 23:12:38 2020 kern.info kernel: [200701.960041] br-lan: port 2(wlan1) entered disabled state
Mon Jun 22 23:12:38 2020 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Mon Jun 22 23:12:38 2020 daemon.err hostapd: Failed to set beacon parameters
Mon Jun 22 23:12:38 2020 daemon.notice hostapd: wlan1: INTERFACE-DISABLED
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.058698] ------------[ cut here ]------------
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.063446] Have pending ack frames!
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.067229] WARNING: CPU: 0 PID: 7793 at backports-5.7-rc3-1/net/mac80211/main.c:1396 ieee80211_free_hw+0xe8/0xf0 [mac80211]
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.078540] Modules linked in: pppoe ppp_async iptable_nat xt_state xt_nat xt_conntrack xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT pppox ppp_generic nf_nat nf_flow_table_hw nf_flow_table nf_conntrack_rtcache nf_conntrack_netlink nf_conntrack mt76x2u mt76x2e mt76x2_common mt76x02_usb mt76x02_lib mt7603e mt76_usb mt76 mac80211 ipt_REJECT cfg80211 xt_time xt_tcpudp xt_tcpmss xt_statistic xt_multiport xt_mark xt_mac xt_limit xt_length xt_hl xt_ecn xt_dscp xt_comment xt_TCPMSS xt_LOG xt_HL xt_DSCP xt_CLASSIFY wireguard usbnet usbhid slhc r8152 nf_reject_ipv4 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_filter ipt_ECN ip_tables hid_generic crc_ccitt compat snd_bcm2835(C) hid evdev ledtrig_heartbeat xt_set ip_set_list_set ip_set_hash_netportnet ip_set_hash_netport ip_set_hash_netnet ip_set_hash_netiface ip_set_hash_net ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.078590]  ip_set_bitmap_ip ip_set nfnetlink nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 ip6_udp_tunnel udp_tunnel snd_rawmidi snd_seq_device snd_pcm_oss snd_pcm_dmaengine snd_pcm snd_timer snd_mixer_oss snd_hwdep snd_compress snd soundcore nls_utf8 vfat fat nls_iso8859_1 nls_cp437
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.196304] CPU: 0 PID: 7793 Comm: kworker/0:1 Tainted: G         C        5.4.46 #0
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.204126] Hardware name: Raspberry Pi 4 Model B Rev 1.1 (DT)
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.210047] Workqueue: usb_hub_wq hub_event
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.214309] pstate: 40400005 (nZcv daif +PAN -UAO)
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.219184] pc : ieee80211_free_hw+0xe8/0xf0 [mac80211]
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.224493] lr : ieee80211_free_hw+0xe8/0xf0 [mac80211]
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.229795] sp : ffffffc0184a39e0
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.233186] x29: ffffffc0184a39e0 x28: 0000000000000000
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.238576] x27: ffffffc008bc3000 x26: ffffff80379068a0
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.243965] x25: ffffff8037906800 x24: ffffff80381c2610
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.249355] x23: ffffffc008ae09a8 x22: 0000000000000000
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.254744] x21: 000000007fffffff x20: 0000000000000000
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.260133] x19: ffffff80384a8800 x18: 0000000000000000
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.265522] x17: 0000000000000000 x16: 0000000000000000
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.270911] x15: 0000000000000000 x14: 0720072007200720
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.276300] x13: 0720072007200720 x12: 0720072007200720
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.281689] x11: 0720072007200720 x10: 0720072007200720
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.287078] x9 : 0720072007200720 x8 : 0720072007200720
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.292468] x7 : 0720072007200720 x6 : 0000000000000001
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.297857] x5 : 0000000000000000 x4 : 0000000000000000
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.303246] x3 : 0000000000000000 x2 : ffffff803b199258
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.308635] x1 : ffffffc02a811000 x0 : 0000000000000018
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.314025] Call trace:
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.316555]  ieee80211_free_hw+0xe8/0xf0 [mac80211]
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.321513]  idr_for_each+0x54/0xd0
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.325085]  ieee80211_free_hw+0x34/0xf0 [mac80211]
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.330041]  0xffffffc008bc00dc
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.333260]  usb_unbind_interface+0x6c/0x210
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.337608]  device_release_driver_internal+0xf0/0x1b8
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.342824]  device_release_driver+0x14/0x20
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.347170]  bus_remove_device+0x118/0x128
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.351345]  device_del+0x144/0x338
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.354911]  usb_disable_device+0x8c/0x1d0
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.359085]  usb_disconnect+0xb4/0x2d8
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.362911]  hub_event+0xbc4/0x11e8
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.366479]  process_one_work+0x1ec/0x378
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.370566]  worker_thread+0x48/0x4d0
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.374306]  kthread+0x120/0x128
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.377613]  ret_from_fork+0x10/0x18
Mon Jun 22 23:12:38 2020 kern.warn kernel: [200702.381265] ---[ end trace be2747c07a098ecf ]---

@bjlockie
Copy link
Author

bjlockie commented Jun 23, 2020

I am downloading a big patch for my Android phone and it keeps crashing. :-(

Mon Jun 22 23:31:00 2020 kern.err kernel: [201803.768979] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Mon Jun 22 23:31:10 2020 daemon.notice hostapd: wlan2: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Mon Jun 22 23:34:57 2020 kern.info kernel: [202040.953082] usb 2-1: USB disconnect, device number 5
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202040.960151] ------------[ cut here ]------------
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202040.964887] STA xx:xx:xx:xx:xx:xx AC 2 txq pending airtime underflow: 4294967224, 72
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202040.964986] WARNING: CPU: 0 PID: 0 at backports-5.7-rc3-1/net/mac80211/sta_info.c:1929 ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202040.986020] Modules linked in: pppoe ppp_async iptable_nat xt_state xt_nat xt_conntrack xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT pppox ppp_generic nf_nat nf_flow_table_hw nf_flow_table nf_conntrack_rtcache nf_conntrack_netlink nf_conntrack mt76x2u mt76x2e mt76x2_common mt76x02_usb mt76x02_lib mt7603e mt76_usb mt76 mac80211 ipt_REJECT cfg80211 xt_time xt_tcpudp xt_tcpmss xt_statistic xt_multiport xt_mark xt_mac xt_limit xt_length xt_hl xt_ecn xt_dscp xt_comment xt_TCPMSS xt_LOG xt_HL xt_DSCP xt_CLASSIFY wireguard usbnet usbhid slhc r8152 nf_reject_ipv4 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_filter ipt_ECN ip_tables hid_generic crc_ccitt compat snd_bcm2835(C) hid evdev ledtrig_heartbeat xt_set ip_set_list_set ip_set_hash_netportnet ip_set_hash_netport ip_set_hash_netnet ip_set_hash_netiface ip_set_hash_net ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202040.986070]  ip_set_bitmap_ip ip_set nfnetlink nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 ip6_udp_tunnel udp_tunnel snd_rawmidi snd_seq_device snd_pcm_oss snd_pcm_dmaengine snd_pcm snd_timer snd_mixer_oss snd_hwdep snd_compress snd soundcore nls_utf8 vfat fat nls_iso8859_1 nls_cp437
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.103783] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        WC        5.4.46 #0
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.111170] Hardware name: Raspberry Pi 4 Model B Rev 1.1 (DT)
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.117083] pstate: 60400005 (nZCv daif +PAN -UAO)
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.121957] pc : ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.129090] lr : ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.136216] sp : ffffffc010003cc0
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.139607] x29: ffffffc010003cc0 x28: ffffff8037b9c980
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.144997] x27: ffffff8037b9bbf8 x26: ffffffc0100a6a24
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.150387] x25: ffffff80383a3e28 x24: 0000000000000000
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.155776] x23: 00000000ffffffb8 x22: 0000000000000002
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.161166] x21: ffffff80360ef5d8 x20: 0000000000000048
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.166555] x19: ffffff8037b98fe0 x18: 0000000000000000
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.171944] x17: 0000000000000000 x16: 0000000000000000
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.177333] x15: 0000000000000000 x14: 363934393234203a
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.182722] x13: 776f6c667265646e x12: 7520656d69747269
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.188111] x11: 6120676e69646e65 x10: 7020717874203220
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.193500] x9 : 43412032663a3738 x8 : 3a63393a61633a39
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.198890] x7 : 633a656120415453 x6 : ffffffc010a001a8
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.204279] x5 : 00ffffffffffffff x4 : 0000000000000000
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.209667] x3 : 0000000000000000 x2 : 00000000ffffffff
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.215056] x1 : ffffffc02a811000 x0 : 0000000000000048
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.220446] Call trace:
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.222976]  ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.229761]  ieee80211_report_low_ack+0x1fc/0x490 [mac80211]
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.235504]  ieee80211_free_txskb+0x18/0x30 [mac80211]
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.240722]  mt76_tx_complete_skb+0xd0/0xe8 [mt76]
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.245592]  mt76x02u_tx_complete_skb+0x6c/0x80 [mt76x02_usb]
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.251417]  mt76u_queues_deinit+0x288/0xbc8 [mt76_usb]
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.256727]  tasklet_action_common.isra.19+0xac/0x150
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.261856]  tasklet_action+0x24/0x30
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.265596]  __do_softirq+0x11c/0x230
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.269336]  irq_exit+0x9c/0xb8
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.272557]  __handle_domain_irq+0x64/0xb8
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.276730]  gic_handle_irq+0x5c/0xb8
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.280469]  el1_irq+0xf0/0x1c0
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.283689]  arch_cpu_idle+0x10/0x18
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.287344]  do_idle+0x1e4/0x258
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.290649]  cpu_startup_entry+0x20/0x28
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.294652]  rest_init+0xb0/0xbc
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.297958]  arch_call_rest_init+0xc/0x14
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.302044]  start_kernel+0x3c4/0x3dc
Mon Jun 22 23:34:57 2020 kern.warn kernel: [202041.305783] ---[ end trace be2747c07a098ed0 ]---

@bjlockie
Copy link
Author

bjlockie commented Jun 23, 2020

Mon Jun 22 23:40:28 2020 kern.err kernel: [202371.779053] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Mon Jun 22 23:41:18 2020 daemon.notice hostapd: wlan3: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Mon Jun 22 23:42:58 2020 daemon.info hostapd: wlan3: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Mon Jun 22 23:42:58 2020 daemon.info hostapd: wlan3: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Mon Jun 22 23:42:58 2020 kern.info kernel: [202522.557589] usb 2-1: USB disconnect, device number 6
Mon Jun 22 23:42:59 2020 kern.err kernel: [202522.780011] mt76x2u 2-1:1.0: mac specific condition occurred
Mon Jun 22 23:42:59 2020 kern.err kernel: [202522.889458] mt76x2u 2-1:1.0: mac specific condition occurred

@bjlockie
Copy link
Author

AP died again when I was playing around with iperf.

Tue Jun 23 00:33:23 2020 kern.err kernel: [ 2204.154861] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110

@bjlockie
Copy link
Author

That's all that's in the log but my AP is dead.

[19927.171290] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110

@bjlockie
Copy link
Author

bjlockie commented Jun 24, 2020

My cell phone was downloading updates in the background.

Tue Jun 23 21:23:45 2020 kern.err kernel: [25574.036152] mt76x2u 2-1:1.0: mac specific condition occurred
Tue Jun 23 21:23:45 2020 kern.err kernel: [25574.145623] mt76x2u 2-1:1.0: mac specific condition occurred
Tue Jun 23 21:23:45 2020 daemon.notice netifd: Network device 'wlan1' link is down
Tue Jun 23 21:23:45 2020 kern.err kernel: [25574.245592] mt76x2u 2-1:1.0: timed out waiting for pending tx
Tue Jun 23 21:23:45 2020 kern.info kernel: [25574.252064] br-lan: port 2(wlan1) entered disabled state
Tue Jun 23 21:23:45 2020 kern.info kernel: [25574.262360] device wlan1 left promiscuous mode
Tue Jun 23 21:23:45 2020 kern.info kernel: [25574.266874] br-lan: port 2(wlan1) entered disabled state
Tue Jun 23 21:23:45 2020 daemon.err hostapd: Failed to set beacon parameters
Tue Jun 23 21:23:45 2020 daemon.notice hostapd: wlan1: INTERFACE-DISABLED

@bjlockie
Copy link
Author

bjlockie commented Jun 24, 2020

Cell phone downloading updates.

[75053.121187] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110
[76604.071034] usb 2-1: USB disconnect, device number 5
[76604.293404] mt76x2u 2-1:1.0: mac specific condition occurred
[76604.402907] mt76x2u 2-1:1.0: mac specific condition occurred
[76604.502942] mt76x2u 2-1:1.0: timed out waiting for pending tx
[76604.520167] device wlan2 left promiscuous mode
[76604.524671] br-lan: port 2(wlan2) entered disabled state

@bjlockie
Copy link
Author

bjlockie commented Jun 25, 2020

Raspberry Pi 4 Model B Rev 1.1
Firmware Version: OpenWrt SNAPSHOT r13626-751e6ab8e6 / LuCI Master git-20.175.45303-bb95e67
Kernel Version: 5.4.48

[ 6124.506299] mt76x2u 2-1:1.0: error: mt76x02u_mcu_wait_resp failed with -110

I tried a script to simulate manually reinserting the USB but that didn't work:

[28188.180665] mt76x2u 2-1:1.0: mac specific condition occurred
[28188.290207] mt76x2u 2-1:1.0: mac specific condition occurred
[28188.390182] mt76x2u 2-1:1.0: timed out waiting for pending tx
[28188.398189] mt76x2u 2-1:1.0: mac specific condition occurred
[28188.437841] br-lan: port 2(wlan0) entered disabled state
[28188.446402] device wlan0 left promiscuous mode
[28188.450858] br-lan: port 2(wlan0) entered disabled state
[28188.545795] ------------[ cut here ]------------
[28188.550438] Have pending ack frames!
[28188.554099] WARNING: CPU: 1 PID: 3897 at backports-5.7-rc3-1/net/mac80211/main.c:1396 ieee80211_free_hw+0xe8/0xf0 [mac80211]
[28188.565314] Modules linked in: pppoe ppp_async iptable_nat xt_state xt_nat xt_conntrack xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT pppox ppp_generic nf_nat nf_flow_table_hw nf_flow_table nf_conntrack_rtcache nf_conntrack_netlink nf_conntrack mt76x2u mt76x2e mt76x2_common mt76x02_usb mt76x02_lib mt7603e mt76_usb mt76 mac80211 ipt_REJECT cfg80211 xt_time xt_tcpudp xt_tcpmss xt_statistic xt_multiport xt_mark xt_mac xt_limit xt_length xt_hl xt_ecn xt_dscp xt_comment xt_TCPMSS xt_LOG xt_HL xt_DSCP xt_CLASSIFY wireguard usbnet usbhid slhc r8152 nf_reject_ipv4 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_filter ipt_ECN ip_tables hid_generic crc_ccitt compat snd_bcm2835(C) hid evdev ledtrig_heartbeat xt_set ip_set_list_set ip_set_hash_netportnet ip_set_hash_netport ip_set_hash_netnet ip_set_hash_netiface ip_set_hash_net ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac
[28188.565364]  ip_set_bitmap_ip ip_set nfnetlink nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 ip6_udp_tunnel udp_tunnel snd_rawmidi snd_seq_device snd_pcm_oss snd_pcm_dmaengine snd_pcm snd_timer snd_mixer_oss snd_hwdep snd_compress snd soundcore nls_utf8 vfat fat nls_iso8859_1 nls_cp437
[28188.682904] CPU: 1 PID: 3897 Comm: ash Tainted: G         C        5.4.48 #0
[28188.689943] Hardware name: Raspberry Pi 4 Model B Rev 1.1 (DT)
[28188.695768] pstate: 80400005 (Nzcv daif +PAN -UAO)
[28188.700556] pc : ieee80211_free_hw+0xe8/0xf0 [mac80211]
[28188.705778] lr : ieee80211_free_hw+0xe8/0xf0 [mac80211]
[28188.710993] sp : ffffffc014c0b9b0
[28188.714298] x29: ffffffc014c0b9b0 x28: 0000000000000000 
[28188.719601] x27: ffffffc008bb1000 x26: ffffff80390f00a0 
[28188.724904] x25: ffffff80390f0000 x24: ffffff8037c6a610 
[28188.730207] x23: ffffffc008abd9a8 x22: 0000000000000000 
[28188.735510] x21: 000000007fffffff x20: 0000000000000000 
[28188.740812] x19: ffffff80367e7600 x18: 0000000000000014 
[28188.746115] x17: 00000000b9a48125 x16: 00000000590d4ae3 
[28188.751417] x15: 00000000319705c0 x14: 0720072007200720 
[28188.756719] x13: 0720072007200720 x12: 0720072007200720 
[28188.762021] x11: 0720072007200720 x10: 0720072007200720 
[28188.767323] x9 : 0720072007200720 x8 : 0720072007200720 
[28188.772625] x7 : 0720072007200720 x6 : 0000000000000001 
[28188.777928] x5 : 0000000000000000 x4 : 0000000000000001 
[28188.783230] x3 : 0000000000000007 x2 : 0000000000000006 
[28188.788532] x1 : 0000000000000007 x0 : 0000000000000018 
[28188.793835] Call trace:
[28188.796278]  ieee80211_free_hw+0xe8/0xf0 [mac80211]
[28188.801153]  idr_for_each+0x54/0xd0
[28188.804638]  ieee80211_free_hw+0x34/0xf0 [mac80211]
[28188.809507]  0xffffffc008bae0dc
[28188.812641]  usb_unbind_interface+0x6c/0x210
[28188.816902]  device_release_driver_internal+0xf0/0x1b8
[28188.822031]  device_release_driver+0x14/0x20
[28188.826291]  bus_remove_device+0x118/0x128
[28188.830379]  device_del+0x144/0x338
[28188.833858]  usb_disable_device+0x8c/0x1d0
[28188.837944]  usb_set_configuration+0x4ac/0xab8
[28188.842378]  generic_disconnect+0x28/0x38
[28188.846378]  usb_unbind_device+0x24/0x60
[28188.850290]  device_release_driver_internal+0xf0/0x1b8
[28188.855418]  device_driver_detach+0x14/0x20
[28188.859593]  unbind_store+0xd4/0xf8
[28188.863071]  drv_attr_store+0x20/0x30
[28188.866726]  sysfs_kf_write+0x40/0x50
[28188.870379]  kernfs_fop_write+0x190/0x320
[28188.874382]  __vfs_write+0x18/0x40
[28188.877774]  vfs_write+0xb0/0x1b8
[28188.881079]  ksys_write+0x4c/0xc8
[28188.884384]  __arm64_sys_write+0x18/0x20
[28188.888301]  el0_svc_handler+0xd4/0x130
[28188.892127]  el0_svc+0x8/0xc
[28188.894998] ---[ end trace f024ee959e9d87b3 ]---
[28192.035049] usb 2-1: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[28192.064030] mt76x2u 2-1:1.0: ASIC revision: 76120044
[28192.094627] mt76x2u 2-1:1.0: ROM patch build: 20141115060606a
[28193.118518] mt76x2u 2-1:1.0: firmware upload failed: -110
[28194.254145] mt76x2u: probe of 2-1:1.0 failed with error -5

@bjlockie
Copy link
Author

Powered hub, short/no cables.
aspberry Pi 4 Model B Rev 1.1
OpenWrt SNAPSHOT r13628-870588b6eb / LuCI Master git-20.171.46309-c351bee
Kernel Version: 5.4.48

Fri Jun 26 10:54:09 2020 kern.err kernel: [60446.848414] mt76x2u 2-1.4:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Fri Jun 26 10:54:42 2020 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Fri Jun 26 10:57:35 2020 kern.info kernel: [60652.634372] usb 2-1.4: USB disconnect, device number 4
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.641485] ------------[ cut here ]------------
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.646141] STA xx:xx:xx:xx:xx:xx AC 2 txq pending airtime underflow: 4294967208, 88
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.646226] WARNING: CPU: 0 PID: 0 at backports-5.7-rc3-1/net/mac80211/sta_info.c:1929 ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.667085] Modules linked in: pppoe ppp_async iptable_nat xt_state xt_nat xt_conntrack xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT pppox ppp_generic nf_nat nf_flow_table_hw nf_flow_table nf_conntrack_rtcache nf_conntrack_netlink nf_conntrack mt76x2u mt76x2e mt76x2_common mt76x02_usb mt76x02_lib mt7603e mt76_usb mt76 mac80211 ipt_REJECT cfg80211 xt_time xt_tcpudp xt_tcpmss xt_statistic xt_multiport xt_mark xt_mac xt_limit xt_length xt_hl xt_ecn xt_dscp xt_comment xt_TCPMSS xt_LOG xt_HL xt_DSCP xt_CLASSIFY wireguard usbnet usbhid slhc r8152 nf_reject_ipv4 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_filter ipt_ECN ip_tables hid_generic crc_ccitt compat snd_bcm2835(C) hid evdev ledtrig_heartbeat xt_set ip_set_list_set ip_set_hash_netportnet ip_set_hash_netport ip_set_hash_netnet ip_set_hash_netiface ip_set_hash_net ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.667136]  ip_set_bitmap_ip ip_set nfnetlink nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 ip6_udp_tunnel udp_tunnel snd_rawmidi snd_seq_device snd_pcm_oss snd_pcm_dmaengine snd_pcm snd_timer snd_mixer_oss snd_hwdep snd_compress snd soundcore nls_utf8 vfat fat nls_iso8859_1 nls_cp437
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.784675] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G         C        5.4.48 #0
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.791975] Hardware name: Raspberry Pi 4 Model B Rev 1.1 (DT)
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.797800] pstate: 60400005 (nZCv daif +PAN -UAO)
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.802588] pc : ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.809634] lr : ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.816672] sp : ffffffc010003cc0
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.819977] x29: ffffffc010003cc0 x28: ffffff803827c980
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.825280] x27: ffffff803827bbf8 x26: ffffffc0100a6ab4
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.830583] x25: ffffff8038a26528 x24: 0000000000000000
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.835885] x23: 00000000ffffffa8 x22: 0000000000000002
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.841188] x21: ffffff8036be15d8 x20: 0000000000000058
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.846490] x19: ffffff8038278fe0 x18: 0000000000000000
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.851792] x17: 0000000000000000 x16: 0000000000000000
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.857094] x15: 0000000000000000 x14: 363934393234203a
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.862397] x13: 776f6c667265646e x12: 7520656d69747269
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.867699] x11: 6120676e69646e65 x10: 7020717874203220
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.873001] x9 : 43412032663a3738 x8 : 3a63393a61633a39
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.878304] x7 : 633a656120415453 x6 : ffffffc010a001a8
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.883606] x5 : 00ffffffffffffff x4 : 0000000000000000
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.888908] x3 : 0000000000000000 x2 : 00000000ffffffff
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.894210] x1 : ffffffc02a811000 x0 : 0000000000000048
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.899513] Call trace:
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.901956]  ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.908654]  ieee80211_report_low_ack+0x1fc/0x490 [mac80211]
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.914310]  ieee80211_free_txskb+0x18/0x30 [mac80211]
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.919442]  mt76_tx_complete_skb+0xd0/0xe8 [mt76]
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.924225]  mt76x02u_tx_complete_skb+0x6c/0x80 [mt76x02_usb]
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.929963]  mt76u_queues_deinit+0x288/0xbc8 [mt76_usb]
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.935186]  tasklet_action_common.isra.19+0xac/0x150
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.940228]  tasklet_action+0x24/0x30
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.943881]  __do_softirq+0x11c/0x230
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.947534]  irq_exit+0x9c/0xb8
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.950668]  __handle_domain_irq+0x64/0xb8
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.954754]  gic_handle_irq+0x5c/0xb8
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.958406]  el1_irq+0xf0/0x1c0
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.961539]  arch_cpu_idle+0x10/0x18
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.965107]  do_idle+0x1e4/0x258
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.968325]  cpu_startup_entry+0x20/0x28
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.972241]  rest_init+0xb0/0xbc
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.975460]  arch_call_rest_init+0xc/0x14
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.979460]  start_kernel+0x3c4/0x3dc
Fri Jun 26 10:57:35 2020 kern.warn kernel: [60652.983112] ---[ end trace 516d432abef194ba ]---
Fri Jun 26 10:57:35 2020 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Fri Jun 26 10:57:35 2020 kern.err kernel: [60653.202410] mt76x2u 2-1.4:1.0: mac specific condition occurred
Fri Jun 26 10:57:35 2020 kern.err kernel: [60653.311876] mt76x2u 2-1.4:1.0: mac specific condition occurred
Fri Jun 26 10:57:35 2020 daemon.notice netifd: Network device 'wlan0' link is down

@bjlockie
Copy link
Author

Kernel Version 5.4.48

Mon Jun 29 10:28:22 2020 kern.err kernel: [222692.612509] mt76x2u 2-1.4:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Mon Jun 29 10:28:59 2020 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx

Adding disable_usb_sg=1 to mt76_usb module.

@bjlockie
Copy link
Author

bjlockie commented Jul 3, 2020

This is new:

Raspberry Pi 4 Model B Rev 1.1
OpenWrt SNAPSHOT r13662-1ba0466d43 / LuCI Master git-20.171.46309-c351bee
Kernel Version: 5.4.48
Uptime: 3d 18h 44m 42s
Fri Jul 3 10:19:23 2020 kern.err kernel: [324603.909608] mt76x2u 2-1.4:1.0: vendor request req:07 off:1114 failed:-71

@Menion2k
Copy link

Kernel Version 5.4.48

Mon Jun 29 10:28:22 2020 kern.err kernel: [222692.612509] mt76x2u 2-1.4:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Mon Jun 29 10:28:59 2020 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx

Adding disable_usb_sg=1 to mt76_usb module.

Same problem here but happens only when more that one device is connected on USB (I have mediatek on USB 3.0 and an atheros ath9k_htc on USB 2.0)

This "disable_usb_sg=1 to mt76_usb module" is in current snapshot?
Bye

@Menion2k
Copy link

I compiled latest MT76 code and now I get:

[ 60.699944] mt76x2u 2-2:1.0: mac specific condition occurred [ 60.807321] mt76x2u 2-2:1.0: mac specific condition occurred [ 60.907318] mt76x2u 2-2:1.0: timed out waiting for pending tx

@bjlockie
Copy link
Author

bjlockie commented Jul 20, 2020

without: echo 1 > /sys/module/mt76_usb/parameters/disable_usb_sg in case the trace helps.

Mon Jul 20 13:01:33 2020 kern.err kernel: [62002.071290] mt76x2u 2-1.4:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Mon Jul 20 13:01:54 2020 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Mon Jul 20 13:03:26 2020 kern.info kernel: [62115.722669] usb 2-1.4: USB disconnect, device number 4
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.730326] ------------[ cut here ]------------
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.734992] STA ae:c9:ca:9c:87:f2 AC 2 txq pending airtime underflow: 4294967224, 72
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.735082] WARNING: CPU: 0 PID: 0 at backports-5.7-rc3-1/net/mac80211/sta_info.c:1929 ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.755942] Modules linked in: pppoe ppp_async iptable_nat xt_state xt_nat xt_conntrack xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT pppox ppp_generic nf_nat nf_flow_table_hw nf_flow_table nf_conntrack_rtcache nf_conntrack_netlink nf_conntrack mt76x2u mt76x2e mt76x2_common mt76x02_usb mt76x02_lib mt7603e mt76_usb mt76 mac80211 ipt_REJECT cfg80211 xt_time xt_tcpudp xt_tcpmss xt_statistic xt_multiport xt_mark xt_mac xt_limit xt_length xt_hl xt_ecn xt_dscp xt_comment xt_TCPMSS xt_LOG xt_HL xt_DSCP xt_CLASSIFY wireguard usbnet usbhid slhc r8152 nf_reject_ipv4 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_filter ipt_ECN ip_tables hid_generic crc_ccitt compat snd_bcm2835(C) hid evdev ledtrig_heartbeat xt_set ip_set_list_set ip_set_hash_netportnet ip_set_hash_netport ip_set_hash_netnet ip_set_hash_netiface ip_set_hash_net ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.755992]  ip_set_bitmap_ip ip_set nfnetlink nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 ip6_udp_tunnel udp_tunnel snd_rawmidi snd_seq_device snd_pcm_oss snd_pcm_dmaengine snd_pcm snd_timer snd_mixer_oss snd_hwdep snd_compress snd soundcore nls_utf8 vfat fat nls_iso8859_1 nls_cp437
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.873531] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G         C        5.4.52 #0
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.880831] Hardware name: Raspberry Pi 4 Model B Rev 1.1 (DT)
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.886656] pstate: 60400005 (nZCv daif +PAN -UAO)
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.891445] pc : ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.898490] lr : ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.905529] sp : ffffffc010003cc0
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.908834] x29: ffffffc010003cc0 x28: ffffff8037c8c980
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.914137] x27: ffffff8037c8bbf8 x26: ffffffc0100a6ab4
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.919439] x25: ffffff8038a5b428 x24: 0000000000000000
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.924742] x23: 00000000ffffffb8 x22: 0000000000000002
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.930045] x21: ffffff8036c6e5d8 x20: 0000000000000048
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.935347] x19: ffffff8037c88fe0 x18: 0000000000000000
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.940649] x17: 0000000000000000 x16: 0000000000000000
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.945951] x15: 0000000000000000 x14: 363934393234203a
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.951253] x13: 776f6c667265646e x12: 7520656d69747269
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.956555] x11: 6120676e69646e65 x10: 7020717874203220
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.961858] x9 : 43412032663a3738 x8 : 3a63393a61633a39
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.967160] x7 : 633a656120415453 x6 : ffffffc010a031a8
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.972463] x5 : 00ffffffffffffff x4 : 0000000000000000
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.977766] x3 : 0000000000000000 x2 : 00000000ffffffff
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.983068] x1 : ffffffc02a810000 x0 : 0000000000000048
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.988370] Call trace:
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.990814]  ieee80211_sta_update_pending_airtime+0x1bc/0x1c8 [mac80211]
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62115.997512]  ieee80211_report_low_ack+0x1fc/0x490 [mac80211]
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.003168]  ieee80211_free_txskb+0x18/0x30 [mac80211]
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.008301]  mt76_tx_complete_skb+0xd0/0xe8 [mt76]
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.013083]  mt76x02u_tx_complete_skb+0x6c/0x80 [mt76x02_usb]
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.018821]  mt76u_queues_deinit+0x288/0xbc8 [mt76_usb]
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.024044]  tasklet_action_common.isra.19+0xac/0x150
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.029086]  tasklet_action+0x24/0x30
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.032739]  __do_softirq+0x11c/0x230
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.036392]  irq_exit+0x9c/0xb8
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.039527]  __handle_domain_irq+0x64/0xb8
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.043613]  gic_handle_irq+0x5c/0xb8
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.047265]  el1_irq+0xf0/0x1c0
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.050397]  arch_cpu_idle+0x10/0x18
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.053965]  do_idle+0x1e4/0x258
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.057184]  cpu_startup_entry+0x24/0x28
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.061098]  rest_init+0xb0/0xbc
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.064317]  arch_call_rest_init+0xc/0x14
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.068317]  start_kernel+0x3c4/0x3dc
Mon Jul 20 13:03:27 2020 kern.warn kernel: [62116.071969] ---[ end trace ae3dd1c7595a8ffa ]---

@Menion2k
Copy link

So, I have built b5df0fb and the problem is still there on a RPi4 with Openwrt snapshot

Apparently, but I need to do some more testing, the problem comes when there is some sustained (even if nothing crazy) traffic going over the air and for the moment I have seen it only with an android phone.

I usually have a Windows10 PC with Intel WiFi card, and so far I did not see the problem happening with it, but I try to make some more tests

@bjlockie
Copy link
Author

Are using it with scatter-gather on demand disabled?
echo 1 > /sys/module/mt76_usb/parameters/disable_usb_sg

@Menion2k
Copy link

No, but I can give it a shot. It is enough to run it runtime? Or shall I do something else, like disconnect/connect?

@bjlockie
Copy link
Author

bjlockie commented Jul 30, 2020

It is enough to run it runtime? Or shall I do something else, like disconnect/connect?

Unplug the USB, run that command, plug in the USB.
That seems to work for me.
scatter-gather on demand doesn't seem to be well supported in Linux from what I've read so I think it should be disabled by default but I think the bug only happens in some circumstances. :-)

I created so it happens on reboot:

# cat /etc/modules.d/mymoduleparam.conf 
mt76-usb disable_usb_sg=1

This will show the status:
# cat /sys/module/mt76_usb/parameters/disable_usb_sg

@Menion2k
Copy link

Hi @bjlockie

Yes apparently it solves the issue

Thanks, bye

@zedrdave
Copy link

Same boat as everyone above (RPi4 + mt76x2u-driver supported USB Wifi regularly dying with mac specific condition occurred), and disabling SG indeed does not help either.

My understanding is that, at this stage, the only hope for a fix, is in a firmware update for RPi?

As a workaround in the meantime, has anyone come up with a script to reset the connection regularly?

(physically unplugging the USB stick works, but there has to be a more efficient way to detect when the error occurred and reload the device…?

@bjlockie
Copy link
Author

bjlockie commented Dec 30, 2022 via email

@TrylobitBroccoli
Copy link

Any updates on this issue?

@zedrdave
Copy link

zedrdave commented Feb 18, 2023

@TrylobitBroccoli unfortunately, even after ensuring drivers/firmware were the very latest, and playing around every possible port config, the bottom line is that RPi + USB3 + wifi is a no-go…

Which is a pretty huge limitation, and ought to be a little more well-known, imho.

@TrylobitBroccoli
Copy link

@zedrdave That's so disappointing. I've got the RPi 4B just for this purpose... Is there an alternative that can be used that is OpenWRT compatible and similar to RPi and doesn't produce this kind of problems?

@leezu
Copy link

leezu commented Feb 20, 2023

@TrylobitBroccoli @zedrdave have you tried using the the USB2 ports? This improves stability for me, but occasional mt7921u 1-1.3:1.3: Message 00020003 (seq 6) timeout and failed to remove key (0, MAC) from hardware (-110) errors remain, which however may rather be wifi firmware issues than USB issues.

@lriesebos
Copy link

@TrylobitBroccoli I actually use a NanoPi R4S as a router with a mt76x2u type wifi adapter for the access point, and after switching off SG as part of the module initialization, the system appears to be working stable. I have this setup running now for over a week without issues (so yes, still pretty new). when leaving SG enabled, the -110 error would appear after 2-3 days.

@bjlockie
Copy link
Author

bjlockie commented Feb 20, 2023 via email

@zedrdave
Copy link

Unfortunately USB 2 is even less stable. Running on a powered USB 3 (with SG disabled) leads to random disconnects, every few GB of traffic…

@neheb
Copy link
Contributor

neheb commented Mar 3, 2023

Just got this error after putting adapter behind a USB3 hub. I put it back directly.

@LorenzoBianconi expected?

@bjlockie
Copy link
Author

bjlockie commented Mar 4, 2023 via email

@neheb
Copy link
Contributor

neheb commented Mar 4, 2023

No, passive

@bjlockie
Copy link
Author

bjlockie commented Mar 4, 2023 via email

@smoti17
Copy link

smoti17 commented Mar 13, 2023

I tried both passive and powered USB hubs between the WNDR3800 and the mt76, does not help.
AIUI, the WNDR3800s single USB port is USB2.

@bjlockie
Copy link
Author

Is there something about power saving you can turn of in mt76?
I only had an AP on a Raspberry Pi (ARM).
I think your router is MIPS.

@rovitotv
Copy link

rovitotv commented Jul 4, 2023

I had the exact same issue when I added a USB 3.0 ALFA AWUS036ACM to my Raspberry Pi 4 router and Raspberry Pi 4 Access Point. I could reproduce the problems simply by running the speed test from my Android phone and either the router or the access point WiFi would stop working. To get the WiFi working again I often would perform a reboot. Now that I have the fix from @bjlockie (to disable the scatter gather in USB) I seem to be able to run all the speed tests that I want.

Fingers crossed I will report how long my OpenWRT Raspberry Pi devices continue to function.

@zedrdave
Copy link

zedrdave commented Jul 4, 2023

Unfortunately disabling SG (or any of the other USB port fiddling suggestions) never solved the issue for me. Kept having random disconnects every few days (presumably when reaching some arbitrary traffic threshold).

Eventually gave up and plugged it to a Wifi repeater through ethernet (works like a charm).

@rovitotv
Copy link

I have been running with no issues for over 11 days since I disabled usb scatter gather feature. I am only using 5 GHZ and I have two different Raspberry Pi's one with OpenWRT 22.03.5 and the main router with OpenWRT 22.03.3. I have fast transition turned on so I can roam between the two OpenWRT systems.

@Qualtagh
Copy link

Qualtagh commented Aug 12, 2023

I also have (had?) this issue, and disabling SG didn't help.
Logs contained errors like ieee80211 phy0: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-512.
In order to fix them, I followed recommendation given at this answer, i.e., to decrease "Maximum transmit power".
So far, the router has been working only for several hours, but I've been excessively doing actions which previously led to this issue, and it hasn't happened yet.
To me, the issue seems to happen only on using some particular protocols. For example:

  • uploading photos from phone to computer on Samba or watching movies from Samba share (LAN)
  • uploading files to SFTP (WAN)
  • video calls on some websites (but video calls on Telegram work well)

These actions usually make me reboot Raspberry Pi after an hour of usage because Wi-Fi gets lost.
At the same time, I can download any amounts of traffic via YouTube, regular HTTP or torrents and experience no problems at all.
All in all, the above method helped me to get rid of those error messages - that's for sure.
And! Besides that, it probably helped against (or at least reduced) the issue with dying Wi-Fi.

@lriesebos
Copy link

@Qualtagh , just wondering, how did you disable SG?

@bjlockie
Copy link
Author

bjlockie commented Aug 17, 2023

I think this is it:

# sudo vim /etc/modules.d/mymoduleparam.conf 
mt76-usb disable_usb_sg=1

This will show the status:
# sudo cat /sys/module/mt76_usb/parameters/disable_usb_sg

@lriesebos
Copy link

@bjlockie that sound about right. in the past I has problems when I changed the parameter after module initialization, but doing it in a way as you describe worked well for me.

@rovitotv
Copy link

rovitotv commented Jan 4, 2024

quick update.....

I used the fix from @bjlockie to disable scatter gather on OpenWRT version 22.03.5 and version 22.03.3 and it has been stable for months. Today I setup a new RasPi 4 with a USB 3.0 ALFA AWUS036ACM with OpenWRT version 23.05.2 and disabling scatter gather actually makes the WiFi AP unstable under high load. I removed the file /etc/modules.d/mymoduleparam.conf and rebooted and now the WiFi AP is very stable with good performance. I am guessing there is a patch that fixed this issue in 23.05.2 and disabling scatter gather is no longer required. Maybe this issue can be closed now?

@hpojak
Copy link

hpojak commented Jan 28, 2024

I encounter this kind of AP stops with my Raspberry Pi 4B, with Alfa AWUS036ACM, connected to USB 2, though.
It happens after a day, or a few days. From syslog:

Fri Jan 26 18:39:34 2024 kern.err kernel: [96538.948268] mt76x2u 1-1.4:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Fri Jan 26 18:39:37 2024 kern.err kernel: [96541.508315] mt76x2u 1-1.4:1.0: error: mt76x02u_mcu_wait_resp failed with -110
Fri Jan 26 18:39:40 2024 kern.err kernel: [96544.068368] mt76x2u 1-1.4:1.0: error: mt76x02u_mcu_wait_resp failed with -110

/etc/init.d/network restart does not help.
reboot helps.

OpenWrt version 23.05.2, r23630-842932a63d

@callegar
Copy link

This is not just with the RPI4. I am seeing this regularly with a haswell laptop with an usb mt76 wifi adapter (comfast CF-WU782ACV2). Wifi hangs, then after some time it spontaneously recovers. Now trying with scatter/gather disabled.

@lriesebos
Copy link

considering a switch to OpenWRT 23.05.3. wondering, what are your latest experiences for the scatter/gather setting? @rovitotv @hpojak @callegar

@callegar
Copy link

callegar commented Apr 24, 2024

Personally, I have gave up with the Comfast CF-WU782ACV2 which was not just the source of a significant frustration, but also originally not cheap. Scatter/Gather was not the origin of the problem and possibly my board had some inherent design/hardware/firmware flaw or was a counterfeit. I have bought a Fenvi AX1800 on AliExpress that is also Mediatek based (mt7921u) that came at 1/5 of the cost (7€) and differently from the Comfast so far works fine out of the box. It has smaller antennas and a somehow lower antenna gain than the Comfast, though. The immediately evident thing that does not work with the linux driver is the led. Have not tried as an AP, yet.

@smoti17
Copy link

smoti17 commented Jun 2, 2024

FWIW confirming that problem is still present for v23.05.3 on the WNDR3800/AR7161 platform, even with /sys/module/mt76_usb/parameters/disable_usb_sg=y Possibly less severe than earlier versions, but I had one lockup after around 8 days uptime with SG disabled, and it only took one day to crash with SG enabled. Other platforms stable. Really wish I hadn't bought a bunch of the AWUS036ACMs, now looking at alternative hardware..

@rovitotv
Copy link

rovitotv commented Jun 7, 2024

I am really scratching my head...I have two openWRTs running on Raspberry Pi. OpenWrt 22.03.5 r20134-5f15225c1e. One has up-time of 112 days the other has up-time of 169 days. I use the WiFi everyday with no issues. I can upgrade to OpenWrt 23 and see what happens.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests