EAP Identity Response dropped on 5GHz

EAP Identity Response dropped on 5GHz

[Wolfgang Breyha]

Hi!

My/our setup:

I'm using my HP Elitebook 2540p with Intel 6200 abgn
pci id: 8086:4239 (rev 35)

Kernel from Fedora 14, compat-wireless-20101130, wpa_supplicant from GIT
with -D nl80211.

I try to connect to CISCO APs with 802.1x.

Everything works fine on 2.4GHz frequencies. But on 5GHz frequencies I
see the EAP Identity Request from the AP and I see the response in
wireshark.

But I don't see the response on an other laptop monitoring this channel
and the AP logs a timeout after a while for the EAP Request.

In the same moments I see
> Dec  1 15:53:18 hpwb kernel: [15439.900071] wlan0: dropped frame to 00:26:cb:xx:xx:xx (unauthorized port)
> Dec  1 15:53:19 hpwb kernel: [15440.894484] wlan0: dropped frame to 00:26:cb:xx:xx:xx (unauthorized port)
> Dec  1 15:53:20 hpwb kernel: [15441.893895] wlan0: dropped frame to 00:26:cb:xx:xx:xx (unauthorized port)

wpa_supplicant logs:

> 1291215721.998646: Process pending EAPOL frame that was received just before association notification
> 1291215721.998677: RX EAPOL from 00:26:cb:xx:xx:xx
> 1291215721.998713: Setting authentication timeout: 70 sec 0 usec
> 1291215721.998747: EAPOL: Received EAP-Packet frame
> 1291215721.998778: EAPOL: SUPP_PAE entering state RESTART
> 1291215721.998806: EAP: EAP entering state INITIALIZE
> 1291215721.998835: EAP: EAP entering state IDLE
> 1291215721.998865: EAPOL: SUPP_PAE entering state AUTHENTICATING
> 1291215721.998895: EAPOL: SUPP_BE entering state REQUEST
> 1291215721.998924: EAPOL: getSuppRsp
> 1291215721.998952: EAP: EAP entering state RECEIVED
> 1291215721.998998: EAP: Received EAP-Request id=1 method=1 vendor=0 vendorMethod=0
> 1291215721.999034: EAP: EAP entering state IDENTITY
> 1291215721.999065: CTRL-EVENT-EAP-STARTED EAP authentication started
> 1291215721.999087: EAP: EAP-Request Identity data - hexdump_ascii(len=40):
> 1291215721.999159: EAP: using real identity - hexdump_ascii(len=15):
> 1291215721.999198: EAP: EAP entering state SEND_RESPONSE
> 1291215721.999220: EAP: EAP entering state IDLE
> 1291215721.999267: EAPOL: SUPP_BE entering state RESPONSE
> 1291215721.999290: EAPOL: txSuppRsp
> 1291215721.999318: TX EAPOL: dst=00:26:cb:xx:xx:xx
> 1291215721.999361: EAPOL: SUPP_BE entering state RECEIVE
> 1291215721.999411: nl80211: Event message available
> 1291215721.999463: nl80211: Ignore connect event (cmd=46) when using userspace SME
> 1291215721.999511: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
> 1291215721.999551: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
> 1291215721.999588: Event 5 received on interface wlan0
> 1291215721.999627: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
> 1291215721.999665: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
> 1291215721.999698: Event 5 received on interface wlan0
> 1291215721.999741: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
> 1291215721.999779: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
> 1291215721.999813: Event 5 received on interface wlan0
> 1291215722.007464: nl80211: Event message available
> 1291215722.007565: nl80211: Regulatory domain change
> 1291215722.007610: Event 30 received on interface wlan0
> 1291215725.001681: EAPOL: startWhen --> 0
> 1291215752.024711: EAPOL: authWhile --> 0
> 1291215752.024808: EAPOL: SUPP_BE entering state TIMEOUT

After the timeout wpa_supplicant restarts with an "EAPOL START" packet
and everything works cleanly.

I tried to shortcircuit the if in
net/mac80211/tx.c:1914ff
>         if (!ieee80211_vif_is_mesh(&sdata->vif) &&
>                 unlikely(!is_multicast_ether_addr(hdr.addr1) &&
>                       !(sta_flags & WLAN_STA_AUTHORIZED) &&
>                       !(cpu_to_be16(ethertype) == sdata->control_port_protocol &&
>                        compare_ether_addr(sdata->vif.addr,
>                                           skb->data + ETH_ALEN) == 0))) {
but that didn't help.

With kind regards,
Wolfgang Breyha
University of Vienna

Re: EAP Identity Response dropped on 5GHz

[Wolfgang Breyha]

Wolfgang Breyha wrote, on 01.12.2010 16:26:
> In the same moments I see
>> Dec  1 15:53:18 hpwb kernel: [15439.900071] wlan0: dropped frame to 00:26:cb:xx:xx:xx (unauthorized port)
>> Dec  1 15:53:19 hpwb kernel: [15440.894484] wlan0: dropped frame to 00:26:cb:xx:xx:xx (unauthorized port)
>> Dec  1 15:53:20 hpwb kernel: [15441.893895] wlan0: dropped frame to 00:26:cb:xx:xx:xx (unauthorized port)

These are IPv6 discovery packets of ethertype 0x86DD. So that's correct.

But introducing a usleep(100000) in
wpa_supplicant/src/eap_peer/eap.c:136, or in other words....
> wpa_supplicant logs:
> 
>> 1291215721.998646: Process pending EAPOL frame that was received just before association notification
>> 1291215721.998677: RX EAPOL from 00:26:cb:xx:xx:xx
>> 1291215721.998713: Setting authentication timeout: 70 sec 0 usec
>> 1291215721.998747: EAPOL: Received EAP-Packet frame
>> 1291215721.998778: EAPOL: SUPP_PAE entering state RESTART
>> 1291215721.998806: EAP: EAP entering state INITIALIZE
............ HERE ................
>> 1291215721.998835: EAP: EAP entering state IDLE
>> 1291215721.998865: EAPOL: SUPP_PAE entering state AUTHENTICATING
>> 1291215721.998895: EAPOL: SUPP_BE entering state REQUEST
>> 1291215721.998924: EAPOL: getSuppRsp
>> 1291215721.998952: EAP: EAP entering state RECEIVED
>> 1291215721.998998: EAP: Received EAP-Request id=1 method=1 vendor=0 vendorMethod=0
>> 1291215721.999034: EAP: EAP entering state IDENTITY
>> 1291215721.999065: CTRL-EVENT-EAP-STARTED EAP authentication started
>> 1291215721.999087: EAP: EAP-Request Identity data - hexdump_ascii(len=40):
>> 1291215721.999159: EAP: using real identity - hexdump_ascii(len=15):
>> 1291215721.999198: EAP: EAP entering state SEND_RESPONSE
>> 1291215721.999220: EAP: EAP entering state IDLE
>> 1291215721.999267: EAPOL: SUPP_BE entering state RESPONSE
>> 1291215721.999290: EAPOL: txSuppRsp
>> 1291215721.999318: TX EAPOL: dst=00:26:cb:xx:xx:xx
.... lets path this packet through to the AP over air.

I haven't found the source of this race condition which causes this. The
reason why it only happens on 5GHz channels is unknown as well.

With kind regards,
Wolfgang Breyha
-- 
Wolfgang Breyha <wbreyha@gmx.net> | http://www.blafasel.at/
Vienna University Computer Center | Austria

Re: EAP Identity Response dropped on 5GHz

[Eliad Peller]

hi Wolfgang,

On Thu, Dec 2, 2010 at 4:24 PM, Wolfgang Breyha <wbreyha@gmx.net> wrote:
> But introducing a usleep(100000) in
> wpa_supplicant/src/eap_peer/eap.c:136, or in other words....
>> wpa_supplicant logs:
>>
>>> 1291215721.998646: Process pending EAPOL frame that was received just before association notification
>>> 1291215721.998677: RX EAPOL from 00:26:cb:xx:xx:xx
>>> 1291215721.998713: Setting authentication timeout: 70 sec 0 usec
>>> 1291215721.998747: EAPOL: Received EAP-Packet frame
>>> 1291215721.998778: EAPOL: SUPP_PAE entering state RESTART
>>> 1291215721.998806: EAP: EAP entering state INITIALIZE
> ............ HERE ................
>>> 1291215721.998835: EAP: EAP entering state IDLE
>>> 1291215721.998865: EAPOL: SUPP_PAE entering state AUTHENTICATING
>>> 1291215721.998895: EAPOL: SUPP_BE entering state REQUEST
>>> 1291215721.998924: EAPOL: getSuppRsp
>>> 1291215721.998952: EAP: EAP entering state RECEIVED

>
> I haven't found the source of this race condition which causes this. The
> reason why it only happens on 5GHz channels is unknown as well.
>

sounds a bit similar to another case i've encountered:
http://lists.shmoo.com/pipermail/hostap/2010-November/021940.html

Eliad.