PEAP Authentication Problems with Windows Users

Jacob Dawson dawson at vt.edu
Mon Aug 29 23:28:38 CEST 2011 

We're having an odd problem here, and I just can't pin down quite where to look to fix it.  We use PEAP-MSCHAPv2 for authentication of our windows domain users on wireless.  This is accomplished by terminating the TLS conversation at FreeRADIUS and sending along the MSCHAP conversation to an IAS server. We've tested this in the past, and it's worked fine, and we're doing a modified form of this in production, and it's working fine, but I've lately been unable to get it to work in our pre-production 2.1.11 environment.  What's particularly odd is that it's only affecting the Windows clients.  My OS X client doing PEAP with the same credentials is happy.

What we're doing in production, which continues to work, is this:
We terminate TLS at FreeRADIUS.  This allows us to manage the wireless service certificate there, keeps the IAS operators from having to keep up with it.
We proxy the MSCHAP conversation to our OpenRADIUS server (which is also running and interacting with TACACS).
OpenRADIUS proxies the CHAP stuff to IAS.  It may be tinkering with the MSCHAP fields from IAS to make them more compatible (basically changing out the secrets because it's standing in the middle).
Successful authentication then percolates back through the chain and the user is happy.

In pre-production, it looks like this:
Request comes in from Windows client, is recognized to be a Domain authentication request, gets proxied to an FR virtual server.
Said virtual server gets it, processes the TLS and terminates it, and proxies the MSCHAP conversation to IAS.
IAS does its MSCHAP thing, accepts the user.
Access-Accept percolates back up through the chain.  We send an access challenge, the user sends an Access request, and FR says the user said something weird, so it's rejecting them.

Request comes in from non-windows client, is recognized to be Domain authentication request, gets proxied to an FR virtual server
Said virtual server gets it, processes the TLS and terminates it, and proxies the MSCHAP conversation to IAS.
IAS does its MSCHAP thing, accepts the user.
Access-Accept percolates back up through the chain.  We send an access challenge, the user sends an Access request, and FR says everything's fine, user gets Access-Accept.

Thoughts on where I need to look?  I can't parse out what's happening to cause a response to be invalid for Windows users but not for, say, Mac users.  Our initial guess here is that the Windows clients are looking at the MPPE keys, and are unhappy about them, whereas the Mac clients are not, though we suspect neither set of clients requires them.

Posting relevant bits of debug output below.

Thanks much,
Jacob M. Dawson

---------

Pre-production failure:
rad_recv: Access-Request packet from host 198.82.171.153 port 32768, id=138, length=293
	User-Name = "HOKIES\\dawson"
	Calling-Station-Id = "00-1d-e0-90-5f-db"
	Called-Station-Id = "00-21-55-4d-c4-40:CNS-Test"
	NAS-Port = 29
	NAS-IP-Address = 198.82.171.153
	NAS-Identifier = "cas-6509-3.wsm8b"
	Airespace-Wlan-Id = 17
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "1381"
	EAP-Message = 0x020b005f19001703010054bdd79574acfa8744908880dfa66a9e861f5fff5d2b3b7e387679b867704afa60476df6cc1ac0f30d92a4dc753cebb4bc4e71f4e0bc4db75534ab2403ec993619f05ad02497597deaa193debe78641e14b4718e84
	State = 0x5b4a8e485341972bae816e794759d3ea
	Message-Authenticator = 0xc234d7f3f04c9d023687fd78e4d5c9da
(75) # Executing section authorize from file /usr/local/freeradius-2.1.11/etc/raddb/sites-enabled/default
(75)   group authorize {
(75)  - entering group authorize {...}
(75)    policy split_username_prefix {
(75)   - entering policy split_username_prefix {...}
(75)    ? if (request:User-Name =~ /^([a-z]+)[\\\/]+([-a-z0-9_.]+)$/i)
(75) ? Evaluating (request:User-Name =~ /^([a-z]+)[\\\/]+([-a-z0-9_.]+)$/i) -> TRUE
(75)    ? if (request:User-Name =~ /^([a-z]+)[\\\/]+([-a-z0-9_.]+)$/i) -> TRUE
(75)     if (request:User-Name =~ /^([a-z]+)[\\\/]+([-a-z0-9_.]+)$/i) {
(75)    - entering if (request:User-Name =~ /^([a-z]+)[\\\/]+([-a-z0-9_.]+)$/i) {...}
(75)     update request {
(75) 	expand: %{2} -> dawson
(75) 	expand: %{1} -> HOKIES
(75)     } # update request = notfound
(75)     [updated] = updated
(75)    - if (request:User-Name =~ /^([a-z]+)[\\\/]+([-a-z0-9_.]+)$/i) returns updated
(75)     ... skipping else for request 75: Preceding "if" was taken
(75)   - policy split_username_prefix returns updated
(75)    policy split_username_suffix {
(75)   - entering policy split_username_suffix {...}
(75)    ? if (request:User-Name =~ /^([^@]*)@([-[:alnum:]]+\.[-[:alnum:].]+)$/i)
(75) ? Evaluating (request:User-Name =~ /^([^@]*)@([-[:alnum:]]+\.[-[:alnum:].]+)$/i) -> FALSE
(75)    ? if (request:User-Name =~ /^([^@]*)@([-[:alnum:]]+\.[-[:alnum:].]+)$/i) -> FALSE
(75)     else else {
(75)    - entering else else {...}
(75)     [noop] = noop
(75)    - else else returns noop
(75)   - policy split_username_suffix returns noop
(75)   [preprocess] = ok
(75) auth_log : 	expand: /usr/local/freeradius-2.1.11/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /usr/local/freeradius-2.1.11/var/log/radius/radacct/198.82.171.153/auth-detail-20110823
(75) auth_log : /usr/local/freeradius-2.1.11/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /usr/local/freeradius-2.1.11/var/log/radius/radacct/198.82.171.153/auth-detail-20110823
(75) auth_log : 	expand: %t -> Tue Aug 23 10:40:16 2011
(75)   [auth_log] = ok
rlm_perl: Added pair NAS-Port-Type = Wireless-802.11
rlm_perl: Added pair Service-Type = Framed-User
rlm_perl: Added pair Tunnel-Type = VLAN
rlm_perl: Added pair State = 0x5b4a8e485341972bae816e794759d3ea
rlm_perl: Added pair Called-Station-Id = 00-21-55-4d-c4-40:CNS-Test
rlm_perl: Added pair Message-Authenticator = 0xc234d7f3f04c9d023687fd78e4d5c9da
rlm_perl: Added pair Airespace-Wlan-Id = 17
rlm_perl: Added pair Stripped-User-Domain = HOKIES
rlm_perl: Added pair NAS-IP-Address = 198.82.171.153
rlm_perl: Added pair Tunnel-Private-Group-Id = 1381
rlm_perl: Added pair Tunnel-Medium-Type = IEEE-802
rlm_perl: Added pair Calling-Station-Id = 00-1d-e0-90-5f-db
rlm_perl: Added pair User-Name = HOKIES\\dawson
rlm_perl: Added pair NAS-Identifier = cas-6509-3.wsm8b
rlm_perl: Added pair EAP-Message = 0x020b005f19001703010054bdd79574acfa8744908880dfa66a9e861f5fff5d2b3b7e387679b867704afa60476df6cc1ac0f30d92a4dc753cebb4bc4e71f4e0bc4db75534ab2403ec993619f05ad02497597deaa193debe78641e14b4718e84
rlm_perl: Added pair Stripped-User-Name = dawson
rlm_perl: Added pair NAS-Port = 29
rlm_perl: Added pair Framed-MTU = 1300
(75)   [perl] = noop
(75)   ? if ("%{Stripped-User-Domain}" != "HOKIES")
(75) 	expand: %{Stripped-User-Domain} -> HOKIES
(75) ? Evaluating ("%{Stripped-User-Domain}" != "HOKIES") -> FALSE
(75)   ? if ("%{Stripped-User-Domain}" != "HOKIES") -> FALSE
(75) eap : EAP packet type response id 11 length 95
(75) eap : Continuing tunnel setup.
(75)   [eap] = ok
(75) Found Auth-Type = ?
(75) # Executing group from file /usr/local/freeradius-2.1.11/etc/raddb/sites-enabled/default
(75)   group authenticate {
(75)  - entering group authenticate {...}
(75) eap : Request found, released from the list
(75) eap : EAP/peap
(75) eap : processing type peap
(75) peap : processing EAP-TLS
(75) peap : eaptls_verify returned 7 
(75) peap : Done initial handshake
(75) peap : eaptls_process returned 7 
(75) peap : FR_TLS_OK
(75) peap : Session established.  Decoding tunneled attributes.
(75) peap : Peap state phase2
(75) peap : EAP type mschapv2
(75) peap : Got tunneled request
	EAP-Message = 0x020b00481a020b004331bf4d439d3028cbdba8fff532c04f1cf60000000000000000bee44f94acbe708a682535adc0505e56a87462580576d06600484f4b4945535c646177736f6e
server  {
(75) peap : Setting User-Name to HOKIES\dawson
Sending tunneled request
	EAP-Message = 0x020b00481a020b004331bf4d439d3028cbdba8fff532c04f1cf60000000000000000bee44f94acbe708a682535adc0505e56a87462580576d06600484f4b4945535c646177736f6e
	FreeRADIUS-Proxied-To = 127.0.0.1
	User-Name = "HOKIES\\dawson"
	State = 0x21ebcfee21e0d5ab22fbf5cfb29bfd25
	NAS-Port-Type = Wireless-802.11
	Service-Type = Framed-User
	Tunnel-Type:0 = VLAN
	Called-Station-Id = "00-21-55-4d-c4-40:CNS-Test"
	NAS-IP-Address = 198.82.171.153
	Tunnel-Private-Group-Id:0 = "1381"
	Tunnel-Medium-Type:0 = IEEE-802
	Calling-Station-Id = "00-1d-e0-90-5f-db"
	NAS-Identifier = "cas-6509-3.wsm8b"
	NAS-Port = 29
	Framed-MTU = 1300
server proxy-inner-tunnel {
(75) # Executing section authorize from file /usr/local/freeradius-2.1.11/etc/raddb/sites-enabled/proxy-inner-tunnel
(75)   group authorize {
(75)  - entering group authorize {...}
(75)   ? if ("%{User-Name}" =~ /^(host\/.*)$/)
(75) 	expand: %{User-Name} -> HOKIES\dawson
(75) ? Evaluating ("%{User-Name}" =~ /^(host\/.*)$/) -> FALSE
(75)   ? if ("%{User-Name}" =~ /^(host\/.*)$/) -> FALSE
(75)    else else {
(75)   - entering else else {...}
(75)    update control {
(75)    } # update control = notfound
(75)   - else else returns notfound
} # server proxy-inner-tunnel
(75) peap : Got tunneled reply code 0
  PEAP: Calling authenticate in order to initiate tunneled EAP session.
(75) # Executing group from file /usr/local/freeradius-2.1.11/etc/raddb/sites-enabled/proxy-inner-tunnel
(75)   group authenticate {
(75)  - entering group authenticate {...}
(75) eap : Request found, released from the list
(75) eap : EAP/mschapv2
(75) eap : processing type mschapv2
rlm_eap_mschapv2: cancelling authentication and letting it be proxied
(75) eap :   Not-EAP proxy set.  Not composing EAP
(75)   [eap] = handled
  PEAP: Tunneled authentication will be proxied to DomainUser
  PEAP: Remembering to do EAP-MS-CHAP-V2 post-proxy.
(75) eap :   Tunneled session will be proxied.  Not doing EAP.
(75)   [eap] = handled
(75)   WARNING: Empty pre-proxy section.  Using default return values.
Sending Access-Request of id 161 to 198.82.160.219 port 1812
	User-Name = "HOKIES\\dawson"
	NAS-Port-Type = Wireless-802.11
	Service-Type = Framed-User
	Tunnel-Type:0 = VLAN
	Called-Station-Id = "00-21-55-4d-c4-40:CNS-Test"
	NAS-IP-Address = 198.82.171.153
	Tunnel-Private-Group-Id:0 = "1381"
	Tunnel-Medium-Type:0 = IEEE-802
	Calling-Station-Id = "00-1d-e0-90-5f-db"
	NAS-Identifier = "cas-6509-3.wsm8b"
	NAS-Port = 29
	Framed-MTU = 1300
	MS-CHAP-Challenge = 0xd3827513a357a99d4eb9a5c87a716418
	MS-CHAP2-Response = 0x0b4fbf4d439d3028cbdba8fff532c04f1cf60000000000000000bee44f94acbe708a682535adc0505e56a87462580576d066
	Proxy-State = 0x313338
(75) Proxying request to home server 198.82.160.219 port 1812
Sending Access-Request of id 161 to 198.82.160.219 port 1812
	User-Name = "HOKIES\\dawson"
	NAS-Port-Type = Wireless-802.11
	Service-Type = Framed-User
	Tunnel-Type:0 = VLAN
	Called-Station-Id = "00-21-55-4d-c4-40:CNS-Test"
	NAS-IP-Address = 198.82.171.153
	Tunnel-Private-Group-Id:0 = "1381"
	Tunnel-Medium-Type:0 = IEEE-802
	Calling-Station-Id = "00-1d-e0-90-5f-db"
	NAS-Identifier = "cas-6509-3.wsm8b"
	NAS-Port = 29
	Framed-MTU = 1300
	MS-CHAP-Challenge = 0xd3827513a357a99d4eb9a5c87a716418
	MS-CHAP2-Response = 0x0b4fbf4d439d3028cbdba8fff532c04f1cf60000000000000000bee44f94acbe708a682535adc0505e56a87462580576d066
	Proxy-State = 0x313338
Waking up in 0.2 seconds.
rad_recv: Access-Accept packet from host 198.82.160.219 port 1812, id=161, length=219
DEBUG: Compare b472204 to calculated digest f796ca40, secret temporaryS3CR3T
	Proxy-State = 0x313338
	Framed-Protocol = PPP
	Service-Type = Framed-User
	Class = 0x6538078a000001370001c652a0db01cc5476fe414ece0000000000004586
	MS-MPPE-Recv-Key = 0x7208bb9a9555b125d123303ac3db12a1
	MS-MPPE-Send-Key = 0x0cd6218a695a558ade111bcd7b05cfc2
	MS-CHAP2-Success = 0x0b533d32434230433038364541464632333233453842414534314643443231333130453939354641454134
	MS-CHAP-Domain = "\013HOKIES"
(75) # Executing section post-proxy from file /usr/local/freeradius-2.1.11/etc/raddb/sites-enabled/default
(75)   group post-proxy {
(75)  - entering group post-proxy {...}
(75) eap : Doing post-proxy callback
(75) eap : Passing reply from proxy back into the tunnel.
server proxy-inner-tunnel {
(75) eap : Passing reply back for EAP-MS-CHAP-V2
(75) # Executing section post-proxy from file /usr/local/freeradius-2.1.11/etc/raddb/sites-enabled/proxy-inner-tunnel
(75)   group post-proxy {
(75)  - entering group post-proxy {...}
(75)   [eap] = noop
(75)   WARNING: Empty post-auth section.  Using default return values.
} # server proxy-inner-tunnel
(75) eap : Final reply from tunneled session code 2
	Proxy-State = 0x313338
	Framed-Protocol = PPP
	Service-Type = Framed-User
	Class = 0x6538078a000001370001c652a0db01cc5476fe414ece0000000000004586
	MS-MPPE-Recv-Key = 0x7208bb9a9555b125d123303ac3db12a1
	MS-MPPE-Send-Key = 0x0cd6218a695a558ade111bcd7b05cfc2
	MS-CHAP2-Success = 0x0b533d32434230433038364541464632333233453842414534314643443231333130453939354641454134
	MS-CHAP-Domain = "\013HOKIES"
(75) eap : Got reply 2
(75) eap : Got tunneled reply RADIUS code 2
	Proxy-State = 0x313338
	Framed-Protocol = PPP
	Service-Type = Framed-User
	Class = 0x6538078a000001370001c652a0db01cc5476fe414ece0000000000004586
	MS-MPPE-Recv-Key = 0x7208bb9a9555b125d123303ac3db12a1
	MS-MPPE-Send-Key = 0x0cd6218a695a558ade111bcd7b05cfc2
	MS-CHAP2-Success = 0x0b533d32434230433038364541464632333233453842414534314643443231333130453939354641454134
	MS-CHAP-Domain = "\013HOKIES"
(75) eap : Tunneled authentication was successful.
(75) eap : SUCCESS
(75) eap : Reply was handled
(75)   [eap] = ok
(75) Found Auth-Type = ?
(75) Found Auth-Type = ?
(75) Warning:  Found 2 auth-types on request for user 'HOKIES\dawson'
(75) Auth-Type = Accept, accepting the user
(75) Login OK: [HOKIES\\dawson] (from client 198.82.171.153 port 29 cli 00-1d-e0-90-5f-db)
(75) # Executing section post-auth from file /usr/local/freeradius-2.1.11/etc/raddb/sites-enabled/default
(75)   group post-auth {
(75)  - entering group post-auth {...}
(75)   [exec] = noop
Sending Access-Challenge of id 138 to 198.82.171.153 port 32768
	EAP-Message = 0x010c00261900170301001b0167b434a0313cb3f29b20e1f731efe3d173083c964cda1451135a
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x5b4a8e485246972bae816e794759d3ea
(75) Finished request 75.
Waking up in 0.2 seconds.
rad_recv: Access-Request packet from host 198.82.171.153 port 32768, id=139, length=236
	User-Name = "HOKIES\\dawson"
	Calling-Station-Id = "00-1d-e0-90-5f-db"
	Called-Station-Id = "00-21-55-4d-c4-40:CNS-Test"
	NAS-Port = 29
	NAS-IP-Address = 198.82.171.153
	NAS-Identifier = "cas-6509-3.wsm8b"
	Airespace-Wlan-Id = 17
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "1381"
	EAP-Message = 0x020c00261900170301001b00dae368dd150e9d42e0c8888cb128e6ecc520b887a849a8a1d743
	State = 0x5b4a8e485246972bae816e794759d3ea
	Message-Authenticator = 0x26b42d72271f1819599977a28920622f
(76) # Executing section authorize from file /usr/local/freeradius-2.1.11/etc/raddb/sites-enabled/default
(76)   group authorize {
(76)  - entering group authorize {...}
(76)    policy split_username_prefix {
(76)   - entering policy split_username_prefix {...}
(76)    ? if (request:User-Name =~ /^([a-z]+)[\\\/]+([-a-z0-9_.]+)$/i)
(76) ? Evaluating (request:User-Name =~ /^([a-z]+)[\\\/]+([-a-z0-9_.]+)$/i) -> TRUE
(76)    ? if (request:User-Name =~ /^([a-z]+)[\\\/]+([-a-z0-9_.]+)$/i) -> TRUE
(76)     if (request:User-Name =~ /^([a-z]+)[\\\/]+([-a-z0-9_.]+)$/i) {
(76)    - entering if (request:User-Name =~ /^([a-z]+)[\\\/]+([-a-z0-9_.]+)$/i) {...}
(76)     update request {
(76) 	expand: %{2} -> dawson
(76) 	expand: %{1} -> HOKIES
(76)     } # update request = notfound
(76)     [updated] = updated
(76)    - if (request:User-Name =~ /^([a-z]+)[\\\/]+([-a-z0-9_.]+)$/i) returns updated
(76)     ... skipping else for request 76: Preceding "if" was taken
(76)   - policy split_username_prefix returns updated
(76)    policy split_username_suffix {
(76)   - entering policy split_username_suffix {...}
(76)    ? if (request:User-Name =~ /^([^@]*)@([-[:alnum:]]+\.[-[:alnum:].]+)$/i)
(76) ? Evaluating (request:User-Name =~ /^([^@]*)@([-[:alnum:]]+\.[-[:alnum:].]+)$/i) -> FALSE
(76)    ? if (request:User-Name =~ /^([^@]*)@([-[:alnum:]]+\.[-[:alnum:].]+)$/i) -> FALSE
(76)     else else {
(76)    - entering else else {...}
(76)     [noop] = noop
(76)    - else else returns noop
(76)   - policy split_username_suffix returns noop
(76)   [preprocess] = ok
(76) auth_log : 	expand: /usr/local/freeradius-2.1.11/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /usr/local/freeradius-2.1.11/var/log/radius/radacct/198.82.171.153/auth-detail-20110823
(76) auth_log : /usr/local/freeradius-2.1.11/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /usr/local/freeradius-2.1.11/var/log/radius/radacct/198.82.171.153/auth-detail-20110823
(76) auth_log : 	expand: %t -> Tue Aug 23 10:40:16 2011
(76)   [auth_log] = ok
rlm_perl: Added pair NAS-Port-Type = Wireless-802.11
rlm_perl: Added pair Service-Type = Framed-User
rlm_perl: Added pair Tunnel-Type = VLAN
rlm_perl: Added pair State = 0x5b4a8e485246972bae816e794759d3ea
rlm_perl: Added pair Called-Station-Id = 00-21-55-4d-c4-40:CNS-Test
rlm_perl: Added pair Message-Authenticator = 0x26b42d72271f1819599977a28920622f
rlm_perl: Added pair Airespace-Wlan-Id = 17
rlm_perl: Added pair Stripped-User-Domain = HOKIES
rlm_perl: Added pair NAS-IP-Address = 198.82.171.153
rlm_perl: Added pair Tunnel-Private-Group-Id = 1381
rlm_perl: Added pair Tunnel-Medium-Type = IEEE-802
rlm_perl: Added pair Calling-Station-Id = 00-1d-e0-90-5f-db
rlm_perl: Added pair User-Name = HOKIES\\dawson
rlm_perl: Added pair NAS-Identifier = cas-6509-3.wsm8b
rlm_perl: Added pair EAP-Message = 0x020c00261900170301001b00dae368dd150e9d42e0c8888cb128e6ecc520b887a849a8a1d743
rlm_perl: Added pair Stripped-User-Name = dawson
rlm_perl: Added pair NAS-Port = 29
rlm_perl: Added pair Framed-MTU = 1300
(76)   [perl] = noop
(76)   ? if ("%{Stripped-User-Domain}" != "HOKIES")
(76) 	expand: %{Stripped-User-Domain} -> HOKIES
(76) ? Evaluating ("%{Stripped-User-Domain}" != "HOKIES") -> FALSE
(76)   ? if ("%{Stripped-User-Domain}" != "HOKIES") -> FALSE
(76) eap : EAP packet type response id 12 length 38
(76) eap : Continuing tunnel setup.
(76)   [eap] = ok
(76) Found Auth-Type = ?
(76) # Executing group from file /usr/local/freeradius-2.1.11/etc/raddb/sites-enabled/default
(76)   group authenticate {
(76)  - entering group authenticate {...}
(76) eap : Request found, released from the list
(76) eap : EAP/peap
(76) eap : processing type peap
(76) peap : processing EAP-TLS
(76) peap : eaptls_verify returned 7 
(76) peap : Done initial handshake
(76) peap : eaptls_process returned 7 
(76) peap : FR_TLS_OK
(76) peap : Session established.  Decoding tunneled attributes.
(76) peap : Peap state send tlv success
(76) peap : Received EAP-TLV response.
(76) peap : Client rejected our response.  The password is probably incorrect.
(76) peap : We sent a success, but received something weird in return.
(76) eap : Handler failed in EAP/peap
(76) eap : Failed in EAP select
(76)   [eap] = invalid
(76) Failed to authenticate the user.
(76) Login incorrect: [HOKIES\\dawson] (from client 198.82.171.153 port 29 cli 00-1d-e0-90-5f-db)
(76) Using Post-Auth-Type Reject
(76) # Executing group from file /usr/local/freeradius-2.1.11/etc/raddb/sites-enabled/default
(76)   group REJECT {
(76)  - entering group REJECT {...}
(76) attr_filter.access_reject : 	expand: %{User-Name} -> HOKIES\dawson
attr_filter: Matched entry DEFAULT at line 11
(76)   [attr_filter.access_reject] = updated
(76) Finished request 76.
Waking up in 0.2 seconds.
Waking up in 0.6 seconds.
(76) Sending delayed reject
Sending Access-Reject of id 139 to 198.82.171.153 port 32768
	EAP-Message = 0x040c0004
	Message-Authenticator = 0x00000000000000000000000000000000

-----

Production Success:
Waking up in 4.9 seconds.
	User-Name = "HOKIES\\dawson"
	Calling-Station-Id = "00-1d-e0-90-5f-db"
	Called-Station-Id = "00-21-55-4d-c4-40:CNS-Test"
	NAS-Port = 29
	NAS-IP-Address = 198.82.171.153
	NAS-Identifier = "cas-6509-3.wsm8b"
	Airespace-Wlan-Id = 17
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "1381"
	EAP-Message = 0x020a005f1900170301005499a000fc4d08b0c067d3251047d61b836767466160c386b38d37d4b6c39b07ce3b09c85590c8a923419e6f0ae464ac472050214b71b4d641e06f8a439348319233d622cd7900f8f172726407b0010bcb54c6a1d6
	State = 0x764462057e4e7bc59f1c525ed4400d40
	Message-Authenticator = 0xd9566738adb17439ce7d7568c8bc8264
+- entering group authorize
++[mschap] returns noop
  rlm_eap: EAP packet type response id 10 length 95
  rlm_eap: Continuing tunnel setup.
++[eap] returns ok
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
+- entering group EAP
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
  eaptls_verify returned 7 
  rlm_eap_tls: Done initial handshake
  eaptls_process returned 7 
  rlm_eap_peap: EAPTLS_OK
  rlm_eap_peap: Session established.  Decoding tunneled attributes.
  rlm_eap_peap: EAP type mschapv2
  PEAP: Setting User-Name to HOKIES\dawson
+- entering group authorize
++? if ("%{User-Name}" =~ /^(host\/.*)$/)
	expand: %{User-Name} -> HOKIES\dawson
? Evaluating ("%{User-Name}" =~ /^(host\/.*)$/) -> FALSE
++? if ("%{User-Name}" =~ /^(host\/.*)$/) -> FALSE
++- entering else else
+++[control] returns notfound
++- else else returns notfound
  PEAP: Calling authenticate in order to initiate tunneled EAP session.
+- entering group authenticate
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/mschapv2
  rlm_eap: processing type mschapv2
  Not-EAP proxy set.  Not composing EAP
++[eap] returns handled
  PEAP: Tunneled authentication will be proxied to openradius
  PEAP: Remembering to do EAP-MS-CHAP-V2 post-proxy.
  Tunneled session will be proxied.  Not doing EAP.
++[eap] returns handled
+- entering group pre-proxy
    preproxy_users: Matched entry DEFAULT at line 1
++[files] returns ok
	User-Name = "HOKIES\\dawson"
	Calling-Station-Id = "00-1d-e0-90-5f-db"
	Called-Station-Id = "00-21-55-4d-c4-40:CNS-Test"
	NAS-Port = 29
	NAS-IP-Address := 198.82.247.103
	NAS-Identifier = "cas-6509-3.wsm8b"
	Airespace-Wlan-Id = 17
	Service-Type := Framed-User
	Framed-MTU = 1300
	NAS-Port-Type := Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "1381"
	MS-CHAP-Challenge = 0x20760eb105e545d6a131f324c1d30464
	MS-CHAP2-Response = 0x0a4f84e590f059f31dc3ca5b621b238582190000000000000000385984c78f91f816edb8f1b279838a0a890bdd6573bac9f7
	Proxy-State = 0x323433
Proxying request 9 to home server 198.82.247.67 port 1812
	User-Name = "HOKIES\\dawson"
	Calling-Station-Id = "00-1d-e0-90-5f-db"
	Called-Station-Id = "00-21-55-4d-c4-40:CNS-Test"
	NAS-Port = 29
	NAS-IP-Address := 198.82.247.103
	NAS-Identifier = "cas-6509-3.wsm8b"
	Airespace-Wlan-Id = 17
	Service-Type := Framed-User
	Framed-MTU = 1300
	NAS-Port-Type := Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "1381"
	MS-CHAP-Challenge = 0x20760eb105e545d6a131f324c1d30464
	MS-CHAP2-Response = 0x0a4f84e590f059f31dc3ca5b621b238582190000000000000000385984c78f91f816edb8f1b279838a0a890bdd6573bac9f7
	Proxy-State = 0x323433
Going to the next request
Waking up in 0.9 seconds.
	Framed-Protocol = PPP
	Service-Type = Framed-User
	MS-MPPE-Recv-Key = 0xe32365fe45921738025084f44fd7822a
	MS-MPPE-Send-Key = 0xf65c13fbcd70a80768ea868ec27085ff
	MS-CHAP2-Success = 0x0a533d46333146313034313438374339373131303542344546363341364339333146344135424141383434
	MS-CHAP-Domain = "\nHOKIES"
+- entering group post-proxy
  rlm_eap: Doing post-proxy callback
  PEAP: Passing reply from proxy back into the tunnel.
  PEAP: Passing reply back for EAP-MS-CHAP-V2
+- entering group post-proxy
  rlm_eap: Doing post-proxy callback
  rlm_eap_mschapv2: Passing reply from proxy back into the tunnel 0x1cd469a0 2.
  rlm_eap_mschapv2: Authentication succeeded.
MSCHAP Success 
++[eap] returns ok
 PEAP: Got reply 11
  PEAP: Got tunneled Access-Challenge
  PEAP: Reply was handled
++[eap] returns ok
	EAP-Message = 0x010b004a1900170301003f084cf62c48fb9b9e951aa3801c9a88bbe2078c7a667df320929296299bdff2863bf8572a744dac5d9409953cda9855feca24aa24b8205677fbf3f7e3767f36
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x764462057f4f7bc59f1c525ed4400d40
Finished request 9.
Going to the next request
Waking up in 4.9 seconds.
	User-Name = "HOKIES\\dawson"
	Calling-Station-Id = "00-1d-e0-90-5f-db"
	Called-Station-Id = "00-21-55-4d-c4-40:CNS-Test"
	NAS-Port = 29
	NAS-IP-Address = 198.82.171.153
	NAS-Identifier = "cas-6509-3.wsm8b"
	Airespace-Wlan-Id = 17
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "1381"
	EAP-Message = 0x020b001d19001703010012091d2f1089b72dd14c76daf331c2dc4de167
	State = 0x764462057f4f7bc59f1c525ed4400d40
	Message-Authenticator = 0xee39bc3d804727c33f69fc7d8172d2bf
+- entering group authorize
++[mschap] returns noop
  rlm_eap: EAP packet type response id 11 length 29
  rlm_eap: Continuing tunnel setup.
++[eap] returns ok
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
+- entering group EAP
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
  eaptls_verify returned 7 
  rlm_eap_tls: Done initial handshake
  eaptls_process returned 7 
  rlm_eap_peap: EAPTLS_OK
  rlm_eap_peap: Session established.  Decoding tunneled attributes.
  rlm_eap_peap: EAP type mschapv2
  PEAP: Setting User-Name to HOKIES\dawson
+- entering group authorize
++? if ("%{User-Name}" =~ /^(host\/.*)$/)
	expand: %{User-Name} -> HOKIES\dawson
? Evaluating ("%{User-Name}" =~ /^(host\/.*)$/) -> FALSE
++? if ("%{User-Name}" =~ /^(host\/.*)$/) -> FALSE
++- entering else else
+++[control] returns notfound
++- else else returns notfound
  PEAP: Calling authenticate in order to initiate tunneled EAP session.
+- entering group authenticate
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/mschapv2
  rlm_eap: processing type mschapv2
  rlm_eap: Freeing handler
++[eap] returns ok
  PEAP: Tunneled authentication was successful.
  rlm_eap_peap: SUCCESS
++[eap] returns handled
	EAP-Message = 0x010c00261900170301001badffc5c8196273037ffc5ae8b421cb5a11d4cdbf3d67e521a2dd10
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x764462057c487bc59f1c525ed4400d40
Finished request 10.
Going to the next request
Waking up in 4.9 seconds.
	User-Name = "HOKIES\\dawson"
	Calling-Station-Id = "00-1d-e0-90-5f-db"
	Called-Station-Id = "00-21-55-4d-c4-40:CNS-Test"
	NAS-Port = 29
	NAS-IP-Address = 198.82.171.153
	NAS-Identifier = "cas-6509-3.wsm8b"
	Airespace-Wlan-Id = 17
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "1381"
	EAP-Message = 0x020c00261900170301001be252b19386182f2a3d9b6255f0b51007da074f90f732568c1dfbb8
	State = 0x764462057c487bc59f1c525ed4400d40
	Message-Authenticator = 0xc04ab29e63cd60e30bfd3fed2ba3be09
+- entering group authorize
++[mschap] returns noop
  rlm_eap: EAP packet type response id 12 length 38
  rlm_eap: Continuing tunnel setup.
++[eap] returns ok
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
+- entering group EAP
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
  eaptls_verify returned 7 
  rlm_eap_tls: Done initial handshake
  eaptls_process returned 7 
  rlm_eap_peap: EAPTLS_OK
  rlm_eap_peap: Session established.  Decoding tunneled attributes.
  rlm_eap_peap: Received EAP-TLV response.
  rlm_eap_peap: Success
  rlm_eap: Freeing handler
++[eap] returns ok
perl_pool: item 0x17a6e7a0 asigned new request. Handled so far: 1
found interpetator at address 0x17a6e7a0
rlm_perl: no serial number; assuming non-TLS authentication
rlm_perl: Added pair NAS-Port-Type = Wireless-802.11
rlm_perl: Added pair Service-Type = Framed-User
rlm_perl: Added pair Tunnel-Type = VLAN
rlm_perl: Added pair State = 0x764462057c487bc59f1c525ed4400d40
rlm_perl: Added pair Called-Station-Id = 00-21-55-4d-c4-40:CNS-Test
rlm_perl: Added pair Message-Authenticator = 0xc04ab29e63cd60e30bfd3fed2ba3be09
rlm_perl: Added pair Airespace-Wlan-Id = 17
rlm_perl: Added pair EAP-Type = PEAP
rlm_perl: Added pair NAS-IP-Address = 198.82.171.153
rlm_perl: Added pair Tunnel-Private-Group-Id = 1381
rlm_perl: Added pair Tunnel-Medium-Type = IEEE-802
rlm_perl: Added pair Calling-Station-Id = 00-1d-e0-90-5f-db
rlm_perl: Added pair User-Name = HOKIES\\dawson
rlm_perl: Added pair NAS-Identifier = cas-6509-3.wsm8b
rlm_perl: Added pair EAP-Message = 0x020c00261900170301001be252b19386182f2a3d9b6255f0b51007da074f90f732568c1dfbb8
rlm_perl: Added pair NAS-Port = 29
rlm_perl: Added pair Framed-MTU = 1300
rlm_perl: Added pair User-Name = HOKIES\\dawson
rlm_perl: Added pair MS-MPPE-Recv-Key = 0x4e3e827b7fb173dbe293fadd607586b838cd55ae5261090fd483569509a070de
rlm_perl: Added pair EAP-Message = 0x030c0004
rlm_perl: Added pair MS-MPPE-Send-Key = 0xb43ef9e36d44d66d205184ee8ca81f0f14e3a52cd254bd27268c7c99f58a18b0
rlm_perl: Added pair Message-Authenticator = 0x00000000000000000000000000000000
rlm_perl: Added pair Auth-Type = EAP
perl_pool total/active/spare [32/0/32]
Unreserve perl at address 0x17a6e7a0
++[perl] returns ok
Login OK: [HOKIES\\\\dawson/<via Auth-Type = EAP>] (from client cas-6509-3.wsm8b port 29 cli 00-1d-e0-90-5f-db)
	User-Name = "HOKIES\\\\dawson"
	MS-MPPE-Recv-Key = 0x4e3e827b7fb173dbe293fadd607586b838cd55ae5261090fd483569509a070de
	EAP-Message = 0x030c0004
	MS-MPPE-Send-Key = 0xb43ef9e36d44d66d205184ee8ca81f0f14e3a52cd254bd27268c7c99f58a18b0
	Message-Authenticator = 0x00000000000000000000000000000000
Finished request 11.
Going to the next request
Waking up in 4.9 seconds.

More information about the Freeradius-Users mailing list