From owner-freebsd-wireless@FreeBSD.ORG Tue Jan 28 07:16:30 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 4DB55410; Tue, 28 Jan 2014 07:16:30 +0000 (UTC) Received: from mail-pd0-x236.google.com (mail-pd0-x236.google.com [IPv6:2607:f8b0:400e:c02::236]) (using TLSv1 with cipher ECDHE-RSA-RC4-SHA (128/128 bits)) (No client certificate requested) by mx1.freebsd.org (Postfix) with ESMTPS id 13D411F79; Tue, 28 Jan 2014 07:16:30 +0000 (UTC) Received: by mail-pd0-f182.google.com with SMTP id v10so6187pde.27 for ; Mon, 27 Jan 2014 23:16:29 -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=jidnN1AOVCs5gApHG0S758txJYP83NXFxdZ2ktXNrcc=; b=rI+UjxrboKupplerj6VzQ2iqL2GlIgTb5bu2p3otJbJFWT2G1elOfYj4wwnTEOE/4b FbGyq4kUwqytUYKTbTJSl3kynG7q0GQAkqPo29uXJSJfvjGynM005liVp4SGE5ffoEOs hcl/t1Wn9fLFkz/NxAeUwQG13FzqL/Dbd4kBoPw+I1H7LiHqvG41keX41bEdLy2/L9Zt yzXMpLVIiDkfxDHV32qyj8v8efzPWiUIXhC2x32rhHPvf2gC7gVvip7O1PUMrsgozYOP IVdonCCR9X9NuWwBVor5yBk8C4oBFF/3RFVX75qajBJ+t5MRQAikwCMhLL/oJUu+WUyN TOWg== MIME-Version: 1.0 X-Received: by 10.68.17.41 with SMTP id l9mr34537285pbd.76.1390893389565; Mon, 27 Jan 2014 23:16:29 -0800 (PST) Sender: kob6558@gmail.com Received: by 10.67.30.1 with HTTP; Mon, 27 Jan 2014 23:16:29 -0800 (PST) In-Reply-To: References: Date: Mon, 27 Jan 2014 23:16:29 -0800 X-Google-Sender-Auth: jptXVLNSRrkg1vJWTsayoNjq9UY Message-ID: Subject: Re: IWN hangs periodically on 10.0RC3 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@freebsd.org" , FreeBSD Stable Mailing List 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: Tue, 28 Jan 2014 07:16:30 -0000 On Fri, Jan 10, 2014 at 9:51 PM, Kevin Oberman wrote: > On Fri, Jan 10, 2014 at 9:37 AM, Adrian Chadd wrote: > >> .. when you see it hang, does anything get logged in dmesg (eg a >> firmware panic) ? >> >> Try recompiling your kernel with: >> >> IEEE80211_DEBUG >> IWN_DEBUG >> >> That way it can be debugged :) >> >> The first thing I'd check is whether there's more fun races going on >> in the crypto code - try wlandebug +crypto . >> >> >> -a >> > > I just sent a message about issues I am seeing with my IWN to wireless@. > Then I saw these responses. Sorry. > > As far as logs go, I wee a number if cases of the following sequence: > Jan 1 18:00:12 rogue dbus[1451]: [system] Activating service > name='org.freedesktop.PackageKit' (using servicehelper) > Jan 1 18:00:12 rogue dbus[1451]: [system] Successfully activated service > 'org.freedesktop.PackageKit' > Jan 1 18:28:56 rogue wpa_supplicant[620]: wlan0: CTRL-EVENT-DISCONNECTED > bssid=00:26:b8:67:c3:2d reason=0 > Jan 1 18:28:56 rogue kernel: wlan0: link state changed to DOWN > Jan 1 18:28:59 rogue wpa_supplicant[620]: wlan0: Trying to associate with > 00:26:b8:67:c3:2d (SSID='babcom' freq=2437 MHz) > Jan 1 18:28:59 rogue wpa_supplicant[620]: wlan0: Associated with > 00:26:b8:67:c3:2d > Jan 1 18:28:59 rogue kernel: wlan0: link state changed to UP > Jan 1 18:28:59 rogue dhclient[652]: send_packet: No buffer space available > Jan 1 18:28:59 rogue devd: Executing '/etc/rc.d/dhclient quietstart wlan0' > Jan 1 18:28:59 rogue wpa_supplicant[620]: wlan0: WPA: Key negotiation > completed with 00:26:b8:67:c3:2d [PTK=CCMP GTK=CCMP] > Jan 1 18:28:59 rogue wpa_supplicant[620]: wlan0: CTRL-EVENT-CONNECTED - > Connection to 00:26:b8:67:c3:2d completed [id=1 id_str=] > Jan 1 18:29:02 rogue dhclient: New IP Address (wlan0): 192.168.1.5 > Jan 1 18:29:02 rogue dhclient: New Subnet Mask (wlan0): 255.255.255.0 > Jan 1 18:29:02 rogue dhclient: New Broadcast Address (wlan0): > 192.168.1.255 > Jan 1 18:29:02 rogue dhclient: New Routers (wlan0): 192.168.1.1 > > So it seems that the bounce is happening fairly often, but the system > usually recovers. It seems to be pretty consistently 2-3 time4s a day. > Note that the dbus messages about packagekit always immediately precede > the link going down. > > Every tthe or four of these fail to recover: > Jan 3 14:09:05 rogue kernel: wlan0: link state changed to DOWN > Jan 3 14:09:56 rogue ntpd[1303]: sendto(198.129.254.218) (fd=25): Network > is down > Jan 3 14:10:15 rogue ntpd[1303]: sendto(208.79.18.86) (fd=25): Network is > down > Jan 3 14:10:29 rogue ntpd[1303]: sendto(198.124.252.90) (fd=25): Network > is down > Jan 3 14:10:49 rogue ntpd[1303]: sendto(198.55.111.5) (fd=25): Network is > down > Jan 3 14:11:00 rogue ntpd[1303]: sendto(192.95.38.104) (fd=25): Network > is down > Jan 3 14:14:02 rogue ntpd[1303]: sendto(198.129.252.38) (fd=25): Network > is down > Jan 3 14:14:12 rogue wpa_supplicant[620]: ioctl[SIOCS80211, op=26, val=0, > arg_len=0]: Operation not supported > Jan 3 14:14:12 rogue wpa_supplicant[620]: ioctl[SIOCS80211, op=26, val=0, > arg_len=0]: Operation not supported > Jan 3 14:14:12 rogue wpa_supplicant[620]: wlan0: CTRL-EVENT-TERMINATING > Jan 3 14:14:12 rogue dhclient[652]: connection closed > Jan 3 14:14:12 rogue dhclient[652]: exiting. > Jan 3 14:14:12 rogue wpa_supplicant[67153]: Successfully initialized > wpa_supplicant > Jan 3 14:14:16 rogue wpa_supplicant[67154]: wlan0: Trying to associate > with 00:26:b8:67:c3:2d (SSID='babcom' freq=2437 MHz) > Jan 3 14:14:16 rogue wpa_supplicant[67154]: wlan0: Associated with > 00:26:b8:67:c3:2d > Jan 3 14:14:16 rogue kernel: wlan0: link state changed to UP > Jan 3 14:14:16 rogue devd: Executing '/etc/rc.d/dhclient quietstart wlan0' > Jan 3 14:14:16 rogue dhclient[67191]: send_packet: No buffer space > available > Jan 3 14:14:17 rogue wpa_supplicant[67154]: wlan0: WPA: Key negotiation > completed with 00:26:b8:67:c3:2d [PTK=CCMP GTK=CCMP] > Jan 3 14:14:17 rogue wpa_supplicant[67154]: wlan0: CTRL-EVENT-CONNECTED - > Connection to 00:26:b8:67:c3:2d completed [id=1 id_str=] > Jan 3 14:14:18 rogue dhclient: New IP Address (wlan0): 192.168.1.5 > Jan 3 14:14:18 rogue dhclient: New Subnet Mask (wlan0): 255.255.255.0 > Jan 3 14:14:18 rogue dhclient: New Broadcast Address (wlan0): > 192.168.1.255 > Jan 3 14:14:18 rogue dhclient: New Routers (wlan0): 192.168.1.1 > > The restart took place when I restarted the interface about 5 minutes > after it went down and, as you can see, it came up normally. I'll admit > that I am completely baffled by the dbus/packagekit tie-in as I can't see > what packagekit would do to touch the network. > > I'll be building a new kernel with debug shortly. > > In my other message (to wireless) I also mentioned the (possibly > unrelated) issue of poor performance and and periodic sub-second > connectivity drops. > > -- > R. Kevin Oberman, Network Engineer, Retired > E-mail: rkoberman@gmail.com > I was about to send a report that removing bgscan fixed the issue, but, then it happened again. Nothing new in the log from prior cases. Any other flags to I should try to set in wlandebug? state? assoc? I'll admit that I have no idea which might be helpful. One thing I seem to have failed to post is the ifconfig after the failure: wlan0: flags=8c43 metric 0 mtu 1500 ether a0:88:b4:c6:ad:28 inet 192.168.1.5 netmask 0xffffff00 broadcast 192.168.1.255 nd6 options=29 media: IEEE 802.11 Wireless Ethernet autoselect (autoselect) status: no carrier ssid "" channel 7 (2442 MHz 11g) country US authmode WPA1+WPA2/802.11i privacy ON deftxkey UNDEF txpower 15 bmiss 10 scanvalid 60 protmode CTS wme roaming MANUAL Note: My AP is on channel 6. -- R. Kevin Oberman, Network Engineer, Retired E-mail: rkoberman@gmail.com