search

openwrt / mt76

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

Many kernel OOPSes; on latest commit #194

Closed djwlindenaar closed 4 years ago

djwlindenaar commented 6 years ago

Hi, I've got a very unstable situation with my Xiaomi MIR3G. Depending on what's connected, Kernel oops. I've just installed the latest snapshot containing the August 24 commits to mt76.

I've not set up logging over the serial terminal, so not all logs are fully complete due to the automatic reset/watchdog, I guess.

Anything I can add to help resolving this issue?

Aug 26 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.112329] CPU 3 Unable to handle kernel paging request at virtual address 07400858, epc == 8010782c, ra == 80178948
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.123003] Oops[#1]:
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.125289] CPU: 3 PID: 14158 Comm: luci Not tainted 4.14.66 #0
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.131182] task: 8ef37080 task.stack: 8f182000
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.135691] $ 0   : 00000000 00000001 00000058 81243328
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.140907] $ 4   : 8059c1b8 00000001 00000001 07400858
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.146118] $ 8   : 000047da 000047d9 8fa0c850 00000110
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.151329] $12   : 8000001f 00000000 00000114 00000001
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.156539] $16   : 8fc20700 014080c0 8f190000 8055cf78
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.161752] $20   : 80630000 00000002 00008124 ffffee4b
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.166968] $24   : ffffffe0 80058a3c
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.172186] $28   : 8f182000 8f183978 80538f00 80178948
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.177399] Hi    : 00048bb3
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.180262] Lo    : 5ad76016
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.183160] epc   : 8010782c kmem_cache_alloc+0x128/0x17c
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.188545] ra    : 80178948 __kernfs_new_node+0x60/0x16c
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.193915] Status: 11007c03   KERNEL EXL IE
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.198089] Cause : 40800008 (ExcCode 02)
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.202077] BadVA : 07400858
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.204943] PrId  : 0001992f (MIPS 1004Kc)
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.209014] Modules linked in: pppoe ppp_async pppox ppp_generic nf_conntrack_ipv6 mt76x2e mt7603e mt76 mac80211 iptable_nat ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_FLOWOFFLOAD xt_CT slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_conntrack_ipv4 nf_nat_ipv4 nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack iptable_mangle iptable_filter ip_tables crc_ccitt compat ledtrig_usbport ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables x_tables leds_gpio xhci_mtk xhci_plat_hcd xhci_pci xhci_hcd gpio_button_hotplug usbcore nls_base usb_common
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.277431] Process luci (pid: 14158, threadinfo=8f182000, task=8ef37080, tls=77f2eda8)
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.285396] Stack : 80000001 8017a130 8f190120 80630000 8efce060 01400000 8fc05700 80178948
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.293738]         805a0000 00000000 00000000 8ecb7308 00000000 0000000d ffffee4b 8efce060
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.302081]         80495db4 00000124 8efce060 8ecb7308 00000000 0000000e ffffee4b 80179e44
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.310422]         00000000 8efce060 805a0000 8f190120 80495db4 805bea20 80495db4 8017be50
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.318755]         8efcef00 8ecb7308 00000000 805634bc 8efcef00 805bea20 8efce060 8017c978
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.327092]         ...
Aug 25 15:40:25 192.168.2.9 OpenWrt_Huiskamer kernel: [ 1006.329531] Call Trace:

Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.291823] CPU 3 Unable to handle kernel paging request at virtual address 07406000, epc == 80108aac, ra == 80108a1c
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.302415] Oops[#1]:
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.304681] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 4.14.66 #0
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.310662] task: 8fc44b00 task.stack: 8fc70000
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.315168] $ 0   : 00000000 00000001 07406000 00c45000
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.320381] $ 4   : 8059c1b8 01090220 812426f0 01080020
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.325595] $ 8   : 0000bc4e 00000002 00000001 88000000
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.330807] $12   : 8fc15f60 00000008 86b0fbee 0000003c
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.336016] $16   : 8fc02a00 01090220 07406000 80339464
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.341227] $20   : 00000720 00000000 8e840bc0 01080020
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.346437] $24   : 0e050800 8000cf94
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.351650] $28   : 8fc70000 8fc15a10 00000000 80108a1c
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.356860] Hi    : 00002665
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.359723] Lo    : 94af5487
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.362617] epc   : 80108aac __kmalloc_track_caller+0x148/0x228
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.368517] ra    : 80108a1c __kmalloc_track_caller+0xb8/0x228
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.374319] Status: 11007c03   KERNEL EXL IE
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.378491] Cause : 40800008 (ExcCode 02)
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.382477] BadVA : 07406000
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.385343] PrId  : 0001992f (MIPS 1004Kc)
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.389415] Modules linked in: pppoe ppp_async pppox ppp_generic nf_conntrack_ipv6 mt76x2e mt7603e mt76 mac80211 iptable_nat ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_FLOWOFFLOAD xt_CT slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_conntrack_ipv4 nf_nat_ipv4 nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack iptable_mangle iptable_filter ip_tables crc_ccitt compat ledtrig_usbport ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables x_tables leds_gpio xhci_mtk xhci_plat_hcd xhci_pci xhci_hcd gpio_button_hotplug usbcore nls_base usb_common
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.457826] Process swapper/3 (pid: 0, threadinfo=8fc70000, task=8fc44b00, tls=00000000)
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.465875] Stack : 8e335054 80344724 00000000 00000000 8ea5ee40 00000000 01080020 80337584
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.474208]         00000548 8e970000 8fc15aac 8f1038c0 8ea5ee40 8ea5ee40 00000000 00000660
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.482540]         00000018 80339464 805bd760 8059c1b8 8fc15b3c 00000001 8fc15bd4 8e840bc0
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.490874]         8ea5ee40 00000006 8f1b0a46 00000018 00000000 8e840bc0 00000000 8f22cdd4
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.499208]         8e840bc0 8e840bc0 00000001 8f294a00 8e335480 8f22d6ec 8e335994 380000e0
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.507542]         ...
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.509979] Call Trace:
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.512413] [<80108aac>] __kmalloc_track_caller+0x148/0x228
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.517973] [<80337584>] __kmalloc_reserve.isra.7+0x40/0xa4
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.523523] [<80339464>] pskb_expand_head+0x88/0x318
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.528601] [<8f22cdd4>] ieee80211_beacon_get_tim+0x244/0xebc [mac80211]
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.535294] Code: 00000000  8e020014  02421021 <8c470000> 41666000  30c60001  000000c0  8f85000c  8e020000
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.545031]
Aug 25 16:00:39 192.168.2.9 OpenWrt_Huiskamer kernel: [  261.546640] ---[ end trace d681cbd75f337a56 ]---

Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.653222] CPU 1 Unable to handle kernel paging request at virtual address 07404058, epc == 803a0b68, ra == 8032bb68
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.663836] Oops[#1]:
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.666113] CPU: 1 PID: 970 Comm: dnsmasq Not tainted 4.14.66 #0
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.672100] task: 8fdb9f40 task.stack: 8f17a000
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.676609] $ 0   : 00000000 00000001 07404000 00000001
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.681828] $ 4   : 00004000 00000000 8f17bc6c 00000001
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.687043] $ 8   : 00000000 00007c00 00000093 001d8144
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.692259] $12   : 00000000 035b4960 86b0d9b3 00402cb1
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.697476] $16   : 8ebf8000 00000000 8ea4d180 8f17bc6c
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.702693] $20   : 00000001 00000000 8f17bb6c 00000000
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.707910] $24   : 000010d9 8000cf94
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.713130] $28   : 8f17a000 8f17bae8 fffffffc 8032bb68
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.718348] Hi    : 0000000a
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.721216] Lo    : 66666669
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.724099] epc   : 803a0b68 tcp_poll+0x1b4/0x310
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.728792] ra    : 8032bb68 sock_poll+0xa8/0xc8
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.733389] Status: 11007c03   KERNEL EXL IE
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.737565] Cause : 40800008 (ExcCode 02)
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.741557] BadVA : 07404058
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.744422] PrId  : 0001992f (MIPS 1004Kc)
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.748496] Modules linked in: pppoe ppp_async pppox ppp_generic nf_conntrack_ipv6 mt76x2e mt7603e mt76 mac80211 iptable_nat ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_FLOWOFFLOAD xt_CT slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_conntrack_ipv4 nf_nat_ipv4 nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack iptable_mangle iptable_filter ip_tables crc_ccitt compat ledtrig_usbport ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables x_tables leds_gpio xhci_mtk xhci_plat_hcd xhci_pci xhci_hcd gpio_button_hotplug usbcore nls_base usb_common
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.816930] Process dnsmasq (pid: 970, threadinfo=8f17a000, task=8fdb9f40, tls=77f31da8)
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.824989] Stack : 00000000 803c678c 8f17bbf4 804868a4 00000001 40b59480 00000000 00000000
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.833331]         8f887680 8032bb68 8fd4c000 00000000 00000001 805fb690 8e9c2300 8f17bbec
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.841672]         8ea4d180 8f17bbf4 8ea4d180 80124038 00000001 fffffff0 8f3eb300 8ea40080
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.850014]         00000000 00000000 00000000 00000000 00000000 805a0000 78b39efe 000080fe
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.858353]         8eb59480 00000000 00000010 00000003 00000001 00000004 00000001 00000005
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.866690]         ...
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.869134] Call Trace:
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.871583] [<803a0b68>] tcp_poll+0x1b4/0x310
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.875935] [<8032bb68>] sock_poll+0xa8/0xc8
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.880209] [<80124038>] do_sys_poll+0x224/0x4f4
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.884810] [<80124c1c>] SyS_poll+0xb0/0x108
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.889083] [<80019578>] syscall_common+0x34/0x58
Aug 25 16:48:08 192.168.2.9 OpenWrt_Huiskamer kernel: [  633.893771] Code: 10600048  00000000  8e020020 <8c420058> 1040002a  00000000  0040f809  02002025  14400026

 OpenWrt SNAPSHOT, r7925-b6adfde0c6
 -----------------------------------------------------
root@OpenWrt_Huiskamer:~# uname -a
Linux OpenWrt_Huiskamer 4.14.66 #0 SMP Fri Aug 24 19:33:54 2018 mips GNU/Linux
root@OpenWrt_Huiskamer:~# cat /proc/cpuinfo
system type     : MediaTek MT7621 ver:1 eco:3
machine         : Xiaomi Mi Router 3G
djwlindenaar commented 6 years ago

Update: I've tried again with latest snapshot and now with a serial console running. Withing 10 minutes after bringing the MT7603 up (around uptime of 19500s), kernel oops. Before that no issues were seen (with only 5GHz). Anything I could try?

[20112.065008] Oops[#1]:
[20112.067292] CPU: 3 PID: 11887 Comm: uhttpd Not tainted 4.14.67 #0
[20112.073370] task: 8e06be80 task.stack: 8ed74000
[20112.077884] $ 0   : 00000000 8e048b0f 00000000 81242700
[20112.083111] $ 4   : 805a01b8 00000001 00000001 07406000
[20112.088333] $ 8   : 00b37ac2 00b37ac1 00000000 7273752f
[20112.093559] $12   : 45474155 00000040 00000000 2d6e653d
[20112.098784] $16   : 8fc02900 014000c0 8ed88000 805a0000
[20112.104009] $20   : 8e048b02 8062feb4 fffffff8 805b0000
[20112.109256] $24   : 00000001 801d5140                  
[20112.114503] $28   : 8ed74000 8ed75df0 00000002 8011e270
[20112.119724] Hi    : 00000000
[20112.122584] Lo    : 00000000
[20112.125490] epc   : 8010782c kmem_cache_alloc+0x128/0x17c
[20112.130876] ra    : 8011e270 getname_kernel+0x3c/0xf4
[20112.135917] Status: 11007c03 KERNEL EXL IE 
[20112.140103] Cause : 40800008 (ExcCode 02)
[20112.144120] BadVA : 07406000
[20112.147026] PrId  : 0001992f (MIPS 1004Kc)
[20112.151100] Modules linked in: pppoe ppp_async pppox ppp_generic nf_conntrack_ipv6 mt76x2e mt7603e mt76 mac80211 iptable_nat ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_FLOWOFFLOAD xt_CT slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_conntrack_ipv4 nf_nat_ipv4 nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack iptable_mangle iptable_filter ip_tables crc_ccitt compat ledtrig_usbport ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables x_tables leds_gpio xhci_mtk xhci_plat_hcd xhci_pci xhci_hcd gpio_button_hotplug usbcore nls_base usb_common
[20112.219543] Process uhttpd (pid: 11887, threadinfo=8ed74000, task=8e06be80, tls=77fe0da8)
[20112.227690] Stack : 00000000 00000000 00000010 8e455000 8e048b00 0000000d 01400000 8011e270
[20112.236026]         811cbaa0 811cbaa0 80000000 8e048b00 8e048b00 8e048b00 80630000 fffffffe
[20112.244360]         805a9b60 801142ac 00000002 80113d90 ffffffff 8ed75e6c 8e048b00 8e048b00
[20112.252694]         8e048b00 80160f6c 00000000 80000000 00000011 8ed75e8c 00000000 8e048b02
[20112.261026]         805aa0b0 80115320 00000000 8f8b1cb0 77ef49d0 8e048b00 8e048b00 80538f8c
[20112.269363]         ...
[20112.271800] Call Trace:
[20112.274259] [<8010782c>] kmem_cache_alloc+0x128/0x17c
[20112.279299] [<8011e270>] getname_kernel+0x3c/0xf4
[20112.284002] [<801142ac>] open_exec+0x14/0x60
[20112.288276] [<80160f6c>] load_script+0x1fc/0x250
[20112.292872] [<80115320>] search_binary_handler.part.9+0xa8/0x234
[20112.298855] [<80115c88>] do_execveat_common+0x4d8/0x6a4
[20112.304059] [<80116080>] SyS_execve+0x34/0x48
[20112.308411] [<80019578>] syscall_common+0x34/0x58
[20112.313094] Code: 00000000  8e020014  00e23821 <8ce20000> 10000009  cc400000  1040ffbd  00000000  8e060010 
[20112.322820] 
[20112.327865] ---[ end trace 779e46925637e214 ]---
[20112.335526] Kernel panic - not syncing: Fatal exception
djwlindenaar commented 6 years ago

More...

[ 2171.413234] CPU 2 Unable to handle kernel paging request at virtual address 07406000, epc == 8010782c, ra == 803391cc
[ 2171.423865] Oops[#1]:
[ 2171.426137] CPU: 2 PID: 923 Comm: rpcd Not tainted 4.14.67 #0
[ 2171.431862] task: 8fdd8640 task.stack: 8f11e000
[ 2171.436376] $ 0   : 00000000 7fbff314 00000000 81235318
[ 2171.441598] $ 4   : 805a01b8 00000001 00000001 07406000
[ 2171.446810] $ 8   : 00032b5d 00032b5c 00000000 80000000
[ 2171.452024] $12   : 8f11e000 00000000 00000000 77f632c0
[ 2171.457242] $16   : 8fc20600 015004c0 8eb80000 8fc20600
[ 2171.462459] $20   : 00000000 0000001c 00000000 00000003
[ 2171.467683] $24   : 00000000 77ec8020                  
[ 2171.472901] $28   : 8f11e000 8f11fc50 00000000 803391cc
[ 2171.478119] Hi    : 00000000
[ 2171.480983] Lo    : 00000000
[ 2171.483873] epc   : 8010782c kmem_cache_alloc+0x128/0x17c
[ 2171.489262] ra    : 803391cc __alloc_skb+0x74/0x180
[ 2171.494119] Status: 11007c03 KERNEL EXL IE 
[ 2171.498294] Cause : 40800008 (ExcCode 02)
[ 2171.502289] BadVA : 07406000
[ 2171.505156] PrId  : 0001992f (MIPS 1004Kc)
[ 2171.509231] Modules linked in: pppoe ppp_async pppox ppp_generic nf_conntrack_ipv6 mt76x2e mt7603e mt76 mac80211 iptable_nat ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_FLOWOFFLOAD xt_CT slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_conntrack_ipv4 nf_nat_ipv4 nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack iptable_mangle iptable_filter ip_tables crc_ccitt compat ledtrig_usbport ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables x_tables leds_gpio xhci_mtk xhci_plat_hcd xhci_pci xhci_hcd gpio_button_hotplug usbcore nls_base usb_common
[ 2171.577663] Process rpcd (pid: 923, threadinfo=8f11e000, task=8fdd8640, tls=77f64da8)
[ 2171.585460] Stack : 10000000 8006580c 00000000 8e8df878 8e8c8f00 0000001c 015004c0 803391cc
[ 2171.593819]         00000001 80065688 805a0000 80129cf8 8f11fcf8 00000000 8e8df880 8e8c8f00
[ 2171.602159]         00000000 00000000 00020000 00000000 0000001c 8033a8f4 00000000 800657b4
[ 2171.610498]         8f9eda18 00000000 8e8f9720 802299a4 8e8c8f00 00000000 8f11fee8 00020000
[ 2171.618838]         80065da4 0000001c 00000000 00000000 00000000 80331dc4 8eb80540 8f11fee8
[ 2171.627178]         ...
[ 2171.629621] Call Trace:
[ 2171.632081] [<8010782c>] kmem_cache_alloc+0x128/0x17c
[ 2171.637129] [<803391cc>] __alloc_skb+0x74/0x180
[ 2171.641642] [<8033a8f4>] alloc_skb_with_frags+0x80/0x1e4
[ 2171.646958] [<80331dc4>] sock_alloc_send_pskb+0x234/0x29c
[ 2171.652350] [<804036cc>] unix_stream_sendmsg+0x180/0x37c
[ 2171.657649] [<8032f084>] ___sys_sendmsg+0x1b4/0x268
[ 2171.662518] [<803300b0>] __sys_sendmsg+0x54/0x84
[ 2171.667140] [<80019578>] syscall_common+0x34/0x58
[ 2171.671824] Code: 00000000  8e020014  00e23821 <8ce20000> 10000009  cc400000  1040ffbd  00000000  8e060010 
[ 2171.681551] 
[ 2171.683324] CPU 2 Unable to handle kernel paging request at virtual address 07406000, epc == 801077a0, ra == 803391cc
[ 2171.693929] Oops[#2]:
[ 2171.696216] CPU: 2 PID: 923 Comm: rpcd Tainted: G      D         4.14.67 #0
[ 2171.703154] task: 8fdd8640 task.stack: 8f11e000
[ 2171.707663] $ 0   : 00000000 00000001 07406000 00c33000
[ 2171.712880] $ 4   : 805a01b8 01080020 81235318 ffffffff
[ 2171.718097] $ 8   : 00032b5d 00000003 00000008 8e2e46c0
[ 2171.723314] $12   : 8f68d400 8f68d444 804b3e8c 00000001
[ 2171.728527] $16   : 8fc20600 01080020 07406000 8fc20600
[ 2171.733743] $20   : 00000000 000000b3 00000000 00000000
[ 2171.738958] $24   : c0a80208 00000000                  
[ 2171.744171] $28   : 8f11e000 8fc118d8 8ea6b780 803391cc
[ 2171.749386] Hi    : 00000000
[ 2171.752255] Lo    : 00000000
[ 2171.755148] epc   : 801077a0 kmem_cache_alloc+0x9c/0x17c
[ 2171.760450] ra    : 803391cc __alloc_skb+0x74/0x180
[ 2171.765301] Status: 11007c03 KERNEL EXL IE 
[ 2171.769478] Cause : 40800008 (ExcCode 02)
[ 2171.773473] BadVA : 07406000
[ 2171.776340] PrId  : 0001992f (MIPS 1004Kc)
[ 2171.780413] Modules linked in: pppoe ppp_async pppox ppp_generic nf_conntrack_ipv6 mt76x2e mt7603e mt76 mac80211 iptable_nat ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_FLOWOFFLOAD xt_CT slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_conntrack_ipv4 nf_nat_ipv4 nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack iptable_mangle iptable_filter ip_tables crc_ccitt compat ledtrig_usbport ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables x_tables leds_gpio xhci_mtk xhci_plat_hcd xhci_pci xhci_hcd gpio_button_hotplug usbcore nls_base usb_common
[ 2171.848873] Process rpcd (pid: 923, threadinfo=8f11e000, task=8fdd8640, tls=77f64da8)
[ 2171.856667] Stack : 8edab3c0 00000000 8fd5b000 8f0ad000 8ff20fc0 000000b3 01080020 803391cc
[ 2171.865007]         805c2028 00000000 8f0ad000 00000002 805c1760 8edab3c0 00000000 8ff20fc0
[ 2171.873346]         00000000 00000000 00020000 00000000 000000b3 8033a8f4 00000000 8fdd9d10
[ 2171.881685]         00000000 80015fc8 00000001 80456504 8ff20fc0 00000000 00000050 00020000
[ 2171.890025]         80065da4 000000b3 00000000 8ff20fc0 8ea6b780 80331dc4 8ea39618 8edab3c0
[ 2171.898365]         ...
[ 2171.900805] Call Trace:
[ 2171.903256] [<801077a0>] kmem_cache_alloc+0x9c/0x17c
[ 2171.908216] [<803391cc>] __alloc_skb+0x74/0x180
[ 2171.912737] [<8033a8f4>] alloc_skb_with_frags+0x80/0x1e4
[ 2171.918051] [<80331dc4>] sock_alloc_send_pskb+0x234/0x29c
[ 2171.923435] [<80331e48>] sock_alloc_send_skb+0x1c/0x28
[ 2171.928583] [<803998b4>] __ip_append_data.isra.3+0x2d4/0x834
[ 2171.934227] [<80399ed4>] ip_append_data.part.4+0xc0/0xe8
[ 2171.939542] [<803cec8c>] icmp_push_reply+0x84/0x168
[ 2171.944409] [<803cf598>] icmp_reply.constprop.12+0x1e0/0x23c
[ 2171.950057] [<803cf664>] icmp_echo+0x70/0x98
[ 2171.954308] [<803cfebc>] icmp_rcv+0x314/0x36c
[ 2171.958657] [<8039517c>] ip_local_deliver_finish+0x18c/0x248
[ 2171.964300] [<8039577c>] ip_local_deliver+0x78/0xdc
[ 2171.969168] [<80395a80>] ip_rcv+0x2a0/0x320
[ 2171.973345] [<8034bc58>] __netif_receive_skb_core+0xa94/0xc5c
[ 2171.979083] [<80351bc0>] netif_receive_skb_internal+0xd8/0xf0
[ 2171.984836] [<80457df0>] br_pass_frame_up+0xe8/0x154
[ 2171.989787] [<804583e8>] br_handle_frame_finish+0x534/0x578
[ 2171.995346] [<8045875c>] br_handle_frame+0x330/0x3d4
[ 2172.000301] [<8034b94c>] __netif_receive_skb_core+0x788/0xc5c
[ 2172.006032] [<8034e7c4>] process_backlog+0x98/0x160
[ 2172.010897] [<8035202c>] net_rx_action+0x150/0x30c
[ 2172.015697] [<80489250>] __do_softirq+0x128/0x2ec
[ 2172.020402] [<80032ab4>] irq_exit+0xac/0xc8
[ 2172.024589] [<8024b02c>] plat_irq_dispatch+0xfc/0x138
[ 2172.029632] [<8000b5e8>] except_vec_vi_end+0xb8/0xc4
[ 2172.034595] [<800108c8>] die+0xd4/0x11c
[ 2172.038437] [<8001c6b0>] __do_page_fault+0x350/0x478
[ 2172.043390] [<800220a8>] tlb_do_page_fault_0+0x118/0x120
[ 2172.048695] [<803391cc>] __alloc_skb+0x74/0x180
[ 2172.053208] Code: 00000000  8e020014  02421021 <8c470000> 41666000  30c60001  000000c0  8f85000c  8e020000 
[ 2172.062937] 
[ 2172.064626] ---[ end trace 23fa26d415efcf5a ]---
[ 2172.071373] Kernel panic - not syncing: Fatal exception in interrupt
djwlindenaar commented 6 years ago

And two more...

[ 5874.665454] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 4.14.67 #0
[ 5874.671434] task: 8fc44b00 task.stack: 8fc70000
[ 5874.675938] $ 0   : 00000000 00000001 00000000 812426d0
[ 5874.681157] $ 4   : 805a01b8 00000001 00000001 07406000
[ 5874.686372] $ 8   : 0000b16d 0000b16c 00000008 8ea96760
[ 5874.691580] $12   : 8ea17e00 8ea17e44 804b3e8c 00000001
[ 5874.696789] $16   : 8fc02c00 01090220 8f3b0000 803391f4
[ 5874.701999] $20   : 00000180 000000b3 00000000 00000000
[ 5874.707207] $24   : c0a80208 00000000                  
[ 5874.712418] $28   : 8fc70000 8fc158b0 8ea90880 80108a1c
[ 5874.717627] Hi    : 00000000
[ 5874.720490] Lo    : 00000000
[ 5874.723385] epc   : 80108b38 __kmalloc_track_caller+0x1d4/0x228
[ 5874.729274] ra    : 80108a1c __kmalloc_track_caller+0xb8/0x228
[ 5874.735074] Status: 11007c03 KERNEL EXL IE 
[ 5874.739245] Cause : 40800008 (ExcCode 02)
[ 5874.743232] BadVA : 07406000
[ 5874.746095] PrId  : 0001992f (MIPS 1004Kc)
[ 5874.750167] Modules linked in: pppoe ppp_async pppox ppp_generic nf_conntrack_ipv6 mt76x2e mt7603e mt76 mac80211 iptable_nat ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_FLOWOFFLOAD xt_CT slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_conntrack_ipv4 nf_nat_ipv4 nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack iptable_mangle iptable_filter ip_tables crc_ccitt compat ledtrig_usbport ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables x_tables leds_gpio xhci_mtk xhci_plat_hcd xhci_pci xhci_hcd gpio_button_hotplug usbcore nls_base usb_common
[ 5874.818578] Process swapper/3 (pid: 0, threadinfo=8fc70000, task=8fc44b00, tls=00000000)
[ 5874.826626] Stack : 00000000 8fc20600 00000000 801076e0 8eedaa80 8fc1590f 01080020 803390f4
[ 5874.834960]         8fc20600 80107784 00000000 8f2a9900 8eedaa80 000000d2 01080020 8fc20600
[ 5874.843294]         00000000 803391f4 8fc01d80 811b4600 00000000 812426f0 8fc02a00 01090220
[ 5874.851627]         00000000 8fd91260 00000000 00000000 00020000 00000000 000000b3 8033a8f4
[ 5874.859960]         00000000 8fc02a00 00000003 8fc02a00 8fc02a00 801057f0 8fd91260 00000000
[ 5874.868293]         ...
[ 5874.870728] Call Trace:
[ 5874.873164] [<80108b38>] __kmalloc_track_caller+0x1d4/0x228
[ 5874.878722] [<803390f4>] __kmalloc_reserve.isra.7+0x40/0xa4
[ 5874.884270] [<803391f4>] __alloc_skb+0x9c/0x180
[ 5874.888781] [<8033a8f4>] alloc_skb_with_frags+0x80/0x1e4
[ 5874.894093] [<80331dc4>] sock_alloc_send_pskb+0x234/0x29c
[ 5874.899471] [<80331e48>] sock_alloc_send_skb+0x1c/0x28
[ 5874.904608] [<803998b4>] __ip_append_data.isra.3+0x2d4/0x834
[ 5874.910243] [<80399ed4>] ip_append_data.part.4+0xc0/0xe8
[ 5874.915552] [<803cec8c>] icmp_push_reply+0x84/0x168
[ 5874.920410] [<803cf598>] icmp_reply.constprop.12+0x1e0/0x23c
[ 5874.926043] [<803cf664>] icmp_echo+0x70/0x98
[ 5874.930297] [<803cfebc>] icmp_rcv+0x314/0x36c
[ 5874.934634] [<8039517c>] ip_local_deliver_finish+0x18c/0x248
[ 5874.940268] [<8039577c>] ip_local_deliver+0x78/0xdc
[ 5874.945122] [<80395a80>] ip_rcv+0x2a0/0x320
[ 5874.949294] [<8034bc58>] __netif_receive_skb_core+0xa94/0xc5c
[ 5874.955026] [<80351bc0>] netif_receive_skb_internal+0xd8/0xf0
[ 5874.960772] [<80457df0>] br_pass_frame_up+0xe8/0x154
[ 5874.965714] [<804583e8>] br_handle_frame_finish+0x534/0x578
[ 5874.971263] [<8045875c>] br_handle_frame+0x330/0x3d4
[ 5874.976204] [<8034b94c>] __netif_receive_skb_core+0x788/0xc5c
[ 5874.981926] [<8034e7c4>] process_backlog+0x98/0x160
[ 5874.986781] [<8035202c>] net_rx_action+0x150/0x30c
[ 5874.991574] [<80489250>] __do_softirq+0x128/0x2ec
[ 5874.996269] [<80032ab4>] irq_exit+0xac/0xc8
[ 5875.000454] [<8024b02c>] plat_irq_dispatch+0xfc/0x138
[ 5875.005488] [<8000b5e8>] except_vec_vi_end+0xb8/0xc4
[ 5875.010434] [<8000cfb0>] r4k_wait_irqoff+0x1c/0x24
[ 5875.015226] [<800666cc>] do_idle+0xe4/0x168
[ 5875.019394] [<80066948>] cpu_startup_entry+0x24/0x2c
[ 5875.024340] Code: 00000000  8e020014  00e23821 <8ce20000> 10000009  cc400000  1040ffbd  00000000  8e060010 
[ 5875.034064] 
[ 5875.035687] ---[ end trace 7e6c827a4fbaaaf3 ]---
[ 5875.042197] Kernel panic - not syncing: Fatal exception in interrupt
[ 5457.291173] CPU 3 Unable to handle kernel paging request at virtual address 07406000, epc == 80108b38, ra == 80108a1c
[ 5457.301766] Oops[#1]:
[ 5457.304032] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 4.14.67 #0
[ 5457.310014] task: 8fc44b00 task.stack: 8fc70000
[ 5457.314521] $ 0   : 00000000 00000001 00000000 812426f0
[ 5457.319733] $ 4   : 805a01b8 00000001 00000001 07406000
[ 5457.324942] $ 8   : 0029ef52 0029ef51 00000001 88000000
[ 5457.330151] $12   : 8fc15f60 00000008 8e289980 000004f6
[ 5457.335361] $16   : 8fc02a00 01090220 8e068000 8033afd4
[ 5457.340571] $20   : 00000720 00000000 8f118bc0 01080020
[ 5457.345781] $24   : 00000000 8000cf94                  
[ 5457.350990] $28   : 8fc70000 8fc159b0 00000000 80108a1c
[ 5457.356200] Hi    : 00002665
[ 5457.359062] Lo    : 94af5487
[ 5457.361956] epc   : 80108b38 __kmalloc_track_caller+0x1d4/0x228
[ 5457.367845] ra    : 80108a1c __kmalloc_track_caller+0xb8/0x228
[ 5457.373646] Status: 11007c03 KERNEL EXL IE 
[ 5457.377816] Cause : 40800008 (ExcCode 02)
[ 5457.381803] BadVA : 07406000
[ 5457.384666] PrId  : 0001992f (MIPS 1004Kc)
[ 5457.388738] Modules linked in: pppoe ppp_async pppox ppp_generic nf_conntrack_ipv6 mt76x2e mt7603e mt76 mac80211 iptable_nat ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_FLOWOFFLOAD xt_CT slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_conntrack_ipv4 nf_nat_ipv4 nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack iptable_mangle iptable_filter ip_tables crc_ccitt compat ledtrig_usbport ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables x_tables leds_gpio xhci_mtk xhci_plat_hcd xhci_pci xhci_hcd gpio_button_hotplug usbcore nls_base usb_common
[ 5457.457165] Process swapper/3 (pid: 0, threadinfo=8fc70000, task=8fc44b00, tls=00000000)
[ 5457.465218] Stack : 8f577ebc 8f219c80 8f577e54 8f577e78 8e978e40 00000000 01080020 803390f4
[ 5457.473554]         00000000 00000000 8f577ef0 80335ec0 8e978e40 8e978e40 00000000 00000660
[ 5457.481889]         00000018 8033afd4 867e8e83 8e9b8c50 8f577e4c 8f577ee4 8e9b8c5c 8f118bc0
[ 5457.490226]         8e978e40 00000006 8f170a46 00000018 00000000 8f118bc0 00000000 8f22cdd4
[ 5457.498564]         00000548 8f098000 8fc15aac 8ea0b700 8e352480 8f22d6ec 00000000 00000000
[ 5457.506902]         ...
[ 5457.509338] Call Trace:
[ 5457.511783] [<80108b38>] __kmalloc_track_caller+0x1d4/0x228
[ 5457.517341] [<803390f4>] __kmalloc_reserve.isra.7+0x40/0xa4
[ 5457.522892] [<8033afd4>] pskb_expand_head+0x88/0x318
[ 5457.527969] [<8f22cdd4>] ieee80211_beacon_get_tim+0x244/0xebc [mac80211]
[ 5457.534687] Code: 00000000  8e020014  00e23821 <8ce20000> 10000009  cc400000  1040ffbd  00000000  8e060010 
[ 5457.544421] 
[ 5457.546093] ---[ end trace 0d184c9b71478196 ]---
[ 5457.552526] Kernel panic - not syncing: Fatal exception in interrupt
djwlindenaar commented 6 years ago

another...

[ 6714.047044] CPU 0 Unable to handle kernel paging request at virtual address 00000014, epc == 8033cf3c, ra == 8033cf80
[ 6714.057668] Oops[#1]:
[ 6714.059934] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.14.67 #0
[ 6714.065914] task: 805a2a40 task.stack: 80590000
[ 6714.070418] $ 0   : 00000000 00000001 8e17ff40 8e180050
[ 6714.075629] $ 4   : 00000000 406f34dc 0000006c 00000000
[ 6714.080837] $ 8   : 00000004 ffffff80 ffffffff 00000200
[ 6714.086046] $12   : 00000100 00000000 ffffffff 00000000
[ 6714.091253] $16   : 00000022 00000000 8ea3b840 0000000c
[ 6714.096462] $20   : 00000001 0000f8c4 00000000 8f129a20
[ 6714.101671] $24   : 00000000 800c5e9c                  
[ 6714.106878] $28   : 80590000 8fc09d00 00000000 8033cf80
[ 6714.112088] Hi    : 00000027
[ 6714.114949] Lo    : 00000000
[ 6714.117835] epc   : 8033cf3c __pskb_pull_tail+0x258/0x3f4
[ 6714.123208] ra    : 8033cf80 __pskb_pull_tail+0x29c/0x3f4
[ 6714.128575] Status: 11008403 KERNEL EXL IE 
[ 6714.132745] Cause : 40800008 (ExcCode 02)
[ 6714.136732] BadVA : 00000014
[ 6714.139594] PrId  : 0001992f (MIPS 1004Kc)
[ 6714.143664] Modules linked in: pppoe ppp_async pppox ppp_generic nf_conntrack_ipv6 mt76x2e mt7603e mt76 mac80211 iptable_nat ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_FLOWOFFLOAD xt_CT slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_conntrack_ipv4 nf_nat_ipv4 nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack iptable_mangle iptable_filter ip_tables crc_ccitt compat ledtrig_usbport ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables x_tables leds_gpio xhci_mtk xhci_plat_hcd xhci_pci xhci_hcd gpio_button_hotplug usbcore nls_base usb_common
[ 6714.212070] Process swapper/0 (pid: 0, threadinfo=80590000, task=805a2a40, tls=00000000)
[ 6714.220116] Stack : 8ea3b840 805a01b8 0000006c 8e9f2210 8ea3b840 8f128bc0 8ee7f840 00000000
[ 6714.228448]         8ee7f840 0000ffc4 8f129a28 8f228a20 01080020 00000003 00000740 00000021
[ 6714.236779]         00000000 01080020 8f129da8 8f17f4b0 01095220 00000003 00000001 00000000
[ 6714.245110]         ffffffff 8f129a28 8ea3b840 8f128bc0 00000000 00000000 00000000 00000000
[ 6714.253440]         00000000 00000000 00000000 00000000 8ea3b840 00000000 8fc09e50 00000000
[ 6714.261770]         ...
[ 6714.264206] Call Trace:
[ 6714.266640] [<8033cf3c>] __pskb_pull_tail+0x258/0x3f4
[ 6714.271804] [<8f228a20>] ieee80211_rx_napi+0x698/0xaf4 [mac80211]
[ 6714.277903] [<8f11207c>] mt76_rx_complete+0x24c/0x2f8 [mt76]
[ 6714.283541] [<8f1122e4>] mt76_rx_poll_complete+0x1bc/0x26c [mt76]
[ 6714.289610] [<8f110e74>] mt76_dma_attach+0xb64/0xde8 [mt76]
[ 6714.295158] Code: 14800015  26040005  8c64002c <8c820014> 30430001  10600002  00000000  2444ffff  0000000f 
[ 6714.304882] 
[ 6714.306523] ---[ end trace 0ee200075efaad72 ]---
[ 6714.312993] Kernel panic - not syncing: Fatal exception in interrupt
nbd168 commented 5 years ago

Please try the latest version (master only, not 18.06).

djwlindenaar commented 5 years ago

Ok. Will put it on tomorrow. And report back the results

djwlindenaar commented 5 years ago

This happened just now... Not fixed yet...

Modules:    pppoe@8f3d8000+2290 ppp_async@8f3d4000+1be0 pppox@8e9bc000+58a  ppp_generic@8f3c8000+5aa2   nf_conntrack_ipv6@8e9c2000+15e0 mt76x2e@8e984000+2b5b   mt76x2_common@8f0d8000+2c88 mt76x02_lib@8f2e0000+8c27   mt7603e@8f1b0000+79c9   mt76@8e948000+5c0a  mac80211@8f200000+6f2e1 iptable_nat@8f11d000+310    ipt_REJECT@8f7c3000+410 ipt_MASQUERADE@8f02b000+2f0 cfg80211@8f140000+395b0 xt_time@8e941000+730    xt_tcpudp@8f78c000+750  xt_state@8e86f000+310   xt_nat@8e9cd000+650 xt_multiport@8e9cb000+550   xt_mark@8e9c8000+2f0    xt_mac@8e9c4000+2b0 xt_limit@8e9b7000+4f0   xt_conntrack@8e9b5000+950   xt_comment@8e9b1000+230 xt_TCPMSS@8e9ae000+b30  xt_REDIRECT@8f0c8000+310    xt_LOG@8f0c5000+350 xt_FLOWOFFLOAD@8f0c2000+b60 xt_CT@8e85f000+ad0  slhc@8e9a0000+149b  nf_reject_ipv4@8f0f3000+923 nf_nat_redirect@8f0f6000+5fb    nf_nat_masquerade_ipv4@8e83c000+67c nf_conntrack_ipv4@8e8d4000+1470 nf_nat_ipv4@8e996000+1031   nf_nat@8e98c000+3adc    nf_log_ipv4@8e841000+dd0    nf_flow_table_hw@8e84c000+920   nf_flow_table@8e980000+365f nf_defrag_ipv6@8f0dc000+139e    nf_defrag_ipv4@8e84f000+4b6 nf_conntrack_rtcache@8e851000+af0   nf_conntrack@8f0e0000+1168d iptable_mangle@8e844000+3d0 iptable_filter@8f0b8000+2d0 ip_tables@8e86c000+2bcd crc_ccitt@8e974000+42b  compat@8e97a000+406ledtrig_usbport@8f78f000+b00 ip6t_REJECT@8e923000+450    nf_reject_ipv6@8f76d000+ac8 nf_log_ipv6@8e828000+1070   nf_log_common@8f76e000+baf  ip6table_mangle@8f7f0000+4d0    ip6table_filter@8e963000+2d0    ip6_tables@8e95c000+2aa1    x_tables@8e958000+374f  leds_gpio@8f03f000+bb0  xhci_mtk@8f038000+14b0  xhci_plat_hcd@8f794000+1650 xhci_pci@8f79e000+b30   xhci_hcd@8f040000+16ba9 gpio_button_hotplug@8f7e6000+1930   usbcore@8f000000+210b1  nls_base@8f792000+1550  usb_common@8f78b000+a17
<6>[    2.527486] nand: ESMT NAND 128MiB 3,3V 8-bit
<6>[    2.531822] nand: 128 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
<6>[    2.539388] Scanning device for bad blocks
<5>[    2.687809] 10 fixed-partitions partitions found on MTD device MT7621-NAND
<5>[    2.694649] Creating 10 MTD partitions on "MT7621-NAND":
<5>[    2.699960] 0x000000000000-0x000000080000 : "Bootloader"
<5>[    2.706401] 0x000000080000-0x0000000c0000 : "Config"
<5>[    2.712392] 0x0000000c0000-0x000000100000 : "Bdata"
<5>[    2.718330] 0x000000100000-0x000000140000 : "Factory"
<5>[    2.724406] 0x000000140000-0x000000180000 : "crash"
<5>[    2.730319] 0x000000180000-0x0000001c0000 : "crash_syslog"
<5>[    2.736865] 0x0000001c0000-0x000000200000 : "reserved0"
<5>[    2.743165] 0x000000200000-0x000000600000 : "kernel_stock"
<5>[    2.749779] 0x000000600000-0x000000a00000 : "kernel"
<5>[    2.755802] 0x000000a00000-0x000007f80000 : "ubi"
<4>[    2.762519] [mtk_nand] probe successfully!
<4>[    2.767374] Signature matched and data read!
<4>[    2.771621] load_fact_bbt success 1023
<6>[    2.776148] libphy: Fixed MDIO Bus: probed
<6>[    2.849680] libphy: mdio: probed
<6>[    4.253371] mtk_soc_eth 1e100000.ethernet: loaded mt7530 driver
<6>[    4.260071] mtk_soc_eth 1e100000.ethernet eth0: mediatek frame engine at 0xbe100000, irq 20
<6>[    4.270888] NET: Registered protocol family 10
<6>[    4.276796] Segment Routing with IPv6
<6>[    4.280632] NET: Registered protocol family 17
<6>[    4.285112] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
<6>[    4.298032] 8021q: 802.1Q VLAN Support v1.8
<5>[    4.305228] UBI: auto-attach mtd9
<5>[    4.308642] ubi0: attaching mtd9
<5>[    5.418850] ubi0: scanning is finished
<5>[    5.438674] ubi0: attached mtd9 (name "ubi", size 117 MiB)
<5>[    5.444150] ubi0: PEB size: 131072 bytes (128 KiB), LEB size: 126976 bytes
<5>[    5.451061] ubi0: min./max. I/O unit sizes: 2048/2048, sub-page size 2048
<5>[    5.457846] ubi0: VID header offset: 2048 (aligned 2048), data offset: 4096
<5>[    5.464771] ubi0: good PEBs: 940, bad PEBs: 0, corrupted PEBs: 0
<5>[    5.470765] ubi0: user volume: 2, internal volumes: 1, max. volumes count: 128
<5>[    5.477977] ubi0: max/mean erase counter: 4/1, WL threshold: 4096, image sequence number: 882138774
<5>[    5.486978] ubi0: available PEBs: 0, total reserved PEBs: 940, PEBs reserved for bad PEB handling: 20
<5>[    5.496197] ubi0: background thread "ubi_bgt0d" started, PID 392
<6>[    5.498254] block ubiblock0_0: created from ubi0:0(rootfs)
<5>[    5.498268] ubiblock: device ubiblock0_0 (rootfs) set to be root filesystem
<6>[    5.498288] hctosys: unable to open rtc device (rtc0)
<6>[    5.498679] usb_vbus: disabling
<6>[    5.528487] VFS: Mounted root (squashfs filesystem) readonly on device 254:0.
<6>[    5.536151] Freeing unused kernel memory: 252K
<4>[    5.540618] This architecture does not have kernel memory protection.
<14>[    5.960776] init: Console is alive
<14>[    5.964416] init: - watchdog -
<6>[    6.102632] mtk_soc_eth 1e100000.ethernet eth0: port 2 link up
<14>[    6.543098] kmodloader: loading kernel modules from /etc/modules-boot.d/*
<6>[    6.633879] usbcore: registered new interface driver usbfs
<6>[    6.639493] usbcore: registered new interface driver hub
<6>[    6.644957] usbcore: registered new device driver usb
<4>[    6.659967] xhci-mtk 1e1c0000.xhci: 1e1c0000.xhci supply vusb33 not found, using dummy regulator
<6>[    6.668961] xhci-mtk 1e1c0000.xhci: xHCI Host Controller
<6>[    6.674282] xhci-mtk 1e1c0000.xhci: new USB bus registered, assigned bus number 1
<6>[    6.687296] xhci-mtk 1e1c0000.xhci: hcc params 0x01401198 hci version 0x96 quirks 0x00210010
<6>[    6.695774] xhci-mtk 1e1c0000.xhci: irq 19, io mem 0x1e1c0000
<6>[    6.702582] hub 1-0:1.0: USB hub found
<6>[    6.706400] hub 1-0:1.0: 2 ports detected
<6>[    6.711119] xhci-mtk 1e1c0000.xhci: xHCI Host Controller
<6>[    6.716435] xhci-mtk 1e1c0000.xhci: new USB bus registered, assigned bus number 2
<6>[    6.723934] xhci-mtk 1e1c0000.xhci: Host supports USB 3.0  SuperSpeed
<6>[    6.730548] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
<6>[    6.739564] hub 2-0:1.0: USB hub found
<6>[    6.743384] hub 2-0:1.0: 1 port detected
<14>[    6.750745] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
<14>[    6.767452] init: - preinit -
<6>[    7.486134] mtk_soc_eth 1e100000.ethernet: PPE started
<5>[    7.563625] random: procd: uninitialized urandom read (4 bytes read)
<5>[   10.646593] UBIFS (ubi0:1): background thread "ubifs_bgt0_1" started, PID 495
<5>[   10.720490] UBIFS (ubi0:1): recovery needed
<5>[   10.913016] UBIFS (ubi0:1): recovery completed
<5>[   10.917586] UBIFS (ubi0:1): UBIFS: mounted UBI device 0, volume 1, name "rootfs_data"
<5>[   10.925381] UBIFS (ubi0:1): LEB size: 126976 bytes (124 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
<5>[   10.935265] UBIFS (ubi0:1): FS size: 112500736 bytes (107 MiB, 886 LEBs), journal size 5586944 bytes (5 MiB, 44 LEBs)
<5>[   10.945834] UBIFS (ubi0:1): reserved for root: 4952683 bytes (4836 KiB)
<5>[   10.952434] UBIFS (ubi0:1): media format: w4/r0 (latest is w5/r0), UUID FA999E51-890B-4B09-95E5-24BAA5545859, small LPT model
<14>[   10.975295] mount_root: switching to ubifs overlay
<12>[   11.006144] urandom-seed: Seeding with /etc/urandom.seed
<6>[   11.112475] mtk_soc_eth 1e100000.ethernet: 0x100 = 0x5a60000c, 0x10c = 0x80818
<14>[   11.129926] procd: - early -
<14>[   11.132905] procd: - watchdog -
<14>[   11.767310] procd: - watchdog -
<14>[   11.770767] procd: - ubus -
<5>[   11.816149] random: ubusd: uninitialized urandom read (4 bytes read)
<5>[   11.832222] random: ubusd: uninitialized urandom read (4 bytes read)
<5>[   11.838987] random: ubusd: uninitialized urandom read (4 bytes read)
<14>[   11.846154] procd: - init -
<14>[   12.160949] kmodloader: loading kernel modules from /etc/modules.d/*
<6>[   12.171334] ip6_tables: (C) 2000-2006 Netfilter Core Team
<6>[   12.185649] Loading modules backported from Linux version v4.19-rc5-0-g6bf4ca7fbc85
<6>[   12.193343] Backport generated by backports.git v4.19-rc5-1-0-g05571dcd
<6>[   12.201951] ip_tables: (C) 2000-2006 Netfilter Core Team
<6>[   12.214212] nf_conntrack version 0.5.0 (4096 buckets, 16384 max)
<6>[   12.259329] xt_time: kernel timezone is -0000
<4>[   12.326256] bus=0x1, slot = 0x0, irq=0xff
<6>[   12.330523] mt7603e 0000:01:00.0: ASIC revision: 76030010
<6>[   12.361649] mt7603e 0000:01:00.0: Firmware Version: ap_pcie
<6>[   12.367270] mt7603e 0000:01:00.0: Build Time: 20160107100755
<4>[   12.407131] firmware init done
<7>[   12.581394] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
<4>[   12.591655] bus=0x2, slot = 0x1, irq=0xff
<6>[   12.595975] mt76x2e 0000:02:00.0: ASIC revision: 76120044
<6>[   13.321666] mt76x2e 0000:02:00.0: ROM patch build: 20141115060606a
<6>[   13.331353] mt76x2e 0000:02:00.0: Firmware Version: 0.0.00
<6>[   13.336831] mt76x2e 0000:02:00.0: Build: 1
<6>[   13.340926] mt76x2e 0000:02:00.0: Build Time: 201507311614____
<6>[   13.367137] mt76x2e 0000:02:00.0: Firmware running!
<7>[   13.374997] ieee80211 phy1: Selected rate control algorithm 'minstrel_ht'
<6>[   13.382312] PPP generic driver version 2.4.2
<6>[   13.388203] NET: Registered protocol family 24
<14>[   13.396681] kmodloader: done loading kernel modules from /etc/modules.d/*
<4>[   13.938218] urandom_read: 5 callbacks suppressed
<5>[   13.938229] random: jshn: uninitialized urandom read (4 bytes read)
<6>[   18.956453] mtk_soc_eth 1e100000.ethernet: PPE started
<6>[   18.966644] device eth0 entered promiscuous mode
<6>[   18.973207] br-lan: port 1(eth0.1) entered blocking state
<6>[   18.978689] br-lan: port 1(eth0.1) entered disabled state
<6>[   18.984853] device eth0.1 entered promiscuous mode
<6>[   18.996120] br-lan: port 1(eth0.1) entered blocking state
<6>[   19.001665] br-lan: port 1(eth0.1) entered forwarding state
<6>[   19.007813] IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready
<5>[   19.602305] random: crng init done
<6>[   19.997684] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
<6>[   20.488136] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
<6>[   20.497250] br-lan: port 2(wlan0) entered blocking state
<6>[   20.502581] br-lan: port 2(wlan0) entered disabled state
<6>[   20.508364] device wlan0 entered promiscuous mode
<6>[   20.513229] br-lan: port 2(wlan0) entered blocking state
<6>[   20.518570] br-lan: port 2(wlan0) entered forwarding state
<6>[   20.874253] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
<6>[   21.610312] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
<6>[   21.623866] br-lan: port 3(wlan1) entered blocking state
<6>[   21.629303] br-lan: port 3(wlan1) entered disabled state
<6>[   21.635237] device wlan1 entered promiscuous mode
<6>[   86.210015] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
<6>[   86.216826] br-lan: port 3(wlan1) entered blocking state
<6>[   86.222174] br-lan: port 3(wlan1) entered forwarding state
<6>[  171.637786] device wlan1 left promiscuous mode
<6>[  171.642538] br-lan: port 3(wlan1) entered disabled state
<6>[  171.742267] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
<6>[  171.752193] br-lan: port 3(wlan1) entered blocking state
<6>[  171.757808] br-lan: port 3(wlan1) entered disabled state
<6>[  171.763777] device wlan1 entered promiscuous mode
<6>[  234.371958] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
<6>[  234.379000] br-lan: port 3(wlan1) entered blocking state
<6>[  234.384356] br-lan: port 3(wlan1) entered forwarding state
<6>[  328.378144] device wlan1 left promiscuous mode
<6>[  328.382914] br-lan: port 3(wlan1) entered disabled state
<6>[  329.851713] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
<6>[  329.861213] br-lan: port 3(wlan1) entered blocking state
<6>[  329.866519] br-lan: port 3(wlan1) entered disabled state
<6>[  329.872456] device wlan1 entered promiscuous mode
<6>[  359.184585] br-lan: port 3(wlan1) entered disabled state
<6>[  359.258573] device wlan1 left promiscuous mode
<6>[  359.263025] br-lan: port 3(wlan1) entered disabled state
<6>[  359.743144] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
<6>[  370.933024] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
<6>[ 2392.199236] device wlan0 left promiscuous mode
<6>[ 2392.203993] br-lan: port 2(wlan0) entered disabled state
<6>[ 2394.045127] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
<6>[ 2394.057487] br-lan: port 2(wlan0) entered blocking state
<6>[ 2394.062989] br-lan: port 2(wlan0) entered disabled state
<6>[ 2394.069145] device wlan0 entered promiscuous mode
<6>[ 2394.459133] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
<6>[ 2394.465924] br-lan: port 2(wlan0) entered blocking state
<6>[ 2394.471262] br-lan: port 2(wlan0) entered forwarding state
<6>[ 2475.958261] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
<6>[ 2710.259485] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
<6>[ 2710.272779] br-lan: port 3(wlan1) entered blocking state
<6>[ 2710.278186] br-lan: port 3(wlan1) entered disabled state
<6>[ 2710.284205] device wlan1 entered promiscuous mode
<6>[ 2774.217215] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
<6>[ 2774.223967] br-lan: port 3(wlan1) entered blocking state
<6>[ 2774.229323] br-lan: port 3(wlan1) entered forwarding state
<1>[ 3170.812247] CPU 1 Unable to handle kernel paging request at virtual address 07406000, epc == 8010c5c0, ra == 8010c4a4
<4>[ 3170.822847] Oops[#1]:
<4>[ 3170.825114] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.14.78 #0
<4>[ 3170.831095] task: 8fc43e80 task.stack: 8fc64000
<4>[ 3170.835602] $ 0   : 00000000 00000001 00000000 812266f0
<4>[ 3170.840819] $ 4   : 805a61b8 00000001 00000001 07406000
<4>[ 3170.846033] $ 8   : 0009d4cf 0009d4ce 00000001 22000000
<4>[ 3170.851246] $12   : 8fc0df60 00000008 86b122f3 000002e2
<4>[ 3170.856460] $16   : 8fc02a00 01090220 8d9c0000 803415b0
<4>[ 3170.861673] $20   : 00000720 00000000 8f1d0bc0 01080020
<4>[ 3170.866886] $24   : 00000000 8000cf94                  
<4>[ 3170.872100] $28   : 8fc64000 8fc0d9a8 00000000 8010c4a4
<4>[ 3170.877314] Hi    : 00002665
<4>[ 3170.880179] Lo    : 94af5487
<4>[ 3170.883079] epc   : 8010c5c0 __kmalloc_track_caller+0x1d4/0x228
<4>[ 3170.888976] ra    : 8010c4a4 __kmalloc_track_caller+0xb8/0x228
<4>[ 3170.894779] Status: 11007c03  KERNEL EXL IE 
<4>[ 3170.898957] Cause : 40800008 (ExcCode 02)
<4>[ 3170.902947] BadVA : 07406000
<4>[ 3170.905812] PrId  : 0001992f (MIPS 1004Kc)
<4>[ 3170.909886] Modules linked in: pppoe ppp_async pppox ppp_generic nf_conntrack_ipv6 mt76x2e mt76x2_common mt76x02_lib mt7603e mt76 mac80211 iptable_nat ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_FLOWOFFLOAD xt_CT slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_conntrack_ipv4 nf_nat_ipv4 nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack iptable_mangle iptable_filter ip_tables crc_ccitt compat ledtrig_usbport ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables x_tables leds_gpio xhci_mtk xhci_plat_hcd xhci_pci xhci_hcd gpio_button_hotplug usbcore nls_base usb_common
<4>[ 3170.980561] Process swapper/1 (pid: 0, threadinfo=8fc64000, task=8fc43e80, tls=00000000)
<4>[ 3170.988610] Stack : 00000fff 8fc1ec40 00000000 1cc282ae 8ef90b40 00000000 01080020 8033f6d8
<4>[ 3170.996949]         8fc1ee70 8fc1ef08 8f17cc5c ffffffff 8ef90b40 8ef90b40 00000000 00000660
<4>[ 3171.005287]         00000018 803415b0 00000000 00000000 00000548 00000004 00020034 8f1d0bc0
<4>[ 3171.013625]         8ef90b40 00000006 8f1727e6 00000018 00000000 8f1d0bc0 00000000 8f22dca8
<4>[ 3171.021963]         8f17dbd4 8f17d560 8f17cc54 8f0d0000 8fd61480 8f22e5c0 805a0000 8f0e15c4
<4>[ 3171.030302]         ...
<4>[ 3171.032741] Call Trace:
<4>[ 3171.035185] [<8010c5c0>] __kmalloc_track_caller+0x1d4/0x228
<4>[ 3171.040759] [<8033f6d8>] __kmalloc_reserve.isra.7+0x40/0xa4
<4>[ 3171.046319] [<803415b0>] pskb_expand_head+0x88/0x318
<4>[ 3171.051403] [<8f22dca8>] ieee80211_beacon_get_tim+0x244/0xebc [mac80211]
<4>[ 3171.058115] Code: 00000000  8e020014  00e23821 <8ce20000> 10000009  cc400000  1040ffbd  00000000  8e060010 
<4>[ 3171.067847] 
<4>[ 3171.069489] ---[ end trace 987d9f77fb835753 ]---
djwlindenaar commented 5 years ago

Another one:

Is this helpful or do you need a different type of log..?

<1>[   53.725980] CPU 0 Unable to handle kernel paging request at virtual address 00000014, epc == 803413ec, ra == 80341094
<4>[   53.736598] Oops[#1]:
<4>[   53.738863] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.14.78 #0
<4>[   53.744840] task: 805a8a40 task.stack: 80596000
<4>[   53.749345] $ 0   : 00000000 00000001 00000001 00000001
<4>[   53.754557] $ 4   : 00000000 0000000d 8f263830 0000000a
<4>[   53.759764] $ 8   : 0000d2f0 000000c0 8eaa8775 00000000
<4>[   53.764972] $12   : 00010000 00000fff 00000001 00000001
<4>[   53.770181] $16   : 00000013 8eb10004 8eb0ff40 8f3f2b40
<4>[   53.775391] $20   : 00000001 00000001 00000001 8f1bddb0
<4>[   53.780599] $24   : 00000078 8f25af94                  
<4>[   53.785809] $28   : 80596000 8fc09e48 00000000 80341094
<4>[   53.791018] Hi    : 00014f00
<4>[   53.793880] Lo    : 0000000a
<4>[   53.796772] epc   : 803413ec skb_release_data+0x78/0x1b4
<4>[   53.802058] ra    : 80341094 consume_skb+0x60/0x88
<4>[   53.806820] Status: 11008403  KERNEL EXL IE 
<4>[   53.810989] Cause : 40800008 (ExcCode 02)
<4>[   53.814972] BadVA : 00000014
<4>[   53.817835] PrId  : 0001992f (MIPS 1004Kc)
<4>[   53.821905] Modules linked in: pppoe ppp_async pppox ppp_generic nf_conntrack_ipv6 mt76x2e mt76x2_common mt76x02_lib mt7603e mt76 mac80211 iptable_nat ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_FLOWOFFLOAD xt_CT slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_conntrack_ipv4 nf_nat_ipv4 nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack iptable_mangle iptable_filter ip_tables crc_ccitt compat ledtrig_usbport ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables x_tables leds_gpio xhci_mtk xhci_plat_hcd xhci_pci xhci_hcd gpio_button_hotplug usbcore nls_base usb_common
<4>[   53.892570] Process swapper/0 (pid: 0, threadinfo=80596000, task=805a8a40, tls=00000000)
<4>[   53.900616] Stack : 8f3f2b40 8f1bd560 8f3f2b40 803406ec 8f3f2b40 8e26e000 811c7d00 8f3f2b40
<4>[   53.908949]         8f1bd5a0 80341094 80599d20 8f1bd5a0 8e26e000 811c7d00 8f1bd5a0 8f159260
<4>[   53.917281]         8fc09f20 8009ec54 0ed39c80 805b0000 000002e4 00000800 00000001 000002e4
<4>[   53.925611]         8f1bd560 00000000 80640000 00000040 00000000 00000000 80599d38 00000000
<4>[   53.933941]         000002e4 00000000 8f1bda28 00000001 81216560 00000040 0000012c 8fc09f18
<4>[   53.942272]         ...
<4>[   53.944707] Call Trace:
<4>[   53.947142] [<803413ec>] skb_release_data+0x78/0x1b4
<4>[   53.952088] [<80341094>] consume_skb+0x60/0x88
<4>[   53.956529] [<8f159260>] mt76_dma_tx_queue_skb+0xe1c/0x1198 [mt76]
<4>[   53.962680] Code: 10000017  00809825  8e240000 <8c820014> 30430001  10600002  00000000  2444ffff  0000000f 
<4>[   53.972404] 
<4>[   53.974046] ---[ end trace 26d456b7ce34125e ]---
nbd168 commented 5 years ago

Please try latest OpenWrt master

djwlindenaar commented 5 years ago

Just installed it on my MIR3G. Will report anything interesting.

djwlindenaar commented 5 years ago

Well, I did not get any crashes (yet), which is more stable than it's ever been!

Something else is interesting though. I'm getting very long ping latency on the 2.4GHz (check the rtt results. avg 600ms!):

--- 192.168.2.9 ping statistics ---
65546 packets transmitted, 65378 received, 0.256309% packet loss, time 66233ms
rtt min/avg/max/mdev = 0.526/607.335/3470.424/230.510 ms, pipe 4

In the next experiment, I connected my Android phone (OnePlus 5) to the 2.4 GHz net and immediately there are many missing pings. Also in the logread output I see the following repeated every couple of seconds. This STA is actually not my phone, but the computer that was connected stably over night!!!:

Sun Nov 18 11:05:35 2018 daemon.info hostapd: wlan0: STA 50:85:69:xx:xx:xx IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Sun Nov 18 11:05:51 2018 daemon.info hostapd: wlan0: STA 50:85:69:xx:xx:xx IEEE 802.11: authenticated
Sun Nov 18 11:05:51 2018 daemon.info hostapd: wlan0: STA 50:85:69:xx:xx:xx IEEE 802.11: associated (aid 1)
Sun Nov 18 11:05:51 2018 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 50:85:69:xx:xx:xx
Sun Nov 18 11:05:51 2018 daemon.info hostapd: wlan0: STA 50:85:69:xx:xx:xx RADIUS: starting accounting session ...
Sun Nov 18 11:05:51 2018 daemon.info hostapd: wlan0: STA 50:85:69:xx:xx:xx WPA: pairwise key handshake completed (RSN)
Sun Nov 18 11:06:01 2018 daemon.info hostapd: wlan0: STA 50:85:69:xx:xx:xx IEEE 802.11: disconnected due to excessive missing ACKs
Sun Nov 18 11:06:01 2018 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED 50:85:69:xx:xx:xx

Then also for the Android phone the same thing:

Sun Nov 18 11:15:03 2018 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 94:65:2d:xx:xx:xx
Sun Nov 18 11:15:03 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx RADIUS: starting accounting session ...
Sun Nov 18 11:15:03 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx WPA: pairwise key handshake completed (RSN)
Sun Nov 18 11:15:09 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx IEEE 802.11: disconnected due to excessive missing ACKs
Sun Nov 18 11:15:09 2018 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED 94:65:2d:xx:xx:xx
Sun Nov 18 11:15:10 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx IEEE 802.11: authenticated
Sun Nov 18 11:15:10 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx IEEE 802.11: associated (aid 1)
Sun Nov 18 11:15:10 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx static
Sun Nov 18 11:15:10 2018 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 94:65:2d:xx:xx:xx
djwlindenaar commented 5 years ago

To make it reproducible, I've given the 5GHz (wlan1) and 2.4GHz (wlan0) a different SSID. Below you see the log with the following events:

  1. the computer associating with the 2.4GHz net (12:04:06)
  2. the phone associating with the 5GHz net (12:04:10)
  3. I command the phone to associate with the 2.4GHz (12:04:49)
  4. the computer getting kicked off before anything else
  5. after some 2 seconds the phone associates with the wlan0
Sun Nov 18 12:04:06 2018 daemon.info hostapd: wlan0: STA 00:24:2c:xx:xx:xx IEEE 802.11: authenticated
Sun Nov 18 12:04:06 2018 daemon.info hostapd: wlan0: STA 00:24:2c:xx:xx:xx IEEE 802.11: associated (aid 1)
Sun Nov 18 12:04:06 2018 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 00:24:2c:xx:xx:xx
Sun Nov 18 12:04:06 2018 daemon.info hostapd: wlan0: STA 00:24:2c:xx:xx:xx RADIUS: starting accounting session 92724901E54D816A
Sun Nov 18 12:04:06 2018 daemon.info hostapd: wlan0: STA 00:24:2c:xx:xx:xx WPA: pairwise key handshake completed (RSN)
Sun Nov 18 12:04:10 2018 daemon.info hostapd: wlan1: STA 94:65:2d:xx:xx:xx IEEE 802.11: authenticated
Sun Nov 18 12:04:10 2018 daemon.info hostapd: wlan1: STA 94:65:2d:xx:xx:xx IEEE 802.11: associated (aid 2)
Sun Nov 18 12:04:10 2018 daemon.notice hostapd: wlan1: AP-STA-CONNECTED 94:65:2d:xx:xx:xx
Sun Nov 18 12:04:10 2018 daemon.info hostapd: wlan1: STA 94:65:2d:xx:xx:xx RADIUS: starting accounting session B169B94DE2CA429F
Sun Nov 18 12:04:10 2018 daemon.info hostapd: wlan1: STA 94:65:2d:xx:xx:xx WPA: pairwise key handshake completed (RSN)
Sun Nov 18 12:04:49 2018 daemon.info hostapd: wlan0: STA 00:24:2c:xx:xx:xx IEEE 802.11: disconnected due to excessive missing ACKs
Sun Nov 18 12:04:49 2018 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED 00:24:2c:xx:xx:xx
Sun Nov 18 12:04:50 2018 daemon.info hostapd: wlan0: STA 00:24:2c:xx:xx:xx IEEE 802.11: authenticated
Sun Nov 18 12:04:50 2018 daemon.info hostapd: wlan0: STA 00:24:2c:xx:xx:xx IEEE 802.11: associated (aid 1)
Sun Nov 18 12:04:50 2018 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 00:24:2c:xx:xx:xx
Sun Nov 18 12:04:50 2018 daemon.info hostapd: wlan0: STA 00:24:2c:xx:xx:xx RADIUS: starting accounting session 92724901E54D816A
Sun Nov 18 12:04:50 2018 daemon.info hostapd: wlan0: STA 00:24:2c:xx:xx:xx WPA: pairwise key handshake completed (RSN)
Sun Nov 18 12:04:51 2018 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED 94:65:2d:xx:xx:xx
Sun Nov 18 12:04:51 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx IEEE 802.11: authenticated
Sun Nov 18 12:04:51 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx IEEE 802.11: associated (aid 2)
Sun Nov 18 12:04:51 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx static
Sun Nov 18 12:04:51 2018 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 94:65:2d:xx:xx:xx
Sun Nov 18 12:04:51 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx RADIUS: starting accounting session 3B39368590922921
Sun Nov 18 12:04:51 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx WPA: pairwise key handshake completed (RSN)
Sun Nov 18 12:05:04 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx IEEE 802.11: disconnected due to excessive missing ACKs
Sun Nov 18 12:05:04 2018 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED 94:65:2d:xx:xx:xx
Sun Nov 18 12:05:07 2018 daemon.info hostapd: wlan1: STA 94:65:2d:xx:xx:xx IEEE 802.11: authenticated
Sun Nov 18 12:05:07 2018 daemon.info hostapd: wlan1: STA 94:65:2d:xx:xx:xx IEEE 802.11: associated (aid 2)
Sun Nov 18 12:05:07 2018 daemon.notice hostapd: wlan1: AP-STA-CONNECTED 94:65:2d:xx:xx:xx
Sun Nov 18 12:05:07 2018 daemon.info hostapd: wlan1: STA 94:65:2d:xx:xx:xx RADIUS: starting accounting session AD699EAA6220D85C
Sun Nov 18 12:05:07 2018 daemon.info hostapd: wlan1: STA 94:65:2d:xx:xx:xx WPA: pairwise key handshake completed (RSN)
Sun Nov 18 12:05:21 2018 daemon.info hostapd: wlan0: STA 00:24:2c:xx:xx:xx IEEE 802.11: disconnected due to excessive missing ACKs
Sun Nov 18 12:05:21 2018 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED 00:24:2c:xx:xx:xx
Sun Nov 18 12:05:22 2018 daemon.info hostapd: wlan0: STA 00:24:2c:xx:xx:xx IEEE 802.11: authenticated
Sun Nov 18 12:05:22 2018 daemon.info hostapd: wlan0: STA 00:24:2c:xx:xx:xx IEEE 802.11: associated (aid 1)
Sun Nov 19 12:05:22 2018 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 00:24:2c:xx:xx:xx
djwlindenaar commented 5 years ago

Right, so even with just the computer connected, we have these disconnections due to missing ACK.

I do notice that is traffic related. If I'm just running ping, it disconnects every ~40 seconds If I'm netcat'ing data it disconnects every ~6 seconds

This does not explain the behavior in my previous post, when my phone connects, though. There is not yet any data being communicated between my phone and computer and the disconnect immediately happens when I enable wifi on my phone. The phone is still trying to associate at that time.

nbd168 commented 5 years ago

Please try the latest version from OpenWrt master, I pushed some more fixes.

djwlindenaar commented 5 years ago

Just installed it. Looks like one issue is solved related to the missing ACKs; Progress :)

Wed Nov 21 21:07:02 2018 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED 94:65:2d:xx:xx:xx
Wed Nov 21 21:07:03 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx IEEE 802.11: authenticated
Wed Nov 21 21:07:03 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx IEEE 802.11: associated (aid 1)
Wed Nov 21 21:07:03 2018 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 94:65:2d:xx:xx:xx
Wed Nov 21 21:07:03 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx RADIUS: starting accounting session 0F13CB1CA8458575
Wed Nov 21 21:07:03 2018 daemon.info hostapd: wlan0: STA 94:65:2d:xx:xx:xx WPA: pairwise key handshake completed (RSN)
Wed Nov 21 21:07:03 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx static

But the long ping times are still there. Albeit without packet loss. Also note there are some pings that have a great rtt. 

--- 192.168.2.9 ping statistics ---
332 packets transmitted, 332 received, 0% packet loss, time 1271ms
rtt min/avg/max/mdev = 0.767/763.824/1709.315/373.150 ms, pipe 2
64 bytes from 192.168.2.9: icmp_seq=163 ttl=64 time=0.832 ms
64 bytes from 192.168.2.9: icmp_seq=164 ttl=64 time=0.881 ms
64 bytes from 192.168.2.9: icmp_seq=165 ttl=64 time=43.6 ms
64 bytes from 192.168.2.9: icmp_seq=166 ttl=64 time=43.4 ms
64 bytes from 192.168.2.9: icmp_seq=167 ttl=64 time=25.5 ms
64 bytes from 192.168.2.9: icmp_seq=171 ttl=64 time=0.960 ms
64 bytes from 192.168.2.9: icmp_seq=172 ttl=64 time=0.887 ms
64 bytes from 192.168.2.9: icmp_seq=174 ttl=64 time=0.903 ms
64 bytes from 192.168.2.9: icmp_seq=175 ttl=64 time=0.970 ms
64 bytes from 192.168.2.9: icmp_seq=187 ttl=64 time=8.60 ms
64 bytes from 192.168.2.9: icmp_seq=188 ttl=64 time=30.8 ms
64 bytes from 192.168.2.9: icmp_seq=189 ttl=64 time=52.4 ms
64 bytes from 192.168.2.9: icmp_seq=190 ttl=64 time=73.9 ms
64 bytes from 192.168.2.9: icmp_seq=191 ttl=64 time=75.7 ms
64 bytes from 192.168.2.9: icmp_seq=196 ttl=64 time=26.2 ms
64 bytes from 192.168.2.9: icmp_seq=201 ttl=64 time=92.7 ms
64 bytes from 192.168.2.9: icmp_seq=206 ttl=64 time=75.8 ms
64 bytes from 192.168.2.9: icmp_seq=282 ttl=64 time=0.767 ms
64 bytes from 192.168.2.9: icmp_seq=283 ttl=64 time=0.923 ms
64 bytes from 192.168.2.9: icmp_seq=314 ttl=64 time=0.848 ms
djwlindenaar commented 5 years ago

I do get a lot of these items in my log now, with my phone connected. 

Wed Nov 21 21:29:57 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx off
Wed Nov 21 21:29:58 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx static
Wed Nov 21 21:29:58 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx off
Wed Nov 21 21:29:58 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx static
Wed Nov 21 21:29:59 2018 daemon.notice hostapd: wlan1: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx off
Wed Nov 21 21:29:59 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx static
Wed Nov 21 21:29:59 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx off
Wed Nov 21 21:30:00 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx static
Wed Nov 21 21:30:00 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx off
Wed Nov 21 21:30:00 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx static
Wed Nov 21 21:30:00 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx off
Wed Nov 21 21:30:02 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx static
Wed Nov 22 21:30:02 2018 daemon.notice hostapd: wlan0: STA-OPMODE-SMPS-MODE-CHANGED 94:65:2d:xx:xx:xx off
nbd168 commented 5 years ago

Are these ping times measured by pinging your phone from another device? If so, these latency values could just be normal power-save related latency...

djwlindenaar commented 5 years ago

Nope. Between PC and router. With the 5GHz I get (much) less than 10 ms...

Also for power save I'd not expect average of 700 ms rtt, right?

nbd168 commented 5 years ago

Right. I didn't look at the total stats only at the capture of individual pings. Thanks for reporting this, I will continue to work on it.

djwlindenaar commented 5 years ago

I just did some more experimenting... I guess this might give you an opening for further debugging.

My router stopped completing authentication, so I rebooted it (just interface up/down did not help). I then remembered I had a server on the network which broadcasts uncompressed audio continuously. After disabling that, I get the following rtt :)

--- 192.168.2.9 ping statistics ---
550 packets transmitted, 550 received, 0% packet loss, time 1535ms
rtt min/avg/max/mdev = 0.714/2.203/111.993/11.418 ms

Here's a capture of the packets that were on the network, which apparently confuses the mt7603 on the MiR3G...

Frame 233192: 1334 bytes on wire (10672 bits), 1334 bytes captured (10672 bits) on interface 0
Ethernet II, Src: Asiarock_c3:b8:fa (00:19:66:xx:xx:xx), Dst: IPv4mcast_38 (01:00:5e:00:00:38)
Internet Protocol Version 4, Src: 192.168.2.10, Dst: 224.0.0.56
User Datagram Protocol, Src Port: 49217, Dst Port: 46966
Real-Time Transport Protocol
    [Stream setup by SDP (frame 232556)]
    10.. .... = Version: RFC 1889 Version (2)
    ..0. .... = Padding: False
    ...0 .... = Extension: False
    .... 0000 = Contributing source identifiers count: 0
    0... .... = Marker: False
    Payload type: 16-bit uncompressed audio, stereo (10)
    Sequence number: 59974
    [Extended sequence number: 59974]
    Timestamp: 3338328384
    Synchronization Source identifier: 0xba1a8523 (3122300195)
    Payload: 000000000000000000000000000000000000000000000000...
djwlindenaar commented 5 years ago

Another bit of testing shows that when I run a multicast transfer, the ping times shoot up to 400-500 ms.

here I used iperf to do a multicast transfer starting from seq=9387 server: iperf -s -u -B 226.94.1.1 -i 1 client: iperf -c 226.94.1.1 -u -T 32 -t 3 -i 1

64 bytes from 192.168.2.9: icmp_seq=9377 ttl=64 time=0.909 ms
64 bytes from 192.168.2.9: icmp_seq=9378 ttl=64 time=0.795 ms
64 bytes from 192.168.2.9: icmp_seq=9379 ttl=64 time=0.837 ms
64 bytes from 192.168.2.9: icmp_seq=9380 ttl=64 time=0.811 ms
64 bytes from 192.168.2.9: icmp_seq=9381 ttl=64 time=0.760 ms
64 bytes from 192.168.2.9: icmp_seq=9382 ttl=64 time=0.747 ms
64 bytes from 192.168.2.9: icmp_seq=9383 ttl=64 time=0.808 ms
64 bytes from 192.168.2.9: icmp_seq=9384 ttl=64 time=0.820 ms
64 bytes from 192.168.2.9: icmp_seq=9385 ttl=64 time=0.777 ms
64 bytes from 192.168.2.9: icmp_seq=9386 ttl=64 time=0.783 ms
64 bytes from 192.168.2.9: icmp_seq=9387 ttl=64 time=226 ms
64 bytes from 192.168.2.9: icmp_seq=9388 ttl=64 time=42.6 ms
64 bytes from 192.168.2.9: icmp_seq=9389 ttl=64 time=500 ms
64 bytes from 192.168.2.9: icmp_seq=9390 ttl=64 time=640 ms
64 bytes from 192.168.2.9: icmp_seq=9391 ttl=64 time=354 ms
64 bytes from 192.168.2.9: icmp_seq=9392 ttl=64 time=651 ms
64 bytes from 192.168.2.9: icmp_seq=9393 ttl=64 time=368 ms
64 bytes from 192.168.2.9: icmp_seq=9394 ttl=64 time=601 ms
64 bytes from 192.168.2.9: icmp_seq=9395 ttl=64 time=632 ms
64 bytes from 192.168.2.9: icmp_seq=9396 ttl=64 time=247 ms
64 bytes from 192.168.2.9: icmp_seq=9397 ttl=64 time=650 ms

Normal unicast does not have the same effect. Be it TCP or UDP does not matter. There is an increase in ping times still, but an order of magnitude less..

64 bytes from 192.168.2.9: icmp_seq=9063 ttl=64 time=0.769 ms
64 bytes from 192.168.2.9: icmp_seq=9064 ttl=64 time=0.781 ms
64 bytes from 192.168.2.9: icmp_seq=9065 ttl=64 time=0.737 ms
64 bytes from 192.168.2.9: icmp_seq=9066 ttl=64 time=0.717 ms
64 bytes from 192.168.2.9: icmp_seq=9067 ttl=64 time=0.740 ms
64 bytes from 192.168.2.9: icmp_seq=9068 ttl=64 time=4.58 ms
64 bytes from 192.168.2.9: icmp_seq=9069 ttl=64 time=23.6 ms
64 bytes from 192.168.2.9: icmp_seq=9070 ttl=64 time=28.8 ms
64 bytes from 192.168.2.9: icmp_seq=9071 ttl=64 time=12.4 ms
64 bytes from 192.168.2.9: icmp_seq=9072 ttl=64 time=33.1 ms
64 bytes from 192.168.2.9: icmp_seq=9073 ttl=64 time=25.8 ms
64 bytes from 192.168.2.9: icmp_seq=9074 ttl=64 time=16.6 ms

Hope this helps...

djwlindenaar commented 5 years ago

Just tested the Nov.29 commit and the behavior has changed, but not improved :)

Started a multicast stream around seq=154, stopped around seq=190. A lot of dropped pings...

64 bytes from 192.168.2.9: icmp_seq=147 ttl=64 time=0.978 ms
64 bytes from 192.168.2.9: icmp_seq=148 ttl=64 time=0.917 ms
64 bytes from 192.168.2.9: icmp_seq=149 ttl=64 time=0.735 ms
64 bytes from 192.168.2.9: icmp_seq=150 ttl=64 time=1.73 ms
64 bytes from 192.168.2.9: icmp_seq=151 ttl=64 time=0.753 ms
64 bytes from 192.168.2.9: icmp_seq=152 ttl=64 time=0.787 ms
64 bytes from 192.168.2.9: icmp_seq=153 ttl=64 time=7.67 ms
64 bytes from 192.168.2.9: icmp_seq=154 ttl=64 time=0.856 ms
64 bytes from 192.168.2.9: icmp_seq=164 ttl=64 time=0.855 ms
64 bytes from 192.168.2.9: icmp_seq=169 ttl=64 time=338 ms
64 bytes from 192.168.2.9: icmp_seq=170 ttl=64 time=0.797 ms
64 bytes from 192.168.2.9: icmp_seq=180 ttl=64 time=65.3 ms
64 bytes from 192.168.2.9: icmp_seq=189 ttl=64 time=200 ms
64 bytes from 192.168.2.9: icmp_seq=190 ttl=64 time=731 ms
64 bytes from 192.168.2.9: icmp_seq=191 ttl=64 time=0.742 ms
64 bytes from 192.168.2.9: icmp_seq=192 ttl=64 time=1.07 ms
64 bytes from 192.168.2.9: icmp_seq=193 ttl=64 time=0.758 ms
64 bytes from 192.168.2.9: icmp_seq=194 ttl=64 time=0.730 ms
64 bytes from 192.168.2.9: icmp_seq=195 ttl=64 time=0.853 ms
64 bytes from 192.168.2.9: icmp_seq=196 ttl=64 time=2.17 ms
djwlindenaar commented 5 years ago

Just tested quickly, but it seems the latest commits have solved the multicast issues... Good progress! Thanks

I'll keep testing to see how things look.

Best regards

djwlindenaar commented 5 years ago

So after running the setup for a couple of weeks, things looked stable, but...

I've now started to stress it a little bit, by restarting the continuous multicasting of audio. This seemed to work for a while, until yesterday. The 2.4GHz seemed to be available, but no data was flowing. Then also association stopped working.

@nbd168 : Any logging you'd like to see? I've looked in the dmesg, it showed no crashes or any related messages

Best regards Daniel

nbd168 commented 5 years ago

Please try the latest version, it should work better now.

djwlindenaar commented 5 years ago

Just tried it, but it seems less stable overall. Also while multicasting on the network, many pings get lost...

Any logging I can help you with?

nbd168 commented 5 years ago

Should work better now, please try

djwlindenaar commented 5 years ago

tried it. Still the same behavior with multicast.

following ping started with a multicast going on the network. Stopped it at ping count 135...

64 bytes from 192.168.2.5: icmp_seq=5 ttl=64 time=912 ms
64 bytes from 192.168.2.5: icmp_seq=7 ttl=64 time=225 ms
64 bytes from 192.168.2.5: icmp_seq=11 ttl=64 time=60.1 ms
64 bytes from 192.168.2.5: icmp_seq=15 ttl=64 time=122 ms
64 bytes from 192.168.2.5: icmp_seq=17 ttl=64 time=105 ms
64 bytes from 192.168.2.5: icmp_seq=115 ttl=64 time=977 ms
64 bytes from 192.168.2.5: icmp_seq=135 ttl=64 time=6.37 ms
64 bytes from 192.168.2.5: icmp_seq=136 ttl=64 time=1.15 ms
64 bytes from 192.168.2.5: icmp_seq=137 ttl=64 time=1.21 ms
64 bytes from 192.168.2.5: icmp_seq=138 ttl=64 time=14.3 ms
64 bytes from 192.168.2.5: icmp_seq=139 ttl=64 time=0.984 ms
64 bytes from 192.168.2.5: icmp_seq=140 ttl=64 time=1.06 ms
64 bytes from 192.168.2.5: icmp_seq=141 ttl=64 time=1.21 ms
64 bytes from 192.168.2.5: icmp_seq=142 ttl=64 time=1.31 ms
64 bytes from 192.168.2.5: icmp_seq=143 ttl=64 time=1.19 ms
64 bytes from 192.168.2.5: icmp_seq=144 ttl=64 time=1.25 ms
64 bytes from 192.168.2.5: icmp_seq=145 ttl=64 time=1.14 ms
64 bytes from 192.168.2.5: icmp_seq=146 ttl=64 time=1.00 ms
64 bytes from 192.168.2.5: icmp_seq=147 ttl=64 time=2.29 ms
lukasz1992 commented 5 years ago

@djwlindenaar could you test again again master branch of mt76?

djwlindenaar commented 5 years ago

Ok, Will test in the weekend.

kofec commented 5 years ago 
[    0.000000] Linux version 4.14.108 (kofec@E5420Mint) (gcc version 7.4.0 (OpenWrt GCC 7.4.0 r8810-09004e6e13)) #0 SMP Wed Mar 27 15:46:39 2019
[    0.000000] SoC Type: MediaTek MT7621 ver:1 eco:3
[    0.000000] MIPS: machine is Xiaomi Mi Router 3G
root@Xiaomi3G:~# opkg list-installed | grep mt76
kmod-mt76-core - 4.14.108+2019-03-27-a11b6734-1
kmod-mt7603 - 4.14.108+2019-03-27-a11b6734-1
kmod-mt76x02-common - 4.14.108+2019-03-27-a11b6734-1
kmod-mt76x2 - 4.14.108+2019-03-27-a11b6734-1
kmod-mt76x2-common - 4.14.108+2019-03-27-a11b6734-1
[50567.614606] ------------[ cut here ]------------
[50567.619425] WARNING: CPU: 2 PID: 19 at backports-4.19.23-1/net/mac80211/tx.c:4263 ieee80211_reserve_tid+0xbe8/0xc04 [mac80211]
[50567.630829] Modules linked in: ath9k_htc ath9k_common pppoe ppp_async ath9k_hw ath pppox ppp_generic nf_conntrack_netlink nf_conntrack_ipv6 mt76x2e mt76x2_common mt76x02_lib mt7603e mt76 mac80211 lz4 iptable_nat ipt_REJECT ipt_MASQUERADE cfg80211 xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark xt_mac xt_limit xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_FLOWOFFLOAD wireguard usbhid slhc nfnetlink nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_conntrack_ipv4 nf_nat_ipv4 nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack lz4_decompress lz4_compress iptable_mangle iptable_filter ip_tables hid_generic crc_itu_t crc_ccitt compat fuse hid evdev input_core i2c_dev ledtrig_usbport nf_log_ipv6 nf_log_common ip6table_mangle
[50567.702056]  ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 nfsv4 nfsv3 nfs ip6_udp_tunnel udp_tunnel vfat fat ntfs lockd sunrpc grace cifs dns_resolver nls_utf8 nls_iso8859_1 nls_cp437 zram zsmalloc eeprom_93cx6 sha256_generic md5 md4 hmac ecb des_generic usb_storage leds_gpio xhci_plat_hcd xhci_pci xhci_mtk xhci_hcd uhci_hcd ohci_platform ohci_hcd ehci_platform sd_mod scsi_mod ehci_hcd gpio_button_hotplug ext4 mbcache jbd2 usbcore nls_base usb_common crc32c_generic
[50567.744923] CPU: 2 PID: 19 Comm: ksoftirqd/2 Not tainted 4.14.108 #0
[50567.751255] Stack : 00000000 8e9637b0 8e474bc0 800741e8 805b0000 8054bc04 00000000 00000000
[50567.759596]         80517aac 8fc83bec 8fc789bc 805848e7 80512938 00000001 8fc83b90 1cc2828c
[50567.767939]         00000000 00000000 805e0000 00007108 00000000 00000168 00000008 00000000
[50567.776296]         00000000 80590000 000b5ddb 00000000 00000000 00000000 805b0000 8e72d8ac
[50567.784647]         00000009 000010a7 8da51480 8e9637b0 00000003 802a0080 00000008 805e0008
[50567.792998]         ...
[50567.795443] Call Trace:
[50567.797919] [<800106a0>] show_stack+0x58/0x100
[50567.802391] [<80454b9c>] dump_stack+0x9c/0xe0
[50567.806746] [<80032a28>] __warn+0xe0/0x114
[50567.810832] [<80032aec>] warn_slowpath_null+0x1c/0x30
[50567.816020] [<8e72d8ac>] ieee80211_reserve_tid+0xbe8/0xc04 [mac80211]
[50567.822528] [<8006a7d8>] autoremove_wake_function+0x14/0x4c
[50567.828194] ---[ end trace 3383f16113216471 ]---
siwind commented 5 years ago

Same kernel OOPs situation with My router, 2.4G/5G wifi disabled.

root@OpenWrt:~# cat /proc/cpuinfo 
system type             : MediaTek MT7621 ver:1 eco:3
machine                 : Newifi-D2

Driver info:

root@OpenWrt:~# uname -a
Linux OpenWrt 4.14.108 #0 SMP Wed Mar 27 23:57:39 2019 mips GNU/Linux
root@OpenWrt:~# opkg list-installed | grep mt76
kmod-mt76-core - 4.14.108+2019-03-27-a11b6734-1
kmod-mt7603 - 4.14.108+2019-03-27-a11b6734-1
kmod-mt76x02-common - 4.14.108+2019-03-27-a11b6734-1
kmod-mt76x2 - 4.14.108+2019-03-27-a11b6734-1
kmod-mt76x2-common - 4.14.108+2019-03-27-a11b6734-1

Thanks for the hard working on it!

djwlindenaar commented 5 years ago

Some improvement has been achieved, however not yet completely solved...

When doing multicast, no packet loss occurs anymore (Yay!). However, latencies are still extremely high. see below; multicast started at icmp_seq=88

64 bytes from 192.168.2.5: icmp_seq=81 ttl=64 time=1.11 ms
64 bytes from 192.168.2.5: icmp_seq=82 ttl=64 time=1.10 ms
64 bytes from 192.168.2.5: icmp_seq=83 ttl=64 time=1.16 ms
64 bytes from 192.168.2.5: icmp_seq=84 ttl=64 time=1.07 ms
64 bytes from 192.168.2.5: icmp_seq=85 ttl=64 time=1.53 ms
64 bytes from 192.168.2.5: icmp_seq=86 ttl=64 time=1.11 ms
64 bytes from 192.168.2.5: icmp_seq=87 ttl=64 time=1.08 ms
64 bytes from 192.168.2.5: icmp_seq=88 ttl=64 time=345 ms
64 bytes from 192.168.2.5: icmp_seq=89 ttl=64 time=682 ms
64 bytes from 192.168.2.5: icmp_seq=90 ttl=64 time=727 ms
64 bytes from 192.168.2.5: icmp_seq=91 ttl=64 time=672 ms
64 bytes from 192.168.2.5: icmp_seq=92 ttl=64 time=716 ms
64 bytes from 192.168.2.5: icmp_seq=93 ttl=64 time=691 ms

After a couple of days of this, 2.4g connection got dropped and things don't look so good anymore...

nbd168 commented 5 years ago

Please try the latest version