User attributed missing from access accept message
Carroll, Diana C
diana.c.carroll at intel.com
Sat Jun 19 02:44:28 CEST 2010
I have a bit of a puzzle:
I have a FreeRADIUS server that takes a TTLS request, handles the TLS outer authentication locally, and then proxies the MSCHAPv2 inner authentication to another server based on the realm specified in the user request.
When it receives the MSCHAPv2 access-accept message from one server (another FreeRADIUS server), it includes the user attributes in the access-accept message to the client as expected. However, when it receives the MSCHAPv2 access-accept message from the second server (an NPS server) it does not include the user attributes in the access-accept message to the client, resulting in a connection failure.
In the below logs, the same client is attempting to connect in both instances, with the same username. The outer TLS authentication (request, log, and result) is identical. The only differences for the inner MSCHAPv2 method are the username and the realm, and of course the server that the request is proxied to. Because of this, my best guess is that the differences in the server messages are triggering the different behavior. Since I don't have control over the NPS server to examine its configuration, I'm hoping there may be something I can do on the proxy server to correct the problem.
Logs are below, with usernames etc. scrubbed, of course. Input or suggestions would be much appreciated.
Thanks,
Diana
#################################################################################################################################################
##################################################################################################################################################
FAILED LOG: SERVER DOES NOT INCLUDE USER ATTRIBUTES IN ACCESS-ACCEPT.
##***********************************************************************************************************************************************
rlm_eap_ttls: Session established. Proceeding to decode tunneled attributes.
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 7
modcall[authorize]: module "preprocess" returns ok for request 7
radius_xlat: '/usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20100619'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%
Y%m%d expands to /usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-2010061
9
modcall[authorize]: module "auth_log" returns ok for request 7
modcall[authorize]: module "chap" returns noop for request 7
rlm_eap: No EAP-Message, not doing EAP
modcall[authorize]: module "eap" returns noop for request 7
rlm_mschap: Found MS-CHAP attributes. Setting 'Auth-Type = mschap'
modcall[authorize]: module "mschap" returns ok for request 7
modcall[authorize]: module "digest" returns noop for request 7
rlm_realm: Looking up realm "inner-realm.com" for User-Name = "rlm\inner-user-identity at inner-realm.com"
rlm_realm: Found realm "inner-realm.com"
rlm_realm: Adding Stripped-User-Name = "rlm\inner-user-identity"
rlm_realm: Proxying request from user rlm\inner-user-identity to realm inner-realm.com
rlm_realm: Adding Realm = "inner-realm.com"
rlm_realm: Preparing to proxy authentication request to realm "inner-realm.com"
modcall[authorize]: module "realmsuffix" returns updated for request 7
rlm_realm: Request already proxied. Ignoring.
modcall[authorize]: module "realmslash" returns noop for request 7
rlm_realm: Request already proxied. Ignoring.
modcall[authorize]: module "realmbackslash" returns noop for request 7
rlm_realm: Request already proxied. Ignoring.
modcall[authorize]: module "realmpercent" returns noop for request 7
rlm_fastusers: checking defaults
fastusers: Matched DEFAULT at 56
modcall[authorize]: module "fastusers" returns updated for request 7
modcall: leaving group authorize (returns updated) for request 7
TTLS: Tunneled authentication will be proxied to inner-realm.com
Tunneled session will be proxied. Not doing EAP.
modcall[authenticate]: module "eap" returns handled for request 7
modcall: leaving group authenticate (returns handled) for request 7
Sending Access-Request of id 0 to 143.185.231.134 port 1812
User-Name = "rlm\\inner-user-identity"
MS-CHAP-Challenge = 0xde2f71c04581580092f1e6a607518c80
MS-CHAP2-Response = 0xb00051ef59af51b36ded5808d861b07c722b00000000000000
00ff24005614e7135900d88db3c736c7c5abbccc1d6537d45c
NAS-IP-Address = 127.0.0.1
Proxy-State = 0x323437
Waking up in 3 seconds...
rad_recv: Access-Accept packet from host 143.185.231.134:1812, id=0, length=71
Proxy-State = 0x323437
Class = 0x844e067500000137000102008fb9e78600000000000000000000000001cb08
6c7fcf9744000000000000001b
Processing the post-proxy section of radiusd.conf
modcall: entering group post-proxy for request 7
TTLS: Passing reply from proxy back into the tunnel.
Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 7
radius_xlat: '/usr/local/var/log/radius/radacct/127.0.0.1/reply-detail-20100619
'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/reply-detail-
%Y%m%d expands to /usr/local/var/log/radius/radacct/127.0.0.1/reply-detail-20100
619
modcall[post-auth]: module "reply_log" returns ok for request 7
modcall: leaving group post-auth (returns ok) for request 7
POST-AUTH 2
TTLS: Got reply 2
TTLS: Got tunneled Access-Accept
fastusers: Matched DEFAULT at 56
modcall[authorize]: module "fastusers" returns updated for request 7
modcall: leaving group authorize (returns updated) for request 7
TTLS: Tunneled authentication will be proxied to inner-realm.com
Tunneled session will be proxied. Not doing EAP.
modcall[authenticate]: module "eap" returns handled for request 7
modcall: leaving group authenticate (returns handled) for request 7
Sending Access-Request of id 0 to 143.185.231.134 port 1812
User-Name = "rlm\\inner-user-identity"
MS-CHAP-Challenge = 0x0000000000000000000000000000000
MS-CHAP2-Response = 0x0000000000000000000000000000000000000000000000000000000000000000
NAS-IP-Address = 127.0.0.1
Proxy-State = 0x323437
Waking up in 3 seconds...
rad_recv: Access-Accept packet from host 143.185.231.134:1812, id=0, length=71
Proxy-State = 0x323437
Class = 0x844e067500000137000102008fb9e78600000000000000000000000001cb08
6c7fcf9744000000000000001b
Processing the post-proxy section of radiusd.conf
modcall: entering group post-proxy for request 7
TTLS: Passing reply from proxy back into the tunnel.
Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 7
radius_xlat: '/usr/local/var/log/radius/radacct/127.0.0.1/reply-detail-20100619
'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/reply-detail-
%Y%m%d expands to /usr/local/var/log/radius/radacct/127.0.0.1/reply-detail-20100
619
modcall[post-auth]: module "reply_log" returns ok for request 7
modcall: leaving group post-auth (returns ok) for request 7
POST-AUTH 2
TTLS: Got reply 2
TTLS: Got tunneled Access-Accept
TTLS: Reply was OK
rlm_eap: Freeing handler
modcall[post-proxy]: module "eap" returns ok for request 7
modcall: leaving group post-proxy (returns ok) for request 7
authorize: Skipping authorize in post-proxy stage
rad_check_password: Found Auth-Type EAP
rad_check_password: Found Auth-Type
Warning: Found 2 auth-types on request for user 'outer-identity'
rad_check_password: Auth-Type = Accept, accepting the user
Login OK: [outer-identity/<no User-Password attribute>] (from client 143.185.231.1
20 port 2048 cli outer-identity)
Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 7
radius_xlat: '/usr/local/var/log/radius/radacct/143.185.231.120/reply-detail-20
100619'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/reply-detail-
%Y%m%d expands to /usr/local/var/log/radius/radacct/143.185.231.120/reply-detail
-20100619
modcall[post-auth]: module "reply_log" returns ok for request 7
modcall: leaving group post-auth (returns ok) for request 7
Sending Access-Accept of id 247 to 143.185.231.120 port 19801
MS-MPPE-Recv-Key = 0xdc288be3eb579f52eb527e34141e57b7bc66bd6d87522df6193
fadda49fc7232
MS-MPPE-Send-Key = 0x044c7a5288aa39133f56fc16b4a441cb77cf17e7130e42e9f9f
8836ad6c7d8a6
EAP-Message = 0x03f70004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "outer-identity"
#################################################################################################################################################
##################################################################################################################################################
SUCCESSFUL LOG: SERVER INCLUDES USER ATTRIBUTES IN ACCESS-ACCEPT. (Also note it sends one last challenge message to the client before accepting)
##***********************************************************************************************************************************************
rlm_eap_ttls: Session established. Proceeding to decode tunneled attributes.
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 7
modcall[authorize]: module "preprocess" returns ok for request 7
radius_xlat: '/usr/local/var/log/radius/radacct/127.0.0.1/auth-detail-20100518'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/127.0.0.1/auth-
detail-20100518
modcall[authorize]: module "auth_log" returns ok for request 7
modcall[authorize]: module "chap" returns noop for request 7
rlm_eap: No EAP-Message, not doing EAP
modcall[authorize]: module "eap" returns noop for request 7
rlm_mschap: Found MS-CHAP attributes. Setting 'Auth-Type = mschap'
modcall[authorize]: module "mschap" returns ok for request 7
modcall[authorize]: module "digest" returns noop for request 7
rlm_realm: Looking up realm "inner-realm1.com.com" for User-Name = "user at inner-realm1.com.com"
rlm_realm: Found realm "inner-realm1.com.com"
rlm_realm: Proxying request from user user to realm inner-realm1.com.com
rlm_realm: Adding Realm = "inner-realm1.com.com"
rlm_realm: Preparing to proxy authentication request to realm "inner-realm1.com.com"
modcall[authorize]: module "realmsuffix" returns updated for request 7
rlm_realm: Request already proxied. Ignoring.
modcall[authorize]: module "realmslash" returns noop for request 7
rlm_realm: Request already proxied. Ignoring.
modcall[authorize]: module "realmbackslash" returns noop for request 7
rlm_realm: Request already proxied. Ignoring.
modcall[authorize]: module "realmpercent" returns noop for request 7
rlm_fastusers: checking defaults
fastusers: Matched DEFAULT at 56
modcall[authorize]: module "fastusers" returns updated for request 7
modcall: leaving group authorize (returns updated) for request 7
TTLS: Tunneled authentication will be proxied to inner-realm1.com.com
Tunneled session will be proxied. Not doing EAP.
modcall[authenticate]: module "eap" returns handled for request 7
modcall: leaving group authenticate (returns handled) for request 7
Sending Access-Request of id 0 to 143.185.55.33 port 1812
User-Name = "user at inner-realm1.com.com"
MS-CHAP-Challenge = 0x0000000000000000000000000000000
MS-CHAP2-Response = 0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
NAS-IP-Address = 127.0.0.1
Proxy-State = 0x3932
--- Walking the entire request list ---
Waking up in 2 seconds...
rad_recv: Access-Accept packet from host 143.185.55.33:1812, id=0, length=183
MS-CHAP2-Success = 0x000000000000000000000000000000000000000000000000000000000000000000000000000
MS-MPPE-Recv-Key = 0x000000000000000000000000000000000
MS-MPPE-Send-Key = 0x00000000000000000000000000000000
MS-MPPE-Encryption-Policy = 0x00000001
MS-MPPE-Encryption-Types = 0x00000004
Proxy-State = 0x3932
Processing the post-proxy section of radiusd.conf
modcall: entering group post-proxy for request 7
TTLS: Passing reply from proxy back into the tunnel.
Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 7
radius_xlat: '/usr/local/var/log/radius/radacct/127.0.0.1/reply-detail-20100518'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to
/usr/local/var/log/radius/radacct/127.0.0.1/reply-detail-20100518
modcall[post-auth]: module "reply_log" returns ok for request 7
modcall: leaving group post-auth (returns ok) for request 7
POST-AUTH 2
TTLS: Got reply 2
TTLS: Got tunneled Access-Accept
TTLS: Got MS-CHAP2-Success, tunneling it to the client in a challenge.
TTLS: Reply was handled
modcall[post-proxy]: module "eap" returns ok for request 7
modcall: leaving group post-proxy (returns ok) for request 7
authorize: Skipping authorize in post-proxy stage
rad_check_password: Found Auth-Type EAP
rad_check_password: Found Auth-Type
Warning: Found 2 auth-types on request for user 'OUTER-USER-IDENTITY'
rad_check_password: Auth-Type = Accept, accepting the user
Login OK: [OUTER-USER-IDENTITY/<no User-Password attribute>] (from client 143.185.231.120 port 2048 cli OUTER-USER-IDENTITY)
Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 7
radius_xlat: '/usr/local/var/log/radius/radacct/143.185.231.120/reply-detail-20100518'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to
/usr/local/var/log/radius/radacct/143.185.231.120/reply-detail-20100518
modcall[post-auth]: module "reply_log" returns ok for request 7
modcall: leaving group post-auth (returns ok) for request 7
Sending Access-Challenge of id 92 to 143.185.231.120 port 19801
EAP-Message =
0x015d005f15800000005517030100500567cc163f1f6f8f19129db2000d8e0571876063fd30672824aed960537504a0b3cd5983f650f57f2a9c9496117fdb85dee6d022e320bc61e11
d5dec880350f7e21df200c89c706642eb7ba96224e09f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x9603a2b18e8b334ff1d21f8277ef6714
Finished request 7
Going to the next request
Waking up in 2 seconds...
rad_recv: Access-Request packet from host 143.185.231.120:19801, id=93, length=145
User-Name = "OUTER-USER-IDENTITY at outer-realm.com"
NAS-IP-Address = 143.185.231.120
NAS-Port = 2048
Service-Type = Login-User
State = 0x9603a2b18e8b334ff1d21f8277ef6714
Called-Station-Id = "\000\000\004\000\003("
Calling-Station-Id = "OUTER-USER-IDENTITY"
NAS-Identifier = "testuser"
NAS-Port-Type = Wireless-Other
EAP-Message = 0x025d00061500
Message-Authenticator = 0x3b8b00276b6f5db8960e79474390ff39
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 8
modcall[authorize]: module "preprocess" returns ok for request 8
radius_xlat: '/usr/local/var/log/radius/radacct/143.185.231.120/auth-detail-20100518'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to
/usr/local/var/log/radius/radacct/143.185.231.120/auth-detail-20100518
modcall[authorize]: module "auth_log" returns ok for request 8
modcall[authorize]: module "chap" returns noop for request 8
rlm_eap: EAP packet type response id 93 length 6
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 8
modcall[authorize]: module "mschap" returns noop for request 8
modcall[authorize]: module "digest" returns noop for request 8
rlm_realm: Looking up realm "outer-realm.com" for User-Name = "OUTER-USER-IDENTITY at outer-realm.com"
rlm_realm: Found realm "outer-realm.com"
rlm_realm: Adding Stripped-User-Name = "OUTER-USER-IDENTITY"
rlm_realm: Proxying request from user OUTER-USER-IDENTITY to realm outer-realm.com
rlm_realm: Adding Realm = "outer-realm.com"
rlm_realm: Authentication realm is LOCAL.
modcall[authorize]: module "realmsuffix" returns noop for request 8
rlm_realm: Request already proxied. Ignoring.
modcall[authorize]: module "realmslash" returns noop for request 8
rlm_realm: Request already proxied. Ignoring.
modcall[authorize]: module "realmbackslash" returns noop for request 8
rlm_realm: Request already proxied. Ignoring.
modcall[authorize]: module "realmpercent" returns noop for request 8
rlm_fastusers: checking defaults
fastusers: Matched DEFAULT at 56
fastusers: Matched DEFAULT at 148
modcall[authorize]: module "fastusers" returns updated for request 8
modcall: leaving group authorize (returns updated) for request 8
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 8
rlm_eap: Request found, released from the list
rlm_eap: EAP/ttls
rlm_eap: processing type ttls
rlm_eap_ttls: Authenticate
rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
rlm_eap_tls: ack handshake is finished
eaptls_verify returned 3
eaptls_process returned 3
rlm_eap: Freeing handler
modcall[authenticate]: module "eap" returns ok for request 8
modcall: leaving group authenticate (returns ok) for request 8
Login OK: [OUTER-USER-IDENTITY/<no User-Password attribute>] (from client 143.185.231.120 port 2048 cli OUTER-USER-IDENTITY)
Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 8
radius_xlat: '/usr/local/var/log/radius/radacct/143.185.231.120/reply-detail-20100518'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to
/usr/local/var/log/radius/radacct/143.185.231.120/reply-detail-20100518
modcall[post-auth]: module "reply_log" returns ok for request 8
modcall: leaving group post-auth (returns ok) for request 8
Sending Access-Accept of id 93 to 143.185.231.120 port 19801
Session-Timeout = 604800
Motorola-WiMAX-Convergence-Sublayer = 0x00
Motorola-WiMAX-Network-Domain-Name = "wimax.local"
Motorola-WiMAX-EMS-Address = 192.168.1.103
Motorola-WiMAX-NTP-Server = 0x01c0a80101
Motorola-WiMAX-HO-SVC-CLASS = 0x03
Motorola-WiMAX-Service-Flows = "2|Default"
Motorola-WiMAX-Maximum-Total-Bandwidth = 0x0000c3500000c350
Motorola-WiMAX-Maximum-Commit-Bandwidth = 0x0000c3500000c350
MS-MPPE-Encryption-Policy = 0x00000001
MS-MPPE-Encryption-Types = 0x00000000
MS-MPPE-Recv-Key = 0x5e5962b00b2d85f96311b742047f447d03d5389a4656ec509d0d80f8655bcc6e
MS-MPPE-Send-Key = 0xb0085e231ca9692be345d3400d89e7146fe1e7a9623171f7bdb8bd55f0c35838
EAP-Message = 0x035d0004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "OUTER-USER-IDENTITY"
Finished request 8
More information about the Freeradius-Users
mailing list