iwn firmware instability with an up-to-date stable kernel

Sat Apr 24 04:42:51 UTC 2010

On Fri, Apr 23, 2010 at 8:05 PM, Brandon Gooch
<jamesbrandongooch at gmail.com> wrote:
> 2010/4/23 Garrett Cooper <yanefbsd at gmail.com>:
>> 2010/4/23 Garrett Cooper <yanefbsd at gmail.com>:
>>> 2010/4/18 Olivier Cochard-Labbé <olivier at cochard.me>:
>>>> 2010/4/18 Bernhard Schmidt <bschmidt at techwires.net>:
>>>>> Are you able to reproduce this on demand? As in type a few commands and
>>>>> the firmware error occurs?
>>>>>
>>>>
>>>> No, I'm not able to reproduce on demand this problem.
>>>
>>> I'm seeing similar issues on occasion with my Lenovo as well:
>>>
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: firmware error log:
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: error type      =
>>> "NMI_INTERRUPT_WDG" (0x00000004)
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: program counter = 0x0000046C
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: source line     = 0x000000D0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: error data      = 0x0000000207030000
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: branch link     = 0x00008370000004C2
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: interrupt link  = 0x000006DA000018B8
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: time            = 4287402440
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: driver status:
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring  0: qid=0  cur=1   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring  1: qid=1  cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring  2: qid=2  cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring  3: qid=3  cur=36  queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring  4: qid=4  cur=123 queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring  5: qid=5  cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring  6: qid=6  cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring  7: qid=7  cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring  8: qid=8  cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring  9: qid=9  cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring 10: qid=10 cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring 11: qid=11 cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring 12: qid=12 cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring 13: qid=13 cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring 14: qid=14 cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: tx ring 15: qid=15 cur=0   queued=0
>>> Apr 23 19:25:24 garrcoop-fbsd kernel: rx ring: cur=8
>>>
>>> This may be because the system was under load (I was installing a port
>>> shortly before the connection dropped). I'll try poking at this
>>> further because it's going to be an annoying productivity loss :/.
>>
>>    Sorry... should have included more helpful details.
>> Thanks,
>> -Garrett
>>
>> dmesg:
>>
>> iwn0: <Intel(R) PRO/Wireless 4965BGN> mem 0xdf2fe000-0xdf2fffff irq 17
>> at device 0.0 on pci3
>> iwn0: MIMO 2T3R, MoW1, address 00:1d:e0:7d:9f:c7
>> iwn0: [ITHREAD]
>> iwn0: 11a rates: 6Mbps 9Mbps 12Mbps 18Mbps 24Mbps 36Mbps 48Mbps 54Mbps
>> iwn0: 11b rates: 1Mbps 2Mbps 5.5Mbps 11Mbps
>> iwn0: 11g rates: 1Mbps 2Mbps 5.5Mbps 11Mbps 6Mbps 9Mbps 12Mbps 18Mbps
>> 24Mbps 36Mbps 48Mbps 54Mbps
>>
>> pciconf -lv snippet:
>>
>> iwn0 at pci0:3:0:0:        class=0x028000 card=0x11108086 chip=0x42308086
>> rev=0x61 hdr=0x00
>>    vendor     = 'Intel Corporation'
>>    device     = 'Intel Wireless WiFi Link 4965AGN (Intel 4965AGN)'
>>    class      = network
>> cbb0 at pci0:21:0:0:       class=0x060700 card=0x20c617aa chip=0x04761180
>> rev=0xba hdr=0x02
>>
>> uname -a:
>>
>> $ uname -a
>> FreeBSD garrcoop-fbsd.cisco.com 8.0-STABLE FreeBSD 8.0-STABLE #0
>> r207006: Wed Apr 21 13:18:44 PDT 2010
>> root at garrcoop-fbsd.cisco.com:/usr/obj/usr/src/sys/LAPPY_X86  i386
>
> I'm actually looking at this right now. For me, it's actually
> happening when my machine stays on overnight (or for long periods of
> time, idle).
>
> Also, it seems to be causing the kernel to panic, although I'm now
> wondering if the Machine Check Architecture is somehow catching this
> device error and causing an exception (hw.mca.enabled=1)(?) -- not
> possible, right ???
>
> Whatever the case, I can't seem to get the firmware error to occur
> with iwn(4) debugging or wlandebug options enabled, so who knows
> exactly what leads to this.
>
> I know Bernhard has worked hard on this driver, it's a shame that this
> freaky bug has bit us all now, without leaving many clues :(
>
> I've attached a textdump for posterity if nothing else :)

    Connectivity appears to be shoddy in my neck of the woods (kind of
ironic... but meh). Just running buildworld, buildkernel, then doing a
tcpdump in parallel causes the pseudo device to go up and down a lot.
I assume this isn't standard behavior?
    Just for reference buildworld was started shortly after 19:39:05,
and it finished at 21:29. The interface has also gone up and down once
since then while the system's been basically idle.
Thanks,
-Garrett

Apr 23 19:39:05 garrcoop-fbsd kernel: wlan0: promiscuous mode enabled
Apr 23 19:41:04 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 19:41:04 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:7f:81:90 (SSID='blizzard' freq=2412 MHz)
Apr 23 19:41:04 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Apr 23 19:41:04 garrcoop-fbsd kernel: wlan0: link state changed to DOWN
Apr 23 19:41:14 garrcoop-fbsd wpa_supplicant[17226]: Authentication
with 00:00:00:00:00:00 timed out.
Apr 23 19:41:14 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 19:41:14 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:7f:81:90 (SSID='blizzard' freq=2412 MHz)
Apr 23 19:41:14 garrcoop-fbsd wpa_supplicant[17226]: Associated with
00:1a:30:7f:81:90
Apr 23 19:41:14 garrcoop-fbsd kernel: wlan0: link state changed to UP
Apr 23 19:41:14 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-STARTED EAP authentication started
Apr 23 19:41:14 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
Apr 23 19:41:14 garrcoop-fbsd wpa_supplicant[17226]: OpenSSL:
tls_connection_handshake - Failed to read possible Application Data
error:00000000:lib(0):func(0):reason(0)
Apr 23 19:41:14 garrcoop-fbsd wpa_supplicant[17226]: EAP-TLV: TLV
Result - Success - EAP-TLV/Phase2 Completed
Apr 23 19:41:14 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
Apr 23 19:41:14 garrcoop-fbsd wpa_supplicant[17226]: WPA: Key
negotiation completed with 00:1a:30:7f:81:90 [PTK=TKIP GTK=TKIP]
Apr 23 19:41:14 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-CONNECTED - Connection to 00:1a:30:7f:81:90 completed
(reauth) [id=0 id_str=]
Apr 23 19:41:18 garrcoop-fbsd dhclient: New IP Address (wlan0): 173.37.1.93
Apr 23 19:41:18 garrcoop-fbsd dhclient: New Subnet Mask (wlan0): 255.255.254.0
Apr 23 19:41:18 garrcoop-fbsd dhclient: New Broadcast Address (wlan0):
255.255.255.255
Apr 23 19:41:18 garrcoop-fbsd dhclient: New Routers (wlan0): 173.37.0.1
Apr 23 19:44:03 garrcoop-fbsd sudo: garrcoop : TTY=pts/3 ;
PWD=/usr/home/garrcoop ; USER=root ; COMMAND=/usr/local/bin/bash
Apr 23 19:46:06 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 19:46:06 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:7f:7d:d0 (SSID='blizzard' freq=2462 MHz)
Apr 23 19:46:06 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Apr 23 19:46:06 garrcoop-fbsd kernel: wlan0: link state changed to DOWN
Apr 23 19:46:16 garrcoop-fbsd wpa_supplicant[17226]: Authentication
with 00:00:00:00:00:00 timed out.
Apr 23 19:46:16 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 19:46:16 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:7f:7d:d0 (SSID='blizzard' freq=2462 MHz)
Apr 23 19:46:16 garrcoop-fbsd wpa_supplicant[17226]: Associated with
00:1a:30:7f:7d:d0
Apr 23 19:46:16 garrcoop-fbsd kernel: wlan0: link state changed to UP
Apr 23 19:46:16 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-STARTED EAP authentication started
Apr 23 19:46:16 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
Apr 23 19:46:16 garrcoop-fbsd wpa_supplicant[17226]: OpenSSL:
tls_connection_handshake - Failed to read possible Application Data
error:00000000:lib(0):func(0):reason(0)
Apr 23 19:46:16 garrcoop-fbsd wpa_supplicant[17226]: EAP-TLV: TLV
Result - Success - EAP-TLV/Phase2 Completed
Apr 23 19:46:16 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
Apr 23 19:46:16 garrcoop-fbsd wpa_supplicant[17226]: WPA: Key
negotiation completed with 00:1a:30:7f:7d:d0 [PTK=TKIP GTK=TKIP]
Apr 23 19:46:16 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-CONNECTED - Connection to 00:1a:30:7f:7d:d0 completed
(reauth) [id=0 id_str=]
Apr 23 19:46:16 garrcoop-fbsd dhclient: New IP Address (wlan0): 173.37.1.93
Apr 23 19:46:16 garrcoop-fbsd dhclient: New Subnet Mask (wlan0): 255.255.254.0
Apr 23 19:46:16 garrcoop-fbsd dhclient: New Broadcast Address (wlan0):
255.255.255.255
Apr 23 19:46:16 garrcoop-fbsd dhclient: New Routers (wlan0): 173.37.0.1
Apr 23 19:51:08 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 19:56:10 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 19:56:10 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:7f:81:90 (SSID='blizzard' freq=2412 MHz)
Apr 23 19:56:10 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Apr 23 19:56:10 garrcoop-fbsd kernel: wlan0: link state changed to DOWN
Apr 23 19:56:20 garrcoop-fbsd wpa_supplicant[17226]: Authentication
with 00:00:00:00:00:00 timed out.
Apr 23 19:56:20 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 19:56:20 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:7f:81:90 (SSID='blizzard' freq=2412 MHz)
Apr 23 19:56:20 garrcoop-fbsd wpa_supplicant[17226]: Associated with
00:1a:30:7f:81:90
Apr 23 19:56:20 garrcoop-fbsd kernel: wlan0: link state changed to UP
Apr 23 19:56:20 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-STARTED EAP authentication started
Apr 23 19:56:20 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
Apr 23 19:56:20 garrcoop-fbsd wpa_supplicant[17226]: OpenSSL:
tls_connection_handshake - Failed to read possible Application Data
error:00000000:lib(0):func(0):reason(0)
Apr 23 19:56:20 garrcoop-fbsd wpa_supplicant[17226]: EAP-TLV: TLV
Result - Success - EAP-TLV/Phase2 Completed
Apr 23 19:56:20 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
Apr 23 19:56:20 garrcoop-fbsd wpa_supplicant[17226]: WPA: Key
negotiation completed with 00:1a:30:7f:81:90 [PTK=TKIP GTK=TKIP]
Apr 23 19:56:20 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-CONNECTED - Connection to 00:1a:30:7f:81:90 completed
(reauth) [id=0 id_str=]
Apr 23 19:56:27 garrcoop-fbsd dhclient: New IP Address (wlan0): 173.37.1.93
Apr 23 19:56:27 garrcoop-fbsd dhclient: New Subnet Mask (wlan0): 255.255.254.0
Apr 23 19:56:27 garrcoop-fbsd dhclient: New Broadcast Address (wlan0):
255.255.255.255
Apr 23 19:56:27 garrcoop-fbsd dhclient: New Routers (wlan0): 173.37.0.1
Apr 23 20:01:12 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 20:06:14 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 20:11:16 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 20:11:16 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:c0:fd:c0 (SSID='blizzard' freq=2462 MHz)
Apr 23 20:11:16 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Apr 23 20:11:16 garrcoop-fbsd kernel: wlan0: link state changed to DOWN
Apr 23 20:11:26 garrcoop-fbsd wpa_supplicant[17226]: Authentication
with 00:00:00:00:00:00 timed out.
Apr 23 20:11:26 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 20:11:26 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:c0:fd:c0 (SSID='blizzard' freq=2462 MHz)
Apr 23 20:11:26 garrcoop-fbsd wpa_supplicant[17226]: Associated with
00:1a:30:c0:fd:c0
Apr 23 20:11:26 garrcoop-fbsd kernel: wlan0: link state changed to UP
Apr 23 20:11:26 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-STARTED EAP authentication started
Apr 23 20:11:26 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
Apr 23 20:11:26 garrcoop-fbsd wpa_supplicant[17226]: OpenSSL:
tls_connection_handshake - Failed to read possible Application Data
error:00000000:lib(0):func(0):reason(0)
Apr 23 20:11:26 garrcoop-fbsd wpa_supplicant[17226]: EAP-TLV: TLV
Result - Success - EAP-TLV/Phase2 Completed
Apr 23 20:11:26 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
Apr 23 20:11:26 garrcoop-fbsd wpa_supplicant[17226]: WPA: Key
negotiation completed with 00:1a:30:c0:fd:c0 [PTK=TKIP GTK=TKIP]
Apr 23 20:11:26 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-CONNECTED - Connection to 00:1a:30:c0:fd:c0 completed
(reauth) [id=0 id_str=]
Apr 23 20:11:31 garrcoop-fbsd dhclient: New IP Address (wlan0): 173.37.1.93
Apr 23 20:11:31 garrcoop-fbsd dhclient: New Subnet Mask (wlan0): 255.255.254.0
Apr 23 20:11:31 garrcoop-fbsd dhclient: New Broadcast Address (wlan0):
255.255.255.255
Apr 23 20:11:31 garrcoop-fbsd dhclient: New Routers (wlan0): 173.37.0.1
Apr 23 20:16:18 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 20:21:20 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 20:26:22 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 20:31:24 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 20:41:28 garrcoop-fbsd last message repeated 2 times
Apr 23 20:46:31 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 20:46:31 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:7f:7d:d0 (SSID='blizzard' freq=2462 MHz)
Apr 23 20:46:31 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Apr 23 20:46:31 garrcoop-fbsd kernel: wlan0: link state changed to DOWN
Apr 23 20:46:41 garrcoop-fbsd wpa_supplicant[17226]: Authentication
with 00:00:00:00:00:00 timed out.
Apr 23 20:46:41 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 20:46:41 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:7f:7d:d0 (SSID='blizzard' freq=2462 MHz)
Apr 23 20:46:41 garrcoop-fbsd wpa_supplicant[17226]: Associated with
00:1a:30:7f:7d:d0
Apr 23 20:46:41 garrcoop-fbsd kernel: wlan0: link state changed to UP
Apr 23 20:46:41 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-STARTED EAP authentication started
Apr 23 20:46:41 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
Apr 23 20:46:41 garrcoop-fbsd wpa_supplicant[17226]: OpenSSL:
tls_connection_handshake - Failed to read possible Application Data
error:00000000:lib(0):func(0):reason(0)
Apr 23 20:46:41 garrcoop-fbsd wpa_supplicant[17226]: EAP-TLV: TLV
Result - Success - EAP-TLV/Phase2 Completed
Apr 23 20:46:43 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
Apr 23 20:46:43 garrcoop-fbsd wpa_supplicant[17226]: WPA: Key
negotiation completed with 00:1a:30:7f:7d:d0 [PTK=TKIP GTK=TKIP]
Apr 23 20:46:43 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-CONNECTED - Connection to 00:1a:30:7f:7d:d0 completed
(reauth) [id=0 id_str=]
Apr 23 20:46:45 garrcoop-fbsd dhclient: New IP Address (wlan0): 173.37.1.93
Apr 23 20:46:45 garrcoop-fbsd dhclient: New Subnet Mask (wlan0): 255.255.254.0
Apr 23 20:46:45 garrcoop-fbsd dhclient: New Broadcast Address (wlan0):
255.255.255.255
Apr 23 20:46:45 garrcoop-fbsd dhclient: New Routers (wlan0): 173.37.0.1
Apr 23 20:51:33 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 20:51:33 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:c0:fd:c0 (SSID='blizzard' freq=2462 MHz)
Apr 23 20:51:33 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Apr 23 20:51:33 garrcoop-fbsd kernel: wlan0: link state changed to DOWN
Apr 23 20:51:43 garrcoop-fbsd wpa_supplicant[17226]: Authentication
with 00:00:00:00:00:00 timed out.
Apr 23 20:51:43 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 20:51:43 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:c0:fd:c0 (SSID='blizzard' freq=2462 MHz)
Apr 23 20:51:43 garrcoop-fbsd wpa_supplicant[17226]: Associated with
00:1a:30:c0:fd:c0
Apr 23 20:51:43 garrcoop-fbsd kernel: wlan0: link state changed to UP
Apr 23 20:51:43 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-STARTED EAP authentication started
Apr 23 20:51:43 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
Apr 23 20:51:43 garrcoop-fbsd wpa_supplicant[17226]: OpenSSL:
tls_connection_handshake - Failed to read possible Application Data
error:00000000:lib(0):func(0):reason(0)
Apr 23 20:51:43 garrcoop-fbsd wpa_supplicant[17226]: EAP-TLV: TLV
Result - Success - EAP-TLV/Phase2 Completed
Apr 23 20:51:43 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
Apr 23 20:51:43 garrcoop-fbsd wpa_supplicant[17226]: WPA: Key
negotiation completed with 00:1a:30:c0:fd:c0 [PTK=TKIP GTK=TKIP]
Apr 23 20:51:43 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-CONNECTED - Connection to 00:1a:30:c0:fd:c0 completed
(reauth) [id=0 id_str=]
Apr 23 20:51:51 garrcoop-fbsd dhclient: New IP Address (wlan0): 173.37.1.93
Apr 23 20:51:51 garrcoop-fbsd dhclient: New Subnet Mask (wlan0): 255.255.254.0
Apr 23 20:51:51 garrcoop-fbsd dhclient: New Broadcast Address (wlan0):
255.255.255.255
Apr 23 20:51:51 garrcoop-fbsd dhclient: New Routers (wlan0): 173.37.0.1
Apr 23 20:56:35 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 21:01:37 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 21:04:22 garrcoop-fbsd wpa_supplicant[17226]: WPA: Group
rekeying completed with 00:1a:30:c0:fd:c0 [GTK=TKIP]
Apr 23 21:06:39 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 21:06:39 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:7f:7d:d0 (SSID='blizzard' freq=2462 MHz)
Apr 23 21:06:39 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Apr 23 21:06:39 garrcoop-fbsd kernel: wlan0: link state changed to DOWN
Apr 23 21:06:49 garrcoop-fbsd wpa_supplicant[17226]: Authentication
with 00:00:00:00:00:00 timed out.
Apr 23 21:06:49 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 21:06:49 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:7f:7d:d0 (SSID='blizzard' freq=2462 MHz)
Apr 23 21:06:49 garrcoop-fbsd wpa_supplicant[17226]: Associated with
00:1a:30:7f:7d:d0
Apr 23 21:06:49 garrcoop-fbsd kernel: wlan0: link state changed to UP
Apr 23 21:06:49 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-STARTED EAP authentication started
Apr 23 21:06:49 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
Apr 23 21:06:49 garrcoop-fbsd wpa_supplicant[17226]: OpenSSL:
tls_connection_handshake - Failed to read possible Application Data
error:00000000:lib(0):func(0):reason(0)
Apr 23 21:06:49 garrcoop-fbsd wpa_supplicant[17226]: EAP-TLV: TLV
Result - Success - EAP-TLV/Phase2 Completed
Apr 23 21:06:49 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
Apr 23 21:06:49 garrcoop-fbsd wpa_supplicant[17226]: WPA: Key
negotiation completed with 00:1a:30:7f:7d:d0 [PTK=TKIP GTK=TKIP]
Apr 23 21:06:49 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-CONNECTED - Connection to 00:1a:30:7f:7d:d0 completed
(reauth) [id=0 id_str=]
Apr 23 21:06:49 garrcoop-fbsd dhclient: New IP Address (wlan0): 173.37.1.93
Apr 23 21:06:49 garrcoop-fbsd dhclient: New Subnet Mask (wlan0): 255.255.254.0
Apr 23 21:06:49 garrcoop-fbsd dhclient: New Broadcast Address (wlan0):
255.255.255.255
Apr 23 21:06:49 garrcoop-fbsd dhclient: New Routers (wlan0): 173.37.0.1
Apr 23 21:11:41 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 21:16:43 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 21:16:43 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:7f:81:90 (SSID='blizzard' freq=2412 MHz)
Apr 23 21:16:43 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Apr 23 21:16:43 garrcoop-fbsd kernel: wlan0: link state changed to DOWN
Apr 23 21:16:53 garrcoop-fbsd wpa_supplicant[17226]: Authentication
with 00:00:00:00:00:00 timed out.
Apr 23 21:16:53 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 21:16:53 garrcoop-fbsd wpa_supplicant[17226]: Trying to
associate with 00:1a:30:7f:81:90 (SSID='blizzard' freq=2412 MHz)
Apr 23 21:16:53 garrcoop-fbsd wpa_supplicant[17226]: Associated with
00:1a:30:7f:81:90
Apr 23 21:16:53 garrcoop-fbsd kernel: wlan0: link state changed to UP
Apr 23 21:16:53 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-STARTED EAP authentication started
Apr 23 21:16:53 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
Apr 23 21:16:53 garrcoop-fbsd wpa_supplicant[17226]: OpenSSL:
tls_connection_handshake - Failed to read possible Application Data
error:00000000:lib(0):func(0):reason(0)
Apr 23 21:16:53 garrcoop-fbsd wpa_supplicant[17226]: EAP-TLV: TLV
Result - Success - EAP-TLV/Phase2 Completed
Apr 23 21:16:53 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
Apr 23 21:16:53 garrcoop-fbsd wpa_supplicant[17226]: WPA: Key
negotiation completed with 00:1a:30:7f:81:90 [PTK=TKIP GTK=TKIP]
Apr 23 21:16:53 garrcoop-fbsd wpa_supplicant[17226]:
CTRL-EVENT-CONNECTED - Connection to 00:1a:30:7f:81:90 completed
(reauth) [id=0 id_str=]
Apr 23 21:16:53 garrcoop-fbsd dhclient: New IP Address (wlan0): 173.37.1.93
Apr 23 21:16:53 garrcoop-fbsd dhclient: New Subnet Mask (wlan0): 255.255.254.0
Apr 23 21:16:53 garrcoop-fbsd dhclient: New Broadcast Address (wlan0):
255.255.255.255
Apr 23 21:16:53 garrcoop-fbsd dhclient: New Routers (wlan0): 173.37.0.1
Apr 23 21:18:34 garrcoop-fbsd wpa_supplicant[17226]: WPA: Group
rekeying completed with 00:1a:30:7f:81:90 [GTK=TKIP]
Apr 23 21:21:45 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 21:26:47 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 21:31:49 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS
Apr 23 21:32:57 garrcoop-fbsd kernel: wlan0: promiscuous mode disabled
Apr 23 21:36:50 garrcoop-fbsd wpa_supplicant[17226]: CTRL-EVENT-SCAN-RESULTS