EAP-TLV: Earlier failure - force failed Phase 2

Dan Williams dcbw at redhat.com
Mon Jan 4 15:42:30 PST 2016 

On Mon, 2016-01-04 at 15:28 -0800, Adam Jacobs wrote:
> Gotcha,  here's the NM config.  I'm running version 1.0.4 which is
> stock for Ubuntu 15.10.

This all looks pretty standard; can you get the supplicant debug info? 
 Double-check to ensure it doesn't include your password.  Since
wpa_supplicant is auto-started as a D-Bus service, if you kill it it
will just be restarted again.  The simplest way to get output is
probably:

1) mv /usr/sbin/wpa_supplicant /
2) killall -TERM wpa_supplicant
3) /wpa_supplicant -dddtu
4) reproduce the problem, get the output
5) Ctrl+C the supplicant
6) mv /wpa_supplicant /usr/sbin

and toggle rfkill or 'nmcli r wifi off; nmcli r wifi on"

Dan

> 
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  Config: added
> 'ssid' value 'Mocana-SECURE'
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  Config: added
> 'scan_ssid' value '1'
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  Config: added
> 'key_mgmt' value 'WPA-EAP'
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  Config: added
> 'password' value '<omitted>'
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  Config: added
> 'eap' value 'PEAP'
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  Config: added
> 'fragment_size' value '1300'
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  Config: added
> 'phase2' value 'auth=MSCHAPV2'
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  Config: added
> 'ca_cert' value '/home/ajacobs/Documents/MocanaRoot.pem'
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  Config: added
> 'identity' value 'ajacobs'
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  Config: added
> 'bgscan' value 'simple:30:-65:300'
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  Config: added
> 'proactive_key_caching' value '1'
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  Config: set
> interface ap_scan to 1
> Jan  4 12:20:02 jeremiah NetworkManager[5337]: <info>  (wlan0):
> supplicant interface state: inactive -> scanning
> 
> 
> 
> 
> I see a couple of parameters being set there that I'm NOT setting
> when I manually configure wpa_supplicant myself, to perhaps it's one
> of those?  Maybe proactive_key_caching?  That seems like a likely
> candidate.  I'm going to try turning that back on in my manual config
> and see if it reproduces the problem.
> 
> 
> 
> 
> Adam
> 
> 
> ________________________________________
> From: Dan Williams [dcbw at redhat.com]
> Sent: Monday, January 04, 2016 15:18
> To: Adam Jacobs; Jouni Malinen
> Cc: hostap at lists.infradead.org
> Subject: Re: EAP-TLV: Earlier failure - force failed Phase 2
> 
> On Mon, 2016-01-04 at 14:46 -0800, Adam Jacobs wrote:
> > Well, this is weird.
> > 
> > My laptop runs Ubuntu, and when I reproduced the error, it was
> > invoking wpa_supplicant via NetworkManager.  Of course, to test
> > disabling TLS1.2, I had to shut off NetworkManager and invoke
> > wpa_supplicant manually.
> > 
> > What I've now discovered is that if I invoke wpa_supplicant
> > manually,
> > everything works fine even if I DON'T disable TLS1.2.  My config
> > looks like this:
> > 
> > 
> > 
> > network={
> >   ssid="Mocana-SECURE"
> >   key_mgmt=WPA-EAP
> >   eap=PEAP
> >   identity="ajacobs"
> >   password="**********"
> >   phase2="auth=MSCHAPV2"
> >   ca_cert="/usr/local/etc/MocanaRoot.pem"
> > }
> > 
> > 
> > 
> > 
> > So it must be something about the way NetworkManager is
> > calling/managing NetworkSupplicant that causes this failure.
> >  Unfortunately I don't know of any way to debug that further, and
> > as
> > I've shown wpa_supplicant to be working properly it is probably no
> > longer the domain of this group, Still, I'm happy to take
> > suggestions
> > if anyone has any ideas for debugging further.
> 
> You can look in your syslog where NM will print the configuration
> options it's sending to the supplicant.  We obviously intend that NM
> will work here, so this seems like a bug or misconfiguration.  You'll
> see stuff like:
> 
> NetworkManager[831]: <info>  Config: added 'ssid' value 'my SSID'
> NetworkManager[831]: <info>  Config: added 'scan_ssid' value '1'
> NetworkManager[831]: <info>  Config: added 'key_mgmt' value 'WPA-PSK'
> NetworkManager[831]: <info>  Config: added 'psk' value '<omitted>'
> NetworkManager[831]: <info>  Config: added 'proto' value 'WPA RSN'
> 
> and while this is obviously for a WPA-PSK connection, yours will EAP
> -specific stuff.
> 
> What version of NetworkManager are you using?
> 
> Dan
> 
> > 
> > 
> > 
> > Serves me right for using NetworkManager in the first place.
> > 
> > 
> > 
> > 
> > Adam
> > 
> > 
> > ________________________________________
> > From: Jouni Malinen [j at w1.fi]
> > Sent: Friday, January 01, 2016 06:28
> > To: Adam Jacobs
> > Cc: hostap at lists.infradead.org
> > Subject: Re: EAP-TLV: Earlier failure - force failed Phase 2
> > 
> > On Thu, Dec 31, 2015 at 03:36:22PM -0800, Adam Jacobs wrote:
> > > Dec 17 07:18:20 jeremiah wpa_supplicant[1146]: wlan0: CTRL-EVENT
> > > -EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
> > > Dec 17 07:18:20 jeremiah wpa_supplicant[1146]: EAP-MSCHAPV2:
> > > Authentication succeeded
> > > Dec 17 07:18:20 jeremiah wpa_supplicant[1146]: EAP-TLV: TLV
> > > Result
> > > - Success - EAP-TLV/Phase2 Completed
> > > Dec 17 07:18:20 jeremiah wpa_supplicant[1146]: EAP-TLV: Earlier
> > > failure - force failed Phase 2
> > 
> > It looks like Phase 2 (EAP-MSCHAPv2 username/password validation)
> > succeeded, but something went wrong with the following PEAP steps.
> > Adding some more wpa_supplicant debug verbosity (e.g., -d on the
> > command
> > line) would help clarify what exactly happened here.
> > 
> > > It seems to happen more-or-less randomly; I'm not doing anything
> > > in
> > > particular when the connection drops.  I'd say an average session
> > > lasts about 30 minutes or so, before it dies and I need to
> > > restart.
> > > 
> > > Disabling TLS1.2 in wpa_supplicant seems to solve the problem,
> > > but
> > > that's a workaround, not a fix.
> > > 
> > > Any ideas?  In particular, "EAP-TLV: Earlier failure - force
> > > failed
> > > Phase 2" seems to be where the trouble starts.  Anyone know what
> > > that means?
> > 
> > My first guess would be that this ended up using PEAPv0
> > cryptobinding
> > and there was an interop issue of some short that caused the server
> > and
> > wpa_supplicant derive different value. That may very well be
> > dependent
> > on TLS v1.2 being used.
> > 
> > Unfortunately, I do not have a Windows 2012 RADIUS server to test
> > this
> > easily myself. If you can produce more detailed debug logs from
> > wpa_supplicant, that would be useful information to have for
> > figuring
> > out what exactly might be causing this.
> > 
> > As a workaround, it might be possible to add
> > phase1="crypto_binding=0"
> > to disable use of PEAP cryptobinding (if the server allows this).
> > That
> > said, I'd rather get the real issue figured out and fixed.
> > 
> > --
> > Jouni Malinen                                            PGP id
> > EFC895FA
> > 
> > _______________________________________________
> > Hostap mailing list
> > Hostap at lists.infradead.org
> > http://lists.infradead.org/mailman/listinfo/hostap
> 
> _______________________________________________
> Hostap mailing list
> Hostap at lists.infradead.org
> http://lists.infradead.org/mailman/listinfo/hostap

More information about the Hostap mailing list