openwrt / mt76

mac80211 driver for MediaTek MT76x0e, MT76x2e, MT7603, MT7615, MT7628 and MT7688
743 stars 341 forks source link

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

Open bjlockie opened 4 years ago

bjlockie commented 4 years ago

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 commented 4 years ago

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

bjlockie commented 4 years ago

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 commented 4 years ago

[ 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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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

bjlockie commented 4 years ago
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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago
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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago
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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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

Menion2k commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

Hi @bjlockie

Yes apparently it solves the issue

Thanks, bye

bjlockie commented 4 years ago

https://docs.gz.ro/tuning-network-cards-on-linux.html https://wiki.linuxfoundation.org/networking/toe

amisix commented 2 years ago

I'm having this same issue on a Raspberry Pi 4B ver 1.5 with OpenWrt 21.02.1 with one, or two, Alfa AWUS036ACM USB adapters (MT7612U chipset) in AP mode. It doesn't matter the combination, if it's a single adapter or both, same behavior. I can reproduce the issue on demand.

Adding max_usb_current=1 and disable_usb_sg=1 to /boot/config.txt has not resolved the issue. Using a USB 3.0 powered hub, the issue persists (with 2 different hubs) Connecting the adapter(s) directly to the Pi USB 3.0 ports, the issue persists. Using a single AWUS036ACM adapter, the issue persists. Verified (with syslog & USB voltmeter/amp meter) there is no throttling occurring due to low voltage condition. Power supplied by a 3.5amp Canakit power supply with only ~1.2-1.5amps consumed at roughly 35% load. Issue persists despite trying a different power supply and a USB battery pack with 4.5amps available.

I had this exact same configuration with the same adapters and USB hub functioning on a Raspberry Pi 3B just last week. The only glaring difference is that these adapters are plugged into the Pi4 B's USB 3.0 ports instead of the USB 2.0 ports on the Pi 3B.

Does anybody have additional input on possible solutions to this?

Linux RPi4 5.4.154 #0 SMP Sun Oct 24 09:01:35 2021 aarch64 GNU/Linux

kmod-mac80211.
kmod-mt76-core.
kmod-mt76-usb.
kmod-mt76x02-common.
kmod-mt76x2-common.
kmod-mt76x02-usb.
kmod-mt76x2u *

Syslog:

[   13.174262] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[   15.692144] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   90.884423] mt76x2u 2-2.4:1.0: error: mt76x02u_mcu_wait_resp failed with -110
(there is nothing after this)

Kernel Log:

19:33:40 2022 kern.err kernel: [   90.884423] mt76x2u 2-2.4:1.0: error: mt76x02u_mcu_wait_resp failed with -110
19:33:58 2022 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED 98:48:27:de:5c:02
19:33:58 2022 daemon.info hostapd: wlan1: STA 98:48:27:de:5c:02 IEEE 802.11: disassociated
19:33:58 2022 daemon.notice hostapd: wlan1: STA-OPMODE-N_SS-CHANGED 98:48:27:de:5c:02 1
19:33:59 2022 daemon.info hostapd: wlan1: STA 98:48:27:de:5c:02 IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
19:34:01 2022 daemon.notice hostapd: wlan0: STA-OPMODE-N_SS-CHANGED 98:48:27:de:5c:02 2
19:34:01 2022 daemon.info hostapd: wlan0: STA 98:48:27:de:5c:02 IEEE 802.11: associated (aid 1)

Output of lsusb -t:

/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M
    |__ Port 1: Dev 2, If 0, Class=, Driver=mt76x2u, 5000M
    |__ Port 2: Dev 3, If 0, Class=, Driver=hub/4p, 5000M
        |__ Port 4: Dev 5, If 0, Class=, Driver=mt76x2u, 5000M
        |__ Port 2: Dev 4, If 0, Class=, Driver=r8152, 5000M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 480M
    |__ Port 1: Dev 2, If 0, Class=, Driver=hub/4p, 480M
        |__ Port 2: Dev 3, If 0, Class=, Driver=hub/4p, 480M
        |__ Port 4: Dev 4, If 0, Class=, Driver=usbhid, 12M
        |__ Port 4: Dev 4, If 1, Class=, Driver=usbhid, 12M
        |__ Port 4: Dev 4, If 2, Class=, Driver=usbhid, 12M

System log output when the adapters load properly after fresh power on:

xt_time: kernel timezone is -0000
[    6.505096] usb 2-1: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[    6.539296] mt76x2u 2-1:1.0: ASIC revision: 76120044
[    6.587513] mt76x2u 2-1:1.0: ROM patch build: 20141115060606a
[    6.773095] mt76x2u 2-1:1.0: Firmware Version: 0.0.00
[    6.779990] mt76x2u 2-1:1.0: Build: 1
[    6.785315] mt76x2u 2-1:1.0: Build Time: 201507311614____
[    7.611873] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[    7.696738] usb 2-2.4: reset SuperSpeed Gen 1 USB device number 5 using xhci_hcd
[    7.726817] mt76x2u 2-2.4:1.0: ASIC revision: 76120044
[    7.773826] mt76x2u 2-2.4:1.0: ROM patch build: 20141115060606a
[    7.957565] mt76x2u 2-2.4:1.0: Firmware Version: 0.0.00
[    7.966114] mt76x2u 2-2.4:1.0: Build: 1
[    7.971590] mt76x2u 2-2.4:1.0: Build Time: 201507311614____
[    8.799908] ieee80211 phy1: Selected rate control algorithm 'minstrel_ht'
[    8.803117] usbcore: registered new interface driver mt76x2u
[    8.819743] PPP generic driver version 2.4.2
[    8.826441] NET: Registered protocol family 24

System log after crash when the adapter attached to the USB powered hub fails to initialize after restart. Requires adapter to be unplugged/plugged back in or temporarily remove power from the powered hub.

[ 9.916531] mt76x2u 2-2.4:1.0: firmware upload failed: -110 [ 11.452489] mt76x2u: probe of 2-2.4:1.0 failed with error -5

[    7.419657] xt_time: kernel timezone is -0000
[    7.601121] usb 2-1: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[    7.635209] mt76x2u 2-1:1.0: ASIC revision: 76120044
[    7.683048] mt76x2u 2-1:1.0: ROM patch build: 20141115060606a
[    7.868800] mt76x2u 2-1:1.0: Firmware Version: 0.0.00
[    7.875680] mt76x2u 2-1:1.0: Build: 1
[    7.881021] mt76x2u 2-1:1.0: Build Time: 201507311614____
[    8.707851] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[    8.796878] usb 2-2.4: reset SuperSpeed Gen 1 USB device number 5 using xhci_hcd
[    8.830328] mt76x2u 2-2.4:1.0: ASIC revision: 76120044
[    8.868298] mt76x2u 2-2.4:1.0: ROM patch build: 20141115060606a
[    9.916531] mt76x2u 2-2.4:1.0: firmware upload failed: -110
[   11.452489] mt76x2u: probe of 2-2.4:1.0 failed with error -5
[   11.461127] usbcore: registered new interface driver mt76x2u
[   11.476752] PPP generic driver version 2.4.2
[   11.483127] NET: Registered protocol family 24
bjlockie commented 2 years ago

I think that module parameter has been around for a while. Try: echo 1 > /sys/module/mt76_usb/parameters/disable_usb_sg

cat /sys/module/mt76_usb/parameters/disable_usb_sg

Should be "Y".

I think this might make it permanent: echo "mt76-usb disable_usb_sg=1" >> /etc/modprobe.d/mymoduleparam.conf

amisix commented 2 years ago

Thank you so much for your quick and concise response. So far I haven't been able to reproduce the issue (single adapter config) since adding "mt76-usb disable_usb_sg=1" to /etc/modules.d/mymoduleparam.conf and rebooting. I will test it with a second adapter this evening though so far the outlook is good. Thanks.

bjlockie commented 2 years ago

I hope it works for you, it fixed it for me.

amisix commented 2 years ago

As expected, it works great with the dual adapter setup too. Not one hiccup in over two dozen tests. I really like these adapters, it's great to be able to use them now!

amisix commented 2 years ago

@bjlockie I realized while linking your solution that the location of mymoduleparam.conf is /etc/modules.d/ as opposed to /etc/modprobe.d/ as you have listed in your solution. I had to create the file as it was not there by default.

LorenzoBianconi commented 2 years ago

@bjlockie @amisix it seems the issue is related to rpi4 usb controller in some way. I tested it yesterday in ap and sta mode (OpenWrt master) with a mtk development board and it works fine with usb_sg enabled. Are you able to test it on a different board?

bjlockie commented 2 years ago

I don't have any other computers except x86 ones which I'm sure it works on. Is the mtk development board arm based? If it only happens on a Raspberry Pi then maybe sg can automatically be disabled? It doesn't seem to be lot of people having the problem and it is well documented now so I don't think Is a worth much of your time. Big thanks go out to you and all the linux wifi developers.

LorenzoBianconi commented 2 years ago

I don't have any other computers except x86 ones which I'm sure it works on. Is the mtk development board arm based? If it only happens on a Raspberry Pi then maybe sg can automatically be disabled? It doesn't seem to be lot of people having the problem and it is well documented now so I don't think Is a worth much of your time. Big thanks go out to you and all the linux wifi developers.

mt7622 is a ARM Cortex-A53 iirc. I guess it would be nice to bisect it but I do not have any rpi4 available.

amisix commented 2 years ago

Hi Lorenzo, thank you very much for your time with this. Unfortunately I don't have any other boards to test it with either, they're terribly difficult to obtain lately. I just got my Pi 4 new last week and it's Rev. 1.5 which from what I can tell was released fairly recently (if that matters).

Menion2k commented 2 years ago

Hi all

I an having this issue basically since forever with Rpi4.

Disable scatter gather dma helps for this issue yes, but AP mode is still not reliable.

Bye

Il Lun 7 Feb 2022, 17:24 amisix @.***> ha scritto:

Hi Lorenzo, thank you very much for your time with this. Unfortunately I don't have any other boards to test it with either, they're terribly difficult to obtain lately. I just got my Pi 4 new last week and it's Rev. 1.5 which from what I can tell was released fairly recently (if that matters).

— Reply to this email directly, view it on GitHub https://github.com/openwrt/mt76/issues/405#issuecomment-1031659169, or unsubscribe https://github.com/notifications/unsubscribe-auth/AFTIV2GZR3SG7FEFAGMIWYTUZ7W4PANCNFSM4NPKLDJQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you commented.Message ID: @.***>

bjlockie commented 2 years ago

Disable scatter gather dma helps for this issue yes, but AP mode is still not reliable.

Mmm, I had an AP on 5GHz and it was rock solid once I disabled scatter gather.

amisix commented 2 years ago

rock solid once I disabled scatter gather

I've been running two 7612u adapters combined with a 7610u adapter; Stable for 3 weeks since disabling scatter gather.

I think one of the sticking points to properly diagnosing that Scatter Gather is an issue is that most writeups regarding it refer to performance degradation - not a complete loss of functionality as myself and others have experienced; Makes it hard to read logs and properly restart/poweroff your device if your only connection to the Raspberry Pi continues to drop.

LorenzoBianconi commented 2 years ago

@amisix @bjlockie @Menion2k the SG issue seems to be due to a xhci rpi controller bug. Applying this patch, mt76u has been reported to be stable with SG enabled running 2 vif in AP mode. Can you please give it a whirl?

amisix commented 2 years ago

@LorenzoBianconi Thank you (and others) for all your effort regarding this, and coming up with a solution! Unfortunately I'm not advanced enough yet to apply patches but will do so the moment I learn.

bjlockie commented 2 years ago

@LorenzoBianconi Thanks. I only have a 1G raspberry pi 4 (which I don't think they make anymore) and last time I tried to compile something for it it ran out of memory. So I can't test the patch either but thanks for your effort, it is much appreciated.

Menion2k commented 2 years ago

Hi all

Unfortunately I am really busy these days, I will try to compile with the patch as soon as possible.

Bye

Antonio

Il giorno mar 15 mar 2022 alle ore 20:39 bjlockie @.***> ha scritto:

@LorenzoBianconi https://github.com/LorenzoBianconi Thanks. I only have a 1G raspberry pi 4 (which I don't think they make anymore) and last time I tried to compile something for it it ran out of memory. So I can't test the patch either but thanks for your effort, it is much appreciated.

— Reply to this email directly, view it on GitHub https://github.com/openwrt/mt76/issues/405#issuecomment-1068392133, or unsubscribe https://github.com/notifications/unsubscribe-auth/AFTIV2FXZJ7MKGOQAEANDVTVADRPPANCNFSM4NPKLDJQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you were mentioned.Message ID: @.***>

soyersoyer commented 2 years ago

With the latest raspberry buster kernel (Linux rpi4 5.10.103-v7l+ which includes the patch) I still experince this bug about every week. It works well with the disable_usb_sg=1.

zhanglinqiang commented 2 years ago

I think that module parameter has been around for a while. Try: echo 1 > /sys/module/mt76_usb/parameters/disable_usb_sg cat /sys/module/mt76_usb/parameters/disable_usb_sg Should be "Y". I think this might make it permanent: echo "mt76-usb disable_usb_sg=1" >> /etc/modprobe.d/mymoduleparam.conf

The configuration parameter format should be: echo "options mt76-usb disable_usb_sg=1" >> /etc/modprobe.d/mymoduleparam.conf This solved my problem. Unfortunately the problem reappears.