wpa_supplicant: should "Associated with" and "RX EAPOL from" report the same MAC?
Arjan van Bentem
hostap
Sun Apr 17 05:25:17 PDT 2005
Hi all,
Is seeing two different MAC's for "Associated with" and "RX EAPOL from"
to be expected?
The details...
My wpa_supplicant 0.3.8 / ndiswrapper 1.1 / Linksys WMP54G do not get
any further than "WPA: Sending EAPOL-Key 2/4" while my Speedtouch 580
access point then logs that the client is associated, but is still
authenticating.
Trying to figger out what's wrong I noticed two different MAC's in the
debug information: wpa_supplicant says it has associated with the MAC I
know to be my access point, but later on seems to indicate it receives a
reply from some other MAC I do not recognize at all. I've not seen this
while looking at dumps many others posted on the internet. "ifconfig -a"
or "arp" do not list this MAC either.
The log I see (non-stripped log and dmesg output at the end of this
message) when using default settings:
Initializing interface (2) 'wlan0'
>>> Arjan: is the next line OK...? This only
>>> occurs for the snapshot build, not for 0.3.8
ioctl[SIOCSIWPMKSA]: No such device
>>> Arjan: the Linksys WMP54G
Own MAC address: 00:12:17:94:9b:1b
:
Starting AP scan (broadcast SSID)
Scan timeout - try to get results
>>> Arjan: allright, a single BSS found
Received 308 bytes of scan results (1 BSSes)
:
>>> Arjan: indeed, the Speedtouch 580
Trying to associate with 00:90:96:cf:43:cf (SSID='Palahala' freq=2412 MHz)
:
No keys have been configured - skip key clearing
State: SCANNING -> ASSOCIATING
:
Wireless event: new AP: 00:90:96:cf:43:cf
State: ASSOCIATING -> ASSOCIATED
:
Associated to a new BSS: BSSID=00:90:96:cf:43:cf
:
Setting authentication timeout: 10 sec 0 usec
>>> Arjan: a reply from a different MAC?
RX EAPOL from 00:0e:50:26:45:b6
:
State: ASSOCIATED -> 4WAY_HANDSHAKE
>>> Arjan: the very same 3rd MAC again...
WPA: RX message 1 of 4-Way Handshake from 00:0e:50:26:45:b6 (ver=1)
WPA: Renewed SNonce - hexdump(len=32): 23 c0 ...
:
WPA: Sending EAPOL-Key 2/4
>>> Arjan: and the above is repeated for ever,
>>> sometimes with timeout message...
I'm using ndiswrapper 1.1 on Ubuntu 5.04, installed as described at
http://dossy.org/archives/000110.html (which uses Linksys WMP54GS
whereas my card is a WMP54G), after first running "apt-get install
linux-headers-2.6.10-5-386 build-essential fakeroot".
Same behavior for wpa_supplicant yesterday's snapshot (log above) and
0.3.8, both ONLY using CONFIG_DRIVER_NDISWRAPPER=y and
CONFIG_CTRL_IFACE=y, and even when I doubled the timeout periods in the
source code. When setting the access point to use EAS, then
wpa_supplicant will also log it will use CCMP.
And same behavior when using, for example, all kind of combinations for
ap_scan=2, eapol_version=2, explicitely setting BSSID to match the MAC
of the base station, scan_ssid, proto=WPA, pairwise=TKIP, group=TKIP,
setting the access point to not allow broadcasts, using a short plain
text PSK, et cetera, ...
The very same Linksys card and PSK work fine on Windows XP (dual boot
with Ubuntu), using the same NDIS drivers, and using the same access
point settings.
Thanks for any input (like I cannot even come up with a decent Google
search phrase...),
Arjan.
dmesg:
ndiswrapper version 1.1 loaded (preempt=yes,smp=no)
ndiswrapper: driver bcmwl5 (Linksys,07/17/2003, 3.30.15.0) loaded
PCI: Enabling device 0000:00:0d.0 (0004 -> 0006)
ACPI: PCI interrupt 0000:00:0d.0[A] -> GSI 17 (level, low) -> IRQ 17
ndiswrapper: using irq 17
wlan0: ndiswrapper ethernet device 00:12:17:94:9b:1b using driver
bcmwl5, configuration file 14E4:4320:1737:0013.5.conf
wlan0: encryption modes supported: WEP, WPA with TKIP, WPA with AES/CCMP
Full wpa_supplicant log:
# wpa_supplicant -Dndiswrapper -w -iwlan0 -c/etc/wpa_supplicant.conf -dd
Initializing interface 'wlan0' conf '/etc/wpa_supplicant.conf' driver
'ndiswrapper'
Configuration file '/etc/wpa_supplicant.conf' -> '/etc/wpa_supplicant.conf'
Reading configuration file '/etc/wpa_supplicant.conf'
ctrl_interface='/var/run/wpa_supplicant'
Line: 25 - start of a new network block
ssid - hexdump_ascii(len=8):
50 61 6c 61 68 61 6c 61 Palahala
key_mgmt: 0x2
PSK (ASCII passphrase) - hexdump_ascii(len=59): [REMOVED]
PSK (from passphrase) - hexdump(len=32): [REMOVED]
Priority group 0
id=0 ssid='Palahala'
Initializing interface (2) 'wlan0'
ioctl[SIOCSIWPMKSA]: No such device
Own MAC address: 00:12:17:94:9b:1b
Setting scan request: 0 sec 100000 usec
Wireless event: cmd=0x8b06 len=8
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
State: DISCONNECTED -> SCANNING
Starting AP scan (broadcast SSID)
Scan timeout - try to get results
Received 308 bytes of scan results (1 BSSes)
Scan results: 1
Selecting BSS from priority group 0
0: 00:90:96:cf:43:cf ssid='Palahala' wpa_ie_len=24 rsn_ie_len=0 caps=0x11
selected
Trying to associate with 00:90:96:cf:43:cf (SSID='Palahala' freq=2412 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
State: SCANNING -> ASSOCIATING
Setting authentication timeout: 5 sec 0 usec
Wireless event: cmd=0x8c02 len=199
Custom wireless event:
'ASSOCINFO(ReqIEs=000850616c6168616c61010882848b9624b0486c32048c129860dd050010180100dd160050f20101000050f20201000050f20201000050f202
RespIEs=010882848b9624b0486c32048c129860dd050010180101)'
Association info event
req_ies - hexdump(len=57): 00 08 50 61 6c 61 68 61 6c 61 01 08 82 84 8b
96 24 b0 48 6c 32 04 8c 12 98 60 dd 05 00 10 18 01 00 dd 16 00 50 f2 01
01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
resp_ies - hexdump(len=23): 01 08 82 84 8b 96 24 b0 48 6c 32 04 8c 12 98
60 dd 05 00 10 18 01 01
assoc_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
Wireless event: cmd=0x8b15 len=20
Wireless event: new AP: 00:90:96:cf:43:cf
State: ASSOCIATING -> ASSOCIATED
Association event - clear replay counter
Associated to a new BSS: BSSID=00:90:96:cf:43:cf
No keys have been configured - skip key clearing
Associated with 00:90:96:cf:43:cf
Setting authentication timeout: 10 sec 0 usec
RX EAPOL from 00:0e:50:26:45:b6
RX EAPOL - hexdump(len=99): 01 03 00 5f fe 00 89 00 20 00 00 00 00 00 00
00 00 4b 28 56 3e 9b bc fa e5 8f b1 4d f4 97 87 c7 2b 57 dd ec 8b 32 f9
78 b9 90 c7 68 74 c8 55 7a 51 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
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 4b 28 56 3e 9b bc fa e5 8f b1 4d f4 97 87 c7 2b 57 dd ec
8b 32 f9 78 b9 90 c7 68 74 c8 55 7a 51 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
State: ASSOCIATED -> 4WAY_HANDSHAKE
WPA: RX message 1 of 4-Way Handshake from 00:0e:50:26:45:b6 (ver=1)
WPA: Renewed SNonce - hexdump(len=32): 23 c0 7d 14 0b 1a af 86 3f 87 9d
f9 f4 ef 75 14 a3 72 1d ba bb 28 aa 62 58 10 0a 04 7b 23 a0 ef
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=64): [REMOVED]
WPA: Sending EAPOL-Key 2/4
WPA: TX EAPOL-Key - hexdump(len=137): 00 0e 50 26 45 b6 00 12 17 94 9b
1b 88 8e 01 03 00 77 fe 01 09 00 20 00 00 00 00 00 00 00 00 23 c0 7d 14
0b 1a af 86 3f 87 9d f9 f4 ef 75 14 a3 72 1d ba bb 28 aa 62 58 10 0a 04
7b 23 a0 ef 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 32 d0 cd cc eb 7c 10 13 0b 5e 69 e2
f0 a7 93 28 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
Authentication with 00:90:96:cf:43:cf timed out.
Added BSSID 00:90:96:cf:43:cf into blacklist
State: 4WAY_HANDSHAKE -> DISCONNECTED
No keys have been configured - skip key clearing
Setting scan request: 0 sec 0 usec
State: DISCONNECTED -> SCANNING
Starting AP scan (broadcast SSID)
Wireless event: cmd=0x8b15 len=20
Wireless event: new AP: 00:00:00:00:00:00
State: SCANNING -> DISCONNECTED
Disconnect event - remove keys
Scan timeout - try to get results
Received 308 bytes of scan results (1 BSSes)
Scan results: 1
Selecting BSS from priority group 0
0: 00:90:96:cf:43:cf ssid='Palahala' wpa_ie_len=24 rsn_ie_len=0 caps=0x11
skip - blacklisted
No APs found - clear blacklist and try again
Removed BSSID 00:90:96:cf:43:cf from blacklist (clear)
Selecting BSS from priority group 0
0: 00:90:96:cf:43:cf ssid='Palahala' wpa_ie_len=24 rsn_ie_len=0 caps=0x11
selected
Trying to associate with 00:90:96:cf:43:cf (SSID='Palahala' freq=2412 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
State: DISCONNECTED -> ASSOCIATING
Setting authentication timeout: 5 sec 0 usec
Wireless event: cmd=0x8c02 len=199
Custom wireless event:
'ASSOCINFO(ReqIEs=000850616c6168616c61010882848b9624b0486c32048c129860dd050010180100dd160050f20101000050f20201000050f20201000050f202
RespIEs=010882848b9624b0486c32048c129860dd050010180102)'
Association info event
req_ies - hexdump(len=57): 00 08 50 61 6c 61 68 61 6c 61 01 08 82 84 8b
96 24 b0 48 6c 32 04 8c 12 98 60 dd 05 00 10 18 01 00 dd 16 00 50 f2 01
01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
resp_ies - hexdump(len=23): 01 08 82 84 8b 96 24 b0 48 6c 32 04 8c 12 98
60 dd 05 00 10 18 01 02
assoc_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
Wireless event: cmd=0x8b15 len=20
Wireless event: new AP: 00:90:96:cf:43:cf
State: ASSOCIATING -> ASSOCIATED
Association event - clear replay counter
Associated to a new BSS: BSSID=00:90:96:cf:43:cf
No keys have been configured - skip key clearing
Associated with 00:90:96:cf:43:cf
Setting authentication timeout: 10 sec 0 usec
RX EAPOL from 00:0e:50:26:45:b6
RX EAPOL - hexdump(len=99): 01 03 00 5f fe 00 89 00 20 00 00 00 00 00 00
00 00 4b 28 56 3e 9b bc fa e5 8f b1 4d f4 97 87 c7 2b 57 dd ec 8b 32 f9
78 b9 90 c7 68 74 c8 55 7a 52 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
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 4b 28 56 3e 9b bc fa e5 8f b1 4d f4 97 87 c7 2b 57 dd ec
8b 32 f9 78 b9 90 c7 68 74 c8 55 7a 52 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
State: ASSOCIATED -> 4WAY_HANDSHAKE
WPA: RX message 1 of 4-Way Handshake from 00:0e:50:26:45:b6 (ver=1)
WPA: Renewed SNonce - hexdump(len=32): 41 c7 34 81 0f d0 62 a8 5a 4d 7a
f0 88 59 77 11 e0 34 f7 1e 63 c7 57 13 d7 40 3c 80 a4 ab f6 a9
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=64): [REMOVED]
WPA: Sending EAPOL-Key 2/4
WPA: TX EAPOL-Key - hexdump(len=137): 00 0e 50 26 45 b6 00 12 17 94 9b
1b 88 8e 01 03 00 77 fe 01 09 00 20 00 00 00 00 00 00 00 00 41 c7 34 81
0f d0 62 a8 5a 4d 7a f0 88 59 77 11 e0 34 f7 1e 63 c7 57 13 d7 40 3c 80
a4 ab f6 a9 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 c3 8f 26 72 e2 d1 0e c1 3e 6e dc 75
50 cc 11 c2 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
Signal 2 received - terminating
State: 4WAY_HANDSHAKE -> DISCONNECTED
No keys have been configured - skip key clearing
More information about the Hostap
mailing list