From owner-freebsd-wireless@FreeBSD.ORG Fri Jan 17 19:48:20 2014 Return-Path: Delivered-To: freebsd-wireless@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [8.8.178.115]) (using TLSv1 with cipher ADH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 4E54E560; Fri, 17 Jan 2014 19:48:20 +0000 (UTC) Received: from mail-pd0-x231.google.com (mail-pd0-x231.google.com [IPv6:2607:f8b0:400e:c02::231]) (using TLSv1 with cipher ECDHE-RSA-RC4-SHA (128/128 bits)) (No client certificate requested) by mx1.freebsd.org (Postfix) with ESMTPS id 1545313CF; Fri, 17 Jan 2014 19:48:20 +0000 (UTC) Received: by mail-pd0-f177.google.com with SMTP id x10so3089390pdj.36 for ; Fri, 17 Jan 2014 11:48:19 -0800 (PST) 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=gDULE/zhOAbB7gcRVSmFbtM4nvrCfjOS5qIM3b2RzhU=; b=nd5Q5CtMWCixbAPZhbxj490wj7TLTY82TcTZZjRdP9lO+stTqhLIxwnH6XLhVdfItV GXzyKP9NySGQ6LmncDI/kmvntguZeMQW1LsCHWfyAYdSsdiiwhRpzKS7ewq0EmJuq/JD GKMYzVFkwqO9o+ZJpg/mjiD/zXypxwnro9bQrEmhsj2kq93wwIvRkTER/v3myLQ3a2f+ spyJVkq54mnmkiyzPM+SLviGR2Y36NDDrWuE2MI9Mw9Ni4Mn7aSZYW3jDhpExsqoG5vD tz6QwYH6h9zpzI+xoshyp5Ms7E7M0ZhsHV8w0Gs9u3Lv4LusBzUHWuJAWmPotptO+6b+ Eb4A== MIME-Version: 1.0 X-Received: by 10.68.111.98 with SMTP id ih2mr4072628pbb.73.1389988099740; Fri, 17 Jan 2014 11:48:19 -0800 (PST) Sender: kob6558@gmail.com Received: by 10.67.30.1 with HTTP; Fri, 17 Jan 2014 11:48:19 -0800 (PST) In-Reply-To: References: <20140111132338.7a7fc14c@X220.alogt.com> <20140111133610.313a4bca@X220.alogt.com> <20140112143614.3313f509@X220.alogt.com> Date: Fri, 17 Jan 2014 11:48:19 -0800 X-Google-Sender-Auth: _DspahVqX5DQSsXQuFB8zkvADR4 Message-ID: Subject: Re: IWN performance very bad with 10.0-RC5 From: Kevin Oberman To: Adrian Chadd Content-Type: text/plain; charset=UTF-8 X-Content-Filtered-By: Mailman/MimeDel 2.1.17 Cc: FreeBSD Wireless X-BeenThere: freebsd-wireless@freebsd.org X-Mailman-Version: 2.1.17 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: Fri, 17 Jan 2014 19:48:20 -0000 On Fri, Jan 17, 2014 at 11:21 AM, Adrian Chadd wrote: > Hi, > > So does it still pause with traffic? > Yes, it does. > > Have you disabled bgscan? > Just did so. After the issues I had in the past with bgscan, I should have done it already. I'll know by tomorrow whether it made a difference. Kevin > > > > -a > > > On 15 January 2014 18:04, Kevin Oberman wrote: > > Sorry, It's been a little busy the past couple of days. > > > > No, I have had only one interface losing association and not recovering > > since my first report. That one did not occur in conjunction with one of > the > > crypto events. Those seem to interrupt the network for about half a > > second.Then it restores. Those issues still seem to crop up periodically, > > about twice a day. I suspect that they me be linked to volumeof network > > traffic , butI cannot be sure at this point. > > > > Here is the log during the failure yesterday: > > Jan 14 23:13:27 rogue kernel: wlan0: _ieee80211_crypto_delkey: AES-CCM > keyix > > 0 flags 0x133 rsc 0 tsc 379793 len 16 > > Jan 14 23:13:27 rogue kernel: wlan0: link state changed to DOWN > > Jan 14 23:13:27 rogue wpa_supplicant[2669]: wlan0: > CTRL-EVENT-DISCONNECTED > > bssid=00:26:b8:67:c3:2d reason=0 > > Jan 14 23:13:27 rogue kernel: wlan0: _ieee80211_crypto_delkey: NONE keyix > > 65535 flags 0x3 rsc 0 tsc 0 len 0 > > Jan 14 23:13:27 rogue kernel: wlan0: _ieee80211_crypto_delkey: AES-CCM > keyix > > 1 flags 0x136 rsc 411 tsc 0 len 16 > > Jan 14 23:13:27 rogue kernel: wlan0: _ieee80211_crypto_delkey: AES-CCM > keyix > > 2 flags 0x136 rsc 3344 tsc 0 len 16 > > Jan 14 23:13:27 rogue kernel: wlan0: _ieee80211_crypto_delkey: NONE keyix > > 65535 flags 0x3 rsc 0 tsc 0 len 0 > > Jan 14 23:13:29 rogue ntpd[1291]: sendto(199.7.177.206) (fd=25): Network > is > > down > > Jan 14 23:14:22 rogue dhclient[2755]: My address (192.168.1.5) was > deleted, > > dhclient exiting > > Jan 14 23:14:22 rogue wpa_supplicant[2669]: ioctl[SIOCS80211, op=26, > val=0, > > arg_len=0]: Operation not supported > > Jan 14 23:14:22 rogue wpa_supplicant[2669]: wlan0: CTRL-EVENT-TERMINATING > > Jan 14 23:14:23 rogue wpa_supplicant[3162]: Successfully initialized > > wpa_supplicant > > Jan 14 23:14:23 rogue kernel: wlan0: _ieee80211_crypto_delkey: NONE keyix > > 65535 flags 0x3 rsc 0 tsc 0 len 0 > > Jan 14 23:14:23 rogue kernel: wlan0: _ieee80211_crypto_delkey: NONE keyix > > 65535 flags 0x3 rsc 0 tsc 0 len 0 > > Jan 14 23:14:23 rogue last message repeated 3 times > > Jan 14 23:14:24 rogue wpa_supplicant[3163]: wlan0: Trying to associate > with > > 00:26:b8:67:c3:2d (SSID='babcom' freq=2437 MHz) > > Jan 14 23:14:24 rogue wpa_supplicant[3163]: wlan0: Associated with > > 00:26:b8:67:c3:2d > > Jan 14 23:14:24 rogue kernel: wlan0: link state changed to UP > > Jan 14 23:14:24 rogue devd: Executing '/etc/rc.d/dhclient quietstart > wlan0' > > Jan 14 23:14:24 rogue wpa_supplicant[3163]: wlan0: WPA: Key negotiation > > completed with 00:26:b8:67:c3:2d [PTK=CCMP GTK=CCMP] > > Jan 14 23:14:24 rogue kernel: wlan0: ieee80211_crypto_newkey: cipher 3 > flags > > 0x3 keyix 65535 > > Jan 14 23:14:24 rogue kernel: wlan0: ieee80211_crypto_newkey: no h/w > support > > for cipher AES-CCM, falling back to s/w > > Jan 14 23:14:24 rogue kernel: wlan0: ieee80211_crypto_setkey: AES-CCM > keyix > > 0 flags 0x133 mac 00:26:b8:67:c3:2d rsc 0 tsc 0 len 16 > > Jan 14 23:14:24 rogue kernel: wlan0: ieee80211_crypto_newkey: cipher 3 > flags > > 0x6 keyix 1 > > Jan 14 23:14:24 rogue kernel: wlan0: ieee80211_crypto_newkey: no h/w > support > > for cipher AES-CCM, falling back to s/w > > Jan 14 23:14:24 rogue kernel: wlan0: ieee80211_crypto_setkey: AES-CCM > keyix > > 1 flags 0x136 mac ff:ff:ff:ff:ff:ff rsc 454 tsc 0 len 16 > > Jan 14 23:14:24 rogue wpa_supplicant[3163]: wlan0: CTRL-EVENT-CONNECTED - > > Connection to 00:26:b8:67:c3:2d completed [id=1 id_str=] > > Jan 14 23:14:24 rogue dhclient: New IP Address (wlan0): 192.168.1.5 > > Jan 14 23:14:24 rogue dhclient: New Subnet Mask (wlan0): 255.255.255.0 > > Jan 14 23:14:24 rogue dhclient: New Broadcast Address (wlan0): > 192.168.1.255 > > Jan 14 23:14:24 rogue dhclient: New Routers (wlan0): 192.168.1.1 > > > > I have found a problem with my AP configuration that was the cause of the > > performance issue, so that is not related to FreeBSD and is now fixed. > > > > Thanks, > > Kevin > > > > On Sun, Jan 12, 2014 at 5:01 PM, Adrian Chadd > wrote: > >> > >> Hi, > >> > >> Yup. Is this when things started getting strange? Were they okay > >> before the replay detection kicked in? > >> > >> > >> -a > >> > >> On 12 January 2014 14:45, Kevin Oberman wrote: > >> > On Sat, Jan 11, 2014 at 10:36 PM, Erich Dollansky > >> > wrote: > >> >> > >> >> Hi, > >> >> > >> >> On Fri, 10 Jan 2014 21:45:59 -0800 > >> >> Adrian Chadd wrote: > >> >> > >> >> > Please help dig up which change broke it. Even just test out the > head > >> >> > iwn code from 6 months ago. > >> >> > >> >> I came to a very strange result. I have iwn in the kernel since June > >> >> 2012 using 10. I also have had run in the kernel of another machine > >> >> since February 2011. I could not even add runfw to the kernel those > >> >> days running some 8 stable. I kept it that way until now. > >> >> > >> >> run was always working. iwn gave problems starting between August and > >> >> November of last year on my access point but still worked on other > >> >> places. I used iwn to connect successfully to another wireless > network > >> >> mid November 2013. > >> >> > >> >> After adding the firmware to the kernel for both iwn and run, I could > >> >> compile the kernel and iwn started to work. runfw did not break > >> >> compilation. > >> >> > >> >> I wonder now if the iwn or run could even work without firmware or if > >> >> the firmware was automatically loaded even when iwn or run where > >> >> compiled into the kernel. > >> >> > >> >> Erich > >> > > >> > > >> > Some things look odd here. I had been running with crypto debug for > >> > about 15 > >> > hours when I captured the attached log. The things tha looks odd to me > >> > are > >> > two series of "AES-CCM replay detected" errors. > >> > Jan 12 00:54:03 rogue kernel: wlan0: [00:26:b8:67:c3:2d] AES-CCM > replay > >> > detected tid 16 > >> > [rsc inc. by one 41 times until rsc = csc] > >> > Jan 12 00:54:03 rogue kernel: wlan0: [00:26:b8:67:c3:2d] AES-CCM > replay > >> > detected tid 16 > >> > > >> > One VERY odd thing is the MAC address. It is one byte from being the > >> > address > >> > of my Verizon/ActionTec wireless router. It is the only device on my > >> > network > >> > that has an OID of 00:26:b8, but the last nibble is 28 while these > >> > errors > >> > claim a MAC ending in 2d. > >> > > >> > The setkey statements with a MAC of FF:FF:FF:FF:FF:FF also look odd to > >> > be, > >> > but I am pretty clueless about the meaning of most of the message, do > it > >> > might be fine, but looks strange. > >> > > >> > During this time I have not had the network completely hang and > require > >> > an > >> > interface restart. > >> > > >> > Does this provide anything useful? > >> > > >> > -- > >> > R. Kevin Oberman, Network Engineer, Retired > >> > E-mail: rkoberman@gmail.com > > > > > > > > > > -- > > R. Kevin Oberman, Network Engineer, Retired > > E-mail: rkoberman@gmail.com > -- R. Kevin Oberman, Network Engineer, Retired E-mail: rkoberman@gmail.com