Hi, I am trying to set up Freeradius to proxy PEAP/EAP-MSCHAPv2 request as MSCHAPv2 and know that some of you were able to set up this cofiguration successfully i.e. http://www.mail-archive.com/freeradius-users@lists.freeradius.org/msg22903.h... http://www.mail-archive.com/freeradius-users@lists.freeradius.org/msg16192.h... and others. I have tried the examples in those postings as well as suggestions from other postings without any success. I have started with the default config and turned on the debug option. However, looking at the debug output yet I couldn't quite figure out what went wrong. What I got so far is as follow: 1) Send a PEAP/MSCHAPv2 request using Linux's Xsupplicant or Mac client to the proxy radius 2) Proxy radius terminated EAP locally and proxied request (MSCHAPv2 minus EAP) to home radius 3) Home radius responded with an access-accept packet to proxy radius 4) Proxy Radius sent access-reject to client. See error output below. Tue Oct 3 20:10:37 2006 : Debug: rlm_eap: Request not found in the list Tue Oct 3 20:10:37 2006 : Error: rlm_eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request Tue Oct 3 20:10:37 2006 : Debug: rlm_eap: Failed in handler I am running Freeradius 1.1.3 and have attached below my configuration files and an excerpt of the debug output hoping that the mistake would look obvious to some of you and that you could provide some helpful pointers or links. Thanks a lot for your help. -David For the outer identity, I have set it to use 'Anonymous' and the inner identity, I have set it to use 'peapuser@abc.net' radiusd.conf modules { pap { encryption_scheme = crypt } chap { authtype = CHAP } pam { pam_auth = radiusd } $INCLUDE ${confdir}/eap.conf mschap { authtype = MS-CHAP use_mppe = yes require_encryption = yes require_strong = yes } realm IPASS { format = prefix delimiter = "/" ignore_default = no ignore_null = no } # 'username@realm' # realm suffix { format = suffix delimiter = "@" ignore_default = no ignore_null = no } ... } authorize { preprocess chap mschap suffix eap files } authenticate { Auth-Type PAP { pap } Auth-Type CHAP { chap } Auth-Type MS-CHAP { mschap } eap } preacct { preprocess acct_unique suffix files } accounting { detail radutmp } session { radutmp } post-auth { } pre-proxy { } post-proxy { eap } eap.conf eap { default_eap_type = peap timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no md5 { } leap { } gtc { auth_type = PAP } tls { private_key_password = wireless private_key_file = ${raddbdir}/certs/host.key certificate_file = ${raddbdir}/certs/host.crt CA_file = ${raddbdir}/certs/ca-root.crt dh_file = ${raddbdir}/certs/dh random_file = /dev/urandom } ttls { default_eap_type = md5 copy_request_to_tunnel = yes use_tunneled_reply = yes } peap { default_eap_type = mschapv2 copy_request_to_tunnel = yes use_tunneled_reply = yes proxy_tunneled_request_as_eap = no # Note: If I set proxy_tunneled_request_as_eap = yes (proxying the request as eap-mschapv2) # I was able to connect successfully } mschapv2 { } } proxy.conf realm LOCAL { type = radius authhost = LOCAL accthost = LOCAL } realm NULL { type = radius authhost = LOCAL accthost = LOCAL } realm abc.net { type = radius authhost = 199.186.1.2:1645 accthost = 199.186.1.2:1646 secret = wireless nostrip } users: DEFAULT FreeRADIUS-Proxied-To == 127.0.0.1, Proxy-To-Realm := "abc.net" Debug output (excerpt starting when the home radius replied with an access accept) see attached files for the complete output. Tue Oct 3 20:10:37 2006 : Sending Access-Request of id 30 to 199.186.1.2 port 1645 User-Name = "peapuser@abc.net" NAS-IP-Address = 192.168.2.3 NAS-Identifier = "SJC=s=-=s=QE" NAS-Port-Type = "Wireless - IEEE 802.11" NAS-Port = 472 Called-Station-Id = "00-0D-97-00-48-01:AAA" Calling-Station-Id = "00-16-CB-B9-D7-41" Acct-Session-Id = "2LkFMyhUNqa+" Connect-Info = "CONNECT 11Mbps 802.11b" Service-Type = Framed-User MS-CHAP-Challenge = 0x69e38b9d3be5408dc1740b695350adc6 MS-CHAP2-Response = 0x066ff5f8d276b161dc41b283b74961fde2760000000000000000ee7baf48902aedad5b6c47209b1d2794992879f402 d3eac4 Proxy-State = 0x313534 Tue Oct 3 20:10:37 2006 : Debug: Waking up in 2 seconds... Tue Oct 3 20:10:37 2006 : rad_recv: Access-Accept packet from host 199.186.1.2:1645, id=30, length=184 Tue Oct 3 20:10:37 2006 : Debug: proxy: de-allocating c6b903f6:1645 30 MS-CHAP2-Success = 0x06533d46313445394339363839414443393932343130324542383245334434423741443046384231313436 MS-MPPE-Recv-Key = 0xb6de1db8e81dfea9e7d51b6120a6a2e0 MS-MPPE-Send-Key = 0xa2db97000b60f3715d2068a05f0eb1dd MS-MPPE-Encryption-Policy = 0x00000002 MS-MPPE-Encryption-Types = 0x00000006 Proxy-State = 0x313534 Tue Oct 3 20:10:37 2006 : Debug: Processing the post-proxy section of radiusd.conf Tue Oct 3 20:10:37 2006 : Debug: modcall: entering group post-proxy for request 250 Tue Oct 3 20:10:37 2006 : Debug: modsingle[post-proxy]: calling eap (rlm_eap) for request 250 (0) Tue Oct 3 20:10:37 2006 : Debug: PEAP: Passing reply from proxy back into the tunnel. Tue Oct 3 20:10:37 2006 : Debug: PEAP: Passing reply back for EAP-MS-CHAP-V2 16c490 2 Tue Oct 3 20:10:37 2006 : Debug: Processing the post-proxy section of radiusd.conf Tue Oct 3 20:10:37 2006 : Debug: modcall: entering group post-proxy for request 250 Tue Oct 3 20:10:37 2006 : Debug: modsingle[post-proxy]: calling eap (rlm_eap) for request 250 (2) Tue Oct 3 20:10:37 2006 : Debug: rlm_eap_mschapv2: Passing reply from proxy back into the tunnel 16c490 2. Tue Oct 3 20:10:37 2006 : Debug: rlm_eap_mschapv2: Authentication succeeded. Tue Oct 3 20:10:37 2006 : Debug: MSCHAP Success Tue Oct 3 20:10:37 2006 : Debug: modsingle[post-proxy]: ok returned from eap (rlm_eap) for request 250 Tue Oct 3 20:10:37 2006 : Debug: modcall[post-proxy]: module "eap" returns ok for request 250 Tue Oct 3 20:10:37 2006 : Debug: modcall: leaving group post-proxy (returns ok) for request 250 Tue Oct 3 20:10:37 2006 : Debug: POST-PROXY 2 Tue Oct 3 20:10:37 2006 : Debug: POST-AUTH 2 Tue Oct 3 20:10:37 2006 : Debug: PEAP: Got reply 11 Tue Oct 3 20:10:37 2006 : Debug: PEAP: Got tunneled Access-Challenge Tue Oct 3 20:10:37 2006 : Debug: Saving tunneled attributes for later Tue Oct 3 20:10:37 2006 : Debug: PEAP: Reply was handled Tue Oct 3 20:10:37 2006 : Debug: modsingle[post-proxy]: ok returned from eap (rlm_eap) for request 250 Tue Oct 3 20:10:37 2006 : Debug: modcall[post-proxy]: module "eap" returns ok for request 250 Tue Oct 3 20:10:37 2006 : Debug: modcall: leaving group post-proxy (returns ok) for request 250 Tue Oct 3 20:10:37 2006 : Sending Access-Challenge of id 154 to 192.168.2.3 port 11061 EAP-Message = 0x0107004e19001703010043a102f2b10f2cc23294968cce980785e16f478376f3363f7e260a4151a06470265144600e5157f3 3a11db17f9532985d72bc321a6b264092151734087a050065f761093 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x29916516b9091aa773a614b242bf1cbb Tue Oct 3 20:10:37 2006 : Debug: Finished request 250 Tue Oct 3 20:10:37 2006 : Debug: Going to the next request Tue Oct 3 20:10:37 2006 : Debug: Waking up in 2 seconds... Tue Oct 3 20:10:37 2006 : rad_recv: Access-Request packet from host 192.168.2.3:11061, id=155, length=230 NAS-IP-Address = 192.168.2.3 NAS-Identifier = "SJC=s=-=s=QE" NAS-Port-Type = "Wireless - IEEE 802.11" NAS-Port = 472 Called-Station-Id = "00-0D-97-00-48-01:AAA" Calling-Station-Id = "00-16-CB-B9-D7-41" Acct-Session-Id = "2LkFMyhUNqa+" Connect-Info = "CONNECT 11Mbps 802.11b" User-Name = "anonymous" State = 0x29916516b9091aa773a614b242bf1cbb Service-Type = Framed-User EAP-Message = 0x02070021190017030100168d386231a769e270b8e6a25148612d4e941daab20a5e Message-Authenticator = 0x99c11169be9162c0de5982800e2a0b64 Tue Oct 3 20:10:37 2006 : Debug: Processing the authorize section of radiusd.conf Tue Oct 3 20:10:37 2006 : Debug: modcall: entering group authorize for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: ok returned from preprocess (rlm_preprocess) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authorize]: module "preprocess" returns ok for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: noop returned from chap (rlm_chap) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authorize]: module "chap" returns noop for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: noop returned from mschap (rlm_mschap) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authorize]: module "mschap" returns noop for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: rlm_realm: No '@' in User-Name = "anonymous", looking up realm NULL Tue Oct 3 20:10:37 2006 : Debug: rlm_realm: Found realm "NULL" Tue Oct 3 20:10:37 2006 : Debug: rlm_realm: Adding Stripped-User-Name = "anonymous" Tue Oct 3 20:10:37 2006 : Debug: rlm_realm: Proxying request from user anonymous to realm NULL Tue Oct 3 20:10:37 2006 : Debug: rlm_realm: Adding Realm = "NULL" Tue Oct 3 20:10:37 2006 : Debug: rlm_realm: Authentication realm is LOCAL. Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: noop returned from suffix (rlm_realm) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authorize]: module "suffix" returns noop for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: rlm_eap: EAP packet type response id 7 length 33 Tue Oct 3 20:10:37 2006 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: updated returned from eap (rlm_eap) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authorize]: module "eap" returns updated for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: calling files (rlm_files) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: users: 'anonymous' matched entry "DEFAULT" at line 129 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: ok returned from files (rlm_files) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authorize]: module "files" returns ok for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall: leaving group authorize (returns updated) for request 251 Tue Oct 3 20:10:37 2006 : Debug: rad_check_password: Found Auth-Type EAP Tue Oct 3 20:10:37 2006 : Debug: auth: type "EAP" Tue Oct 3 20:10:37 2006 : Debug: Processing the authenticate section of radiusd.conf Tue Oct 3 20:10:37 2006 : Debug: modcall: entering group authenticate for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: rlm_eap: Request found, released from the list Tue Oct 3 20:10:37 2006 : Debug: rlm_eap: EAP/peap Tue Oct 3 20:10:37 2006 : Debug: rlm_eap: processing type peap Tue Oct 3 20:10:37 2006 : Debug: rlm_eap_peap: Authenticate Tue Oct 3 20:10:37 2006 : Debug: rlm_eap_tls: processing TLS Tue Oct 3 20:10:37 2006 : Debug: eaptls_verify returned 7 Tue Oct 3 20:10:37 2006 : Debug: rlm_eap_tls: Done initial handshake Tue Oct 3 20:10:37 2006 : Debug: eaptls_process returned 7 Tue Oct 3 20:10:37 2006 : Debug: rlm_eap_peap: EAPTLS_OK Tue Oct 3 20:10:37 2006 : Debug: rlm_eap_peap: Session established. Decoding tunneled attributes. Tue Oct 3 20:10:37 2006 : Debug: rlm_eap_peap: EAP type mschapv2 Tue Oct 3 20:10:37 2006 : Debug: rlm_eap_peap: Tunneled data is valid. Tue Oct 3 20:10:37 2006 : Debug: PEAP: Setting User-Name to peapuser@abc.net Tue Oct 3 20:10:37 2006 : Debug: PEAP: Adding old state with bc 97 Tue Oct 3 20:10:37 2006 : Debug: Processing the authorize section of radiusd.conf Tue Oct 3 20:10:37 2006 : Debug: modcall: entering group authorize for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: ok returned from preprocess (rlm_preprocess) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authorize]: module "preprocess" returns ok for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: noop returned from chap (rlm_chap) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authorize]: module "chap" returns noop for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: noop returned from mschap (rlm_mschap) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authorize]: module "mschap" returns noop for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: rlm_realm: Looking up realm "abc.net" for User-Name = "peapuser@abc.net" Tue Oct 3 20:10:37 2006 : Debug: rlm_realm: Found realm "abc.net" Tue Oct 3 20:10:37 2006 : Debug: rlm_realm: Proxying request from user peapuser to realm abc.net Tue Oct 3 20:10:37 2006 : Debug: rlm_realm: Adding Realm = "abc.net" Tue Oct 3 20:10:37 2006 : Debug: rlm_realm: Preparing to proxy authentication request to realm "abc.net" Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: updated returned from suffix (rlm_realm) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authorize]: module "suffix" returns updated for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: rlm_eap: Request is supposed to be proxied to Realm abc.net. Not doing EAP. Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: noop returned from eap (rlm_eap) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authorize]: module "eap" returns noop for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: calling files (rlm_files) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: users: 'peapuser@abc.net' matched entry "DEFAULT" at line 129 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authorize]: ok returned from files (rlm_files) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authorize]: module "files" returns ok for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall: leaving group authorize (returns updated) for request 251 Tue Oct 3 20:10:37 2006 : Debug: PEAP: Calling authenticate in order to initiate t/unneled EAP session. Tue Oct 3 20:10:37 2006 : Debug: Processing the authenticate section of radiusd.conf Tue Oct 3 20:10:37 2006 : Debug: modcall: entering group authenticate for request 251 Tue Oct 3 20:10:37 2006 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 251 (0) Tue Oct 3 20:10:37 2006 : Debug: rlm_eap: Request not found in the list Tue Oct 3 20:10:37 2006 : Error: rlm_eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request Tue Oct 3 20:10:37 2006 : Debug: rlm_eap: Failed in handler Tue Oct 3 20:10:37 2006 : Debug: modsingle[authenticate]: invalid returned from eap (rlm_eap) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authenticate]: module "eap" returns invalid for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall: leaving group authenticate (returns invalid) for request 251 Tue Oct 3 20:10:37 2006 : Debug: PEAP: Can't handle the return code 4 Tue Oct 3 20:10:37 2006 : Debug: rlm_eap: Handler failed in EAP/peap Tue Oct 3 20:10:37 2006 : Debug: rlm_eap: Failed in EAP select Tue Oct 3 20:10:37 2006 : Debug: modsingle[authenticate]: invalid returned from eap (rlm_eap) for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall[authenticate]: module "eap" returns invalid for request 251 Tue Oct 3 20:10:37 2006 : Debug: modcall: leaving group authenticate (returns invalid) for request 251 Tue Oct 3 20:10:37 2006 : Debug: auth: Failed to validate the user. Tue Oct 3 20:10:37 2006 : Debug: Delaying request 251 for 1 seconds Tue Oct 3 20:10:37 2006 : Debug: Finished request 251 Tue Oct 3 20:10:37 2006 : Debug: Going to the next request Tue Oct 3 20:10:37 2006 : Debug: Waking up in 2 seconds... Tue Oct 3 20:10:39 2006 : Debug: --- Walking the entire request list --- Tue Oct 3 20:10:39 2006 : Debug: Cleaning up request 244 ID 148 with timestamp 4522fbf9 Tue Oct 3 20:10:39 2006 : Debug: Cleaning up request 245 ID 149 with timestamp 4522fbf9 Tue Oct 3 20:10:39 2006 : Debug: Cleaning up request 246 ID 150 with timestamp 4522fbf9 Tue Oct 3 20:10:39 2006 : Debug: Cleaning up request 247 ID 151 with timestamp 4522fbf9 Tue Oct 3 20:10:39 2006 : Sending Access-Reject of id 155 to 192.168.2.3 port 11061 EAP-Message = 0x04070004 Message-Authenticator = 0x00000000000000000000000000000000 Tue Oct 3 20:10:39 2006 : Debug: Waking up in 4 seconds... Tue Oct 3 20:10:43 2006 : Debug: --- Walking the entire request list --- Tue Oct 3 20:10:43 2006 : Debug: Cleaning up request 248 ID 152 with timestamp 4522fbfd Tue Oct 3 20:10:43 2006 : Debug: Cleaning up request 249 ID 153 with timestamp 4522fbfd Tue Oct 3 20:10:43 2006 : Debug: Cleaning up request 250 ID 154 with timestamp 4522fbfd Tue Oct 3 20:10:43 2006 : Debug: Cleaning up request 251 ID 155 with timestamp 4522fbfd Tue Oct 3 20:10:43 2006 : Debug: Nothing to do. Sleeping until we see a request.