EAP / MSCHAP / Certificate Troubles

Thu Nov 8 19:45:12 CET 2012

Hey,

I need a bit of assistance.  Brief summary: I have two RADIUS servers
connected to different Active Directory domains.  I got through the
basic setup, EAP-PEAP / MSCHAP were working successfully
authenticating against both domains.

Then:
- I upgraded freeradius on both from 2.1.10 to 2.2.0.
- I generated new 'production' certificates on both servers.

Now one of them is broken.  Broken to the point where I can't even get
eapol_test to run with success (though ntlm_auth still authenticates
against AD properly).  Since I was getting the "EAP session for state
0x56783e8f517027f8 did not finish!" error, I figured I messed
something up badly with my new certs, so I blew away my
/etc/freeradius directory, reinstalled freeradius 2.2.0 again and
started from the ground up (it recreated the default certs).  Still
the same problem.  The other box is working flawlessly with 2.2.0 and
'production' certs.

>From Server:
$ eapol_test -c peap-mschapv2.conf -s XXXXXXX

Output on successful server:
[snip]
EAP: EAP entering state RECEIVED
EAP: Received EAP-Success
EAP: EAP entering state SUCCESS
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
EAPOL: IEEE 802.1X for plaintext connection; no EAPOL-Key frames required
WPA: EAPOL processing complete
EAPOL: SUPP_PAE entering state AUTHENTICATED
EAPOL: SUPP_BE entering state RECEIVE
EAPOL: SUPP_BE entering state SUCCESS
EAPOL: SUPP_BE entering state IDLE
eapol_sm_cb: success=1
EAPOL: Successfully fetched key (len=32)
PMK from EAPOL - hexdump(len=32): fe a7 76 cd 59 70 e1 d2 fb 1d fe 66
32 7c 12 d5 5f f4 29 12 8b 82 0a 17 36 83 a1 b7 93 71 fb 61
EAP: deinitialize previously used EAP method (25, PEAP) at EAP deinit
ENGINE: engine deinit
MPPE keys OK: 1  mismatch: 0
SUCCESS

Output on failed server:
[snip]
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request id=8 method=25 vendor=0 vendorMethod=0
EAP: EAP entering state METHOD
SSL: Received packet(len=91) - Flags 0x00
EAP-PEAP: received 85 bytes encrypted data for Phase 2
EAP-PEAP: Decrypted Phase 2 EAP - hexdump(len=47): 1a 03 07 00 2e 53
3d 46 45 36 37 32 46 35 44 33 34 42 31 30 34 34 43 31 30 44 33 34 39
30 33 41 41 43 31 34 35 34 34 34 35 43 43 45 32 32 39
EAP-PEAP: received Phase 2: code=1 identifier=8 length=51
EAP-PEAP: Phase 2 Request: type=26
EAP-MSCHAPV2: RX identifier 8 mschapv2_id 7
EAP-MSCHAPV2: Received success
EAP-MSCHAPV2: Invalid authenticator response in success request
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: startWhen --> 0
EAPOL test timed out
EAPOL: EAP key not available
EAP: deinitialize previously used EAP method (25, PEAP) at EAP deinit
ENGINE: engine deinit
MPPE keys OK: 0  mismatch: 1
FAILURE

And on the server debug, when it fails, I get an Access-Challenge,
followed by "EAP session for state 0x56783e8f517027f8 did not finish!"
 It's not Windows though, so I'm puzzled.

Server output on failure:
Sending Access-Challenge of id 7 to 127.0.0.1 port 48493
        EAP-Message =
0x0108005b19001703010050cdc6ba2c896eb5118cfb064080452617ab9dac048c60afbdb3a962afa01555069719ac14235bae1e3108e284d27ef322609824fe6898c5cc497db9833039b37e92c921285a0b9bdbcafc0861676b5082
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xa24b0ed9a54317a0931e3b8d4f719448
Thu Nov  8 11:26:17 2012 : Info: Finished request 16.
Thu Nov  8 11:26:17 2012 : Debug: Going to the next request
Thu Nov  8 11:26:17 2012 : Debug: Waking up in 4.9 seconds.
Thu Nov  8 11:26:22 2012 : Info: Cleaning up request 9 ID 0 with timestamp +510
Thu Nov  8 11:26:22 2012 : Info: Cleaning up request 10 ID 1 with timestamp +510
Thu Nov  8 11:26:22 2012 : Info: Cleaning up request 11 ID 2 with timestamp +511
Thu Nov  8 11:26:22 2012 : Info: Cleaning up request 12 ID 3 with timestamp +511
Thu Nov  8 11:26:22 2012 : Info: Cleaning up request 13 ID 4 with timestamp +511
Thu Nov  8 11:26:22 2012 : Info: Cleaning up request 14 ID 5 with timestamp +511
Thu Nov  8 11:26:22 2012 : Info: Cleaning up request 15 ID 6 with timestamp +511
Thu Nov  8 11:26:22 2012 : Info: Cleaning up request 16 ID 7 with timestamp +511
Thu Nov  8 11:26:22 2012 : Debug: WARNING:
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Thu Nov  8 11:26:22 2012 : Debug: WARNING: !! EAP session for state
0xa24b0ed9a54317a0 did not finish!
Thu Nov  8 11:26:22 2012 : Debug: WARNING: !! Please read
http://wiki.freeradius.org/Certificate_Compatibility
Thu Nov  8 11:26:22 2012 : Debug: WARNING:
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!

Things I've already checked:
 - eap.conf is identical on both servers (I copied it over).
 - There were some old discussions about a Samba bug, but both servers
are running 3.5.6.
 - radtest with PAP / users file is still working successfully.

Can someone point me in the right direction?  Where should I be
looking?  Is something lingering from my certificates failure or is
the problem elsewhere?

Thanks in advance,
Jordan