Subject: bin/32536: wpa_supplicant(8) unreliable, dropping connections with iwi(4)
To: None <gnats-admin@netbsd.org, netbsd-bugs@netbsd.org>
From: Lubomir Sedlacik <salo@Xtrmntr.org>
List: netbsd-bugs
Date: 01/15/2006 20:05:00
>Number:         32536
>Category:       bin
>Synopsis:       wpa_supplicant(8) unreliable, dropping connections with iwi(4)
>Confidential:   no
>Severity:       critical
>Priority:       medium
>Responsible:    bin-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Sun Jan 15 20:05:00 +0000 2006
>Originator:     Lubomir Sedlacik
>Release:        NetBSD 3.99.11 Mon Nov 21 20:53:00 CET 2005
>Environment:
System: NetBSD 3.99.11 Mon Nov 21 20:53:00 CET 2005
Architecture: i386
Machine: i386
>Description:
wpa_supplicant(8) isn't working reliably.  using a simple wpa_supplicant.conf
against Linksys AP and stressing the network results in dropped connections
after minutes (or seconds, when using specific traffic).

my /etc/wpa_supplicant.conf:

 network={
         ssid="klozet"
         bssid=00:12:17:dd:27:6e
         scan_ssid=1
         key_mgmt=WPA-PSK
         psk="testing key"
 }

running wpa_supplicant:

 # wpa_supplicant -d -d -i iwi0 -c /etc/wpa_supplicant.conf
Initializing interface 'iwi0' conf '/etc/wpa_supplicant.conf' driver 'default'
Configuration file '/etc/wpa_supplicant.conf' -> '/etc/wpa_supplicant.conf'
Reading configuration file '/etc/wpa_supplicant.conf'
Line: 1 - start of a new network block
ssid - hexdump_ascii(len=6):
     6b 6c 6f 7a 65 74                                 klozet
BSSID - hexdump(len=6): 00 12 17 dd 27 6e
scan_ssid=1 (0x1)
key_mgmt: 0x2
PSK (ASCII passphrase) - hexdump_ascii(len=11): REMOVED
PSK (from passphrase) - hexdump(len=32): REMOVED
Priority group 0
   id=0 ssid='klozet'
Initializing interface (2) 'iwi0'
Own MAC address: 00:0e:35:f1:2b:9a
wpa_driver_bsd_set_wpa: enabled=1
wpa_driver_bsd_set_wpa_internal: wpa=3 privacy=1
wpa_driver_bsd_del_key: keyidx=0
wpa_driver_bsd_del_key: keyidx=1
wpa_driver_bsd_del_key: keyidx=2
wpa_driver_bsd_del_key: keyidx=3
wpa_driver_bsd_set_countermeasures: enabled=0
wpa_driver_bsd_set_drop_unencrypted: enabled=1
Setting scan request: 0 sec 100000 usec
Starting AP scan (specific SSID)
Scan SSID - hexdump_ascii(len=6):
     6b 6c 6f 7a 65 74                                 klozet
Received 0 bytes of scan results (2 BSSes)
Scan results: 2
Selecting BSS from priority group 0
0: 00:12:17:dd:27:6e ssid='klozet' wpa_ie_len=24 rsn_ie_len=0
   selected
Trying to associate with 00:12:17:dd:27:6e (SSID='klozet' freq=2462 MHz)
Cancelling scan request
Automatic auth_alg selection: 0x1
WPA: using IEEE 802.11i/D3.0
WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 2
WPA: using GTK TKIP
WPA: using PTK TKIP
WPA: using KEY_MGMT WPA-PSK
WPA: Own WPA IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
No keys have been configured - skip key clearing
wpa_driver_bsd_set_drop_unencrypted: enabled=1
wpa_driver_bsd_associate: ssid 'klozet' wpa ie len 24 pairwise 2 group 2 key mgmt 1
wpa_driver_bsd_associate: set PRIVACY 1
Setting authentication timeout: 5 sec 0 usec
Association event - clear replay counter
Associated to a new BSS: BSSID=00:12:17:dd:27:6e
No keys have been configured - skip key clearing
Associated with 00:12:17:dd:27:6e
Setting authentication timeout: 10 sec 0 usec
RX EAPOL from 00:12:17:dd:27:6e
RX EAPOL - hexdump(len=99): 01 03 00 5f fe 00 89 00 20 00 00 00 00 00 00 00 00 35 bd 64 b1 f7 67 74 26 99 57 0e
a2 2b 6a c0 9e ee 3b e0 41 34 77 6b bc 8a b5 56 50 2d 5f f2 69 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0
0 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
Setting authentication timeout: 10 sec 0 usec
IEEE 802.1X RX: version=1 type=3 length=95
  EAPOL-Key type=254
WPA: RX EAPOL-Key - hexdump(len=99): 01 03 00 5f fe 00 89 00 20 00 00 00 00 00 00 00 00 35 bd 64 b1 f7 67 74 26
99 57 0e a2 2b 6a c0 9e ee 3b e0 41 34 77 6b bc 8a b5 56 50 2d 5f f2 69 00 00 00 00 00 00 00 00 00 00 00 00 00 0
0 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
WPA: RX message 1 of 4-Way Handshake from 00:12:17:dd:27:6e (ver=1)
WPA: Renewed SNonce - hexdump(len=32): c2 b4 e8 36 48 6c 99 50 e8 77 33 f4 bd 7c 89 85 e7 3f 87 84 de f4 dd de a
a 55 6e 2d 3f 9d 50 f7
WPA: PMK - hexdump(len=32): REMOVED
WPA: PTK - hexdump(len=64): REMOVED
WPA: EAPOL-Key MIC - hexdump(len=16): 9a 9e c5 13 71 47 75 07 b3 8c 27 fa 08 8f 64 5e
WPA: Sending EAPOL-Key 2/4
WPA: TX EAPOL-Key 2/4 - hexdump(len=137): 00 12 17 dd 27 6e 00 0e 35 f1 2b 9a 88 8e 01 03 00 77 fe 01 09 00 20 0
0 00 00 00 00 00 00 00 c2 b4 e8 36 48 6c 99 50 e8 77 33 f4 bd 7c 89 85 e7 3f 87 84 de f4 dd de aa 55 6e 2d 3f 9d
 50 f7 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 9a 9e c5
13 71 47 75 07 b3 8c 27 fa 08 8f 64 5e 00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f
2 02
RX EAPOL from 00:12:17:dd:27:6e
RX EAPOL - hexdump(len=123): 01 03 00 77 fe 01 c9 00 20 00 00 00 00 00 00 00 01 35 bd 64 b1 f7 67 74 26 99 57 0e
 23 09 78 f2 37 a0 b3 91 ff 21 4b fb 00 fd 8e c4 56 e9 b0 86 25 a0 b3 91 ff 21 4b fb 00 fd 8e c4 56 e9 b0 86 26 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 8c 77 71 0d 05 50 5d 34 62 49 fd f6 b4 8f c9 ae 00 20 3f 2d da 50 ea 41 c3 ae 40 dd 3b 05 20 d6 1f 22 ab 5e 59 e7 c0 35 f2 96 26 1f b5 fb 33 4e 01 0f
IEEE 802.1X RX: version=1 type=3 length=127
  EAPOL-Key type=254
WPA: RX EAPOL-Key - hexdump(len=131): 01 03 00 7f fe 03 91 00 20 00 00 00 00 00 00 00 02 34 ab 3e 1c db 63 28 21 29 5f 2d 23 09 78 f2 37 a0 b3 91 ff 21 4b fb 00 fd 8e c4 56 e9 b0 86 25 a0 b3 91 ff 21 4b fb 00 fd 8e c4 56 e9 b0 86 26 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 8c 77 71 0d 05 50 5d 34 62 49 fd f6 b4 8f c9 ae 00 20 3f 2d da 50 ea 41 c3 ae 40 dd 3b 05 20 d6 1f 22 ab 5e 59 e7 c0 35 f2 96 26 1f b5 fb 33 4e 01 0f
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 94 4b 39 77 28 d4 bb 38 9e 09 a9 29 8f f8 45 b3 00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
IEEE 802.1X RX: version=1 type=3 length=119
  EAPOL-Key type=254
WPA: RX EAPOL-Key - hexdump(len=123): 01 03 00 77 fe 01 c9 00 20 00 00 00 00 00 00 00 01 35 bd 64 b1 f7 67 74 26 99 57 0e a2 2b 6a c0 9e ee 3b e0 41 34 77 6b bc 8a b5 56 50 2d 5f f2 69 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 94 4b 39 77 28 d4 bb 38 9e 09 a9 29 8f f8 45 b3 00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
WPA: RX message 3 of 4-Way Handshake from 00:12:17:dd:27:6e (ver=1)
WPA: IE KeyData - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
WPA: Sending EAPOL-Key 4/4
WPA: TX EAPOL-Key 4/4 - hexdump(len=113): 00 12 17 dd 27 6e 00 0e 35 f1 2b 9a 88 8e 01 03 00 5f fe 01 09 00 20 00 00 00 00 00 00 00 01 c2 b4 e8 36 48 6c 99 50 e8 77 33 f4 bd 7c 89 85 e7 3f 87 84 de f4 dd de aa 55 6e 2d 3f 9d 50 f7 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 05 66 96 d9 7f 6c be 28 17 75 b6 ea b4 a6 6d e9 00 00
WPA: Installing PTK to the driver.
WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
wpa_driver_bsd_set_key: alg=TKIP addr=00:12:17:dd:27:6e key_idx=0 set_tx=1 seq_len=6 key_len=32
RX EAPOL from 00:12:17:dd:27:6e
RX EAPOL - hexdump(len=131): 01 03 00 7f fe 03 91 00 20 00 00 00 00 00 00 00 02 35 bd 64 b1 f7 67 74 26 99 57 0e a2 2b 6a c0 9e ee 3b e0 41 34 77 6b bc 8a b5 56 50 2d 5f f2 6a ee 3b e0 41 34 77 6b bc 8a b5 56 50 2d 5f f2 6b 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 14 77 6c 73 5f 24 69 84 3e 94 0f 05 f4 5e 98 98 00 20 cc 21 77 12 cd 4e b3 21 d1 59 07 96 7c 03 e0 52 6b 30 b7 35 99 ab ce 81 6a cb bc 0a a0 11 9d af
IEEE 802.1X RX: version=1 type=3 length=127
  EAPOL-Key type=254
WPA: RX EAPOL-Key - hexdump(len=131): 01 03 00 7f fe 03 91 00 20 00 00 00 00 00 00 00 02 35 bd 64 b1 f7 67 74 26 99 57 0e a2 2b 6a c0 9e ee 3b e0 41 34 77 6b bc 8a b5 56 50 2d 5f f2 6a ee 3b e0 41 34 77 6b bc 8a b5 56 50 2d 5f f2 6b 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 14 77 6c 73 5f 24 69 84 3e 94 0f 05 f4 5e 98 98 00 20 cc 21 77 12 cd 4e b3 21 d1 59 07 96 7c 03 e0 52 6b 30 b7 35 99 ab ce 81 6a cb bc 0a a0 11 9d af
WPA: RX message 1 of Group Key Handshake from 00:12:17:dd:27:6e (ver=1)
WPA: Group Key - hexdump(len=32): REMOVED
WPA: Installing GTK to the driver (keyidx=1 tx=0).
WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
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
WPA: Sending EAPOL-Key 2/2
WPA: TX EAPOL-Key 2/2 - hexdump(len=113): 00 12 17 dd 27 6e 00 0e 35 f1 2b 9a 88 8e 01 03 00 5f fe 03 11 00 20 00 00 00 00 00 00 00 02 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 4c c0 f2 85 f3 2e 43 2f 86 e3 ed 6e 9d 65 d5 4e 00 00
WPA: Key negotiation completed with 00:12:17:dd:27:6e PTK=TKIP GTK=TKIP
Cancelling authentication timeout

so far so good, network seems to work just fine:

 # ifconfig iwi0
 iwi0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> mtu 1500
         ssid klozet nwkey 1:"",0xc413f6de46404dfc2922cc9d7ec79cce,"",""
         powersave off
         bssid 00:12:17:dd:27:6e chan 11
         address: 00:0e:35:f1:2b:9a
         media: IEEE802.11 OFDM54
         status: active

now i try to open few bookmarks at once in tabs in firefox, tunnelled via ssh
connection (debug output from wpa_supplicant(8)):

Received 0 bytes of scan results (3 BSSes)
Scan results: 3
Selecting BSS from priority group 0
0: 00:12:17:dd:27:6e ssid='klozet' wpa_ie_len=24 rsn_ie_len=0
   selected
Already associated with the selected AP.

and the newtork link drops.  to bring it up again it's necessary to kill
wpa_supplicant(8), bring the interace down and up (several times) and start it
again.
>How-To-Repeat:
set up a basic WPA configuration,
start wpa_supplicant(8),
generate multiple http requests at once over tunnelled connection,
see network go down
>Fix:
n/a