From owner-freebsd-stable@FreeBSD.ORG Wed Jan 29 06:09:15 2014 Return-Path: Delivered-To: freebsd-stable@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) (using TLSv1 with cipher ADH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 72EEFECF; Wed, 29 Jan 2014 06:09:15 +0000 (UTC) Received: from mail-pd0-x230.google.com (mail-pd0-x230.google.com [IPv6:2607:f8b0:400e:c02::230]) (using TLSv1 with cipher ECDHE-RSA-RC4-SHA (128/128 bits)) (No client certificate requested) by mx1.freebsd.org (Postfix) with ESMTPS id 373961362; Wed, 29 Jan 2014 06:09:15 +0000 (UTC) Received: by mail-pd0-f176.google.com with SMTP id w10so1309427pde.35 for ; Tue, 28 Jan 2014 22:09:14 -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=vsIrK6vdLeM0AM+OsxBQJBkn7zdq/u9sLXueZtZhCKg=; b=F1QZOaTmgxm3hpsuN7X+4csZRA4Bt6RHTlfssB5cFIcSUYq1PtsiZ4Qz85SETNuhZs 2my2GZ336hNSde4N00fwZZTHpU5O58sF9Wi6WbyCPpxzvChkjneTZ97budWzC+qc31cw LeVBUgpFcRqIW0HDQDs7wdCtSbUV7P9oWPkbfjyvRs93MtA3NWVfOLD/kP/Au2Xyy5Oo SLGeKZDLtJXQ2SXE3rqZkaiEq54E3oZTD6dmEEw/+UptOlRUijvRGy2k+N7VmTqrDbyT 62ldk1JI8VU6j0ED7zqqwgEyfn0blSi8JVnbEdA6/94zZ9YFq695Sk2aSYOMJYpNuKR+ IYJQ== MIME-Version: 1.0 X-Received: by 10.68.218.65 with SMTP id pe1mr5971592pbc.1.1390975754801; Tue, 28 Jan 2014 22:09:14 -0800 (PST) Sender: kob6558@gmail.com Received: by 10.67.30.1 with HTTP; Tue, 28 Jan 2014 22:09:14 -0800 (PST) In-Reply-To: References: Date: Tue, 28 Jan 2014 22:09:14 -0800 X-Google-Sender-Auth: _jeyDwpqls-2VJSrr8EwwsqlXr4 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 Stable Mailing List , Lars Engels X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.17 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 29 Jan 2014 06:09:15 -0000 On Tue, Jan 28, 2014 at 3:57 PM, Adrian Chadd wrote: > What's in dmesg? Did the firmware panic? > > Adrian > pci3: on pcib2 iwn0: mem 0xf2400000-0xf2401fff irq 17 at device 0.0 on pci3 [...] wlan0: Ethernet address: a0:88:b4:c6:ad:28 ipfw2 (+ipv6) initialized, divert loadable, nat loadable, default to deny, logging disabled These are the only entries that look even a bit related to the wireless. Let me know if you want the whole thing. No indication I see of a firmware panic in either dmesg or var/log/messages. [EOF] > On Jan 28, 2014 2:16 AM, "Kevin Oberman" wrote: > >> 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 >> > -- R. Kevin Oberman, Network Engineer, Retired E-mail: rkoberman@gmail.com