From owner-freebsd-stable@FreeBSD.ORG Sat Jan 11 05:51:42 2014 Return-Path: Delivered-To: freebsd-stable@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 6DAFE232; Sat, 11 Jan 2014 05:51:42 +0000 (UTC) Received: from mail-pb0-x22c.google.com (mail-pb0-x22c.google.com [IPv6:2607:f8b0:400e:c01::22c]) (using TLSv1 with cipher ECDHE-RSA-RC4-SHA (128/128 bits)) (No client certificate requested) by mx1.freebsd.org (Postfix) with ESMTPS id 343A213E2; Sat, 11 Jan 2014 05:51:42 +0000 (UTC) Received: by mail-pb0-f44.google.com with SMTP id rq2so5276951pbb.17 for ; Fri, 10 Jan 2014 21:51:41 -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=GUtZc8j89VvHnXWhbSVCypJ+xwbRzXea1jep1Vy3vck=; b=ZxSeKz/jQb7bjBV79xg3TOtkiEJUcqeRqMZDZSD9Zq3VuyP1u9PLPlnc84NGB1DnUF lSFhzScl+R/rZYQ4oohHRmqM8iz22SvbPFBr44pHpZ5tL+JP+yt7JazFnmO2v+TlYD5z NQ46r1UZl5IuGCcFQX8r+mRRv/pAUReQM7x6AwEx7b2rs+NPjnSC4jpo8za6fjiYQWmN SyEhkoLRRkxQdaeZCSc/VyD5m4EsIXCO/Feb4l2Uj2p4YiYV+1gnlkUAgMiKQ147K46X ORkQTvRLXMNVRl0d84WTve2uXQIMafQV0CtP9PgpG6O7zHSt1EYLM77bEPM8cOrj3AHq teVw== MIME-Version: 1.0 X-Received: by 10.68.227.36 with SMTP id rx4mr16456801pbc.164.1389419501804; Fri, 10 Jan 2014 21:51:41 -0800 (PST) Sender: kob6558@gmail.com Received: by 10.67.23.101 with HTTP; Fri, 10 Jan 2014 21:51:41 -0800 (PST) In-Reply-To: References: Date: Fri, 10 Jan 2014 21:51:41 -0800 X-Google-Sender-Auth: r2SmyYoyEG_Zst5gxrYYYoPrdSw 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 , 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: Sat, 11 Jan 2014 05:51:42 -0000 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