From owner-freebsd-wireless@FreeBSD.ORG Sun Mar 22 01:09:08 2015 Return-Path: Delivered-To: freebsd-wireless@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [8.8.178.115]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id A307247A for ; Sun, 22 Mar 2015 01:09:08 +0000 (UTC) Received: from mail-ig0-x232.google.com (mail-ig0-x232.google.com [IPv6:2607:f8b0:4001:c05::232]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (Client CN "smtp.gmail.com", Issuer "Google Internet Authority G2" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 5565D326 for ; Sun, 22 Mar 2015 01:09:08 +0000 (UTC) Received: by igbud6 with SMTP id ud6so16468959igb.1 for ; Sat, 21 Mar 2015 18:09:07 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:sender:in-reply-to:references:date:message-id:subject :from:to:cc:content-type; bh=pnKz8g5fgTAB9xGiYVXa+YeT0QnpY/ZBQ4/AdZCxCks=; b=sVcNPlQIBsYa6kPSbiD20G8RUK5mpKCjLmU0fqOcMxZR2FQw9OdRZUUTRbnkbOe7Hq gxYCs0Mj9TgqEwNybWrMaMky8w91H6LBakTB8mYRnUTu8D3Kyl9QckVyRZW3BFpHZTLh xnjGnuVQrWNIAB8wC5uCfAHbvf+fgFAqHRM52gBSOJuDXIMLeja3zsWf4J2NEA1udohN IiqEYydbe3pLBgIrt+BPXOxFRfL44uej+2nTKmM/1Zme+WOUWwBPuk3n/NOoTjtKNb3U pHjfzX8HCELhFfY5gDJEUwGfi4hEeZgA3RTXPpLx2w53YZz6jM+lEim89uBdDL5K2Gtf YK6A== MIME-Version: 1.0 X-Received: by 10.50.36.65 with SMTP id o1mr5878899igj.32.1426986547747; Sat, 21 Mar 2015 18:09:07 -0700 (PDT) Sender: adrian.chadd@gmail.com Received: by 10.36.17.194 with HTTP; Sat, 21 Mar 2015 18:09:07 -0700 (PDT) Received: by 10.36.17.194 with HTTP; Sat, 21 Mar 2015 18:09:07 -0700 (PDT) In-Reply-To: References: Date: Sat, 21 Mar 2015 18:09:07 -0700 X-Google-Sender-Auth: AtWQpfwpohe35gWq0oxSPbWkVaY Message-ID: Subject: Re: ath0 performence issues "ar9300_Stub_GetCTSTimeout" "ar9300_Stub_GetCTSTimeout From: Adrian Chadd To: Miguel Clara Content-Type: text/plain; charset=UTF-8 X-Content-Filtered-By: Mailman/MimeDel 2.1.18-1 Cc: freebsd-wireless@freebsd.org X-BeenThere: freebsd-wireless@freebsd.org X-Mailman-Version: 2.1.18-1 Precedence: list List-Id: "Discussions of 802.11 stack, tools device driver development." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 22 Mar 2015 01:09:08 -0000 Tsfoor means that it didn't receive enough beacons before a timeout. I've fixed the messages in head but they're not important. Its doing something, like scanning or something, which is generating those messages. Do athstats 1 for a while both before and afafter it happens. Adrian On Mar 21, 2015 6:00 PM, "Miguel Clara" wrote: > > > On Fri, Mar 20, 2015 at 2:42 PM, Miguel Clara > wrote: > >> >> On Fri, Mar 20, 2015 at 2:41 PM, Miguel Clara >> wrote: >> >>> >>> On Fri, Mar 20, 2015 at 3:25 AM, Miguel Clara >>> wrote: >>> >>>> >>>> On Fri, Mar 20, 2015 at 3:20 AM, Adrian Chadd >>>> wrote: >>>> >>>>> What's the output of ifconfig -v wlan0 ? >>>>> >>>>> and run athstats 1 for a while whilst doing traffic, say speedtest, >>>>> and paste the results from there. >>>>> >>>>> >>>>> >>>>> ]# ifconfig -v wlan0 >>>> >>>> >>>> wlan0: flags=8843 metric 0 mtu >>>> 1500 >>>> ether e0:06:e6:aa:bf:5b >>>> inet 10.10.50.70 netmask 0xffffff00 broadcast 10.10.50.255 >>>> nd6 options=29 >>>> media: IEEE 802.11 Wireless Ethernet MCS mode 11na >>>> status: associated >>>> ssid PissnLove5G channel 48 (5240 MHz 11a ht/40-) bssid >>>> 60:a4:4c:28:13:c4 >>>> regdomain 108 country DEBUG indoor ecm authmode WPA2/802.11i >>>> -wps >>>> -tsn privacy ON deftxkey UNDEF >>>> AES-CCM 2:128-bit >>>> AES-CCM 3:128-bit powersavemode OFF powersavesleep 100 txpower >>>> 30 >>>> txpowmax 50.0 -dotd rtsthreshold 2346 fragthreshold 2346 bmiss 7 >>>> 11a ucast NONE mgmt 6 Mb/s mcast 6 Mb/s maxretry 6 >>>> 11b ucast NONE mgmt 1 Mb/s mcast 1 Mb/s maxretry 6 >>>> 11g ucast NONE mgmt 1 Mb/s mcast 1 Mb/s maxretry 6 >>>> turboA ucast NONE mgmt 6 Mb/s mcast 6 Mb/s maxretry 6 >>>> turboG ucast NONE mgmt 1 Mb/s mcast 1 Mb/s maxretry 6 >>>> sturbo ucast NONE mgmt 6 Mb/s mcast 6 Mb/s maxretry 6 >>>> 11na ucast NONE mgmt 12 MCS mcast 12 MCS maxretry 6 >>>> 11ng ucast NONE mgmt 2 MCS mcast 2 MCS maxretry 6 >>>> half ucast NONE mgmt 3 Mb/s mcast 3 Mb/s maxretry 6 >>>> quarter ucast NONE mgmt 1 Mb/s mcast 1 Mb/s maxretry 6 >>>> scanvalid 60 -bgscan bgscanintvl 300 bgscanidle 250 >>>> roam:11a rssi 7dBm rate 12 Mb/s >>>> roam:11b rssi 7dBm rate 1 Mb/s >>>> roam:11g rssi 7dBm rate 5 Mb/s >>>> roam:turboA rssi 7dBm rate 12 Mb/s >>>> roam:turboG rssi 7dBm rate 12 Mb/s >>>> roam:sturbo rssi 7dBm rate 12 Mb/s >>>> roam:11na rssi 7dBm MCS 1 >>>> roam:11ng rssi 7dBm MCS 1 >>>> roam:half rssi 7dBm rate 6 Mb/s >>>> roam:quarter rssi 7dBm rate 3 Mb/s >>>> -pureg protmode CTS ht htcompat ampdu ampdulimit 64k >>>> ampdudensity 4 >>>> amsdu shortgi htprotmode RTSCTS -puren -smps -rifs wme burst >>>> -dwds >>>> roaming MANUAL bintval 100 >>>> AC_BE cwmin 4 cwmax 10 aifs 3 txopLimit 0 -acm ack >>>> cwmin 4 cwmax 10 aifs 3 txopLimit 0 -acm >>>> AC_BK cwmin 4 cwmax 10 aifs 7 txopLimit 0 -acm ack >>>> cwmin 4 cwmax 10 aifs 7 txopLimit 0 -acm >>>> AC_VI cwmin 3 cwmax 4 aifs 2 txopLimit 94 -acm ack >>>> cwmin 3 cwmax 4 aifs 2 txopLimit 94 -acm >>>> AC_VO cwmin 2 cwmax 3 aifs 2 txopLimit 47 -acm ack >>>> cwmin 2 cwmax 3 aifs 2 txopLimit 47 -acm >>>> groups: wlan >>>> >>>> Going to recompile and I'll re-run athstats >>>> >>> >>> Hum it seems that after the recompile/reboot things are a bit better... >>> >>> [miguelc@r2d2:~ ]% speedtest >>> Retrieving speedtest.net configuration... >>> Retrieving speedtest.net server list... >>> Testing from Vodafone Portugal (89.114.40.155)... >>> Selecting best server based on latency... >>> Hosted by Vodafone PT (Porto) [16.63 km]: 22.599 ms >>> Testing download speed........................................ >>> Download: 91.17 Mbits/s >>> Testing upload speed.................................................. >>> Upload: 9.48 Mbits/s >>> [miguelc@r2d2:~ ]% speedtest >>> Retrieving speedtest.net configuration... >>> Retrieving speedtest.net server list... >>> Testing from Vodafone Portugal (89.114.40.155)... >>> Selecting best server based on latency... >>> Hosted by Vodafone PT (Porto) [16.63 km]: 5.164 ms >>> Testing download speed........................................ >>> Download: 93.21 Mbits/s >>> Testing upload speed.................................................. >>> Upload: 10.65 Mbits/s >>> >>> ########################################### >>> [ ID] Interval Transfer Bandwidth >>> [ 4] 0.00-1.01 sec 1.42 MBytes 11.8 Mbits/sec >>> [ 4] 1.01-2.00 sec 5.66 KBytes 46.7 Kbits/sec >>> [ 4] 2.00-3.00 sec 3.94 MBytes 33.1 Mbits/sec >>> [ 4] 3.00-4.00 sec 4.15 MBytes 34.8 Mbits/sec >>> [ 4] 4.00-5.00 sec 4.52 MBytes 37.9 Mbits/sec >>> [ 4] 5.00-6.00 sec 4.44 MBytes 37.3 Mbits/sec >>> [ 4] 6.00-7.00 sec 4.44 MBytes 37.3 Mbits/sec >>> [ 4] 7.00-8.00 sec 4.36 MBytes 36.6 Mbits/sec >>> [ 4] 8.00-9.00 sec 6.67 MBytes 55.9 Mbits/sec >>> [ 4] 9.00-10.00 sec 5.45 MBytes 45.7 Mbits/sec >>> - - - - - - - - - - - - - - - - - - - - - - - - - >>> [ ID] Interval Transfer Bandwidth >>> [ 4] 0.00-10.00 sec 39.4 MBytes 33.1 Mbits/sec >>> sender >>> [ 4] 0.00-10.00 sec 38.9 MBytes 32.6 Mbits/sec >>> receiver >>> >>> ( First Iperf was run on purpose in the middle of the first speedtest >>> (and while runing athstats 1) >>> [ ID] Interval Transfer Bandwidth >>> [ 4] 0.00-1.00 sec 6.20 MBytes 52.0 Mbits/sec >>> [ 4] 1.00-2.00 sec 6.46 MBytes 54.2 Mbits/sec >>> [ 4] 2.00-3.00 sec 6.55 MBytes 55.0 Mbits/sec >>> [ 4] 3.00-4.00 sec 8.64 MBytes 72.5 Mbits/sec >>> [ 4] 4.00-5.00 sec 8.50 MBytes 71.3 Mbits/sec >>> [ 4] 5.00-6.00 sec 8.81 MBytes 73.9 Mbits/sec >>> [ 4] 6.00-7.00 sec 9.24 MBytes 77.5 Mbits/sec >>> [ 4] 7.00-8.00 sec 8.87 MBytes 74.4 Mbits/sec >>> [ 4] 8.00-9.00 sec 8.68 MBytes 72.8 Mbits/sec >>> [ 4] 9.00-10.00 sec 8.94 MBytes 75.0 Mbits/sec >>> - - - - - - - - - - - - - - - - - - - - - - - - - >>> [ ID] Interval Transfer Bandwidth >>> [ 4] 0.00-10.00 sec 80.9 MBytes 67.8 Mbits/sec >>> sender >>> [ 4] 0.00-10.00 sec 80.6 MBytes 67.6 Mbits/sec >>> receiver >>> ############################################################ >>> >>> athstats ==> http://pastebin.com/zXhG6FWc >>> >>> typo: >> >>> things look better, *I've* had better results before though, but I would >>> still consider this ok if it keeps this state... >>> >> > I left the Laptop online for quite some time (almost all day) but with no > user activiy. > > I was just replying some email (as adrian might have noticed :) )and > notice the internet seemed a lot slower, and I'm back to the same reported > state in see the error messages: > ar9300_Stub_GetCTSTimeout: called > ar9300_Stub_GetCTSTimeout: called > ar9300_Stub_GetAntennaSwitch: called > ar9300_Stub_GetAntennaSwitch: called > ar9300_Stub_GetCTSTimeout: called > ar9300_Stub_GetCTSTimeout: called > ar9300_Stub_GetAntennaSwitch: called > ar9300_Stub_GetAntennaSwitch: called > ar9300_Stub_GetCTSTimeout: called > ar9300_Stub_GetCTSTimeout: called > ar9300_Stub_GetAntennaSwitch: called > ar9300_Stub_GetAntennaSwitch: called > ar9300_Stub_GetCTSTimeout: called > ar9300_Stub_GetCTSTimeout: called > ar9300_Stub_GetAntennaSwitch: called > ar9300_Stub_GetAntennaSwitch: called > ar9300_Stub_GetCTSTimeout: called > ar9300_Stub_GetCTSTimeout: called > ar9300_Stub_GetAntennaSwitch: called > ar9300_Stub_GetAntennaSwitch: called > ath0: ath_intr: TSFOOR > > > and speedtest results are very poor: > speedtest > Retrieving speedtest.net configuration... > Retrieving speedtest.net server list... > Testing from Vodafone Portugal (89.114.40.155)... > Selecting best server based on latency... > Hosted by Vodafone PT (Porto) [16.63 km]: 5.686 ms > Testing download speed........................................ > Download: 33.64 Mbits/s > Testing upload speed.................................................. > Upload: 6.69 Mbits/s > > I was also playing with the "Fn-F3" key was reported in the other thread > but I've done it earlier and saw no issues at the time. > > I wonder then if this as something to do with long periods of inactivity > which as the first TSFOOR is ~22pm > Mar 21 21:55:10 r2d2 kernel: ath0: ath_intr: TSFOOR > > Thats basicly ~the time I resumed the session, and by that I mean just > login back to lumina-DE - I did not use resume/suspend, as I was plaining > to be back sooner :) > > > > > >>> -a >>>>> >>>>> >>>>> On 19 March 2015 at 20:17, Adrian Chadd wrote: >>>>> > Ah, add ATH_DEBUG, AH_DEBUG and AH_DIAGAPI to your kernel and >>>>> recompile! >>>>> > >>>>> > >>>>> > -a >>>>> > >>>>> > >>>>> > On 19 March 2015 at 19:32, Miguel Clara >>>>> wrote: >>>>> >> >>>>> >> On Fri, Mar 20, 2015 at 2:11 AM, Miguel Clara < >>>>> miguelmclara@gmail.com> >>>>> >> wrote: >>>>> >>> >>>>> >>> >>>>> >>> On Fri, Mar 20, 2015 at 1:55 AM, Miguel Clara < >>>>> miguelmclara@gmail.com> >>>>> >>> wrote: >>>>> >>>> >>>>> >>>> >>>>> >>>> On Fri, Mar 20, 2015 at 1:18 AM, Miguel Clara < >>>>> miguelmclara@gmail.com> >>>>> >>>> wrote: >>>>> >>>>> >>>>> >>>>> >>>>> >>>>> On Thu, Mar 19, 2015 at 9:49 PM, Adrian Chadd < >>>>> adrian@freebsd.org> >>>>> >>>>> wrote: >>>>> >>>>>> >>>>> >>>>>> Whilst running this, can you run 'athstats 1' on the freebsd >>>>> box? >>>>> >>>>>> >>>>> >>>>>> i wonder what the signal level and retransmit rates are. >>>>> >>>>> >>>>> >>>>> >>>>> >>>>> Not sure hwo to do that... do I need ath_debug? >>>>> >>>>> >>>>> >>>>> I did found '/usr/src/tools/tools/ath/athstats' and tried to >>>>> "make" >>>>> >>>>> >>>>> >>>>> clang -O2 -pipe -DATH_DEFAULT='"ath0"' >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats/../common >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats/../../../../sys >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats/../../../../sys/dev/ath >>>>> >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats/../../../../sys/dev/ath/ath_hal >>>>> >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats/../../../../sys/contrib/dev/ath/ath_hal >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats -DATH_SUPPORT_ANI >>>>> -DATH_SUPPORT_TDMA >>>>> >>>>> -DATH_DEFAULT='"ath0"' -I/usr/src/tools/tools/ath/athstats >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats/../common >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats/../../../../sys >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats/../../../../sys/dev/ath >>>>> >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats/../../../../sys/dev/ath/ath_hal >>>>> >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats/../../../../sys/contrib/dev/ath/ath_hal >>>>> >>>>> -I/usr/src/tools/tools/ath/athstats -std=gnu99 -fstack-protector >>>>> >>>>> -fbracket-depth=512 -Qunused-arguments -rpath /usr/lib/private >>>>> -o athstats >>>>> >>>>> main.o athstats.o -L/usr/src/lib/libbsdstat -lbsdstat >>>>> >>>>> /usr/bin/ld: cannot find -lbsdstat >>>>> >>>>> clang: error: linker command failed with exit code 1 (use -v to >>>>> see >>>>> >>>>> invocation) >>>>> >>>>> *** Error code 1 >>>>> >>>>> >>>>> >>>>> Stop. >>>>> >>>>> make: stopped in /usr/src/tools/tools/ath/athstats >>>>> >>>>> >>>>> >>>>> I installed bsdstats but after make clean;make I still get the >>>>> same. >>>>> >>>> >>>>> >>>> >>>>> >>>> Oh wait: >>>>> >>>> -L/usr/src/lib/libbsdstat -lbsdstat >>>>> >>>> >>>>> >>>> /usr/bin/ld: cannot find -lbsdstat >>>>> >>>> >>>>> >>>> Should it look in /usr/private? >>>>> >>>> >>>>> >>>> Or maybe not... I saw this: >>>>> >>>> ###################### >>>>> >>>> commit 050d4409aa855fa1f82f6ca0dbb7e0c865c05e32 >>>>> >>>> Author: bapt >>>>> >>>> Date: Tue Nov 25 22:37:27 2014 +0000 >>>>> >>>> >>>>> >>>> Convert to LIBADD >>>>> >>>> >>>>> >>>> Notes: >>>>> >>>> svn path=/head/; revision=275084 >>>>> >>>> >>>>> >>>> diff --git a/tools/tools/ath/athstats/Makefile >>>>> >>>> b/tools/tools/ath/athstats/Makefile >>>>> >>>> index 8d1bfa6..a7ff43b 100644 >>>>> >>>> --- a/tools/tools/ath/athstats/Makefile >>>>> >>>> +++ b/tools/tools/ath/athstats/Makefile >>>>> >>>> @@ -23,9 +23,7 @@ CFLAGS+=-DATH_SUPPORT_TDMA >>>>> >>>> >>>>> >>>> CFLAGS.clang+= -fbracket-depth=512 >>>>> >>>> >>>>> >>>> -USEPRIVATELIB= bsdstat >>>>> >>>> - >>>>> >>>> -LDADD= ${LDBSDSTAT} >>>>> >>>> +LIBADD= bsdstat >>>>> >>>> >>>>> >>>> opt_ah.h: >>>>> >>>> echo "#define AH_DEBUG 1" > opt_ah.h >>>>> >>>> ################# >>>>> >>>> >>>>> >>>> reverting gives me this: >>>>> >>>> >>>>> >>>> [...]ib/private -rpath /usr/lib/private -o athstats main.o >>>>> athstats.o >>>>> >>>> athstats.o: In function `athstats_new': >>>>> >>>> athstats.c:(.text+0x3e): undefined reference to `bsdstat_init' >>>>> >>>> clang: error: linker command failed with exit code 1 (use -v to >>>>> see >>>>> >>>> invocation) >>>>> >>>> >>>>> >>>> If I can get around this I'd love to post those stats >>>>> >>>> >>>>> >>> >>>>> >>> Sadly I'm no C expert... I'm not even a coder but "bsdstat_init" >>>>> defiantly >>>>> >>> exists and the include bsdstat.h is in athstats.h... >>>>> >>> makes no sense (to me) :| >>>>> >>> >>>>> >> >>>>> >> In the mean time I checked out a version before bsdstat and I was >>>>> able to >>>>> >> complie, output follows >>>>> >> % sudo athstats >>>>> >> athstats: ioctl: ath0: Invalid argument <------------------ Is this >>>>> >> expected? >>>>> >> athstats: ioctl: ath0: Invalid argument >>>>> >> 990785 data frames received >>>>> >> 559194 data frames transmit >>>>> >> 7602 tx frames with an alternate rate >>>>> >> 27634 short on-chip tx retries >>>>> >> 100075 long on-chip tx retries >>>>> >> 374 tx failed 'cuz too many retries >>>>> >> 24 mib overflow interrupts >>>>> >> 3 tx linearized to cluster >>>>> >> MCS3 current transmit rate >>>>> >> 17 beacon miss interrupts >>>>> >> 31173 rx failed 'cuz of bad CRC >>>>> >> 114 rx failed 'cuz of PHY err >>>>> >> 5 OFDM restart >>>>> >> 109 CCK restart >>>>> >> 247 periodic calibrations >>>>> >> -0/+0 TDMA slot adjust (usecs, smoothed) >>>>> >> 28 rssi of last ack >>>>> >> 40 avg recv rssi >>>>> >> -96 rx noise floor >>>>> >> 614 tx frames through raw api >>>>> >> 601749 A-MPDU sub-frames received >>>>> >> 187766 Half-GI frames received >>>>> >> 443941 40MHz frames received >>>>> >> 12776 CRC errors for non-last A-MPDU subframes >>>>> >> 198 CRC errors for last subframe in an A-MPDU >>>>> >> 558554 Frames transmitted with HT Protection >>>>> >> 169 TX Timeout >>>>> >> Antenna profile: >>>>> >> [0] tx 558817 rx 36629 >>>>> >> [1] tx 0 rx 772652 >>>>> >> [2] tx 0 rx 26737 >>>>> >> [3] tx 0 rx 30276 >>>>> >> [4] tx 0 rx 28833 >>>>> >> [5] tx 0 rx 25606 >>>>> >> [6] tx 0 rx 30300 >>>>> >> [7] tx 0 rx 39752 >>>>> >> >>>>> >> >>>>> >> >>>>> >>> >>>>> >>> >>>>> >>>> >>>>> >>>>> >>>>> >>>>>> Thanks, >>>>> >>>>>> >>>>> >>>>>> >>>>> >>>>>> -a >>>>> >>>>> >>>>> >>>>> >>>>> >>>> >>>>> >>> >>>>> >> >>>>> >>>> >>>> >>> >> >