trouble associating in busybox based environment

Tue May 17 06:08:44 PDT 2011

I gave the 0.8 snapshot a go and I was able to associate twice to normal environment and once to the busybox environment (all consecutively without fails).
I also got ip address assigned via dhcp and was able to get on the hostapd AP via wireless.
Looking good so far.
One thing that I noticed that did not work ... got nothing out when used -dd or -d options even when I was associated. Only association messages in /var/log/messages and nothing else.
This is what the /var/log/messages contains:
Jan  1 00:04:16 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:04:16 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:04:19 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:04:19 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:04:22 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:04:22 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:04:24 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:04:24 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:04:27 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:04:27 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:04:30 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:04:30 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:04:32 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:04:32 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:04:32 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 RADIUS: starting accounting session 000000FB-00000000
Jan  1 00:04:32 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 WPA: pairwise key handshake completed (WPA)
Jan  1 00:04:32 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 WPA: group key handshake completed (WPA)
Jan  1 00:05:00 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:00 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:00 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:05:02 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:02 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:05:05 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:05 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:05:08 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:08 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:05:10 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:10 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:05:13 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:13 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:05:15 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:15 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:05:18 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:18 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:05:21 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:21 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:05:23 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:23 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:05:26 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:26 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:05:29 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: authenticated
Jan  1 00:05:29 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated (aid 1)
Jan  1 00:05:29 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 RADIUS: starting accounting session 000000FB-00000001
Jan  1 00:05:29 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 WPA: pairwise key handshake completed (WPA)
Jan  1 00:05:29 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 WPA: group key handshake completed (WPA)
Jan  1 00:14:11 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 WPA: group key handshake completed (WPA)
Jan  1 00:15:29 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 RADIUS: starting accounting session 000000FB-00000002
Jan  1 00:15:29 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 WPA: pairwise key handshake completed (WPA)
Jan  1 00:15:29 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 WPA: group key handshake completed (WPA)
Jan  1 00:24:11 surap daemon.info hostapd: wlan0: STA 00:19:d2:bd:96:21 WPA: group key handshake completed (WPA)

The last message gets repeated now and then.

Thanks for the tip.

I'll update if I run into other trouble.

--
David

--- Lun 16/5/11, Jouni Malinen <j at w1.fi> ha scritto:

> Da: Jouni Malinen <j at w1.fi>
> Oggetto: Re: trouble associating in busybox based environment
> A: hostap at lists.shmoo.com
> Data: Luned? 16 maggio 2011, 21:07
> On Fri, May 13, 2011 at 12:49:38PM
> +0100, Davide wrote:
> > I'm having trouble getting hostapd to work correctly
> in a busybox based system.
> > 
> > I'm using 2.6.38rc8-kirkwood , BusyBox v1.18.4 and
> hostapd-0.7.3
> 
> hostapd does not use any BusyBox functionality, so I don't
> think this
> has anything to do with BusyBox.
> 
> Which driver are you using in this device for the WLAN
> hardware? The
> debug log seems to indicate that the driver could have
> quite a long
> latency in reporting TX status for frames and this can
> result in a race
> condition that prevents the association. A workaround for
> such driver
> behavior was adding in the current development branch, so I
> would
> recommend testing with a snapshot from the 0.8.x branch.
> 
> > mgmt::assoc_req
> > association request: STA=00:19:d2:bd:96:21
> capab_info=0x431 listen_interval=5
> > Validating WMM IE: OUI 00:50:f2? OUI type 2?
> OUI sub-type 0? version 1? QoS info 0x0
> >???new AID 1
> > wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: association
> OK (aid 1)
> > mgmt::auth cb
> > wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11:
> authenticated
> > Data/PS-poll frame from not associated STA
> 00:19:d2:bd:96:21
> > mgmt::assoc_resp cb
> > wlan0: STA 00:19:d2:bd:96:21 IEEE 802.11: associated
> (aid 1)
> 
> This shows the race condition. That "frame from not
> associated STA"
> should not be there, i.e., the assoc_resp cb should show
> before any data
> frames are received from the station.
> 
> -- 
> Jouni Malinen? ? ? ? ? ?
> ? ? ? ? ? ? ? ?
> ? ? ? ? ? ? ? ? PGP
> id EFC895FA
> _______________________________________________
> HostAP mailing list
> HostAP at lists.shmoo.com
> http://lists.shmoo.com/mailman/listinfo/hostap
> 