search

greearb / ath10k-ct

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

Setting the MCS fails #141

Open Warxo opened 4 years ago

Warxo commented 4 years ago

Hello,

I'm using 2 WLE900VX (Qualcomm Atheros QCA986x/988x 802.11ac Wireless Network Adapter), one is an access point and the other is a client that is connected to the first one. The bandwidth is 80MHz and the Guard Interval is 400 ns short.

When i try to fix the MCS value with "iw dev wlan0 set bitrates vht-mcs-5 2:1" (2 NSS, MCS 1 for example), the transmission bitrate as reported by iw is 702 Mbit/s while it should be something like 130 Mbit/s. I observe the same behavior for each couple NSS:MCS I try. Any attempt to fix the bitrate fails.

Current debug level: 0xc0000032

Software (OS, Firmware version, kernel, driver, etc)

Hardware (NIC chipset, platform, etc)

Logs (on the client):

root@OpenWrt:~# iw dev
phy#0
        Interface wlan0
                ifindex 7
                wdev 0x2
                addr 04:f0:21:54:37:39
                ssid OpenWrt
                type managed
                channel 36 (5180 MHz), width: 80 MHz, center1: 5210 MHz
                txpower 23.00 dBm
                multicast TXQ:
                        qsz-byt qsz-pkt flows   drops   marks   overlmt hashcol tx-bytes        tx-packets
                        0       0       0       0       0       0       0       0               0
root@OpenWrt:~# iperf3 -c 10.0.0.1 -u -b0
Connecting to host 10.0.0.1, port 5201
[  5] local 10.0.0.203 port 56630 connected to 10.0.0.1 port 5201
[ ID] Interval           Transfer     Bitrate         Total Datagrams
[  5]   0.00-1.00   sec  33.4 MBytes   280 Mbits/sec  24190
[  5]   1.00-2.00   sec  34.2 MBytes   287 Mbits/sec  24790
[  5]   2.00-3.00   sec  33.8 MBytes   283 Mbits/sec  24450
[  5]   3.00-4.00   sec  34.4 MBytes   289 Mbits/sec  24940
[  5]   4.00-5.00   sec  33.3 MBytes   279 Mbits/sec  24090
[  5]   5.00-6.00   sec  32.5 MBytes   273 Mbits/sec  23530
[  5]   6.00-7.00   sec  33.9 MBytes   284 Mbits/sec  24520
[  5]   7.00-8.00   sec  34.0 MBytes   285 Mbits/sec  24610
[  5]   8.00-9.00   sec  33.9 MBytes   284 Mbits/sec  24520
[  5]   9.00-10.00  sec  34.0 MBytes   285 Mbits/sec  24640
- - - - - - - - - - - - - - - - - - - - - - - - -
[ ID] Interval           Transfer     Bitrate         Jitter    Lost/Total Datagrams
[  5]   0.00-10.00  sec   337 MBytes   283 Mbits/sec  0.000 ms  0/244280 (0%)  sender
[  5]   0.00-10.00  sec   337 MBytes   283 Mbits/sec  0.039 ms  20/244267 (0.0082%)  receiver

iperf Done.
root@OpenWrt:~# iw dev wlan0 set bitrates vht-mcs-5 1:2
root@OpenWrt:~# iperf3 -c 10.0.0.1 -u -b0
Connecting to host 10.0.0.1, port 5201
[  5] local 10.0.0.203 port 40219 connected to 10.0.0.1 port 5201
[ ID] Interval           Transfer     Bitrate         Total Datagrams
[  5]   0.00-1.00   sec  33.2 MBytes   279 Mbits/sec  24060
[  5]   1.00-2.00   sec  34.2 MBytes   287 Mbits/sec  24780
[  5]   2.00-3.00   sec  32.9 MBytes   276 Mbits/sec  23860
[  5]   3.00-4.00   sec  33.4 MBytes   280 Mbits/sec  24160
[  5]   4.00-5.00   sec  33.9 MBytes   284 Mbits/sec  24550
[  5]   5.00-6.00   sec  33.1 MBytes   278 Mbits/sec  24000
[  5]   6.00-7.00   sec  33.6 MBytes   282 Mbits/sec  24350
[  5]   7.00-8.00   sec  32.9 MBytes   276 Mbits/sec  23820
[  5]   8.00-9.00   sec  34.1 MBytes   286 Mbits/sec  24710
[  5]   9.00-10.00  sec  33.9 MBytes   284 Mbits/sec  24530
- - - - - - - - - - - - - - - - - - - - - - - - -
[ ID] Interval           Transfer     Bitrate         Jitter    Lost/Total Datagrams
[  5]   0.00-10.00  sec   335 MBytes   281 Mbits/sec  0.000 ms  0/242820 (0%)  sender
[  5]   0.00-10.00  sec   335 MBytes   281 Mbits/sec  0.038 ms  0/242820 (0%)  receiver

iperf Done.

root@OpenWrt:~# uname -a
Linux OpenWrt 5.4.42 #0 SMP Wed May 20 15:03:45 2020 i686 GNU/Linux
root@OpenWrt:~# grep "model name" /proc/cpuinfo
model name      : AMD GX-412TC SOC

dmesg_issuefixmcs.txt

greearb commented 4 years ago

Thanks for the nice bug report. I know this can work, but in your case, the firmware is never being requested to change the available rateset. Here is the decoded firmware logs. You have to patch mac80211 to allow setting a single rate. Maybe try the -CT 5.4 kernel, as it has this feature already compiled in?

https://github.com/greearb/linux-ct-5.4

[ 25.889384] kmodloader: done loading kernel modules from /etc/modules.d/* [ 38.376515] ath10k_pci 0000:05:00.0: unsupported HTC service id: 1536 [ 38.383000] ath10k_pci 0000:05:00.0: 10.1 wmi init: vdevs: 16 peers: 127 tid: 256 [ 38.400389] ath10k_pci 0000:05:00.0: wmi print 'P 128 V 8 T 410' [ 38.400412] ath10k_pci 0000:05:00.0: wmi print 'msdu-desc: 1424 sw-crypt: 0 ct-sta: 0' [ 38.400901] ath10k_pci 0000:05:00.0: wmi print 'alloc rem: 20984 iram: 25656' [ 38.460246] ath10k_pci 0000:05:00.0: pdev param 0 not supported by firmware [ 39.375655] ath10k_pci 0000:05:00.0: ath10k_pci ATH10K_DBG_BUFFER: Decoding dbglog buffer, len: 788 ath10k-fw: ts: 83105 args: 5 INF(00) vid: 255 MEM-DBG(05) 0x31102070 0x00000008 0x00000080 0x0040f898 0xc05e0001 ath10k-fw: ts: 83115 args: 3 VDEV_MGR(08) vid: 0 VDEV_CREATE(09) wlan-vdev: 0x440214 fwmode: 1 (STA) fwsubmode: 0 ath10k-fw: ts: 83115 args: 4 WAL(19) vid: 0 UNKNOWN(95) 0x009bda54 0x00000001 0x00000001 0x00000001 ath10k-fw: ts: 83115 args: 5 WAL(19) vid: 0 PEER_KEY_ALLOC(79) ast-idx: 2 sw-peer-key: 0x0041f450 peer: 0x00438d08 key-id: 0 mcast: 8126464 ath10k-fw: ts: 83115 args: 5 WAL(19) vid: 0 ALLOC_TID(86) peer: 0x00438d08 tid: 0x009bdde4 tidno: 1245184 (1245184) tx-hdr-sz: 12576 flags: 0x00000001 (IN-SCHED) ath10k-fw: ts: 83115 args: 5 RESOURCE(23) vid: 0 PEER_ALLOC_WAL_PEER(03) OK, is-bss-peer: 0 addr-31-0: 0x0 addr-47-32: 0x100 peer: 0x9bbf94 wal-peer: 0x438d08 ath10k-fw: ts: 83115 args: 3 RATE_CTRL(10) vid: 0 RC-INIT(09) ratectrl-ctx-alloc (0x71106661), vdev: 0x440214 pRATE: 0x44081c ath10k-fw: ts: 83115 args: 2 RESOURCE(23) vid: 0 PM_BEACON_ALLOC(08) 0x00440214 0x00446bf4 ath10k-fw: ts: 83115 args: 3 RESOURCE(23) vid: 0 VDEV_ALLOC(04) (0x81100003) vdev: 0x440214 self-peer: 0x9bbf94 ath10k-fw: ts: 83115 args: 2 VDEV_MGR(08) vid: 0 VDEV_DELETE(10) wlan-vdev: 0x440214 ath10k-fw: ts: 83115 args: 2 RESOURCE(23) vid: 0 PM_BEACON_FREE(09) 0x00440214 0x00446bf4 ath10k-fw: ts: 83115 args: 4 RATE_CTRL(10) vid: 0 RC-INIT(09) ratectrl-ctx-free (0x71106662), vdev: 0x440214 pRATE: 0x44081c is-free: 0 ath10k-fw: ts: 83115 args: 5 RESOURCE(23) vid: 0 PEER_FREE(02) 0x00440214 0x009bbf94 0x00000000 0x00000100 0x00000001 ath10k-fw: ts: 83115 args: 5 WAL(19) vid: 0 FREE_TID(87) peer: 0x00438d08 tid: 0x009bdde4 tidno: 19 (NON-PAUSE) tx-hdr-sz: 0 flags: 0x000031a2 ath10k-fw: ts: 83116 args: 4 WAL(19) vid: 0 PEER_KEY_FREE(80) sw-peer-key: (0x711000bb) 0x0041f450 peer: 0x00438d08 ath10k-fw: ts: 83116 args: 1 WAL(19) vid: 0 UNKNOWN(91) 0x009bda54 ath10k-fw: ts: 83116 args: 1 RESOURCE(23) vid: 0 VDEV_FREE(05) free wlan-vdev: 0x440214 ath10k-fw: ts: 83119 args: 2 WHAL(03) vid: 255 ERR_RECV_STOPPCU(16) 0x0110298a 0x00000004 ath10k-fw: ts: 83119 args: 0 WHAL(03) vid: 255 ERR_RESET_PM(19)
ath10k-fw: ts: 83126 args: 3 WAL(19) vid: 255 DEV_RESET(35) 0x00000001 0x00000001 0x00000001 ath10k-fw: ts: 83133 args: 3 WAL(19) vid: 255 DEV_RESET(35) 0x00000001 0x00000001 0x00000001 ath10k-fw: ts: 83140 args: 3 WAL(19) vid: 255 DEV_RESET(35) 0x00000001 0x00000001 0x00000001 ath10k-fw: ts: 83147 args: 3 WAL(19) vid: 255 DEV_RESET(35) 0x00000001 0x00000001 0x00000001 ath10k-fw: ts: 83154 args: 3 WAL(19) vid: 255 DEV_RESET(35) 0x00000001 0x00000001 0x00000001 ath10k-fw: ts: 83161 args: 3 WAL(19) vid: 255 DEV_RESET(35) 0x00000001 0x00000001 0x00000001 ath10k-fw: ts: 83168 args: 3 WAL(19) vid: 255 DEV_RESET(35) 0x00000001 0x00000001 0x00000001 ath10k-fw: ts: 83175 args: 3 WAL(19) vid: 255 DEV_RESET(35) 0x00000001 0x00000001 0x00000001 ath10k-fw: ts: 83190 args: 3 WAL(19) vid: 255 DEV_RESET(35) 0x00000001 0x00000001 0x00000001 ath10k-fw: ts: 83191 args: 3 VDEV_MGR(08) vid: 0 VDEV_CREATE(09) wlan-vdev: 0x440214 fwmode: 1 (STA) fwsubmode: 0 ath10k-fw: ts: 83191 args: 4 WAL(19) vid: 0 UNKNOWN(95) 0x009bdaa0 0x00000001 0x00000001 0x00000001 ath10k-fw: ts: 83191 args: 5 WAL(19) vid: 0 PEER_KEY_ALLOC(79) ast-idx: 2 sw-peer-key: 0x0041f488 peer: 0x00438d98 key-id: 0 mcast: 8126464 ath10k-fw: ts: 83191 args: 5 WAL(19) vid: 0 ALLOC_TID(86) peer: 0x00438d98 tid: 0x009bde2c tidno: 1245184 (1245184) tx-hdr-sz: 12576 flags: 0x00000001 (IN-SCHED) ath10k-fw: ts: 83191 args: 5 RESOURCE(23) vid: 0 PEER_ALLOC_WAL_PEER(03) OK, is-bss-peer: 0 addr-31-0: 0x0 addr-47-32: 0x100 peer: 0x9bbf94 wal-peer: 0x438d98 ath10k-fw: ts: 83191 args: 3 RATE_CTRL(10) vid: 0 RC-INIT(09) ratectrl-ctx-alloc (0x71106661), vdev: 0x440214 pRATE: 0x440850 ath10k-fw: ts: 83191 args: 2 RESOURCE(23) vid: 0 PM_BEACON_ALLOC(08) 0x00440214 0x00446c6c ath10k-fw: ts: 83191 args: 3 RESOURCE(23) vid: 0 VDEV_ALLOC(04) (0x81100003) vdev: 0x440214 self-peer: 0x9bbf94 ath10k-fw: ts: 83191 args: 2 RATE_CTRL(10) vid: 0 NSS_CHANGE(02) 0x00000003 0x00000003 ath10k-fw: ts: 83191 args: 1 RATE_CTRL(10) vid: 0 NSS_CHANGE(02) 0x00000003 [ 42.464979] wlan0: authenticate with 04:f0:21:54:3a:67 [ 42.477150] wlan0: send auth to 04:f0:21:54:3a:67 (try 1/3) [ 42.485531] wlan0: authenticated [ 42.490844] wlan0: associate with 04:f0:21:54:3a:67 (try 1/3) [ 42.498811] wlan0: RX AssocResp from 04:f0:21:54:3a:67 (capab=0x1 status=0 aid=1) [ 42.507341] wlan0: associated [ 42.511117] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready [ 43.375815] ath10k_pci 0000:05:00.0: ath10k_pci ATH10K_DBG_BUFFER: Decoding dbglog buffer, len: 664 ath10k-fw: ts: 87282 args: 5 VDEV_MGR(08) vid: 0 VDEV_START(11) wlan-vdev: 0x440214 requestor-id: 0 disable-hw-ack: 70716 wmi_chan.info: 0xa ath10k-fw: ts: 87282 args: 2 WAL(19) vid: 0 VDEV_START(07) type: 1(STA) total-started-for-this-type: 0 ath10k-fw: ts: 87289 args: 3 RESOURCE(23) vid: 0 PM_BEACON_ALLOC(08) 0x3330333b 0x00000000 0x00000064 ath10k-fw: ts: 87289 args: 5 WAL(19) vid: 0 PEER_KEY_ALLOC(79) ast-idx: 186 sw-peer-key: 0x0041f4c0 peer: 0x00438e28 key-id: 0 mcast: 7405568 ath10k-fw: ts: 87289 args: 5 WAL(19) vid: 0 PEER_KEY_ALLOC(79) ast-idx: 170 sw-peer-key: 0x0041f4f8 peer: 0x00438e28 key-id: 0 mcast: 7471105 ath10k-fw: ts: 87289 args: 5 WAL(19) vid: 0 ALLOC_TID(86) peer: 0x00438e28 tid: 0x009bde74 tidno: 1114112 (1114112) tx-hdr-sz: 12576 flags: 0x00000001 (IN-SCHED) ath10k-fw: ts: 87289 args: 5 WAL(19) vid: 0 ALLOC_TID(86) peer: 0x00438e28 tid: 0x009bdebc tidno: 12 (12) tx-hdr-sz: 12544 flags: 0x00000001 (IN-SCHED) ath10k-fw: ts: 87289 args: 5 RESOURCE(23) vid: 0 PEER_ALLOC_WAL_PEER(03) OK, is-bss-peer: 1 addr-31-0: 0x5421f004 addr-47-32: 0x673a peer: 0x9bbfc8 wal-peer: 0x438e28 ath10k-fw: ts: 87320 args: 5 WAL(19) vid: 0 CX_STATE(82) peer: 0x00438e28 peer-flags: 0x00000080 (VHT-ENABLED) auth: 1 val: 0x00000002 ath10k-fw: ts: 87320 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) (0x71100b07) rcSibUpdate: tx-nss-mask: 7 (0x7) phymode: 10 (11AC-VHT80) cur-nss: 3 ni_flags: 0x0601b003 (AUTH QOS HT 40Mhz STBC LDPC VHT 80Mhz) vht-mcs-set: 0x0000ffea ht-mcs-set: 0x00ffffff ath10k-fw: ts: 87320 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) rcSibUpdate (0x71108880): rc-mask-idx: 0(LEGACY) max-valid-rix: 8 pRc: 0x449a30 rate-count: 150 count: 67 validRateMask: 0xff0 ath10k-fw: ts: 87320 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) rcSibUpdate (0x71108880): rc-mask-idx: 1(HT-20) max-valid-rix: 12 pRc: 0x449a30 rate-count: 150 count: 67 validRateMask: 0xf03c0f ath10k-fw: ts: 87320 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) rcSibUpdate (0x71108880): rc-mask-idx: 2(HT-40) max-valid-rix: 12 pRc: 0x449a30 rate-count: 150 count: 67 validRateMask: 0xf03c0f ath10k-fw: ts: 87320 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) rcSibUpdate (0x71108880): rc-mask-idx: 3(VHT-20) max-valid-rix: 12 pRc: 0x449a30 rate-count: 150 count: 67 validRateMask: 0x3f007007 ath10k-fw: ts: 87320 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) rcSibUpdate (0x71108880): rc-mask-idx: 4(VHT-40) max-valid-rix: 12 pRc: 0x449a30 rate-count: 150 count: 67 validRateMask: 0x3f007007 ath10k-fw: ts: 87320 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) rcSibUpdate (0x71108880): rc-mask-idx: 5(VHT-80) max-valid-rix: 11 pRc: 0x449a30 rate-count: 150 count: 67 validRateMask: 0x3b007007 ath10k-fw: ts: 87320 args: 2 VDEV_MGR(08) vid: 0 VDEV_UP(07) 0x00440214 0x009bdaa0 ath10k-fw: ts: 87341 args: 4 WAL(19) vid: 0 TX_BA_SETUP(36) 0x00438e28 0x00010001 0x00000000 0x00000040 ath10k-fw: ts: 87341 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) (0x71100b07) rcSibUpdate: tx-nss-mask: 7 (0x7) phymode: 10 (11AC-VHT80) cur-nss: 3 ni_flags: 0x0601b003 (AUTH QOS HT 40Mhz STBC LDPC VHT 80Mhz) vht-mcs-set: 0x0000ffea ht-mcs-set: 0x00ffffff ath10k-fw: ts: 87341 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) rcSibUpdate (0x71108880): rc-mask-idx: 0(LEGACY) max-valid-rix: 8 pRc: 0x443848 rate-count: 150 count: 67 validRateMask: 0xff0 ath10k-fw: ts: 87341 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) rcSibUpdate (0x71108880): rc-mask-idx: 1(HT-20) max-valid-rix: 12 pRc: 0x443848 rate-count: 150 count: 67 validRateMask: 0xf03c0f ath10k-fw: ts: 87341 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) rcSibUpdate (0x71108880): rc-mask-idx: 2(HT-40) max-valid-rix: 12 pRc: 0x443848 rate-count: 150 count: 67 validRateMask: 0xf03c0f ath10k-fw: ts: 87341 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) rcSibUpdate (0x71108880): rc-mask-idx: 3(VHT-20) max-valid-rix: 12 pRc: 0x443848 rate-count: 150 count: 67 validRateMask: 0x3f007007 ath10k-fw: ts: 87341 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) rcSibUpdate (0x71108880): rc-mask-idx: 4(VHT-40) max-valid-rix: 12 pRc: 0x443848 rate-count: 150 count: 67 validRateMask: 0x3f007007 ath10k-fw: ts: 87341 args: 5 RATE_CTRL(10) vid: 255 ASSOC(01) rcSibUpdate (0x71108880): rc-mask-idx: 5(VHT-80) max-valid-rix: 11 pRc: 0x443848 rate-count: 150 count: 67 validRateMask: 0x3b007007 [ 45.376045] ath10k_pci 0000:05:00.0: ath10k_pci ATH10K_DBG_BUFFER: Decoding dbglog buffer, len: 52 ath10k-fw: ts: 89240 args: 5 WAL(19) vid: 0 ALLOC_TID(86) peer: 0x00438e28 tid: 0x009bdf04 tidno: 393228 (393228) tx-hdr-sz: 15616 flags: 0x00000001 (IN-SCHED) ath10k-fw: ts: 89241 args: 4 WAL(19) vid: 0 TX_BA_SETUP(36) 0x00438e28 0x06010001 0x00000000 0x00000040 [ 254.392637] ath10k_pci 0000:05:00.0: ath10k_pci ATH10K_DBG_BUFFER: Decoding dbglog buffer, len: 28 ath10k-fw: ts: 303968 args: 2 RATE_CTRL(10) vid: 0 NSS_CHANGE(02) 0x00000003 0x00000003 ath10k-fw: ts: 303968 args: 1 RATE_CTRL(10) vid: 0 NSS_CHANGE(02) 0x00000003 [ 486.411115] ath10k_pci 0000:05:00.0: ath10k_pci ATH10K_DBG_BUFFER: Decoding dbglog buffer, len: 28 ath10k-fw: ts: 541141 args: 2 RATE_CTRL(10) vid: 0 NSS_CHANGE(02) 0x00000003 0x00000003 ath10k-fw: ts: 541141 args: 1 RATE_CTRL(10) vid: 0 NSS_CHANGE(02) 0x00000003 [ 1195.462467] ath10k_pci 0000:05:00.0: ath10k_pci ATH10K_DBG_BUFFER: Decoding dbglog buffer, len: 28 ath10k-fw: ts: 1267797 args: 2 RATE_CTRL(10) vid: 0 NSS_CHANGE(02) 0x00000003 0x00000003 ath10k-fw: ts: 1267797 args: 1 RATE_CTRL(10) vid: 0 NSS_CHANGE(02) 0x00000003 [ 2434.555292] ath10k_pci 0000:05:00.0: ath10k_pci ATH10K_DBG_BUFFER: Decoding dbglog buffer, len: 52 ath10k-fw: ts: 2535985 args: 5 WAL(19) vid: 0 ALLOC_TID(86) peer: 0x00438e28 tid: 0x009bdf4c tidno: 65548 (65548) tx-hdr-sz: 15616 flags: 0x00000001 (IN-SCHED) ath10k-fw: ts: 2535985 args: 4 WAL(19) vid: 0 TX_BA_SETUP(36) 0x00438e28 0x01010001 0x00000000 0x00000040 All done. [greearb@ben-home qca]$