Return-path: Received: from mail2.candelatech.com ([208.74.158.173]:39766 "EHLO mail2.candelatech.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S932237AbcI3OVu (ORCPT ); Fri, 30 Sep 2016 10:21:50 -0400 Message-ID: <57EE753E.6090501@candelatech.com> (sfid-20160930_162155_397289_413A9408) Date: Fri, 30 Sep 2016 07:22:54 -0700 From: Ben Greear MIME-Version: 1.0 To: Matteo Grandi CC: LinuxWireless Mailing List Subject: Re: ath10k stuck on 6Mbps and spam syslog References: <57ED2982.4020002@candelatech.com> In-Reply-To: Content-Type: text/plain; charset=utf-8; format=flowed Sender: linux-wireless-owner@vger.kernel.org List-ID: At least some stock ath10k firmware can send frames at CCK (.11b) encodings on 5Ghz, which is out-of-spec, and may cause this warning. Maybe you could check the values printed and see if that is indeed what is causing this splat? Thanks, Ben On 09/30/2016 12:23 AM, Matteo Grandi wrote: > Dear Ben, > Thank you for your reply. > The fact that stock ath10k firmware does not report tx-rate explains > why the station dump shows 6Mbps but the iperf test reach 14.6 (even > if it is really under the expected data rate...). > About the syslog spam, this is the code of the function that seems to > cause the error (I put a comment at line 2621 side). (The warning > start to spam as soon as I assign the channel "iw dev set > channel ) > > /** > * ieee80211_calculate_rx_timestamp - calculate timestamp in frame > * @local: mac80211 hw info struct > * @status: RX status > * @mpdu_len: total MPDU length (including FCS) > * @mpdu_offset: offset into MPDU to calculate timestamp at > * > * This function calculates the RX timestamp at the given MPDU offset, taking > * into account what the RX timestamp was. An offset of 0 will just normalize > * the timestamp to TSF at beginning of MPDU reception. > */ > u64 ieee80211_calculate_rx_timestamp(struct ieee80211_local *local, > struct ieee80211_rx_status *status, > unsigned int mpdu_len, > unsigned int mpdu_offset) > { > u64 ts = status->mactime; > struct rate_info ri; > u16 rate; > > if (WARN_ON(!ieee80211_have_rx_timestamp(status))) //this is the > line 2621 reported in the warning > return 0; > > memset(&ri, 0, sizeof(ri)); > > /* Fill cfg80211 rate info */ > if (status->flag & RX_FLAG_HT) { > ri.mcs = status->rate_idx; > ri.flags |= RATE_INFO_FLAGS_MCS; > if (status->flag & RX_FLAG_40MHZ) > ri.bw = RATE_INFO_BW_40; > else > ri.bw = RATE_INFO_BW_20; > if (status->flag & RX_FLAG_SHORT_GI) > ri.flags |= RATE_INFO_FLAGS_SHORT_GI; > } else if (status->flag & RX_FLAG_VHT) { > ri.flags |= RATE_INFO_FLAGS_VHT_MCS; > ri.mcs = status->rate_idx; > ri.nss = status->vht_nss; > if (status->flag & RX_FLAG_40MHZ) > ri.bw = RATE_INFO_BW_40; > else if (status->vht_flag & RX_VHT_FLAG_80MHZ) > ri.bw = RATE_INFO_BW_80; > else if (status->vht_flag & RX_VHT_FLAG_160MHZ) > ri.bw = RATE_INFO_BW_160; > else > ri.bw = RATE_INFO_BW_20; > if (status->flag & RX_FLAG_SHORT_GI) > ri.flags |= RATE_INFO_FLAGS_SHORT_GI; > } else { > struct ieee80211_supported_band *sband; > int shift = 0; > int bitrate; > > if (status->flag & RX_FLAG_10MHZ) { > shift = 1; > ri.bw = RATE_INFO_BW_10; > } else if (status->flag & RX_FLAG_5MHZ) { > shift = 2; > ri.bw = RATE_INFO_BW_5; > } else { > ri.bw = RATE_INFO_BW_20; > } > > sband = local->hw.wiphy->bands[status->band]; > bitrate = sband->bitrates[status->rate_idx].bitrate; > ri.legacy = DIV_ROUND_UP(bitrate, (1 << shift)); > } > > rate = cfg80211_calculate_bitrate(&ri); > if (WARN_ONCE(!rate, > "Invalid bitrate: flags=0x%x, idx=%d, vht_nss=%d\n", > status->flag, status->rate_idx, status->vht_nss)) > return 0; > > /* rewind from end of MPDU */ > if (status->flag & RX_FLAG_MACTIME_END) > ts -= mpdu_len * 8 * 10 / rate; > > ts += mpdu_offset * 8 * 10 / rate; > /* [SESAME] I2CAT. dbg*/ > //printk(KERN_DEBUG "calculate_rx_timestamp: ts = %lu;\t rate = > %lu;\tmpdu_offset = %lu;\tmpdu_len = %lu\n", > // (long unsigned int) ts, (long unsigned int) rate, (long unsigned > int) mpdu_offset, (long unsigned int) mpdu_len ); > > return ts; > } > > Thank you so much! > > All the best > > Matteo > > > 2016-09-29 16:47 GMT+02:00 Ben Greear : >> stock ath10k firmware does not report tx-rate so the kernel always sees >> 6Mbps. >> >> I don't know about the splat..maybe post the function >> that is causing that? >> >> /home/matteo/linux-imx6/backports4.4.2-i2CAT/net/mac80211/util.c:2621 >> >> Thanks, >> Ben >> >> >> On 09/29/2016 06:39 AM, Matteo Grandi wrote: >>> >>> Hello all, >>> >>> I'm struggling with a problem related on ath10k drivers: >>> I'm using a Compex WLE600V5-27 (802.11ac) miniPCIe card for some HT >>> tests needed for my thesis. >>> I'm using ath10k drivers for this card, and backports-4.4.2, in >>> particular the firmware-5.bin_10.2.4.70.54 because it seem to be the >>> more recent. >>> I've connected in mesh mode the WLE600V5 card with an 802.11n card >>> (using ath9k drivers) but looking at the station dump, the tx bitrate >>> is stuck on 6.0 Mbit/s for the ath10k. The ath9k one works well and >>> watch -n1 iw station dump >>> let me see changes of the tx rate and MCS on the ath9k during iperf >>> tests, but the ath10k stucks on 6.0 Mbit/s. >>> >>> Then something misterious (for me) happen while the channel >>> assignment: the syslog is spammed by this message: >>> >>> [17554.919459] ------------[ cut here ]------------ >>> [17554.919839] WARNING: CPU: 0 PID: 0 at >>> /home/matteo/linux-imx6/backports4.4.2-i2CAT/net/mac80211/util.c:2621 >>> ieee80211_calculate_rx_timestamp+0x204/0x278 [mac80211]() >>> [17554.919855] Modules linked in: arc4 sky2 ath10k_pci(O) >>> ath10k_core(O) ath(O) mac80211(O) cfg80211(O) compat(O) >>> [17554.919926] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G W O >>> 3.14.48-g408ccb9 #4 >>> [17554.919990] [<80015050>] (unwind_backtrace) from [<80011330>] >>> (show_stack+0x10/0x14) >>> [17554.920038] [<80011330>] (show_stack) from [<806537dc>] >>> (dump_stack+0x80/0x90) >>> [17554.920074] [<806537dc>] (dump_stack) from [<8002c578>] >>> (warn_slowpath_common+0x6c/0x88) >>> [17554.920103] [<8002c578>] (warn_slowpath_common) from [<8002c630>] >>> (warn_slowpath_null+0x1c/0x24) >>> [17554.920377] [<8002c630>] (warn_slowpath_null) from [<7f089c74>] >>> (ieee80211_calculate_rx_timestamp+0x204/0x278 [mac80211]) >>> [17554.920826] [<7f089c74>] (ieee80211_calculate_rx_timestamp >>> [mac80211]) from [<7f07d724>] (ieee80211_rx_napi+0xcc/0x8d4 >>> [mac80211]) >>> [17554.921259] [<7f07d724>] (ieee80211_rx_napi [mac80211]) from >>> [<7f117fd0>] (ath10k_wmi_event_mgmt_rx+0x1f4/0x35c [ath10k_core]) >>> [17554.921540] [<7f117fd0>] (ath10k_wmi_event_mgmt_rx [ath10k_core]) >>> from [<7f10d844>] (ath10k_htc_rx_completion_handler+0x1cc/0x464 >>> [ath10k_core]) >>> [17554.921706] [<7f10d844>] (ath10k_htc_rx_completion_handler >>> [ath10k_core]) from [<7f157b4c>] (ath10k_pci_process_rx_cb+0x1ac/0x1fc >>> [ath10k_pci]) >>> [17554.921773] [<7f157b4c>] (ath10k_pci_process_rx_cb [ath10k_pci]) >>> from [<7f15b3ac>] (ath10k_ce_per_engine_service+0x5c/0x94 >>> [ath10k_pci]) >>> [17554.921835] [<7f15b3ac>] (ath10k_ce_per_engine_service >>> [ath10k_pci]) from [<7f15b464>] >>> (ath10k_ce_per_engine_service_any+0x80/0x88 [ath10k_pci]) >>> [17554.921892] [<7f15b464>] (ath10k_ce_per_engine_service_any >>> [ath10k_pci]) from [<7f15a6d8>] (ath10k_pci_tasklet+0x24/0x5c >>> [ath10k_pci]) >>> [17554.921946] [<7f15a6d8>] (ath10k_pci_tasklet [ath10k_pci]) from >>> [<800304c8>] (tasklet_action+0x80/0x110) >>> [17554.921979] [<800304c8>] (tasklet_action) from [<800306b8>] >>> (__do_softirq+0x10c/0x248) >>> [17554.922009] [<800306b8>] (__do_softirq) from [<80030a6c>] >>> (irq_exit+0xac/0xf4) >>> [17554.922042] [<80030a6c>] (irq_exit) from [<8000e904>] >>> (handle_IRQ+0x44/0x90) >>> [17554.922072] [<8000e904>] (handle_IRQ) from [<800084f8>] >>> (gic_handle_irq+0x2c/0x5c) >>> [17554.922105] [<800084f8>] (gic_handle_irq) from [<80011e00>] >>> (__irq_svc+0x40/0x50) >>> [17554.922122] Exception stack(0x80917f18 to 0x80917f60) >>> [17554.922141] 7f00: >>> 80917f60 000d3334 >>> [17554.922166] 7f20: 5221e106 00000ff7 4d693c44 00000ff7 a7705010 >>> 80924060 00000001 a7705014 >>> [17554.922190] 7f40: 8096243d 80916000 00000017 80917f60 a6aaaaab >>> 80492940 60000013 ffffffff >>> [17554.922224] [<80011e00>] (__irq_svc) from [<80492940>] >>> (cpuidle_enter_state+0x50/0xe0) >>> [17554.922252] [<80492940>] (cpuidle_enter_state) from [<80492ac8>] >>> (cpuidle_idle_call+0xf8/0x148) >>> [17554.922281] [<80492ac8>] (cpuidle_idle_call) from [<8000ec48>] >>> (arch_cpu_idle+0x8/0x44) >>> [17554.922322] [<8000ec48>] (arch_cpu_idle) from [<80066648>] >>> (cpu_startup_entry+0xfc/0x140) >>> [17554.922362] [<80066648>] (cpu_startup_entry) from [<808c5b08>] >>> (start_kernel+0x360/0x36c) >>> [17554.922379] ---[ end trace 87d4775146813aed ]--- >>> [17555.943454] ------------[ cut here ]------------ >>> >>> that repeat continuously... >>> Forcing legacy bitrates doesn't change the situation. >>> >>> I made some measurements using iperf, please find it in attachment. >>> >>> Other info: >>> >>> root@Yazi:~# modinfo ath10k_pci >>> filename: >>> >>> /lib/modules/3.14.48-g408ccb9/kernel/drivers/net/wireless/ath/ath10k/ath10k_pci.ko >>> firmware: ath10k/QCA9377/hw1.0/board.bin >>> firmware: ath10k/QCA9377/hw1.0/firmware-5.bin >>> firmware: ath10k/QCA6174/hw3.0/board-2.bin >>> firmware: ath10k/QCA6174/hw3.0/board.bin >>> firmware: ath10k/QCA6174/hw3.0/firmware-5.bin >>> firmware: ath10k/QCA6174/hw3.0/firmware-4.bin >>> firmware: ath10k/QCA6174/hw2.1/board-2.bin >>> firmware: ath10k/QCA6174/hw2.1/board.bin >>> firmware: ath10k/QCA6174/hw2.1/firmware-5.bin >>> firmware: ath10k/QCA6174/hw2.1/firmware-4.bin >>> firmware: ath10k/QCA988X/hw2.0/board-2.bin >>> firmware: ath10k/QCA988X/hw2.0/board.bin >>> firmware: ath10k/QCA988X/hw2.0/firmware-5.bin >>> firmware: ath10k/QCA988X/hw2.0/firmware-4.bin >>> firmware: ath10k/QCA988X/hw2.0/firmware-3.bin >>> firmware: ath10k/QCA988X/hw2.0/firmware-2.bin >>> firmware: ath10k/QCA988X/hw2.0/firmware.bin >>> license: Dual BSD/GPL >>> description: Driver support for Atheros QCA988X PCIe devices >>> author: Qualcomm Atheros >>> version: backported from Linux (v4.4.2-0-g1cb8570) using >>> backports v4.4.2-1-0-gbec4037 >>> srcversion: EBB3D4E36DE49B7EC8057D0 >>> alias: pci:v0000168Cd00000042sv*sd*bc*sc*i* >>> alias: pci:v0000168Cd00000040sv*sd*bc*sc*i* >>> alias: pci:v0000168Cd0000003Esv*sd*bc*sc*i* >>> alias: pci:v0000168Cd00000041sv*sd*bc*sc*i* >>> alias: pci:v0000168Cd0000003Csv*sd*bc*sc*i* >>> depends: ath10k_core,compat >>> vermagic: 3.14.48-g408ccb9 SMP mod_unload modversions ARMv7 p2v8 >>> parm: irq_mode:0: auto, 1: legacy, 2: msi (default: 0) (uint) >>> parm: reset_mode:0: auto, 1: warm only (default: 0) (uint) >>> >>> I don't know if it's only a problem of iw station dump that can't show >>> the tx rate, but the spammed syslog honestly warn me... >>> >>> How shall I check what's wrong and see the HT work? >>> >>> Thanks a lot! >>> >>> Matteo >>> >> >> -- >> Ben Greear >> Candela Technologies Inc http://www.candelatech.com > -- Ben Greear Candela Technologies Inc http://www.candelatech.com