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-ident...@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 = "u...@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 = "u...@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-ident...@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-ident...@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 - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html