greearb / ath10k-ct

Stand-alone ath10k driver based on Candela Technologies Linux kernel.
110 stars 39 forks source link

In some rare RF conditions, no traffic on IBSS connections #18

Open ghost opened 6 years ago

ghost commented 6 years ago

In specific field only RF conditions, some WPA2 IBSS links can be established but no traffic is received

OpenWRT Chaos Calmer, Kernel 3.18.45, mac80211 backported from v4.4-rc5-1913-gc8fdf68, driver ath10k-ct 4.7 2f3171d, fW-020-64bb715 This is also reproducible on ath10k-ct 4.7 1df6b26, fw 18

Hardware (NIC chipset, platform, etc) QCA9882

Logs (dmesg, maybe supplicant and/or hostap) dmesg.txt

greearb commented 6 years ago

I think this might be a supplicant bug. I saw this message in other testing scenarios:

[349951.140828] sta5002: 04:f0:21:67:53:95 authenticate with f8:a0:97:44:94:55 at: 1520282299.350687 [349951.141350] sta5002: failed to insert STA entry for the AP (error -17)

The supplicant does not know how to work around the EEXIST errno (-17).

Please manually hack in the check for EEXIST. This patch will not apply to upstream supplicant, and I have not re-spun it quite yet, but I think it will be enough for you to make the change:

https://www.spinics.net/lists/hostap/msg04278.html

greearb commented 6 years ago

Have you been able to test with supplicant patched as suggested?

ghost commented 6 years ago

I added the suggested patch. I'm now using latest 4.9 driver, mac80211 backported wt-2017-01-31-0-ge882dff19e7 (same as LEDE-17.01), wpa_supplicant 2016-12-19 (same as LEDE-17.01) and it still does not work. Here is the log:

[ 11.740000] ath10k 4.9 driver, optimized for CT firmware, probing pci device: 0x3c. [ 11.760000] ath10k_pci 0000:01:00.0: pci irq legacy oper_irq_mode 1 irq_mode 0 reset_mode 0 [ 11.980000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/pre-cal-pci-0000:01:00.0.bin failed with error -2 [ 11.990000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.050000] firmware ath10k!pre-cal-pci-0000:01:00.0.bin: firmware_loading_store: map pages failed [ 12.060000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/cal-pci-0000:01:00.0.bin failed with error -2 [ 12.070000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.130000] firmware ath10k!cal-pci-0000:01:00.0.bin: firmware_loading_store: map pages failed [ 12.140000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/fwcfg-pci-0000:01:00.0.txt failed with error -2 [ 12.150000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.220000] firmware ath10k!fwcfg-pci-0000:01:00.0.txt: firmware_loading_store: map pages failed [ 12.220000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/ct-firmware-5.bin failed with error -2 [ 12.240000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.300000] firmware ath10k!QCA988X!hw2.0!ct-firmware-5.bin: firmware_loading_store: map pages failed [ 12.310000] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/ct-firmware-5.bin': -11 [ 12.320000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/ct-firmware-2.bin failed with error -2 [ 12.330000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.390000] firmware ath10k!QCA988X!hw2.0!ct-firmware-2.bin: firmware_loading_store: map pages failed [ 12.400000] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/ct-firmware-2.bin': -11 [ 12.410000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/firmware-5.bin failed with error -2 [ 12.420000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.490000] firmware ath10k!QCA988X!hw2.0!firmware-5.bin: firmware_loading_store: map pages failed [ 12.490000] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/firmware-5.bin': -11 [ 12.510000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/firmware-4.bin failed with error -2 [ 12.520000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.580000] firmware ath10k!QCA988X!hw2.0!firmware-4.bin: firmware_loading_store: map pages failed [ 12.590000] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/firmware-4.bin': -11 [ 12.600000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/firmware-3.bin failed with error -2 [ 12.610000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.670000] firmware ath10k!QCA988X!hw2.0!firmware-3.bin: firmware_loading_store: map pages failed [ 12.680000] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/firmware-3.bin': -11 [ 12.930000] ath10k_pci 0000:01:00.0: qca988x hw2.0 target 0x4100016c chip_id 0x043222ff sub 0000:0000 [ 12.940000] ath10k_pci 0000:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 0 testmode 0 [ 12.950000] ath10k_pci 0000:01:00.0: firmware ver 10.1-ct-8x-__fW-021-75f739c api 2 features wmi-10.x,has-wmi-mgmt-tx,txstatus-noack,wmi-10.x-CT,ratemask-CT,get-temp-CT,tx-rc-CT,cust-stats-CT crc32 6c2a63ef [ 13.000000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/board-2.bin failed with error -2 [ 13.010000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 13.080000] firmware ath10k!QCA988X!hw2.0!board-2.bin: firmware_loading_store: map pages failed [ 13.090000] ath10k_pci 0000:01:00.0: board_file api 1 bmi_id N/A crc32 bebc7c08 [ 14.000000] ath10k_pci 0000:01:00.0: 10.1 wmi init: vdevs: 16 peers: 127 tid: 256 [ 14.010000] ath10k_pci 0000:01:00.0: 10.1 features for rx-decap-mode: 0xc0 [ 14.030000] ath10k_pci 0000:01:00.0: wmi print 'P 128 V 8 T 410' [ 14.030000] ath10k_pci 0000:01:00.0: wmi print 'msdu-desc: 1424 sw-crypt: 0' [ 14.040000] ath10k_pci 0000:01:00.0: wmi print 'alloc rem: 26172 iram: 24596' [ 14.100000] ath10k_pci 0000:01:00.0: htt-ver 2.1 wmi-op 2 htt-op 2 cal otp max-sta 128 raw 0 hwcrypto 1 [ 32.620000] ath10k_pci 0000:01:00.0: 10.1 wmi init: vdevs: 16 peers: 127 tid: 256 [ 32.630000] ath10k_pci 0000:01:00.0: 10.1 features for rx-decap-mode: 0xc0 [ 32.640000] ath10k_pci 0000:01:00.0: wmi print 'P 128 V 8 T 410' [ 32.650000] ath10k_pci 0000:01:00.0: wmi print 'msdu-desc: 1424 sw-crypt: 0' [ 32.660000] ath10k_pci 0000:01:00.0: wmi print 'alloc rem: 26172 iram: 24596' [ 32.930000] ath10k_pci 0000:01:00.0: ath10k_pci ATH10K_DBG_BUFFER: [ 32.930000] ath10k: [0000]: F19C0000 0500FC17 70201031 08000000 80000000 58F84000 010006C0 FC9C0000 [ 32.930000] ath10k: [0008]: 085CFC0F 30674400 08000000 80000000 FC9C0000 065CFC0F 58F84000 C8704400 [ 32.930000] ath10k: [0016]: 19000000 FC9C0000 065CFC0F 09000000 C8704400 348D9C00 119D0000 0920000C [ 32.930000] ath10k: [0024]: B0F34300 01000000 00000000 119D0000 065C000C 08000000 C8704400 3C8D9C00 [ 32.930000] ath10k: [0032]: 119D0000 4F4C0014 02000000 ECE54100 A47E4300 00000000 00007100 119D0000 [ 32.930000] ath10k: [0040]: 564C0014 A47E4300 F8D79B00 13000000 00000000 20310000 119D0000 035C0014 [ 32.930000] ath10k: [0048]: 00000000 00000000 00010000 A4B79B00 A47E4300 119D0000 065C000C 05000000 [ 32.930000] ath10k: [0056]: C8704400 448D9C00 119D0000 0928000C 61661071 B0F34300 18FA4300 119D0000 [ 32.930000] ath10k: [0064]: 0928000C 60661071 B0F34300 18FA4300 119D0000 085C0008 B0F34300 58674400 [ 32.930000] ath10k: [0072]: 119D0000 065C000C 11000000 C8704400 4C8D9C00 119D0000 045C000C 03001081 [ 32.930000] ath10k: [0080]: B0F34300 A4B79B00 119D0000 0A200008 B0F34300 00000000 119D0000 075C000C [ 32.930000] ath10k: [0088]: 11000000 C8704400 4C8D9C00 119D0000 095C0008 B0F34300 58674400 119D0000 [ 32.930000] ath10k: [0096]: 075C000C 05000000 C8704400 448D9C00 119D0000 075C000C 08000000 C8704400 [ 32.930000] ath10k: [0104]: 3C8D9C00 119D0000 09280010 62661071 B0F34300 18FA4300 00000000 119D0000 [ 32.930000] ath10k: [0112]: 025C0014 B0F34300 A4B79B00 00000000 00010000 01000000 119D0000 574C0014 [ 32.930000] ath10k: [0120]: A47E4300 F8D79B00 13000000 00000000 A2310000 119D0000 504C0010 BB001071 [ 32.930000] ath10k: [0128]: ECE54100 A47E4300 98000000 119D0000 5B4C0004 68D49B00 129D0000 055C0004 [ 32.930000] ath10k: [0136]: B0F34300 159D0000 100CFC0B 8A291001 04000000 159D0000 130CFC03 1D9D0000 [ 32.930000] ath10k: [0144]: 234CFC0F 01000000 01000000 01000000 249D0000 234CFC0F 01000000 01000000 [ 32.930000] ath10k: [0152]: 01000000 2C9D0000 234CFC0F 01000000 01000000 01000000 349D0000 234CFC0F [ 32.930000] ath10k: [0160]: 01000000 01000000 01000000 3C9D0000 234CFC0F 01000000 01000000 01000000 [ 32.930000] ath10k: [0168]: 449D0000 234CFC0F 01000000 01000000 01000000 4B9D0000 234CFC0F 01000000 [ 32.930000] ath10k: [0176]: 01000000 01000000 539D0000 234CFC0F 01000000 01000000 01000000 539D0000 [ 32.930000] ath10k: [0184]: 0C64FC07 01000000 5B9D0000 234CFC0F 01000000 01000000 01000000 5B9D0000 [ 32.930000] ath10k: [0192]: 0920000C B0F34300 02000000 00000000 5B9D0000 065C000C 08000000 C8704400 [ 32.930000] ath10k: [0200]: 548D9C00 5B9D0000 0928000C 61661071 B0F34300 4CFA4300 5B9D0000 0928000C [ 32.930000] ath10k: [0208]: 60661071 B0F34300 4CFA4300 5B9D0000 085C0008 B0F34300 D8674400 5B9D0000 [ 32.930000] ath10k: [0216]: 065C000C 11000000 C8704400 5C8D9C00 5B9D0000 045C000C 03001081 B0F34300 [ 32.930000] ath10k: [0224]: 00000000 5B9D0000 02280008 03000000 02000000 5B9D0000 02280004 02000000 [ 32.930000] ath10k: [0232]: 5C9D0000 4F4C0014 12000000 24E64100 347F4300 00000000 00007100 5C9D0000 [ 32.930000] ath10k: [0240]: 4F4C0014 02000000 5CE64100 347F4300 00000000 01007200 5C9D0000 564C0014 [ 32.930000] ath10k: [0248]: 347F4300 40D89B00 11000000 00000000 203D0000 5C9D0000 564C0014 347F4300 [ 32.930000] ath10k: [0256]: 88D89B00 12000000 00000000 202D0000 5C9D0000 564C0014 347F4300 D0D89B00 [ 32.930000] ath10k: [0264]: 10000000 0A000000 403D0000 5C9D0000 564C0014 347F4300 18D99B00 13000000 [ 32.930000] ath10k: [0272]: 00000000 203D0000 5C9D0000 035C0014 01000000 04F02131 5A530000 A4B79B00 [ 32.930000] ath10k: [0280]: 347F4300 6E9D0000 0B200014 B0F34300 00000000 00000000 06000000 00008615 [ 32.930000] ath10k: [0288]: 769D0000 07200004 B0F34300 769D0000 094C0014 00000000 00000001 FF000000 [ 32.930000] ath10k: [0296]: 01000000 80000000 769D0000 074C0008 00000000 00000000 219E0000 0920040C [ 32.930000] ath10k: [0304]: 30F44300 00000000 00000000 219E0000 065C040C 08000000 C8704400 648D9C00 [ 32.930000] ath10k: [0312]: 219E0000 0928040C 61661071 30F44300 80FA4300 219E0000 0928040C 60661071 [ 32.930000] ath10k: [0320]: 30F44300 80FA4300 219E0000 085C0408 30F44300 58684400 219E0000 065C040C [ 32.930000] ath10k: [0328]: 11000000 C8704400 6C8D9C00 219E0000 045C040C 03001081 30F44300 00000000 [ 32.930000] ath10k: [0336]: 219E0000 02280408 03000000 02000000 219E0000 02280404 02000000 219E0000 [ 32.930000] ath10k: [0344]: 4F4C0414 13000000 94E64100 C47F4300 00000000 00007100 219E0000 4F4C0414 [ 32.930000] ath10k: [0352]: 03000000 CCE64100 C47F4300 00000000 01007200 219E0000 564C0414 C47F4300 [ 32.930000] ath10k: [0360]: 60D99B00 11000000 00000000 20310000 219E0000 564C0414 C47F4300 A8D99B00 [ 32.930000] ath10k: [0368]: 12000000 00000000 20210000 [ 32.930000] ath10k_pci 0000:01:00.0: ATH10K_END [ 33.620000] ath10k_pci 0000:01:00.0: ath10k_pci ATH10K_DBG_BUFFER: [ 33.620000] ath10k: [0000]: 219E0000 564C0414 C47F4300 F0D99B00 10000000 0A000000 40310000 219E0000 [ 33.620000] ath10k: [0008]: 564C0414 C47F4300 38DA9B00 13000000 00000000 20310000 219E0000 035C0414 [ 33.620000] ath10k: [0016]: 01000000 06F02131 5A530000 DCB79B00 C47F4300 B69E0000 08200004 B0F34300 [ 33.620000] ath10k: [0024]: B69E0000 0A4C0010 00000000 00000001 FF000000 81000000 B69E0000 084C0008 [ 33.620000] ath10k: [0032]: 00000000 00000000 539F0000 0B200414 30F44300 00000000 00000000 06000000 [ 33.620000] ath10k: [0040]: 00008615 569F0000 07200404 30F44300 569F0000 094C0414 02000000 00010000 [ 33.620000] ath10k: [0048]: 01000000 01000000 80000000 569F0000 074C0408 02000000 00000000 5D9F0000 [ 33.620000] ath10k: [0056]: 0B200014 B0F34300 00000000 02000000 06000000 00008615 5D9F0000 07200004 [ 33.620000] ath10k: [0064]: B0F34300 5D9F0000 094C0014 00000000 00010001 FF000000 01000000 80000000 [ 33.620000] ath10k: [0072]: 5D9F0000 074C0008 00000000 00000000 5F9F0000 4F4C0414 62000000 04E74100 [ 33.620000] ath10k: [0080]: C47F4300 01000000 01007300 5F9F0000 1D4C0410 C47F4300 01000000 06000000 [ 33.620000] ath10k: [0088]: 40000000 C99F0000 4F4C0414 DC000000 3CE74100 54804300 00000000 00007100 [ 33.620000] ath10k: [0096]: C99F0000 4F4C0414 CC000000 74E74100 54804300 00000000 01007200 C99F0000 [ 33.620000] ath10k: [0104]: 564C0414 54804300 80DA9B00 11000000 00000000 20310000 C99F0000 564C0414 [ 33.620000] ath10k: [0112]: 54804300 CCC64300 00000000 0C000000 00110000 C99F0000 035C0414 00000000 [ 33.620000] ath10k: [0120]: 06F02131 5A340000 14B89B00 54804300 C99F0000 524C0414 54804300 00000000 [ 33.620000] ath10k: [0128]: 01000000 02000000 08000000 C99F0000 0128FC17 070B1071 02000001 05000000 [ 33.620000] ath10k: [0136]: 00000000 00000000 C99F0000 0128FC17 80881071 08000000 EC854400 08009600 [ 33.620000] ath10k: [0144]: F00F0000 C99F0000 0128FC17 80881071 00000100 EC854400 08009600 00000000 [ 33.620000] ath10k: [0152]: C99F0000 0128FC17 80881071 00000200 EC854400 08009600 00000000 C99F0000 [ 33.620000] ath10k: [0160]: 0128FC17 80881071 00000300 EC854400 08009600 00000000 C99F0000 0128FC17 [ 33.620000] ath10k: [0168]: 80881071 00000400 EC854400 08009600 00000000 C99F0000 0128FC17 80881071 [ 33.620000] ath10k: [0176]: 00000500 EC854400 08009600 00000000 CA9F0000 524C0414 54804300 C2000000 [ 33.620000] ath10k: [0184]: 01000000 02000000 08000000 CA9F0000 0128FC17 070B1071 02000903 07B00102 [ 33.620000] ath10k: [0192]: FAFF0000 FFFF0000 CA9F0000 0128FC17 80881071 08000000 EC854400 3E009600 [ 33.620000] ath10k: [0200]: F00F0000 CA9F0000 0128FC17 80881071 0A000100 EC854400 3E009600 1FF80000 [ 33.620000] ath10k: [0208]: CA9F0000 0128FC17 80881071 0A000200 EC854400 3E009600 1FF80000 CA9F0000 [ 33.620000] ath10k: [0216]: 0128FC17 80881071 0B000300 EC854400 3E009600 1FE00700 CA9F0000 0128FC17 [ 33.620000] ath10k: [0224]: 80881071 0B000400 EC854400 3E009600 1FE00700 CA9F0000 0128FC17 80881071 [ 33.620000] ath10k: [0232]: 0C000500 EC854400 3E009600 1FE00F00 EA9F0000 1D4C0410 C47F4300 01000000 [ 33.620000] ath10k: [0240]: 00000000 40010000 EA9F0000 1D4C0410 C47F4300 01000000 06000000 40010000 [ 33.620000] ath10k: [0248]: EB9F0000 564C0414 54804300 C8DA9B00 06000000 0C000000 003D0000 85A00000 [ 33.620000] ath10k: [0256]: 4F4C0414 2C000000 ACE74100 54804300 01000000 01007300 85A00000 1D4C0410 [ 33.620000] ath10k: [0264]: 54804300 01000000 06000000 C2000000 8AA00000 1C4C0410 54804300 00000000 [ 33.620000] ath10k: [0272]: 06000000 C2000000 [ 33.620000] ath10k_pci 0000:01:00.0: ATH10K_END [ 36.620000] ath10k_pci 0000:01:00.0: ath10k_pci ATH10K_DBG_BUFFER: [ 36.620000] ath10k: [0000]: 6FAA0000 244C0410 54804300 00000100 00000000 40000000 6FAA0000 0128FC17 [ 36.620000] ath10k: [0008]: 070B1071 02000A03 07B00102 FAFF0000 FFFF0000 6FAA0000 0128FC17 80881071 [ 36.620000] ath10k: [0016]: 08000000 442A4400 3E009600 F00F0000 6FAA0000 0128FC17 80881071 0A000100 [ 36.620000] ath10k: [0024]: 442A4400 3E009600 1FF80000 6FAA0000 0128FC17 80881071 0A000200 442A4400 [ 36.620000] ath10k: [0032]: 3E009600 1FF80000 6FAA0000 0128FC17 80881071 0B000300 442A4400 3E009600 [ 36.620000] ath10k: [0040]: 1FE00700 6FAA0000 0128FC17 80881071 0B000400 442A4400 3E009600 1FE00700 [ 36.620000] ath10k: [0048]: 6FAA0000 0128FC17 80881071 0C000500 442A4400 3E009600 1FE00F00 [ 36.620000] ath10k_pci 0000:01:00.0: ATH10K_END [ 43.620000] ath10k_pci 0000:01:00.0: ath10k_pci ATH10K_DBG_BUFFER: [ 43.620000] ath10k: [0000]: 13C70000 284C0408 40000000 03000000 1CC70000 234CFC0F 01000000 01000000

[ 43.620000] ath10k_pci 0000:01:00.0: ATH10K_END

ghost commented 6 years ago

Some additionnal information: I'm building the driver without DFS support (CONFIG_PACKAGE_ATH_DFS in OpenWrt)

greearb commented 6 years ago

There are no obvious errors in the logs, though there is one failed-to-transmit message. Normally one of those is OK and system recovers, but perhaps in your case it is important?

In this particular case that generated the logs, you are seeing no pkts on air from the ath10k system?

Have you tried testing the same setup without encryption to see if the problem is related to encryption?

In the case you just reported, does the problem always happen on this system, or is it transient?

And finally, please show me output of: cat /sys/kernel/debug/ieee80211/phy0/ath10k/fw_regs

(Adjust for your phy name)

ghost commented 6 years ago

It seems to be related to the encryption. Broadcast traffic is exchanged unencrypted successfully but unicast traffic is sent & received encrypted and does not seem to be decrypted.

It always happens on these systems in this particular location (I guess there are some specific RF conditions in this area). I already changed all the HW several times (electronics, antenna, cables) and I always got the same result.

This is working fine using official ath10k + 802.11s +WPA2-SAE

cat /sys/kernel/debug/ieee80211/phy0/ath10k/fw_regs ath10k Target Register Dump (extras-count: 0)

       MAC-FILTER-ADDR-L32 0x00000000
       MAC-FILTER-ADDR-U16 0x00000000
             DCU-SLOT-TIME 0x00000000
           PHY-MODE-SELECT 0x00000000
       PHY-BB-GEN-CONTROLS 0x00000000
                   DMA-IMR 0x00000000
              DMA-TXRX-IMR 0x00000000
             PCU-BSSID-L32 0x00000000
             PCU-BSSID-U16 0x00000000
            PCU-BSSID2-L32 0x00000000
            PCU-BSSID2-U16 0x00000000
          PCU-STA-ADDR-L32 0x00000000
          PCU-STA-ADDR-U16 0x00000000
               MAC-DMA-CFG 0x00000000
             MAC-DMA-TXCFG 0x00000000
              SW-POWERMODE 0x00000000
           SW-CHAINMASK-TX 0x00000000
           SW-CHAINMASK-RX 0x00000000
                 SW-OPMODE 0x00000000
          MAC-PCU-RXFILTER 0x00000000
               SW-RXFILTER 0x00000000
             SHORT-RETRIES 0x00000000
              LONG-RETRIES 0x00000000
                  ADC-TEMP 0x00000000
           NFCAL-PER-CHAIN 0x00000000
greearb commented 6 years ago

Those register values must have been taken when the node was inactive? I need to see them in the case where the system is failing.

And, what you describe sounds like key setting issues, which I have previously seen, but in the cases I have debugged, it appears the stack and/or supplicant was doing the wrong thing.

I now suspect the previous 'dmesg' logs were also from a case that was not actively failing? I need to see as complete of a boot log as possible for the case that is actually failing in order to debug this.

ghost commented 6 years ago

[ 0.000000] Linux version 3.18.92 (tpateloup@build) (gcc version 4.8.3 (OpenWrt/Linaro GCC 4.8-2014.04 5.3.0b1-10-gcfc70d75da) ) #209 Fri May 25 11:12:05 CEST 2018 [ 0.000000] bootconsole [early0] enabled [ 0.000000] CPU0 revision is: 00019750 (MIPS 74Kc) [ 0.000000] SoC: Qualcomm Atheros QCA9558 ver 1 rev 0 [ 0.000000] Determined physical RAM map: [ 0.000000] memory: 08000000 @ 00000000 (usable) [ 0.000000] User-defined physical RAM map: [ 0.000000] memory: 08000000 @ 00000000 (usable) [ 0.000000] Zone ranges: [ 0.000000] Normal [mem 0x00000000-0x07ffffff] [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x00000000-0x07ffffff] [ 0.000000] Initmem setup node 0 [mem 0x00000000-0x07ffffff] [ 0.000000] On node 0 totalpages: 32768 [ 0.000000] free_area_init_node: node 0, pgdat 80388f20, node_mem_map 81000000 [ 0.000000] Normal zone: 256 pages used for memmap [ 0.000000] Normal zone: 0 pages reserved [ 0.000000] Normal zone: 32768 pages, LIFO batch:7 [ 0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes. [ 0.000000] Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes [ 0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768 [ 0.000000] pcpu-alloc: [0] 0 [ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 32512 [ 0.000000] Kernel command line: console=ttyS0,115200 root=/dev/mtdblock5 ro init=/etc/preinit panic=3 mtdparts=spi0.0:128k(u-boot),64k(u-boot-env),1280k(kernel1),6592k(rootfs1),1280k(kernel2),6592k(rootfs2),384k(config),64k(ART),7872k@0x30000(firmware1),7872k@0x7e0000(firmware2) board=JWAP230 mem=128M rootfstype=squashfs noinitrd [ 0.000000] PID hash table entries: 512 (order: -1, 2048 bytes) [ 0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes) [ 0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes) [ 0.000000] Writing ErrCtl register=00000000 [ 0.000000] Readback ErrCtl register=00000000 [ 0.000000] Memory: 125860K/131072K available (2655K kernel code, 117K rwdata, 532K rodata, 144K init, 184K bss, 5212K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 [ 0.000000] NR_IRQS:51 [ 0.000000] Clocks: CPU:720.000MHz, DDR:600.000MHz, AHB:200.000MHz, Ref:40.000MHz [ 0.000000] Calibrating delay loop... 358.80 BogoMIPS (lpj=1794048) [ 0.060000] pid_max: default: 32768 minimum: 301 [ 0.060000] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes) [ 0.070000] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes) [ 0.080000] NET: Registered protocol family 16 [ 0.080000] MIPS: machine is jjPlus JWAP230/232 [ 0.090000] [ 0.090000] WLAN firmware dump buffer allocation of 2097152 bytes @ address 0x87a00000- SUCCESS !!! [ 0.100000] ar724x-pci ar724x-pci.0: PCIe link is down [ 0.100000] registering PCI controller with io_map_base unset [ 0.110000] registering PCI controller with io_map_base unset [ 0.550000] PCI host bridge to bus 0000:00 [ 0.560000] pci_bus 0000:00: root bus resource [mem 0x10000000-0x11ffffff] [ 0.560000] pci_bus 0000:00: root bus resource [io 0x0000] [ 0.570000] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff] [ 0.570000] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 00 [ 0.570000] PCI host bridge to bus 0000:01 [ 0.580000] pci_bus 0000:01: root bus resource [mem 0x12000000-0x13ffffff] [ 0.580000] pci_bus 0000:01: root bus resource [io 0x0001] [ 0.590000] pci_bus 0000:01: No busn resource found for root bus, will use [bus 01-ff] [ 0.590000] pci 0000:01:00.0: [168c:003c] type 00 class 0x028000 [ 0.590000] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x001fffff 64bit] [ 0.590000] pci 0000:01:00.0: reg 0x30: [mem 0x00000000-0x0000ffff pref] [ 0.590000] pci 0000:01:00.0: supports D1 D2 [ 0.590000] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01 [ 0.590000] pci 0000:01:00.0: BAR 0: assigned [mem 0x12000000-0x121fffff 64bit] [ 0.600000] pci 0000:01:00.0: BAR 6: assigned [mem 0x12200000-0x1220ffff pref] [ 0.600000] pci 0000:01:00.0: using irq 41 for pin 1 [ 0.610000] Switched to clocksource MIPS [ 0.610000] NET: Registered protocol family 2 [ 0.620000] TCP established hash table entries: 1024 (order: 0, 4096 bytes) [ 0.620000] TCP bind hash table entries: 1024 (order: 0, 4096 bytes) [ 0.630000] TCP: Hash tables configured (established 1024 bind 1024) [ 0.640000] TCP: reno registered [ 0.640000] UDP hash table entries: 256 (order: 0, 4096 bytes) [ 0.650000] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes) [ 0.650000] NET: Registered protocol family 1 [ 0.660000] PCI: CLS 0 bytes, default 32 [ 0.660000] futex hash table entries: 256 (order: -1, 3072 bytes) [ 0.670000] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ 0.680000] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc. [ 0.690000] msgmni has been set to 245 [ 0.700000] io scheduler noop registered [ 0.700000] io scheduler deadline registered (default) [ 0.710000] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled [ 0.720000] console [ttyS0] disabled [ 0.740000] serial8250.0: ttyS0 at MMIO 0x18020000 (irq = 11, base_baud = 2500000) is a 16550A [ 0.750000] console [ttyS0] enabled [ 0.760000] bootconsole [early0] disabled [ 0.770000] m25p80 spi0.0: found mx25l12805d, expected m25p80 [ 0.770000] m25p80 spi0.0: mx25l12805d (16384 Kbytes) [ 0.780000] 10 cmdlinepart partitions found on MTD device spi0.0 [ 0.780000] Creating 10 MTD partitions on "spi0.0": [ 0.790000] 0x000000000000-0x000000020000 : "u-boot" [ 0.800000] 0x000000020000-0x000000030000 : "u-boot-env" [ 0.800000] 0x000000030000-0x000000170000 : "kernel1" [ 0.810000] 0x000000170000-0x0000007e0000 : "rootfs1" [ 0.810000] 0x0000007e0000-0x000000920000 : "kernel2" [ 0.820000] 0x000000920000-0x000000f90000 : "rootfs2" [ 0.820000] 0x000000f90000-0x000000ff0000 : "config" [ 0.830000] 0x000000ff0000-0x000001000000 : "ART" [ 0.840000] 0x000000030000-0x0000007e0000 : "firmware1" [ 0.840000] 0x0000007e0000-0x000000f90000 : "firmware2" [ 0.850000] tun: Universal TUN/TAP device driver, 1.6 [ 0.850000] tun: (C) 1999-2004 Max Krasnyansky maxk@qualcomm.com [ 0.870000] switch0: Atheros AR8337 rev. 2 switch registered on ag71xx-mdio.0 [ 0.960000] libphy: ag71xx_mdio: probed [ 1.560000] ag71xx ag71xx.0: connected to PHY at ag71xx-mdio.0:00 [uid=004dd036, driver=Atheros AR8216/AR8236/AR8316] [ 1.570000] eth0: Atheros AG71xx at 0xb9000000, irq 4, mode:RGMII [ 2.160000] eth1: Atheros AG71xx at 0xba000000, irq 5, mode:SGMII [ 2.160000] GACT probability on [ 2.170000] u32 classifier [ 2.170000] input device check on [ 2.170000] Actions configured [ 2.180000] Netfilter messages via NETLINK v0.30. [ 2.180000] nfnl_acct: registering with nfnetlink. [ 2.190000] nf_conntrack version 0.5.0 (1966 buckets, 7864 max) [ 2.190000] ctnetlink v0.93: registering with nfnetlink. [ 2.200000] ip_tables: (C) 2000-2006 Netfilter Core Team [ 2.200000] TCP: cubic registered [ 2.210000] NET: Registered protocol family 17 [ 2.210000] bridge: automatic filtering via arp/ip/ip6tables has been deprecated. Update your scripts to load br_netfilter if you need this. [ 2.220000] Bridge firewalling registered [ 2.230000] Ebtables v2.0 registered [ 2.230000] 8021q: 802.1Q VLAN Support v1.8 [ 2.250000] VFS: Mounted root (squashfs filesystem) readonly on device 31:5. [ 2.250000] Freeing unused kernel memory: 144K [ 3.050000] init: Console is alive [ 3.060000] init: - watchdog - [ 5.040000] usbcore: registered new interface driver usbfs [ 5.040000] usbcore: registered new interface driver hub [ 5.050000] usbcore: registered new device driver usb [ 5.060000] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver [ 5.060000] ehci-platform: EHCI generic platform driver [ 5.070000] ehci-platform ehci-platform.0: EHCI Host Controller [ 5.080000] ehci-platform ehci-platform.0: new USB bus registered, assigned bus number 1 [ 5.090000] ehci-platform ehci-platform.0: TX-TX IDP fix enabled [ 5.090000] ehci-platform ehci-platform.0: irq 48, io mem 0x1b000000 [ 5.120000] ehci-platform ehci-platform.0: USB 2.0 started, EHCI 1.00 [ 5.120000] hub 1-0:1.0: USB hub found [ 5.130000] hub 1-0:1.0: 1 port detected [ 5.130000] ehci-platform ehci-platform.1: EHCI Host Controller [ 5.140000] ehci-platform ehci-platform.1: new USB bus registered, assigned bus number 2 [ 5.150000] ehci-platform ehci-platform.1: TX-TX IDP fix enabled [ 5.150000] ehci-platform ehci-platform.1: irq 49, io mem 0x1b400000 [ 5.180000] ehci-platform ehci-platform.1: USB 2.0 started, EHCI 1.00 [ 5.180000] hub 2-0:1.0: USB hub found [ 5.190000] hub 2-0:1.0: 1 port detected [ 5.190000] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver [ 5.200000] ohci-platform: OHCI generic platform driver [ 6.060000] init: - preinit - [ 6.520000] random: mktemp urandom read with 10 bits of entropy available [ 7.580000] eth0: link up (1000Mbps/Full duplex) [ 9.630000] mount_root: mounting /dev/root [ 9.760000] eth0: link down [ 9.770000] procd: - early - [ 9.770000] procd: - watchdog - [ 10.360000] procd: - ubus - [ 11.370000] procd: - init - [ 11.520000] Loading modules backported from Linux version wt-2017-01-31-0-ge882dff19e7f [ 11.530000] Backport generated by backports.git backports-20160324-13-g24da7d3c [ 11.710000] ath10k 4.9 driver, optimized for CT firmware, probing pci device: 0x3c. [ 11.720000] PCI: Enabling device 0000:01:00.0 (0000 -> 0002) [ 11.730000] ath10k_pci 0000:01:00.0: pci irq legacy oper_irq_mode 1 irq_mode 0 reset_mode 0 [ 11.950000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/pre-cal-pci-0000:01:00.0.bin failed with error -2 [ 11.960000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.020000] firmware ath10k!pre-cal-pci-0000:01:00.0.bin: firmware_loading_store: map pages failed [ 12.030000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/cal-pci-0000:01:00.0.bin failed with error -2 [ 12.040000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.100000] firmware ath10k!cal-pci-0000:01:00.0.bin: firmware_loading_store: map pages failed [ 12.110000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/fwcfg-pci-0000:01:00.0.txt failed with error -2 [ 12.120000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.190000] firmware ath10k!fwcfg-pci-0000:01:00.0.txt: firmware_loading_store: map pages failed [ 12.200000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/ct-firmware-5.bin failed with error -2 [ 12.210000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.270000] firmware ath10k!QCA988X!hw2.0!ct-firmware-5.bin: firmware_loading_store: map pages failed [ 12.280000] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/ct-firmware-5.bin': -11 [ 12.290000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/ct-firmware-2.bin failed with error -2 [ 12.300000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.370000] firmware ath10k!QCA988X!hw2.0!ct-firmware-2.bin: firmware_loading_store: map pages failed [ 12.370000] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/ct-firmware-2.bin': -11 [ 12.390000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/firmware-5.bin failed with error -2 [ 12.400000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.460000] firmware ath10k!QCA988X!hw2.0!firmware-5.bin: firmware_loading_store: map pages failed [ 12.470000] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/firmware-5.bin': -11 [ 12.480000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/firmware-4.bin failed with error -2 [ 12.490000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.550000] firmware ath10k!QCA988X!hw2.0!firmware-4.bin: firmware_loading_store: map pages failed [ 12.560000] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/firmware-4.bin': -11 [ 12.570000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/firmware-3.bin failed with error -2 [ 12.580000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 12.650000] firmware ath10k!QCA988X!hw2.0!firmware-3.bin: firmware_loading_store: map pages failed [ 12.650000] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/firmware-3.bin': -11 [ 12.900000] ath10k_pci 0000:01:00.0: qca988x hw2.0 target 0x4100016c chip_id 0x043222ff sub 0000:0000 [ 12.910000] ath10k_pci 0000:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 0 testmode 0 [ 12.920000] ath10k_pci 0000:01:00.0: firmware ver 10.1-ct-8x-__fW-021-75f739c api 2 features wmi-10.x,has-wmi-mgmt-tx,txstatus-noack,wmi-10.x-CT,ratemask-CT,get-temp-CT,tx-rc-CT,cust-stats-CT crc32 6c2a63ef [ 12.970000] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/board-2.bin failed with error -2 [ 12.980000] ath10k_pci 0000:01:00.0: Falling back to user helper [ 13.060000] firmware ath10k!QCA988X!hw2.0!board-2.bin: firmware_loading_store: map pages failed [ 13.070000] ath10k_pci 0000:01:00.0: board_file api 1 bmi_id N/A crc32 bebc7c08 [ 13.980000] ath10k_pci 0000:01:00.0: 10.1 wmi init: vdevs: 16 peers: 127 tid: 256 [ 13.990000] ath10k_pci 0000:01:00.0: 10.1 features for rx-decap-mode: 0xc0 [ 14.000000] ath10k_pci 0000:01:00.0: wmi print 'P 128 V 8 T 410' [ 14.010000] ath10k_pci 0000:01:00.0: wmi print 'msdu-desc: 1424 sw-crypt: 0' [ 14.020000] ath10k_pci 0000:01:00.0: wmi print 'alloc rem: 26172 iram: 24596' [ 14.070000] ath10k_pci 0000:01:00.0: htt-ver 2.1 wmi-op 2 htt-op 2 cal otp max-sta 128 raw 0 hwcrypto 1 [ 14.190000] ath: EEPROM regdomain: 0x0 [ 14.190000] ath: EEPROM indicates default country code should be used [ 14.190000] ath: doing EEPROM country->regdmn map search [ 14.190000] ath: country maps to regdmn code: 0x3a [ 14.190000] ath: Country alpha2 being used: US [ 14.190000] ath: Regpair used: 0x3a [ 14.240000] ip_set: protocol 6 [ 14.330000] batman_adv: B.A.T.M.A.N. advanced 2016.0 (compatibility version 15) loaded [ 14.410000] hidraw: raw HID events driver (C) Jiri Kosina [ 14.420000] Mirror/redirect action on [ 14.430000] usbcore: registered new interface driver cdc_acm [ 14.430000] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters [ 14.480000] usbcore: registered new interface driver usbhid [ 14.480000] usbhid: USB HID core driver [ 14.500000] usbcore: registered new interface driver usbserial [ 14.500000] usbcore: registered new interface driver usbserial_generic [ 14.510000] usbserial: USB Serial support registered for generic [ 14.520000] xt_time: kernel timezone is +0100 [ 14.530000] usbcore: registered new interface driver asix [ 14.540000] usbcore: registered new interface driver ch341 [ 14.540000] usbserial: USB Serial support registered for ch341-uart [ 14.550000] PPP generic driver version 2.4.2 [ 14.560000] usbcore: registered new interface driver snd-usb-audio [ 20.840000] jffs2: notice: (925) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found. [ 23.090000] ar8216: set port:4 speed:1000 [ 23.110000] ar8216: set port:0 speed:1000 [ 29.060000] device eth0 entered promiscuous mode [ 29.900000] eth0: link up (1000Mbps/Full duplex) [ 30.260000] batman_adv: bat0: Adding interface: eth0.10 [ 30.270000] batman_adv: bat0: The MTU of interface eth0.10 is too small (1500) to handle the transport of batman-adv packets. Packets going over this interface will be fragmented on layer2 which could impact the performance. Setting the MTU to 1532 would solve the problem. [ 30.290000] batman_adv: bat0: Interface activated: eth0.10 [ 30.300000] 8021q: adding VLAN 0 to HW filter on device bat0 [ 30.310000] device bat0 entered promiscuous mode [ 30.310000] br-wan: port 1(bat0) entered forwarding state [ 30.320000] br-wan: port 1(bat0) entered forwarding state [ 30.320000] batman_adv: bat0: Adding interface: eth0.11 [ 30.330000] batman_adv: bat0: The MTU of interface eth0.11 is too small (1500) to handle the transport of batman-adv packets. Packets going over this interface will be fragmented on layer2 which could impact the performance. Setting the MTU to 1532 would solve the problem. [ 30.350000] batman_adv: bat0: Interface activated: eth0.11 [ 30.480000] ath: EEPROM regdomain: 0x80fa [ 30.480000] ath: EEPROM indicates we should expect a country code [ 30.480000] ath: doing EEPROM country->regdmn map search [ 30.480000] ath: country maps to regdmn code: 0x37 [ 30.480000] ath: Country alpha2 being used: FR [ 30.480000] ath: Regpair used: 0x37 [ 30.480000] ath: regdomain 0x80fa dynamically updated by user [ 30.880000] batman_adv: bat0: bridge_loop_avoidance: Changing from: enabled to: disabled [ 30.900000] batman_adv: bat0: distributed_arp_table: Changing from: enabled to: disabled [ 30.900000] batman_adv: bat0: hop_penalty: Changing from: 30 to: 20 [ 30.930000] batman_adv: bat0: multicast_mode: Changing from: enabled to: disabled [ 31.700000] batman_adv: bat0: Adding interface: adhoc0 [ 31.700000] batman_adv: bat0: The MTU of interface adhoc0 is too small (1500) to handle the transport of batman-adv packets. Packets going over this interface will be fragmented on layer2 which could impact the performance. Setting the MTU to 1532 would solve the problem. [ 31.730000] batman_adv: bat0: Not using interface adhoc0 (retrying later): interface not active [ 31.910000] Atheros AR8216/AR8236/AR8316 ag71xx-mdio.0:00: Port 1 is up [ 31.910000] Atheros AR8216/AR8236/AR8316 ag71xx-mdio.0:00: Port 5 is up [ 32.320000] br-wan: port 1(bat0) entered forwarding state [ 32.960000] ath10k_pci 0000:01:00.0: 10.1 wmi init: vdevs: 16 peers: 127 tid: 256 [ 32.970000] ath10k_pci 0000:01:00.0: 10.1 features for rx-decap-mode: 0xc0 [ 32.990000] ath10k_pci 0000:01:00.0: wmi print 'P 128 V 8 T 410' [ 32.990000] ath10k_pci 0000:01:00.0: wmi print 'msdu-desc: 1424 sw-crypt: 0' [ 33.000000] ath10k_pci 0000:01:00.0: wmi print 'alloc rem: 26172 iram: 24596' [ 33.080000] device ap0 entered promiscuous mode [ 33.100000] br-lan: port 2(ap0) entered forwarding state [ 33.110000] br-lan: port 2(ap0) entered forwarding state [ 33.240000] ath10k_pci 0000:01:00.0: ath10k_pci ATH10K_DBG_BUFFER: [ 33.240000] ath10k: [0000]: 4F9E0000 0500FC17 70201031 08000000 80000000 58F84000 010006C0 5A9E0000 [ 33.240000] ath10k: [0008]: 085CFC0F 30674400 08000000 80000000 5A9E0000 065CFC0F 58F84000 C8704400 [ 33.240000] ath10k: [0016]: 19000000 5A9E0000 065CFC0F 09000000 C8704400 348D9C00 6F9E0000 0920000C [ 33.240000] ath10k: [0024]: B0F34300 01000000 00000000 6F9E0000 065C000C 08000000 C8704400 3C8D9C00 [ 33.240000] ath10k: [0032]: 6F9E0000 4F4C0014 02000000 ECE54100 A47E4300 00000000 00007100 6F9E0000 [ 33.240000] ath10k: [0040]: 564C0014 A47E4300 F8D79B00 13000000 00000000 20310000 6F9E0000 035C0014 [ 33.240000] ath10k: [0048]: 00000000 00000000 00010000 A4B79B00 A47E4300 6F9E0000 065C000C 05000000 [ 33.240000] ath10k: [0056]: C8704400 448D9C00 6F9E0000 0928000C 61661071 B0F34300 18FA4300 6F9E0000 [ 33.240000] ath10k: [0064]: 0928000C 60661071 B0F34300 18FA4300 6F9E0000 085C0008 B0F34300 58674400 [ 33.240000] ath10k: [0072]: 6F9E0000 065C000C 11000000 C8704400 4C8D9C00 6F9E0000 045C000C 03001081 [ 33.240000] ath10k: [0080]: B0F34300 A4B79B00 6F9E0000 0A200008 B0F34300 00000000 6F9E0000 075C000C [ 33.240000] ath10k: [0088]: 11000000 C8704400 4C8D9C00 6F9E0000 095C0008 B0F34300 58674400 6F9E0000 [ 33.240000] ath10k: [0096]: 075C000C 05000000 C8704400 448D9C00 6F9E0000 075C000C 08000000 C8704400 [ 33.240000] ath10k: [0104]: 3C8D9C00 6F9E0000 09280010 62661071 B0F34300 18FA4300 00000000 6F9E0000 [ 33.240000] ath10k: [0112]: 025C0014 B0F34300 A4B79B00 00000000 00010000 01000000 6F9E0000 574C0014 [ 33.240000] ath10k: [0120]: A47E4300 F8D79B00 13000000 00000000 A2310000 6F9E0000 504C0010 BB001071 [ 33.240000] ath10k: [0128]: ECE54100 A47E4300 98000000 6F9E0000 5B4C0004 68D49B00 6F9E0000 055C0004 [ 33.240000] ath10k: [0136]: B0F34300 739E0000 100CFC0B 8A291001 04000000 739E0000 130CFC03 7A9E0000 [ 33.240000] ath10k: [0144]: 234CFC0F 01000000 01000000 01000000 829E0000 234CFC0F 01000000 01000000 [ 33.240000] ath10k: [0152]: 01000000 8A9E0000 234CFC0F 01000000 01000000 01000000 929E0000 234CFC0F [ 33.240000] ath10k: [0160]: 01000000 01000000 01000000 9A9E0000 234CFC0F 01000000 01000000 01000000 [ 33.240000] ath10k: [0168]: A19E0000 234CFC0F 01000000 01000000 01000000 A99E0000 234CFC0F 01000000 [ 33.240000] ath10k: [0176]: 01000000 01000000 B19E0000 234CFC0F 01000000 01000000 01000000 B19E0000 [ 33.240000] ath10k: [0184]: 0C64FC07 01000000 B99E0000 234CFC0F 01000000 01000000 01000000 B99E0000 [ 33.240000] ath10k: [0192]: 0920000C B0F34300 02000000 00000000 B99E0000 065C000C 08000000 C8704400 [ 33.240000] ath10k: [0200]: 548D9C00 B99E0000 0928000C 61661071 B0F34300 4CFA4300 B99E0000 0928000C [ 33.240000] ath10k: [0208]: 60661071 B0F34300 4CFA4300 B99E0000 085C0008 B0F34300 D8674400 B99E0000 [ 33.240000] ath10k: [0216]: 065C000C 11000000 C8704400 5C8D9C00 B99E0000 045C000C 03001081 B0F34300 [ 33.240000] ath10k: [0224]: 00000000 B99E0000 02280008 03000000 02000000 B99E0000 02280004 02000000 [ 33.240000] ath10k: [0232]: B99E0000 4F4C0014 12000000 24E64100 347F4300 00000000 00007100 B99E0000 [ 33.240000] ath10k: [0240]: 4F4C0014 02000000 5CE64100 347F4300 00000000 01007200 B99E0000 564C0014 [ 33.240000] ath10k: [0248]: 347F4300 40D89B00 11000000 00000000 203D0000 B99E0000 564C0014 347F4300 [ 33.240000] ath10k: [0256]: 88D89B00 12000000 00000000 202D0000 B99E0000 564C0014 347F4300 D0D89B00 [ 33.240000] ath10k: [0264]: 10000000 0A000000 403D0000 B99E0000 564C0014 347F4300 18D99B00 13000000 [ 33.240000] ath10k: [0272]: 00000000 203D0000 B99E0000 035C0014 01000000 04F02131 5A530000 A4B79B00 [ 33.240000] ath10k: [0280]: 347F4300 C99E0000 0B200014 B0F34300 00000000 00000000 06000000 00008615 [ 33.240000] ath10k: [0288]: D19E0000 07200004 B0F34300 D19E0000 094C0014 00000000 00000001 FF000000 [ 33.240000] ath10k: [0296]: 01000000 80000000 D19E0000 074C0008 00000000 00000000 5E9F0000 0920040C [ 33.240000] ath10k: [0304]: 30F44300 00000000 00000000 5E9F0000 065C040C 08000000 C8704400 648D9C00 [ 33.240000] ath10k: [0312]: 5E9F0000 0928040C 61661071 30F44300 80FA4300 5E9F0000 0928040C 60661071 [ 33.240000] ath10k: [0320]: 30F44300 80FA4300 5E9F0000 085C0408 30F44300 58684400 5E9F0000 065C040C [ 33.240000] ath10k: [0328]: 11000000 C8704400 6C8D9C00 5E9F0000 045C040C 03001081 30F44300 00000000 [ 33.240000] ath10k: [0336]: 5E9F0000 02280408 03000000 02000000 5E9F0000 02280404 02000000 5E9F0000 [ 33.240000] ath10k: [0344]: 4F4C0414 13000000 94E64100 C47F4300 00000000 00007100 5E9F0000 4F4C0414 [ 33.240000] ath10k: [0352]: 03000000 CCE64100 C47F4300 00000000 01007200 5E9F0000 564C0414 C47F4300 [ 33.240000] ath10k: [0360]: 60D99B00 11000000 00000000 20310000 5E9F0000 564C0414 C47F4300 A8D99B00 [ 33.240000] ath10k: [0368]: 12000000 00000000 20210000 [ 33.240000] ath10k_pci 0000:01:00.0: ATH10K_END [ 33.240000] batman_adv: bat0: Interface activated: adhoc0 [ 33.520000] adhoc0: Created IBSS using preconfigured BSSID ba:f2:be:e9:36:ab [ 33.520000] adhoc0: Creating new IBSS network, BSSID ba:f2:be:e9:36:ab [ 33.790000] adhoc0: Allowed IBSS STA entry 06:f0:21:31:5a:34 to join, ACL enabled [ 33.960000] ath10k_pci 0000:01:00.0: ath10k_pci ATH10K_DBG_BUFFER: [ 33.960000] ath10k: [0000]: 5E9F0000 564C0414 C47F4300 F0D99B00 10000000 0A000000 40310000 5E9F0000 [ 33.960000] ath10k: [0008]: 564C0414 C47F4300 38DA9B00 13000000 00000000 20310000 5E9F0000 035C0414 [ 33.960000] ath10k: [0016]: 01000000 06F02131 5A530000 DCB79B00 C47F4300 FA9F0000 08200004 B0F34300 [ 33.960000] ath10k: [0024]: FA9F0000 0A4C0010 00000000 00000001 FF000000 81000000 FA9F0000 084C0008 [ 33.960000] ath10k: [0032]: 00000000 00000000 87A00000 0B200414 30F44300 00000000 00000000 06000000 [ 33.960000] ath10k: [0040]: 00008615 89A00000 07200404 30F44300 89A00000 094C0414 02000000 00010000 [ 33.960000] ath10k: [0048]: 01000000 01000000 80000000 89A00000 074C0408 02000000 00000000 90A00000 [ 33.960000] ath10k: [0056]: 0B200014 B0F34300 00000000 02000000 06000000 00008615 90A00000 07200004 [ 33.960000] ath10k: [0064]: B0F34300 90A00000 094C0014 00000000 00010001 FF000000 01000000 80000000 [ 33.960000] ath10k: [0072]: 90A00000 074C0008 00000000 00000000 92A00000 4F4C0414 62000000 04E74100 [ 33.960000] ath10k: [0080]: C47F4300 01000000 01007300 92A00000 1D4C0410 C47F4300 01000000 06000000 [ 33.960000] ath10k: [0088]: 40000000 97A10000 4F4C0414 DC000000 3CE74100 54804300 00000000 00007100 [ 33.960000] ath10k: [0096]: 97A10000 4F4C0414 CC000000 74E74100 54804300 00000000 01007200 97A10000 [ 33.960000] ath10k: [0104]: 564C0414 54804300 80DA9B00 11000000 00000000 20310000 97A10000 564C0414 [ 33.960000] ath10k: [0112]: 54804300 CCC64300 00000000 0C000000 00110000 97A10000 035C0414 00000000 [ 33.960000] ath10k: [0120]: 06F02131 5A340000 14B89B00 54804300 99A10000 524C0414 54804300 00000000 [ 33.960000] ath10k: [0128]: 01000000 02000000 08000000 99A10000 0128FC17 070B1071 02000001 05000000 [ 33.960000] ath10k: [0136]: 00000000 00000000 99A10000 0128FC17 80881071 08000000 EC854400 08009600 [ 33.960000] ath10k: [0144]: F00F0000 99A10000 0128FC17 80881071 00000100 EC854400 08009600 00000000 [ 33.960000] ath10k: [0152]: 99A10000 0128FC17 80881071 00000200 EC854400 08009600 00000000 99A10000 [ 33.960000] ath10k: [0160]: 0128FC17 80881071 00000300 EC854400 08009600 00000000 99A10000 0128FC17 [ 33.960000] ath10k: [0168]: 80881071 00000400 EC854400 08009600 00000000 99A10000 0128FC17 80881071 [ 33.960000] ath10k: [0176]: 00000500 EC854400 08009600 00000000 9DA10000 1D4C0410 C47F4300 01000000 [ 33.960000] ath10k: [0184]: 00000000 40010000 9DA10000 1D4C0410 C47F4300 01000000 06000000 40010000 [ 33.960000] ath10k: [0192]: 9EA10000 564C0414 54804300 C8DA9B00 10000000 0A000000 003D0000 BDA10000 [ 33.960000] ath10k: [0200]: 4F4C0414 2C000000 ACE74100 54804300 01000000 01007300 BDA10000 1D4C0410 [ 33.960000] ath10k: [0208]: 54804300 01000000 06000000 42000000 C1A10000 1C4C0410 54804300 00000000 [ 33.960000] ath10k: [0216]: 06000000 42010000 07A20000 574C0414 54804300 C8DA9B00 10000000 1A000000 [ 33.960000] ath10k: [0224]: 023D0000 07A20000 524C0414 54804300 E2010000 01000000 02000000 08400000 [ 33.960000] ath10k: [0232]: 07A20000 0128FC17 070B1071 02000903 07B00102 FAFF0000 FFFF0000 07A20000 [ 33.960000] ath10k: [0240]: 0128FC17 80881071 08000000 EC854400 3E009600 F00F0000 07A20000 0128FC17 [ 33.960000] ath10k: [0248]: 80881071 0A000100 EC854400 3E009600 1FF80000 07A20000 0128FC17 80881071 [ 33.960000] ath10k: [0256]: 0A000200 EC854400 3E009600 1FF80000 07A20000 0128FC17 80881071 0B000300 [ 33.960000] ath10k: [0264]: EC854400 3E009600 1FE00700 07A20000 0128FC17 80881071 0B000400 EC854400 [ 33.960000] ath10k: [0272]: 3E009600 1FE00700 07A20000 0128FC17 80881071 0C000500 EC854400 3E009600

[ 33.960000] ath10k_pci 0000:01:00.0: ATH10K_END [ 35.110000] br-lan: port 2(ap0) entered forwarding state [ 38.200000] random: nonblocking pool is initialized [ 40.960000] ath10k_pci 0000:01:00.0: ath10k_pci ATH10K_DBG_BUFFER: [ 40.960000] ath10k: [0000]: 18BE0000 244C0410 54804300 00000100 00000000 40000000 18BE0000 0128FC17 [ 40.960000] ath10k: [0008]: 070B1071 02000A03 07B00102 FAFF0000 FFFF0000 18BE0000 0128FC17 80881071 [ 40.960000] ath10k: [0016]: 08000000 442A4400 3E009600 F00F0000 18BE0000 0128FC17 80881071 0A000100 [ 40.960000] ath10k: [0024]: 442A4400 3E009600 1FF80000 18BE0000 0128FC17 80881071 0A000200 442A4400 [ 40.960000] ath10k: [0032]: 3E009600 1FF80000 18BE0000 0128FC17 80881071 0B000300 442A4400 3E009600 [ 40.960000] ath10k: [0040]: 1FE00700 18BE0000 0128FC17 80881071 0B000400 442A4400 3E009600 1FE00700 [ 40.960000] ath10k: [0048]: 18BE0000 0128FC17 80881071 0C000500 442A4400 3E009600 1FE00F00 [ 40.960000] ath10k_pci 0000:01:00.0: ATH10K_END [ 66.410000] batman_adv: bat0: hop_penalty: Changing from: 20 to: 15

greearb commented 6 years ago

Is that log from a working case, or a broken case? If you restart that same node a few times, will it sometimes work and sometimes not? If so, maybe it would be helpful if you could provide one log of broken and one log of the working case so I can compare. Please clearly note any symptoms you see (or do not see) when posting logs so that I know what to look for.

I see no obvious errors in the log you posted above.

ghost commented 6 years ago

This is always broken on this node. In fact it always happens to any node placed on some specific area.

Station 06:f0:21:31:5c:14 (on adhoc0) inactive time: 60 ms rx bytes: 648949 rx packets: 7011 tx bytes: 196474 tx packets: 1742 tx retries: 0 tx failed: 1737 rx drop misc: 0 signal: -72 [-93, -72] dBm signal avg: -76 [-94, -76] dBm tx bitrate: 175.5 MBit/s VHT-MCS 4 80MHz VHT-NSS 1 rx bitrate: 175.6 MBit/s VHT-MCS 2 80MHz VHT-NSS 2 rx duration: 0 us authorized: yes authenticated: yes associated: yes preamble: long WMM/WME: yes MFP: no TDLS peer: no DTIM period: 0 beacon interval:300 short slot time:yes connected time: 235 seconds

On broken nodes, there is always an asymetric number of streams between RX & TX

ghost commented 6 years ago

And moreover it works fine using ath10k + 802.11s +WPA-SAE on these nodes

greearb commented 6 years ago

You could send me the fw_regs from when the radio is running, that might possibly show some new information.

In the past, similar issues have been related to the on-air packet size. The firmware might send a frame 16 bytes too large or too small, for instance. I have previously debugged this by sending frames of a known size and then looked on-air to see if they were the correct size or not. You might also be able to grab a packet sniff and use wireshark to decode it and look for errors.

If you can somehow reproduce this in a lab (maybe using attenuators?) then it would be a lot easier to debug and fix.

ghost commented 6 years ago

It seems to happen when there is a mismatch on the NSS. For example: side A: iw adhoc0 station dump Station 06:f0:21:31:5b:a1 (on adhoc0) inactive time: 0 ms rx bytes: 6569111 rx packets: 40354 tx bytes: 1604311 tx packets: 5958 tx retries: 0 tx failed: 5953 signal: -46 [-93, -46] dBm signal avg: -46 [-92, -46] dBm tx bitrate: 81.0 MBit/s VHT-MCS 4 40MHz VHT-NSS 1 rx bitrate: 162.0 MBit/s VHT-MCS 4 40MHz VHT-NSS 2 authorized: yes authenticated: yes preamble: long WMM/WME: yes MFP: no TDLS peer: no connected time: 321 seconds

side B: Station 06:f0:21:3a:d7:9f (on adhoc0) inactive time: 0 ms rx bytes: 1344861 rx packets: 8825 tx bytes: 4838869 tx packets: 14301 tx retries: 0 tx failed: 0 signal: -49 [-68, -49] dBm signal avg: -48 [-68, -48] dBm tx bitrate: 81.0 MBit/s VHT-MCS 4 40MHz VHT-NSS 1 rx bitrate: 6.0 MBit/s authorized: yes authenticated: yes preamble: long WMM/WME: yes MFP: no TDLS peer: no connected time: 122 seconds

klukonin commented 6 years ago

Hello!

This looks quite like the same issue we faced and reported in dec 2016. 100% reproducible with 10.1 firmware and QCA988X.

@oamouroux Please can you check this issue again? Right at the moment when tx begin to fail and second device shows rx bitrate: 6.0 MBit/s (or sometimes rx bitrate: 48.0 MBit/s) iw adhoc0 station dump should show "inactive time:" WITH NEGATIVE VALUE.

After some time, "inactive time:" switches to a normal state, but no traffic can be sent. In OPEN mode this issue with negative "inactive time:" value still exist, but when it switches to a positive state, traffic can go normally through the wireless IBSS link.

klukonin commented 5 years ago

Hello, @oamouroux and @greearb .

We've jist triggered this issue in our lab again. Look's like thr problem can be solved (or mitigated) with this parameters: 1) max_nss = 2 in fwcfg if we are using MIMO 2x2 device. 2) beacon_int = 10 in wpa_supplicant if we are using encrypted IBSS.

This issue look's like a beacon interval related, but I can't explain why. IBSS without encryption works fine with any beacon_int parameter.

Also I found a bug in kernel mac80211 code and I want to make a commit later.

Best regards, Lukonin Kirill.

klukonin commented 5 years ago

Hello, Ben! @greearb Looks like a found a bug. @oamouroux Please check your issue too.

if we look into fwstats, there will be a strange behavior. Look at the first peer and it's mac address. The first octet behave LIKE A COUNTER! This behavior is reproducible on all 5 nodes in our lab at the same time. I don't know why beacon_int =10 helps in this case. Looks like a bug, really.

This is fwstats PEES stats log below.

         ath10k PEER stats (3)
         =================

          Peer MAC address 65:01:00:00:1e:d4
                 Peer RSSI 55633
              Peer TX rate 0
              Peer RX rate 6000
          Peer RX duration 0

          Peer MAC address 0a:24:68:48:51:d9
                 Peer RSSI 0
              Peer TX rate 6000
              Peer RX rate 0
          Peer RX duration 0

          Peer MAC address 3e:9d:75:48:54:6a
                 Peer RSSI 9
              Peer TX rate 58500
              Peer RX rate 175500
          Peer RX duration 0

         ath10k PEER stats (3)
         =================

          Peer MAC address 67:01:00:00:1e:d4
                 Peer RSSI 55633
              Peer TX rate 0
              Peer RX rate 6000
          Peer RX duration 0

          Peer MAC address 0a:24:68:48:51:d9
                 Peer RSSI 0
              Peer TX rate 6000
              Peer RX rate 0
          Peer RX duration 0

          Peer MAC address 3e:9d:75:48:54:6a
                 Peer RSSI 9
              Peer TX rate 58500
              Peer RX rate 175500
          Peer RX duration 0

         ath10k PEER stats (3)
         =================

          Peer MAC address 69:01:00:00:1e:d4
                 Peer RSSI 55633
              Peer TX rate 0
              Peer RX rate 6000
          Peer RX duration 0

          Peer MAC address 0a:24:68:48:51:d9
                 Peer RSSI 0
              Peer TX rate 6000
              Peer RX rate 0
          Peer RX duration 0

          Peer MAC address 3e:9d:75:48:54:6a
                 Peer RSSI 9
              Peer TX rate 58500
              Peer RX rate 175500
          Peer RX duration 0

         ath10k PEER stats (3)
         =================

          Peer MAC address 6b:01:00:00:1e:d4
                 Peer RSSI 55633
              Peer TX rate 0
              Peer RX rate 6000
          Peer RX duration 0

          Peer MAC address 0a:24:68:48:51:d9
                 Peer RSSI 0
              Peer TX rate 6000
              Peer RX rate 0
          Peer RX duration 0

          Peer MAC address 3e:9d:75:48:54:6a
                 Peer RSSI 9
              Peer TX rate 58500
              Peer RX rate 175500
          Peer RX duration 0
klukonin commented 5 years ago

@greearb

We also noticed that the first peer should not exist at all. there are no any mac address with this value BUT please look below.

         ath10k PEER stats (3)
         =================

          Peer MAC address 3d:00:00:00:3a:ed
                 Peer RSSI 53063
              Peer TX rate 0
              Peer RX rate 6000
          Peer RX duration 0

          Peer MAC address 06:0a:dc:48:44:e5
                 Peer RSSI 31
              Peer TX rate 650000
              Peer RX rate 650000
          Peer RX duration 0

          Peer MAC address 0e:16:25:48:54:6a
                 Peer RSSI 27
              Peer TX rate 526500
              Peer RX rate 526500
          Peer RX duration 0

ip addr shows ibss_5g_1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1564 qdisc mq master bat0 state UP group default qlen 1000 link/ether 3a:ed:ad:48:47:cf brd ff:ff:ff:ff:ff:ff

3a:ed is the first two octets of the interface mac address and the last two octets of phantom peer. Also there is a strange static RSSI value, hmmmm let's look closer....

printf %x\n 53063 cf47

It's a reverse order of last two octets from ibss interface mac.

So may be there are some bugs with pointers inside the firmware. I don't know. We use firmware ver 10.1-ct-8x-__fH-021-4fa9f30 api 2 features wmi-10.x,txstatus-noack,wmi-10.x-CT,ratemask-CT,get-temp-CT,tx-rc-CT,cust-stats-CT crc32 580c6146

greearb commented 5 years ago

The stats parsing in ath10k is complex and bug prone. The issue could easily be in the driver as well. Do you see this weird first peer only in cases where you are having connectivity issues, or does it happen all the time?

And, the 'beacon int' that fixes this is sending around 100 beacons per second, or did I mis-understand that?

klukonin commented 5 years ago

We see this phantom peer all the time, even with AP interface without any sta connected.

For example:

         ath10k PEER stats (1)
         =================

          Peer MAC address 2b:00:00:00:5a:be
                 Peer RSSI 45976
              Peer TX rate 0
              Peer RX rate 0
          Peer RX duration 0

ap_5g_1_1: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq state DOWN group default qlen 1000 link/ether 5a:be:7b:80:98:b3 brd ff:ff:ff:ff:ff:ff

root@OpenWrt:~# printf %x/n 45976 b398 The same pieces of mac and last two octets with reverse order.

And, the 'beacon int' that fixes this is sending around 100 beacons per second, or did I mis-understand that?

You understand that 100% right.

Well, I don;'t want to say "Fixed", because we see a lot of overruns in dmesg.

[23211.095047] ath10k_pci 0000:00:00.0: SWBA overrun on vdev 0, skipped old beacon [23356.278429] ath10k_pci 0000:00:00.0: wmi request nop (id 11199) [23509.833606] ath10k_pci 0000:00:00.0: wmi vdev 0 install key peer 06:0a:dc:48:44:e5 idx 1 cipher 0 len 16 flags 0x1 [23509.833721] ath10k_pci 0000:00:00.0: wmi echo value 0x0ba991e9 [23509.833755] ath10k_pci 0000:00:00.0: wmi event echo value 0x0ba991e9 [23509.834109] ath10k_pci 0000:00:00.0: wmi vdev 0 install key peer 06:0a:dc:48:44:e5 idx 1 cipher 4 len 16 flags 0x1 [23509.834131] ath10k_pci 0000:00:00.0: wmi echo value 0x0ba991e9 [23509.834250] ath10k_pci 0000:00:00.0: wmi event echo value 0x0ba991e9 [23509.834319] ath10k_pci 0000:00:00.0: wmi vdev id 0x0 set param 31 value 1 [23510.071101] ath10k_pci 0000:00:00.0: wmi event debug mesg len 52 [23510.071115] ath10k_pci 0000:00:00.0: dropping dbg buffer due to crash since read [23510.078805] ath10k_pci 0000:00:00.0: ath10k_pci ATH10K_DBG_BUFFER: [23510.085194] ath10k: [0000]: 547D6F01 1D4C0010 E07E4300 01000000 00000000 E2010000 547D6F01 1D4C0010 [23510.094545] ath10k: [0008]: E07E4300 01000000 06000000 E2010000 [23510.100657] ath10k_pci 0000:00:00.0: ATH10K_END [23510.110592] ath10k_pci 0000:00:00.0: wmi vdev 0 install key peer 3a:ed:ad:48:47:cf idx 1 cipher 0 len 16 flags 0x1 [23510.110613] ath10k_pci 0000:00:00.0: wmi echo value 0x0ba991e9 [23510.110737] ath10k_pci 0000:00:00.0: wmi event echo value 0x0ba991e9 [23510.110933] ath10k_pci 0000:00:00.0: wmi vdev 0 install key peer 3a:ed:ad:48:47:cf idx 1 cipher 4 len 16 flags 0x1 [23510.110951] ath10k_pci 0000:00:00.0: wmi echo value 0x0ba991e9 [23510.111087] ath10k_pci 0000:00:00.0: wmi event echo value 0x0ba991e9 [23510.111134] ath10k_pci 0000:00:00.0: wmi vdev id 0x0 set param 31 value 1 [23510.678282] ath10k_pci 0000:00:00.0: wmi vdev 0 install key peer 0e:16:25:48:54:6a idx 1 cipher 0 len 16 flags 0x1 [23510.678309] ath10k_pci 0000:00:00.0: wmi echo value 0x0ba991e9 [23510.678708] ath10k_pci 0000:00:00.0: wmi event echo value 0x0ba991e9 [23510.679101] ath10k_pci 0000:00:00.0: wmi vdev 0 install key peer 0e:16:25:48:54:6a idx 1 cipher 4 len 16 flags 0x1 [23510.679124] ath10k_pci 0000:00:00.0: wmi echo value 0x0ba991e9 [23510.679262] ath10k_pci 0000:00:00.0: wmi event echo value 0x0ba991e9 [23510.679319] ath10k_pci 0000:00:00.0: wmi vdev id 0x0 set param 31 value 1 [23511.071409] ath10k_pci 0000:00:00.0: wmi event debug mesg len 100 [23511.071423] ath10k_pci 0000:00:00.0: dropping dbg buffer due to crash since read

But traffic can pass normally through many IBSS hops without visible issues and throughput drops like in this report. So let it be a "Mitigation", but not "Fix". We tried beacon_int = 10 with reboots, interface restarts and didn't trigger this issue, so I confirm that this trick works all the time.

Also, as we can see, this bug can be reproduced with both 10.1 and 10.4 firmwares in IBSS mode. We will check if beacon_int = 10 parameter helps with 10.4 firmware and let you know.

greearb commented 5 years ago

So that peer thing is probably not related to the IBSS bug. Please open a new bug for the peer stats problem.

For the IBSS problem, I cannot think of any reason why sending beacons more often would fix this particular bug report so I don't have any new ideas on how to fix this more properly in the firmware or driver.

@klukonin Earlier you mentioned you forced the system to 2x2 NSS as part of your fix. Are both the 2x2 force and the beacon hack needed, or will one or the other by itself mitigate the problem?

klukonin commented 5 years ago

I can confirm that max_nss = 2 with beacon_int = 10 helps. max_nss = 2 alone doesn't help We will try to test only beacon_int = 10 hack and I'll report about the result. May be it will work without 2x2 NSS enforcement.

Ok. I will open a new bug report

klukonin commented 5 years ago

Hello @oamouroux and @greearb

He have 100% working recipe of how to trigger this issue and how to avoid it.

1) If we create ibss interface, do sleep 1 and start wpa_supplicant - every node will fail to do traffic exchange with others. Rarely one node can catch a state when it can transmit, but can't receive. TCP acks and small packets can pass, but with very very low throughput, That's why sometimes traffic can pass only in one direction.

2) If we create ibss interface and run wpa_supplicant as fast as we can - this issue does not show itself anymore. It is important that beacon_int parameter should be 10ms.

So may be this issue is not beacon related, but TSF related. I remember a lot of weired things in ath10k and firmware about TSF.

klukonin commented 5 years ago

Also, this can be interesting for you, With original 10.2.6 firmware we see how in mesh mode sometimes TSF offset can raise up to 34 days right after we power on our lab. Mesh TSF logic can handle such situations normally, but I'm no sure about IBSS. Anyway, I don't know how to get current TSF offset value in ibss mode.