From owner-freebsd-bugs@FreeBSD.ORG Sat Jan 9 22:10:02 2010 Return-Path: Delivered-To: freebsd-bugs@hub.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id C84401065697 for ; Sat, 9 Jan 2010 22:10:02 +0000 (UTC) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [IPv6:2001:4f8:fff6::28]) by mx1.freebsd.org (Postfix) with ESMTP id 8B8488FC19 for ; Sat, 9 Jan 2010 22:10:02 +0000 (UTC) Received: from freefall.freebsd.org (localhost [127.0.0.1]) by freefall.freebsd.org (8.14.3/8.14.3) with ESMTP id o09MA2aQ093383 for ; Sat, 9 Jan 2010 22:10:02 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.14.3/8.14.3/Submit) id o09MA2k2093382; Sat, 9 Jan 2010 22:10:02 GMT (envelope-from gnats) Resent-Date: Sat, 9 Jan 2010 22:10:02 GMT Resent-Message-Id: <201001092210.o09MA2k2093382@freefall.freebsd.org> Resent-From: FreeBSD-gnats-submit@FreeBSD.org (GNATS Filer) Resent-To: freebsd-bugs@FreeBSD.org Resent-Reply-To: FreeBSD-gnats-submit@FreeBSD.org, Kevin Dorne Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id A74A31065676 for ; Sat, 9 Jan 2010 22:03:06 +0000 (UTC) (envelope-from nobody@FreeBSD.org) Received: from www.freebsd.org (www.freebsd.org [IPv6:2001:4f8:fff6::21]) by mx1.freebsd.org (Postfix) with ESMTP id 8B2648FC16 for ; Sat, 9 Jan 2010 22:03:06 +0000 (UTC) Received: from www.freebsd.org (localhost [127.0.0.1]) by www.freebsd.org (8.14.3/8.14.3) with ESMTP id o09M36Gu083696 for ; Sat, 9 Jan 2010 22:03:06 GMT (envelope-from nobody@www.freebsd.org) Received: (from nobody@localhost) by www.freebsd.org (8.14.3/8.14.3/Submit) id o09M364D083695; Sat, 9 Jan 2010 22:03:06 GMT (envelope-from nobody) Message-Id: <201001092203.o09M364D083695@www.freebsd.org> Date: Sat, 9 Jan 2010 22:03:06 GMT From: Kevin Dorne To: freebsd-gnats-submit@FreeBSD.org X-Send-Pr-Version: www-3.1 Cc: Subject: misc/142547: wpa_supplicant drops connection on key renegotiation X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 09 Jan 2010 22:10:03 -0000 >Number: 142547 >Category: misc >Synopsis: wpa_supplicant drops connection on key renegotiation >Confidential: no >Severity: serious >Priority: medium >Responsible: freebsd-bugs >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Sat Jan 09 22:10:01 UTC 2010 >Closed-Date: >Last-Modified: >Originator: Kevin Dorne >Release: 8.0-STABLE amd64 >Organization: >Environment: FreeBSD [hostname] 8.0-STABLE FreeBSD 8.0-STABLE #0: Sat Dec 19 02:54:18 PST 2009 root@:/usr/obj/usr/src/sys/GENERIC amd64 >Description: I am using a Thinkpad T61 with Intel 4965agn wireless card, connecting to an access point using WPA authentication. On system startup, the networking works, but once the WPA key is renegotiated, the connection drops. I can get the connection back by restarting the networking (/etc/rc.d/netif restart). This does not occur on the same machine running Linux, so it's not a hardware issue. Relevant lines in /boot/loader.conf: if_iwn_load="YES" iwnfw_load="YES" wlan_wep_load="YES" wlan_ccmp_load="YES" wlan_tkip_load="YES" legal.intel_iwn.license_ack=1 /etc/rc.conf: wlans_iwn0="wlan0" ifconfig_wlan0="WPA DHCP" /etc/wpa_supplicant.conf: ctrl_interface=/var/run/wpa_supplicant ctrl_interface_group=wheel eapol_version=1 ap_scan=1 fast_reauth=1 network={ ssid="[ssid]" scan_ssid=1 key_mgmt=WPA-PSK psk="[pass]" } dmesg: iwn0: mem 0xdf2fe000-0xdf2fffff irq 17 at device 0.0 on pci3 iwn0: Reg Domain: MoW1, address 00:21:5c:5c:ae:1d 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 iwn0: 11na MCS: 15Mbps 30Mbps 45Mbps 60Mbps 90Mbps 120Mbps 135Mbps 150Mbps 30Mbps 60Mbps 90Mbps 120Mbps 180Mbps 240Mbps 270Mbps 300Mbps iwn0: 11ng MCS: 15Mbps 30Mbps 45Mbps 60Mbps 90Mbps 120Mbps 135Mbps 150Mbps 30Mbps 60Mbps 90Mbps 120Mbps 180Mbps 240Mbps 270Mbps 300Mbps Messages from wpa_supplicant on renegotiate: 2010-01-09 13:21:09 RSN: encrypted key data - hexdump(len=48): 8a 3d e7 ef 49 43 2a d2 37 8f bd 0f d0 2b 1e 54 4b 5a 6d 63 76 bf 33 8c dd 8a 7b af 69 4e c1 6a c4 7b bc a8 f3 78 ec 28 56 d8 71 83 0a 1f 27 b7 2010-01-09 13:21:09 WPA: decrypted EAPOL-Key key data - hexdump(len=40): [REMOVED] 2010-01-09 13:21:09 WPA: RX message 1 of Group Key Handshake from 00:22:a4:37:b3:d9 (ver=2) 2010-01-09 13:21:09 RSN: msg 1/2 key data - hexdump(len=40): dd 26 00 0f ac 01 02 00 92 f1 7e a1 81 7f 92 e5 bf 29 cc a9 69 ee 07 47 ee 66 86 e6 c8 81 36 75 35 5a 7b 7e f4 f0 42 0c 2010-01-09 13:21:09 RSN: received GTK in group key handshake - hexdump(len=34): 02 00 92 f1 7e a1 81 7f 92 e5 bf 29 cc a9 69 ee 07 47 ee 66 86 e6 c8 81 36 75 35 5a 7b 7e f4 f0 42 0c 2010-01-09 13:21:09 State: COMPLETED -> GROUP_HANDSHAKE 2010-01-09 13:21:09 WPA: Group Key - hexdump(len=32): [REMOVED] 2010-01-09 13:21:09 WPA: Installing GTK to the driver (keyidx=2 tx=0 len=32). 2010-01-09 13:21:09 WPA: RSC - hexdump(len=6): 10 00 00 00 00 00 2010-01-09 13:21:09 wpa_driver_bsd_set_key: alg=TKIP addr=ff:ff:ff:ff:ff:ff key_idx=2 set_tx=0 seq_len=6 key_len=32 2010-01-09 13:21:09 WPA: Sending EAPOL-Key 2/2 2010-01-09 13:21:09 WPA: TX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 03 02 00 00 00 00 00 00 00 00 00 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 c0 70 91 96 53 f8 d8 9c fd e9 26 79 27 c5 18 03 00 00 2010-01-09 13:21:09 WPA: Group rekeying completed with 00:22:a4:37:b3:d9 [GTK=TKIP] 2010-01-09 13:21:09 Cancelling authentication timeout 2010-01-09 13:21:09 State: GROUP_HANDSHAKE -> COMPLETED 2010-01-09 13:21:09 EAPOL: startWhen --> 0 2010-01-09 13:21:09 EAPOL: disable timer tick 2010-01-09 13:21:09 RX EAPOL from 00:22:a4:37:b3:d9 2010-01-09 13:21:09 RX EAPOL - hexdump(len=147): 01 03 00 8f 02 13 82 00 20 00 00 00 00 00 00 00 04 d8 72 4a 1f cf 42 d1 fe 14 bd 12 28 d4 45 54 11 21 3b 46 b3 11 6f 47 d5 65 d6 2c fc 0e 2e e8 da 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 dd 6b bb 8c 01 8f fb 9e 90 2a dc fe 79 8a ea 8a 00 30 f0 18 5d 96 aa 75 c9 8e ed cb 5a b1 0f 87 8d 43 b6 1e 4c c2 e4 3a a0 f2 4a 71 9b d7 fe e7 4e 43 dd 42 c1 7a dd c3 02 31 94 79 1e 87 f6 8b e5 cf 2010-01-09 13:21:09 IEEE 802.1X RX: version=1 type=3 length=143 2010-01-09 13:21:09 EAPOL-Key type=2 2010-01-09 13:21:09 key_info 0x1382 (ver=2 keyidx=0 rsvd=0 Group Ack MIC Secure Encr) 2010-01-09 13:21:09 key_length=32 key_data_length=48 2010-01-09 13:21:09 replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 04 2010-01-09 13:21:09 key_nonce - hexdump(len=32): d8 72 4a 1f cf 42 d1 fe 14 bd 12 28 d4 45 54 11 21 3b 46 b3 11 6f 47 d5 65 d6 2c fc 0e 2e e8 da 2010-01-09 13:21:09 key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 2010-01-09 13:21:09 key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00 2010-01-09 13:21:09 key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00 2010-01-09 13:21:09 key_mic - hexdump(len=16): dd 6b bb 8c 01 8f fb 9e 90 2a dc fe 79 8a ea 8a 2010-01-09 13:21:09 WPA: RX EAPOL-Key - hexdump(len=147): 01 03 00 8f 02 13 82 00 20 00 00 00 00 00 00 00 04 d8 72 4a 1f cf 42 d1 fe 14 bd 12 28 d4 45 54 11 21 3b 46 b3 11 6f 47 d5 65 d6 2c fc 0e 2e e8 da 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 dd 6b bb 8c 01 8f fb 9e 90 2a dc fe 79 8a ea 8a 00 30 f0 18 5d 96 aa 75 c9 8e ed cb 5a b1 0f 87 8d 43 b6 1e 4c c2 e4 3a a0 f2 4a 71 9b d7 fe e7 4e 43 dd 42 c1 7a dd c3 02 31 94 79 1e 87 f6 8b e5 cf 2010-01-09 13:21:09 RSN: encrypted key data - hexdump(len=48): f0 18 5d 96 aa 75 c9 8e ed cb 5a b1 0f 87 8d 43 b6 1e 4c c2 e4 3a a0 f2 4a 71 9b d7 fe e7 4e 43 dd 42 c1 7a dd c3 02 31 94 79 1e 87 f6 8b e5 cf 2010-01-09 13:21:09 WPA: decrypted EAPOL-Key key data - hexdump(len=40): [REMOVED] 2010-01-09 13:21:09 WPA: RX message 1 of Group Key Handshake from 00:22:a4:37:b3:d9 (ver=2) 2010-01-09 13:21:09 RSN: msg 1/2 key data - hexdump(len=40): dd 26 00 0f ac 01 01 00 b5 e6 9b a6 82 ee 5f 6f 88 bf 9b 83 47 1f 61 1a 7b be 9e 23 fa b1 77 20 ba 51 99 ab 9a 08 b6 50 2010-01-09 13:21:09 RSN: received GTK in group key handshake - hexdump(len=34): 01 00 b5 e6 9b a6 82 ee 5f 6f 88 bf 9b 83 47 1f 61 1a 7b be 9e 23 fa b1 77 20 ba 51 99 ab 9a 08 b6 50 2010-01-09 13:21:09 State: COMPLETED -> GROUP_HANDSHAKE 2010-01-09 13:21:09 WPA: Group Key - hexdump(len=32): [REMOVED] 2010-01-09 13:21:09 WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32). 2010-01-09 13:21:09 WPA: RSC - hexdump(len=6): 00 00 00 00 00 00 2010-01-09 13:21:09 wpa_driver_bsd_set_key: alg=TKIP addr=ff:ff:ff:ff:ff:ff key_idx=1 set_tx=0 seq_len=6 key_len=32 2010-01-09 13:21:09 WPA: Sending EAPOL-Key 2/2 >How-To-Repeat: Happens most times the key is renegotiated. It seems not to do it on occasion when there's heavy, continuous network traffic, but I'm not 100% sure about that. >Fix: None. Workaround is to restart network using /etc/rc.d/netif restart. >Release-Note: >Audit-Trail: >Unformatted: