wifi in AP mode unreliable

Fri Jan 15 11:14:56 PST 2010

I am exhibiting the same behavior though on a non-bridged system (I removed the bridge hoping it will solve the problem). I have also 
posted a previous message on this requesting hints on how to debug this, but got no reply. Since then I have played with the settings a 
lot, and finally decided to give up and use wires.

However, throughout my trials I came onto this:

Jan 15 15:00:45 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: pairwise key handshake completed (RSN)
Jan 15 15:09:45 pinky hostapd: wlan0: WPA rekeying GTK
Jan 15 15:09:45 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: sending 1/2 msg of Group Key Handshake
Jan 15 15:09:45 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: EAPOL-Key timeout
Jan 15 15:09:45 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: sending 1/2 msg of Group Key Handshake
Jan 15 15:09:46 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: EAPOL-Key timeout
Jan 15 15:09:46 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: sending 1/2 msg of Group Key Handshake
Jan 15 15:09:47 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: EAPOL-Key timeout
Jan 15 15:09:47 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: sending 1/2 msg of Group Key Handshake
Jan 15 15:09:48 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: EAPOL-Key timeout
Jan 15 15:09:48 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 IEEE 802.1X: unauthorizing port
Jan 15 15:09:48 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 IEEE 802.11: deauthenticated due to local deauth request
Jan 15 15:11:05 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 IEEE 802.11: authentication OK (open system)
Jan 15 15:11:05 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 MLME: MLME-AUTHENTICATE.indication(70:1a:04:30:df:15, 
OPEN_SYSTEM)
Jan 15 15:11:05 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 MLME: MLME-DELETEKEYS.request(70:1a:04:30:df:15)
Jan 15 15:11:05 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 IEEE 802.11: authenticated

>From my interpretation the problem appears on the regular 10-minute rekeying process. It must be a race condition or such, since some 
times the AP processes the reply correctly and receives the 2/2 msg:

Dec 28 16:37:03 pinky hostapd: wlan0: WPA rekeying GTK
Dec 28 16:37:03 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: sending 1/2 msg of Group Key Handshake
Dec 28 16:37:03 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: EAPOL-Key timeout
Dec 28 16:37:03 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: sending 1/2 msg of Group Key Handshake
Dec 28 16:37:04 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: EAPOL-Key timeout
Dec 28 16:37:04 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: sending 1/2 msg of Group Key Handshake
Dec 28 16:37:05 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: received EAPOL-Key frame (2/2 Group)
Dec 28 16:37:05 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: group key handshake completed (RSN)
Dec 28 16:37:05 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: received EAPOL-Key 2/2 Group with unexpected replay counter
Dec 28 16:37:05 pinky hostapd: wlan0: STA 70:1a:04:30:df:15 WPA: received EAPOL-Key 2/2 Group with unexpected replay counter

Also, the problem must be AP-side since the same notebook flawlessly connects to other APs, as well as other friends using my AP have 
the same problem. 

One interesting thing I have noticed on my notebook is that iwconfig on the client presents a variable bit rate on the connection, ranging 
from 54mb/s to 8, and then back etc. Also, sometimes the connection gets stuck until there's activity on the client-side. For instance, I 
ssh into the server and I get the prompt only after hitting something on the client's keyboard. This happens quite often (every few 
seconds) and is annoying when browsing with all the AJAX sites out-there.

Although it might be the driver's fault, not hostapd, I hope this info will reach those who understand more of the internals of WiFi and help 
them work this stability problem out. 

uname -a:
Linux pinky 2.6.29-hardened #12 Mon Dec 28 08:26:16 EET 2009 i686 AMD Sempron(tm) Processor 3000+ AuthenticAMD GNU/Linux

lspci -v -s 02:06.0
02:06.0 Network controller: RaLink RT2561/RT61 rev B 802.11g
        Subsystem: D-Link System Inc AirPlus G DWL-G510 Wireless Network Adapter (Rev.C)
        Flags: bus master, slow devsel, latency 64, IRQ 17
        Memory at ff5f8000 (32-bit, non-prefetchable) [size=32K]
        Capabilities: [40] Power Management version 2
        Kernel driver in use: rt61pci

On Friday 15 January 2010 17:38:13 Klaus Darilion wrote:
> I tried to do some more debugging myself. When the link is lost on the
> Windows notebook I do no see any log messages. I only see log messages
> just before the link goes up again:
> 
> 14:28:48 wlan0: STA 00:90:4b:1a:77:cd IEEE 802.11: authentication OK
> (open system)
> 14:28:48 wlan0: STA 00:90:4b:1a:77:cd WPA: event 0 notification
> 14:28:48 wlan0: STA 00:90:4b:1a:77:cd MLME:
> MLME-AUTHENTICATE.indication(00:90:4b:1a:77:cd, OPEN_SYSTEM)
> 14:28:48 wlan0: STA 00:90:4b:1a:77:cd MLME:
> MLME-DELETEKEYS.request(00:90:4b:1a:77:cd)
> 14:29:00 wlan0: STA 00:90:4b:1a:77:cd IEEE 802.11: authentication OK
> (open system)
> 14:29:00 wlan0: STA 00:90:4b:1a:77:cd WPA: event 0 notification
> 14:29:00 wlan0: STA 00:90:4b:1a:77:cd MLME:
> MLME-AUTHENTICATE.indication(00:90:4b:1a:77:cd, OPEN_SYSTEM)
> 14:29:00 wlan0: STA 00:90:4b:1a:77:cd MLME:
> MLME-DELETEKEYS.request(00:90:4b:1a:77:cd)
> 
> Further, also during link outages, Network Stumbler reports full signal
> strength.
> 
> Any hints are appreciated.
> 
> thanks
> klaus
> 
> Klaus Darilion schrieb:
> > Hi!
> >
> > My setup is Debian Squeeze with 2.6.32 kernel (from unstable) with
> > hostapd 0.6.9. My wifi card is a Wistron CM9 (Atheros AR5213A) running
> > in AP mode. Wifi interface wlan0 is together with eth1 in a bridge
> > called lan0.
> >
> > The problem is, that wifi is unreliable (comes and goes). I tested with
> > multiple Windows notebooks as clients, all showing the same stability
> > problems. Thus, the problem must be the access point.
> >
> > I tested unencrypted and WPA2 mode, both are not stable.
> >
> > Actually I do not know how to proceed further.
> > 1. Where is the problem - in the kernel module (ath5k ?, ...?) or in
> > hostapd 2. Any hints how to further debug this issue?
> >
> > Here is my hostapd.conf:
> > ------------------------------------
> > interface=wlan0
> > driver=nl80211
> > ssid=alix1
> > channel=11
> > bridge=lan0
> > hw_mode=g
> > # remove for WPA2
> > #macaddr_acl=0
> > #auth_algs=1
> > #ignore_broadcast_ssid=0
> > #wpa=2
> > #wpa_passphrase=holidayonice
> > #wpa_key_mgmt=WPA-PSK
> > #wpa_pairwise=TKIP
> > #rsn_pairwise=CCMP
> >
> >
> > syslog says:
> > 19:53:55 hostapd: wlan0: STA 00:90:4b:1a:77:cd IEEE 802.11: authenticated
> > 19:53:55 hostapd: wlan0: STA 00:90:4b:1a:77:cd IEEE 802.11: associated
> > (aid 1)
> > 19:53:55 hostapd: wlan0: STA 00:90:4b:1a:77:cd RADIUS: starting
> > accounting session 4B4F75F9-00000000
> > 19:53:55 hostapd: wlan0: STA 00:90:4b:1a:77:cd WPA: pairwise key
> > handshake completed (RSN)
> > 20:02:25 hostapd: wlan0: STA 00:90:4b:1a:77:cd WPA: group key handshake
> > completed (RSN)
> > 20:12:25 hostapd: wlan0: STA 00:90:4b:1a:77:cd WPA: group key handshake
> > completed (RSN)
> > 20:21:29 hostapd: wlan0: STA 00:90:4b:1a:77:cd IEEE 802.11: authenticated
> > 20:21:29 hostapd: wlan0: STA 00:90:4b:1a:77:cd IEEE 802.11: associated
> > (aid 1)
> > 20:21:30 hostapd: wlan0: STA 00:90:4b:1a:77:cd RADIUS: starting
> > accounting session 4B4F75F9-00000001
> > 20:21:30 hostapd: wlan0: STA 00:90:4b:1a:77:cd WPA: pairwise key
> > handshake completed (RSN)
> > 20:22:02 hostapd: wlan0: STA 00:90:4b:1a:77:cd IEEE 802.11: disassociated
> > 20:22:03 hostapd: wlan0: STA 00:90:4b:1a:77:cd IEEE 802.11:
> > deauthenticated due to inactivity
> > 20:22:12 hostapd: wlan0: STA 00:90:4b:1a:77:cd IEEE 802.11: authenticated
> > 20:22:12 hostapd: wlan0: STA 00:90:4b:1a:77:cd IEEE 802.11: associated
> > (aid 1)
> > 20:22:12 hostapd: wlan0: STA 00:90:4b:1a:77:cd RADIUS: starting
> > accounting session 4B4F75F9-00000002
> > 20:22:12 hostapd: wlan0: STA 00:90:4b:1a:77:cd WPA: pairwise key
> > handshake completed (RSN)
> > 20:22:25 hostapd: wlan0: STA 00:90:4b:1a:77:cd WPA: group key handshake
> > completed (RSN)
> > 20:32:26 hostapd: wlan0: STA 00:90:4b:1a:77:cd WPA: group key handshake
> > completed (RSN)
> > 20:38:04 hostapd: wlan0: STA 00:90:4b:1a:77:cd IEEE 802.11: authenticated
> > 20:38:04 hostapd: wlan0: STA 00:90:4b:1a:77:cd IEEE 802.11: associated
> > (aid 1)
> > 20:38:04 hostapd: wlan0: STA 00:90:4b:1a:77:cd RADIUS: starting
> > accounting session 4B4F75F9-00000003
> > 20:38:04 hostapd: wlan0: STA 00:90:4b:1a:77:cd WPA: pairwise key
> > handshake completed (RSN)
> >
> >
> > The only suspicious things I see is:
> > IEEE 802.11: disassociated
> > IEEE 802.11: deauthenticated due to inactivity
> >
> > Is this something normal? Or is there a problem?
> >
> >
> > thanks
> > klaus
> >
> > _______________________________________________
> > HostAP mailing list
> > HostAP at lists.shmoo.com
> > http://lists.shmoo.com/mailman/listinfo/hostap
> 
> _______________________________________________
> HostAP mailing list
> HostAP at lists.shmoo.com
> http://lists.shmoo.com/mailman/listinfo/hostap
> 