Date: Mon, 27 Jan 2014 23:16:29 -0800 From: Kevin Oberman <rkoberman@gmail.com> To: Adrian Chadd <adrian@freebsd.org> Cc: "freebsd-wireless@freebsd.org" <freebsd-wireless@freebsd.org>, FreeBSD Stable Mailing List <freebsd-stable@freebsd.org>, Lars Engels <lars.engels@0x20.net> Subject: Re: IWN hangs periodically on 10.0RC3 Message-ID: <CAN6yY1sh_yrngFAgkR9fxuASF6S6XpnAfkUOQS3xadto8z=Mrw@mail.gmail.com> In-Reply-To: <CAN6yY1vhP1gQENAPPicxAwBTQ5nXBJRw9ZobDJc=sw8NnFUBpA@mail.gmail.com> References: <CAN6yY1ujxmUBo-jt8QRa6ozRk8otSX-4LHGum=4na9ObkEGxXQ@mail.gmail.com> <e630ae96669b34cc3f2ba0efadee9aa1@mail.0x20.net> <CAJ-Vmo=mKRTR6vzCUUA5cR8rHDhnhcUcQj1DFCnkPwqqb6PBHg@mail.gmail.com> <CAN6yY1vhP1gQENAPPicxAwBTQ5nXBJRw9ZobDJc=sw8NnFUBpA@mail.gmail.com>
next in thread | previous in thread | raw e-mail | index | archive | help
On Fri, Jan 10, 2014 at 9:51 PM, Kevin Oberman <rkoberman@gmail.com> wrote:
> On Fri, Jan 10, 2014 at 9:37 AM, Adrian Chadd <adrian@freebsd.org> 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<UP,BROADCAST,RUNNING,OACTIVE,SIMPLEX,MULTICAST> 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<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
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
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?CAN6yY1sh_yrngFAgkR9fxuASF6S6XpnAfkUOQS3xadto8z=Mrw>