Hostapd Dropout

Question

I have configured hostapd as an access point following several how-tos using ubuntu 12.04. Everything works well for up to several hours and then at some point hostapd no longer accepts new connections.

hostapd config is as follows:

ssid=PNN
wpa_passphrase=somePassphrase
interface=wlan2
bridge=br0
auth_algs=3
channel=7
driver=nl80211
hw_mode=g
logger_stdout=-1
logger_stdout_level=2
max_num_sta=255
rsn_pairwise=CCMP
wpa=2
wpa_key_mgmt=WPA-PSK
wpa_pairwise=TKIP CCMP

Using the output of

hostapd -dd /etc/hostapd/hostapd.conf

Under normal circumstances new connections are picked up as follows:

mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for our SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
Unknown Microsoft information element ignored (type=8 len=7)

STA 3c:d0:f8:10:0f:f0 sent probe request for broadcast SSID
mgmt::auth
authentication: STA=40:a6:d9:a5:63:dd auth_alg=0 auth_transaction=1 status_code=0 wep=0
  New STA
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.11: authentication OK (open system)
wlan2: STA 40:a6:d9:a5:63:dd MLME: MLME-AUTHENTICATE.indication(40:a6:d9:a5:63:dd, OPEN_SYSTEM)
wlan2: STA 40:a6:d9:a5:63:dd MLME: MLME-DELETEKEYS.request(40:a6:d9:a5:63:dd)
authentication reply: STA=40:a6:d9:a5:63:dd auth_alg=0 auth_transaction=2 resp=0 (IE len=0)
mgmt::proberesp cb
mgmt::auth cb
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.11: authenticated
mgmt::assoc_req
association request: STA=40:a6:d9:a5:63:dd capab_info=0x431 listen_interval=10
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
  new AID 1
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.11: association OK (aid 1)
mgmt::assoc_resp cb
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.11: associated (aid 1)
wlan2: STA 40:a6:d9:a5:63:dd MLME: MLME-ASSOCIATE.indication(40:a6:d9:a5:63:dd)
wlan2: STA 40:a6:d9:a5:63:dd MLME: MLME-DELETEKEYS.request(40:a6:d9:a5:63:dd)
wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x216f2b0 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=40:a6:d9:a5:63:dd
wlan2: STA 40:a6:d9:a5:63:dd WPA: event 1 notification
wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x216f2b0 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=40:a6:d9:a5:63:dd
wlan2: STA 40:a6:d9:a5:63:dd WPA: start authentication
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state INITIALIZE
wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x216f2b0 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=40:a6:d9:a5:63:dd
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.1X: unauthorizing port
WPA: 40:a6:d9:a5:63:dd WPA_PTK_GROUP entering state IDLE
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state AUTHENTICATION
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state AUTHENTICATION2
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state INITPSK
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state PTKSTART
wlan2: STA 40:a6:d9:a5:63:dd WPA: sending 1/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=8 kde_len=0 keyidx=0 encr=0)
nl80211: Event message available
nl80211: Ignored unknown event (cmd=19)
IEEE 802.1X: 40:a6:d9:a5:63:dd TX status - version=2 type=3 length=95 - ack=1
IEEE 802.1X: 121 bytes from 40:a6:d9:a5:63:dd
   IEEE 802.1X: version=2 type=3 length=117
wlan2: STA 40:a6:d9:a5:63:dd WPA: received EAPOL-Key frame (2/4 Pairwise)
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state PTKCALCNEGOTIATING
WPA: PTK derivation - A1=00:0e:8e:3f:f9:71 A2=40:a6:d9:a5:63:dd
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=48): [REMOVED]
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state PTKCALCNEGOTIATING2
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state PTKINITNEGOTIATING
wlan2: STA 40:a6:d9:a5:63:dd WPA: sending 3/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=2 secure=1 mic=1 ack=1 install=1 pairwise=8 kde_len=46 keyidx=1 encr=1)
Plaintext EAPOL-Key Key Data - hexdump(len=56): [REMOVED]
IEEE 802.1X: 40:a6:d9:a5:63:dd TX status - version=2 type=3 length=151 - ack=1
IEEE 802.1X: 99 bytes from 40:a6:d9:a5:63:dd
   IEEE 802.1X: version=2 type=3 length=95
wlan2: STA 40:a6:d9:a5:63:dd WPA: received EAPOL-Key frame (4/4 Pairwise)
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state PTKINITDONE
wpa_driver_nl80211_set_key: ifindex=6 alg=3 addr=0x216f2b0 key_idx=0 set_tx=1 seq_len=0 key_len=16
   addr=40:a6:d9:a5:63:dd
AP-STA-CONNECTED 40:a6:d9:a5:63:dd
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.1X: authorizing port
wlan2: STA 40:a6:d9:a5:63:dd RADIUS: starting accounting session 50E3DF21-00000000
wlan2: STA 40:a6:d9:a5:63:dd WPA: pairwise key handshake completed (RSN)
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
Unknown Microsoft information element ignored (type=8 len=7)

STA 3c:d0:f8:10:0f:f0 sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
Unknown Microsoft information element ignored (type=8 len=7)

STA 5c:95:ae:d8:b7:ec sent probe request for broadcast SSID
mgmt::proberesp cb

Once hostapd no longer accepts new connections the output is as follows:

mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for our SSID
mgmt::proberesp cb
mgmt::auth
authentication: STA=40:a6:d9:a5:63:dd auth_alg=0 auth_transaction=1 status_code=0 wep=0
  New STA
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.11: authentication OK (open system)
wlan2: STA 40:a6:d9:a5:63:dd MLME: MLME-AUTHENTICATE.indication(40:a6:d9:a5:63:dd, OPEN_SYSTEM)
wlan2: STA 40:a6:d9:a5:63:dd MLME: MLME-DELETEKEYS.request(40:a6:d9:a5:63:dd)
authentication reply: STA=40:a6:d9:a5:63:dd auth_alg=0 auth_transaction=2 resp=0 (IE len=0)
mgmt::auth cb
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.11: authenticated
mgmt::assoc_req
association request: STA=40:a6:d9:a5:63:dd capab_info=0x431 listen_interval=10
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
  new AID 1
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.11: association OK (aid 1)
mgmt::assoc_resp cb
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.11: associated (aid 1)
wlan2: STA 40:a6:d9:a5:63:dd MLME: MLME-ASSOCIATE.indication(40:a6:d9:a5:63:dd)
wlan2: STA 40:a6:d9:a5:63:dd MLME: MLME-DELETEKEYS.request(40:a6:d9:a5:63:dd)
wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x263c270 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=40:a6:d9:a5:63:dd
wlan2: STA 40:a6:d9:a5:63:dd WPA: event 1 notification
wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x263c270 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=40:a6:d9:a5:63:dd
wlan2: STA 40:a6:d9:a5:63:dd WPA: start authentication
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state INITIALIZE
wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x263c270 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=40:a6:d9:a5:63:dd
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.1X: unauthorizing port
WPA: 40:a6:d9:a5:63:dd WPA_PTK_GROUP entering state IDLE
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state AUTHENTICATION
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state AUTHENTICATION2
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state INITPSK
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state PTKSTART
wlan2: STA 40:a6:d9:a5:63:dd WPA: sending 1/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=8 kde_len=0 keyidx=0 encr=0)
nl80211: Event message available
nl80211: Ignored unknown event (cmd=19)
IEEE 802.1X: 40:a6:d9:a5:63:dd TX status - version=2 type=3 length=95 - ack=1
wlan2: STA 40:a6:d9:a5:63:dd WPA: EAPOL-Key timeout
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state PTKSTART
wlan2: STA 40:a6:d9:a5:63:dd WPA: sending 1/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=8 kde_len=0 keyidx=0 encr=0)
IEEE 802.1X: 40:a6:d9:a5:63:dd TX status - version=2 type=3 length=95 - ack=1
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 00:15:6d:60:da:3b sent probe request for broadcast SSID
mgmt::proberesp cb
STA 00:15:6d:60:da:3b sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
wlan2: STA 40:a6:d9:a5:63:dd WPA: EAPOL-Key timeout
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state PTKSTART
wlan2: STA 40:a6:d9:a5:63:dd WPA: sending 1/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=8 kde_len=0 keyidx=0 encr=0)
IEEE 802.1X: 40:a6:d9:a5:63:dd TX status - version=2 type=3 length=95 - ack=1
STA 00:15:6d:60:da:3b sent probe request for broadcast SSID
mgmt::proberesp cb
wlan2: STA 40:a6:d9:a5:63:dd WPA: EAPOL-Key timeout
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state PTKSTART
wlan2: STA 40:a6:d9:a5:63:dd WPA: sending 1/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=8 kde_len=0 keyidx=0 encr=0)
IEEE 802.1X: 40:a6:d9:a5:63:dd TX status - version=2 type=3 length=95 - ack=1
STA 00:15:6d:60:da:3b sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
wlan2: STA 40:a6:d9:a5:63:dd WPA: EAPOL-Key timeout
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state PTKSTART
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state DISCONNECT
hostapd_wpa_auth_disconnect: WPA authenticator requests disconnect: STA 40:a6:d9:a5:63:dd reason 2
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state DISCONNECTED
WPA: 40:a6:d9:a5:63:dd WPA_PTK entering state INITIALIZE
wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x263c270 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=40:a6:d9:a5:63:dd
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.1X: unauthorizing port
wlan2: STA 40:a6:d9:a5:63:dd IEEE 802.11: deauthenticated due to local deauth request
nl80211: Event message available
nl80211: Ignored unknown event (cmd=20)
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:a5:63:dd sent probe request for broadcast SSID
mgmt::proberesp cb
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
unknown vendor specific information element ignored (vendor OUI 00:10:18 len=9)
STA 40:a6:d9:b0:cd:fd sent probe request for broadcast SSID
mgmt::proberesp cb

Running the following fixes the problem for another couple of hours.

sudo service hostapd restart

I've done as much reading as possible and have tried reducing the txpower of wlan2 from 16dbm to 10dbm as suggested for stability problems but the problem remains.

If anyone could assist it would be greatly appreciated.

shutdown hostapd service, then start it with sudo hostapd -dd /etc/hostapd/hostapd.conf. hopefully that will give more details — strings, Jan 08 '13 at 17:47
appearently, it seems to have something to do with the driver. Because this happened to me with certain chipsets, but not with others. Same config. — Alba Mendez, Jan 08 '13 at 17:53
@strings - That is where I have copied the above output from as mentioned. — MarcF, Jan 08 '13 at 18:07
@MarcF make sure you run with -dd also use lspci and find out your exact driver as jmendeth mentioned, its quite possibly there is a better driver. — strings, Jan 08 '13 at 18:25
@jmendeth - I am using a SparkLAN WPEA-111N card // lspci gives // 04:00.0 Network controller: Atheros Communications Inc. AR928X Wireless Network Adapter (PCI-Express) (rev 01) — MarcF, Jan 08 '13 at 19:45
if you can, try another card, i had problems with mine for months and turned out to be a bad card, different symptoms, but if you can try another, just might be that. http://askubuntu.com/questions/115458/atheros-wireless-card-shows-up-as-two-different-models/ — geermc4, Jan 15 '13 at 00:24
@geermc4 - That would be something to try but unfortunately the PC is in a somewhat remote location and getting a spare card is not currently possible. — MarcF, Jan 15 '13 at 11:12
http://wiki.openwrt.org/doc/devel/debugging `ssh [email protected] 'killall -9 hostapd; /usr/sbin/hostapd -dd /var/run/hostapd-phy0.conf' > /tmp/hostapd.log` — j0h, May 04 '13 at 03:39
I never resolved the problem completely. It was possibly heat related as reducing the TX power increased the time between failures. — MarcF, Sep 17 '13 at 08:50

score 1 · Answer 1 · answered Sep 20 '13 at 15:53

Run sudo iwconfig and turn off 'Power Management' for your card. Reboot and see if it's fine now. Reboot again and see if it's fine now. If not, we'd have to add it to the Startup Applications.
A friend of mine faced the same issue. The default Atheros drivers were to be blamed. Your TX-log fills up and that leads to authentication failure.

In 'Software Sources'/'Software & Updates', enable 'Backports' under the 'Updates' tab.

Then update the system.

Also: sudo apt-get install linux-backports-modules-cw-3.6-precise-generic

Reboot & check.
If it still fails, check here: Solved: Ubuntu 12.04 Wifi Drivers

@MarcF Whether it works or not, please do let me know via a comment. And accept the Answer if it works at it'd help others know what's to be tried first. :-) — TomKat, Sep 27 '13 at 04:17

score 0 · Answer 2 · answered Mar 20 '14 at 14:13

@TomKat is right the reason it fails to make the authentication handshake is because your TX-log is Filled at 255 entries. After that you restart the process(es) and it's all good again, for awhile, then repete same problem. The reason lowering the Tx power slowed down the time between failures is because you essentially limited the range at which connections were possible hence less people in that range on a say "per hour" basis. So less connections = longer time between failures... Or then again I could be WAY OfF.

Hostapd Dropout

2 Answers2