Subject: Re: regression after partial vmlocking merge (was: ath(4) regression between 4.99.20 and .26)
To: None <current-users@NetBSD.org>
From: David Young <dyoung@pobox.com>
List: current-users
Date: 08/07/2007 20:37:17
On Wed, Aug 08, 2007 at 02:48:47AM +0200, Jukka Salmi wrote:
> Jukka Salmi --> current-users (2007-08-07 14:20:32 +0200):
> > David Young --> current-users (2007-08-06 11:41:42 -0500):
> > > I suggest looking very closely at what hostapd and wpa_supplicant can
> > > tell you about the disconnections.
> > 
> > I'm trying to reproduce the problem while running hostapd (on 4.0_BETA2)
> > and wpa_supplicant (on -current as of yesterday) with -dd, without
> > success so far.
> 
> I finally found a way to reproducibly see the disconnects while running
> both programs with -dd. If wpa_supplicant is started by the rc script
> at system bootup, it seems to always authenticate fine initially, but
> then the first GTK rekeying fails (see below). However, if
> wpa_supplicant is started manually once the system is in multi user,
> I have yet to see a failed rekeying. Hmm...
> 
> In the former case (started at system bootup), wpa_supplicant prints:
> 
> [...]
> EAPOL: SUPP_PAE entering state AUTHENTICATED
> EAPOL: SUPP_BE entering state IDLE
> EAPOL: startWhen --> 0
> 
> So far everything is fine; dhclient runs successfully. But now hostapd
> wants to rekey GTK but times out (see previous mail or [2]here), and
> thus gets blacklisted by wpa_supplicant (IIUC):
> 
> Setting scan request: 0 sec 100000 usec
> Added BSSID 00:0b:6b:20:38:50 into blacklist
> State: COMPLETED -> DISCONNECTED
> EAPOL: External notification - portEnabled=0
> EAPOL: SUPP_PAE entering state DISCONNECTED
> EAPOL: SUPP_BE entering state INITIALIZE
> EAPOL: External notification - portValid=0
> EAPOL: External notification - EAP success=0
> CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
> [...]
> 
> (Full [1]wpa_supplicant and matching [2]hostapd logs are available.)
> 
> I don't understand what's going on. Explanations are most welcome ;-)
> 
> 
> Regards, Jukka
> 
> [1] http://salmi.ch/~jukka/nbsd/wpa_supplicant.log
> [2] http://salmi.ch/~jukka/nbsd/hostapd.log

It sounds like you are homing in on the problem!  What if you compare
the logs in the failure case with the successes?  Do any differences
stand out?

If dhclient and wpa_supplicant are not coordinated in some way, then
dhclient may down/up the interface and kill some crypto state that
way.  (Let me head off the inevitable complaint that dhclient-script
gratuitously downs/ups interfaces with a hearty "patches welcome!")

Incidentally, does your ath attach at cardbus or at pci?

Dave

-- 
David Young             OJC Technologies
dyoung@ojctech.com      Urbana, IL * (217) 278-3933 ext 24