Correction: In the radiusd.conf the realm suffix and realm ntdomain "ignore_null = yes" is set to "yes". realm suffix { format = suffix delimiter = "@" ignore_default = no ignore_null = yes } realm ntdomain { format = prefix delimiter = "\\" ignore_default = no ignore_null = yes } // J Jayal1972 wrote:
Finally I got it, I think. Have to try some more, Im not giving you the "High Five" yet...
The only ERROR (Warning) I get is:
Mon Feb 4 21:30:06 2008 : Error: Warning: Found 2 auth-types on request
for user 'joakimlindgren'
Ivan, Im very glad you helped me with this, I have read the proxy.conf a couple of times and searched the forums...
Probably there are an issue with the 2-factor Radius software, looking into it but I got it to work on a Windows IAS Radius box only accepting PAP so here what I did:
Summary:
I have users in the local radius LDAP (but when Im authenticating against that one I dont use any domain name. So I only authenticate with "testuser" and password.
In Home server (Remote Radius) I got user "usertest" in LDAP (or Radius acually fetching that name from AD) as well but when authenticating I enter "testuser", password and SECURACCESS (as domain).
Using the Windows W2 client with EAP-TTLS and PAP. I ´m NOT using (configured) the "Use anonymous outer identity" configuration in Win. W2 client. Logging in with the username "test", password and the domain "SECURACCESS"
So here are the config that worked (Hopefully ;-):
============ proxy.conf ======================================================= realm NULL { type = radius authhost = LOCAL accthost = LOCAL }
realm SECURACCESS { type = radius authhost = LOCAL accthost = LOCAL }
realm SECURE { type = radius authhost = 192.168.1.xxx:1812 accthost = 192.168.1.xxx:1813 secret = toor
======= users: ===================================================================== DEFAULT FreeRADIUS-Proxied-To == 127.0.0.1, Proxy-To-Realm := "SECURE" =====================================================================
======== eap.conf ===========================================================================
eap { default_eap_type = ttls timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no md5 { }
leap { }
gtc {
auth_type = PAP }
tls {
private_key_password = password private_key_file = ${raddbdir}/certs/jaysCA2/osuse-freeradius/server_keycert.pem certificate_file = ${raddbdir}/certs/jaysCA2/osuse-freeradius/server_keycert.pem CA_file = ${raddbdir}/certs/jaysCA2/cacert.pem dh_file = ${raddbdir}/certs/dh random_file = ${raddbdir}/certs/random fragment_size = 1024 include_length = yes }
ttls {
default_eap_type = md5 copy_request_to_tunnel = yes use_tunneled_reply = yes }
peap {
default_eap_type = mschapv2 proxy_tunneled_request_as_eap = no } mschapv2 { } } ===ENDeap======================================================================================
=========== radiusd.conf ================================================================================
... modules {
pap { auto_header = yes }
chap { authtype = CHAP }
pam { pam_auth = radiusd }
unix { cache = no cache_reload = 600 radwtmp = ${logdir}/radwtmp }
$INCLUDE ${confdir}/eap.conf
mschap { use_mppe = yes require_encryption = yes require_strong = yes }
ldap { server = "192.168.1.71" identity = "cn=admin,o=Contonso" password = "toor" basedn = "o=Contonso" filter = "(uid=%{Stripped-User-Name:-%{User-Name}})" start_tls = yes tls_mode = no tls_cacertfile = /etc/raddb/certs/eDirCerts/edirectory_ROOT_Cert_DER.pem dictionary_mapping = ${raddbdir}/ldap.attrmap ldap_connections_number = 5 password_attribute = nspmPassword tls_require_cert = "allow" timeout = 4 timelimit = 3 net_timeout = 1 port = 389 edir_account_policy_check=yes }
realm suffix { format = suffix delimiter = "@" ignore_default = no ignore_null = no }
realm ntdomain { format = prefix delimiter = "\\" ignore_default = no ignore_null = no }
...
authorize {
preprocess chap mschap suffix ntdomain eap files ldap pap }
authenticate {
Auth-Type PAP { pap }
Auth-Type CHAP { chap } Auth-Type MS-CHAP { mschap }
unix
Auth-Type LDAP { ldap } eap }
post-auth { ldap Post-Auth-Type REJECT { ldap }
}
===ENDradiusd.conf================================================================================
Here are the output of (Configs above):
================= output with comments: ====================================================================
Mon Feb 4 20:52:27 2008 : Debug: Module: Instantiated radutmp (radutmp) Mon Feb 4 20:52:27 2008 : Debug: Listening on authentication *:1812 Mon Feb 4 20:52:27 2008 : Debug: Listening on accounting *:1813 Mon Feb 4 20:52:27 2008 : Debug: Listening on proxy *:1814 Mon Feb 4 20:52:27 2008 : Info: Ready to process requests. rad_recv: Access-Request packet from host 192.168.1.150:32797, id=117, length=179 User-Name = "test@SECURACCESS" NAS-IP-Address = 192.168.1.73 NAS-Port = 1 NAS-Identifier = "10" NAS-Port-Type = Wireless-802.11 Calling-Station-Id = "0012793DFC0C" Called-Station-Id = "000B86600A58" Framed-MTU = 1100 EAP-Message = 0x020f00150174657374405345435552414343455353 Aruba-Essid-Name = "demo-wpa-aes-eap-radius" Aruba-Location-Id = "1.1.1" Message-Authenticator = 0x51efbb1d8d4d27a84db67e2c86647761 Mon Feb 4 20:52:44 2008 : Debug: Processing the authorize section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authorize for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Looking up realm "SECURACCESS" for User-Name = "test@SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Found realm "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Stripped-User-Name = "test" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Proxying request from user test to realm SECURACCESS Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Realm = "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Authentication realm is LOCAL. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ntdomain (rlm_realm) for request 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Request already proxied. Ignoring. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ntdomain (rlm_realm) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ntdomain" returns noop for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP packet type response id 15 length 21 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: - authorize Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing user authorization for test Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: '(uid=test)' Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: 'o=Contonso' Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: attempting LDAP reconnection Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: (re)connect to 192.168.1.71:389, authentication 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: setting TLS CACert File to /etc/raddb/certs/eDirCerts/edirectory_ROOT_Cert_DER.pem Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: starting TLS Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: bind as cn=admin,o=Contonso/toor to 192.168.1.71:389 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: waiting for bind result ... Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: Bind was successful Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing search in o=Contonso, with filter (uid=test) Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: object not found or got ambiguous search result Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: search failed Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ldap" returns notfound for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 0 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authorize (returns updated) for request 0 Mon Feb 4 20:52:44 2008 : Debug: rad_check_password: Found Auth-Type EAP Mon Feb 4 20:52:44 2008 : Debug: auth: type "EAP" Mon Feb 4 20:52:44 2008 : Debug: Processing the authenticate section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authenticate for request 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP Identity Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: processing type tls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: Initiate Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: Start returned 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 0 Mon Feb 4 20:52:44 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 0 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 0 Sending Access-Challenge of id 117 to 192.168.1.150 port 32797 EAP-Message = 0x011000061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x107cc8a30846f226012c371645eddb9e Mon Feb 4 20:52:44 2008 : Debug: Finished request 0 Mon Feb 4 20:52:44 2008 : Debug: Going to the next request Mon Feb 4 20:52:44 2008 : Debug: --- Walking the entire request list --- Mon Feb 4 20:52:44 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.1.150:32797, id=118, length=236 User-Name = "test@SECURACCESS" NAS-IP-Address = 192.168.1.73 NAS-Port = 1 NAS-Identifier = "10" NAS-Port-Type = Wireless-802.11 Calling-Station-Id = "0012793DFC0C" Called-Station-Id = "000B86600A58" Framed-MTU = 1100 EAP-Message = 0x0210003c158000000032160301002d01000029030148d9ff2b7767d68543b95ea38318e434b0c4c8cdb9019a71674cdd8a46aec766000002000a0100 State = 0x107cc8a30846f226012c371645eddb9e Aruba-Essid-Name = "demo-wpa-aes-eap-radius" Aruba-Location-Id = "1.1.1" Message-Authenticator = 0x6c23782a01385cc63aae51872b379200 Mon Feb 4 20:52:44 2008 : Debug: Processing the authorize section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authorize for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 1 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Looking up realm "SECURACCESS" for User-Name = "test@SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Found realm "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Stripped-User-Name = "test" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Proxying request from user test to realm SECURACCESS Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Realm = "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Authentication realm is LOCAL. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ntdomain (rlm_realm) for request 1 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Request already proxied. Ignoring. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ntdomain (rlm_realm) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ntdomain" returns noop for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 1 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP packet type response id 16 length 60 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 1 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: - authorize Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing user authorization for test Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: '(uid=test)' Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: 'o=Contonso' Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing search in o=Contonso, with filter (uid=test) Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: object not found or got ambiguous search result Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: search failed Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ldap" returns notfound for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 1 Mon Feb 4 20:52:44 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 1 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authorize (returns updated) for request 1 Mon Feb 4 20:52:44 2008 : Debug: rad_check_password: Found Auth-Type EAP Mon Feb 4 20:52:44 2008 : Debug: auth: type "EAP" Mon Feb 4 20:52:44 2008 : Debug: Processing the authenticate section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authenticate for request 1 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 1 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: Request found, released from the list Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP/ttls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: processing type ttls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_ttls: Authenticate Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: processing TLS Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: Length Included Mon Feb 4 20:52:44 2008 : Debug: eaptls_verify returned 11 Mon Feb 4 20:52:44 2008 : Debug: (other): before/accept initialization Mon Feb 4 20:52:44 2008 : Debug: TLS_accept: before/accept initialization Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 002d], ClientHello Mon Feb 4 20:52:44 2008 : Debug: TLS_accept: SSLv3 read client hello A Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello Mon Feb 4 20:52:44 2008 : Debug: TLS_accept: SSLv3 write server hello A Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0bd6], Certificate Mon Feb 4 20:52:44 2008 : Debug: TLS_accept: SSLv3 write certificate A Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Mon Feb 4 20:52:44 2008 : Debug: TLS_accept: SSLv3 write server done A Mon Feb 4 20:52:44 2008 : Debug: TLS_accept: SSLv3 flush data Mon Feb 4 20:52:44 2008 : Debug: TLS_accept: Need to read more data: SSLv3 read client certificate A Mon Feb 4 20:52:44 2008 : Debug: In SSL Handshake Phase Mon Feb 4 20:52:44 2008 : Debug: In SSL Accept mode Mon Feb 4 20:52:44 2008 : Debug: eaptls_process returned 13 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 1 Mon Feb 4 20:52:44 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 1 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 1 Sending Access-Challenge of id 118 to 192.168.1.150 port 32797 EAP-Message = 0x0111040a15c000000c33160301004a02000046030147a76d0cda2c50f278059a1a31a8c7beffabd1f3020fa260d03833b9979d1c11201175ba4826f81f5828afe0fe2cc6549c1071c50d11ee2dc38ce646351100e9ee000a001603010bd60b000bd2000bcf0005b2308205ae30820396a003020102020101300d06092a864886f70d010105050030818c310b3009060355040613025345311230100603550408130953746f636b686f6c6d31143012060355040a130b536d617274736563204142312730250603550403131e536d61727473656320436572746966696361746520417574686f72697479312a302806092a864886f70d010901161b6a6f EAP-Message = 0x616b696d2e6c696e646772656e40736d6172747365632e7365301e170d3038303132303031353933385a170d3138303131373031353933385a30818e310b3009060355040613025345311230100603550408130953746f636b686f6c6d310e300c060355040713054e61636b6131143012060355040a130b536d61727473656320414231193017060355040313106f737573652d66726565726164697573312a302806092a864886f70d010901161b6a6f616b696d2e6c696e646772656e40736d6172747365632e736530820222300d06092a864886f70d01010105000382020f003082020a0282020100b43c20decf8f1187548416b9d1e616e6e520 EAP-Message = 0x467f1dca4cfda9b53b995334c53f62e1baa8773f31b3fe21f17b259291cb9ccc89ae1b1c8272edc9f1caf795f460a7fdacb10f8e37fa1c5a41af44d18ce63804e8c9499496944f89fccc98b9ed1528a870dcac0b6cb13d298f988700f3d43c1126b54a1b23ece04cb8f14870efbf296f75d6207ba893cfaa66a40d884706efb0b6c3ea8f483231a94ec488ea099353a79e2ea9a35ccadc66621545658d3827f9d42bac51334b9c083f718a0b46137c85ab951a9299705569f8522bbfc0a0240e4480ee5f7bc42cacd7d77f03b71e8525afcb550fd1243129f99d810769af0aea19aa546ac9af0a249b562b736dcf2ce1fab2a49c0dfe92c8d1f699547b EAP-Message = 0x5fc7984b47789e1e86b5a84816aa8a3e553a45eedfe7a57df10e7cdc8e18baf5b0d769678d09572f0d69f4e43eb2eb2ec5b6fe3255979201ae17ba320861b754ee4fa0543d3f93292954f5c72eb688f8e7528f5a05258d52835ae936f166fb5b87877a38c24bbf48a0e90894313c5c73e354847a43c940c801e4d7672c08be3ad58e53958d5b214b65f86935e4c2b05c7fb12fcd10c31662731911cb0daaa6e3451001dfd85f55c56c60a93057df3de1c9ad94c5e6321c6b646e943b5cdf524d3d288ab93cf2ba9ec5fd5a08e8111ea3cec99f5e2b3de9054dd72d257fe5b267fa85970aa4d1eece1a63e4b930098ec2310203010001a3173015301306 EAP-Message = 0x03551d25040c300a06082b06010505070301300d0609 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x1ee0a0c1040edd41870989724f787a81 Mon Feb 4 20:52:44 2008 : Debug: Finished request 1 Mon Feb 4 20:52:44 2008 : Debug: Going to the next request Mon Feb 4 20:52:44 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.1.150:32797, id=119, length=182 User-Name = "test@SECURACCESS" NAS-IP-Address = 192.168.1.73 NAS-Port = 1 NAS-Identifier = "10" NAS-Port-Type = Wireless-802.11 Calling-Station-Id = "0012793DFC0C" Called-Station-Id = "000B86600A58" Framed-MTU = 1100 EAP-Message = 0x021100061500 State = 0x1ee0a0c1040edd41870989724f787a81 Aruba-Essid-Name = "demo-wpa-aes-eap-radius" Aruba-Location-Id = "1.1.1" Message-Authenticator = 0xfedbf930576e06a382ea355ce61f302d Mon Feb 4 20:52:44 2008 : Debug: Processing the authorize section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authorize for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 2 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Looking up realm "SECURACCESS" for User-Name = "test@SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Found realm "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Stripped-User-Name = "test" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Proxying request from user test to realm SECURACCESS Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Realm = "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Authentication realm is LOCAL. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ntdomain (rlm_realm) for request 2 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Request already proxied. Ignoring. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ntdomain (rlm_realm) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ntdomain" returns noop for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 2 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP packet type response id 17 length 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 2 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: - authorize Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing user authorization for test Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: '(uid=test)' Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: 'o=Contonso' Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing search in o=Contonso, with filter (uid=test) Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: object not found or got ambiguous search result Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: search failed Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ldap" returns notfound for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 2 Mon Feb 4 20:52:44 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 2 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authorize (returns updated) for request 2 Mon Feb 4 20:52:44 2008 : Debug: rad_check_password: Found Auth-Type EAP Mon Feb 4 20:52:44 2008 : Debug: auth: type "EAP" Mon Feb 4 20:52:44 2008 : Debug: Processing the authenticate section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authenticate for request 2 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 2 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: Request found, released from the list Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP/ttls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: processing type ttls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_ttls: Authenticate Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: processing TLS Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: Received EAP-TLS ACK message Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: ack handshake fragment handler Mon Feb 4 20:52:44 2008 : Debug: eaptls_verify returned 1 Mon Feb 4 20:52:44 2008 : Debug: eaptls_process returned 13 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 2 Mon Feb 4 20:52:44 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 2 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 2 Sending Access-Challenge of id 119 to 192.168.1.150 port 32797 EAP-Message = 0x0112040a15c000000c332a864886f70d010105050003820201006f6d9f464dd8b1e40ef92ec6e9a6803f92eb21a582a826e15b5268dc213f7469691c1104e610adbf97fb4ce92739c13bffb77b4b10208521e927cfe798df8492adf5a68bc03075eac5f201097e603e6dcd1c1100339c5c22b45f9b2b94b40fed355b46f3c8d0b9d6e66cecfcd309ca3ec866b9fc5d84a6d56b273d119747721bdaf988a8d6cdf85e913eb2dc51818e0c5a3b717661129e54c67c3d8c917dca799d230ae1765308d8f8c1148e47e55722a4336ef88d11a860ca849e6a1fe055facadadca78ea5710d88d5cf0bf9ac828ffcc220a64cf9e23a67dc0c743ca82bb2ce10a3 EAP-Message = 0x134ba5d30b3e435dc14e13cc4ebe9ef64fd6427b4d06334e0f3b44ffeacec4e5ef92e5ded5a2e70fc2705f33be02dea3ac0e1838f8878c294173055277af8207f4c48fa8024a66f9a27ca6ec66d089b120e006f54d500f6b7e76c0523bac5fc4da6a56ffd6c0936fa84d519f4fcf4bac5e421a70a5cb5a84966ba50a6c1e2dfd1080e99560af85f9e93211e015b596cc288368654ecd6e9e713ad0e18e5944b3ae6f76da7fb2f5b2f953a378a7477d915f9383ccff12f9bd4392dfc772015ff7574d0a2c9de08e8365883018edfa38b55855b271a609566261460dc5a30898b7f869291b5ee4d1ac19ee8096ae2cad43e052595924c4b45a3bc02c5790 EAP-Message = 0x7d3993464b8760b6209c85ff0c930bc538f4dd3e55ef7abe3eefbaf56a51dade00061730820613308203fba003020102020100300d06092a864886f70d010105050030818c310b3009060355040613025345311230100603550408130953746f636b686f6c6d31143012060355040a130b536d617274736563204142312730250603550403131e536d61727473656320436572746966696361746520417574686f72697479312a302806092a864886f70d010901161b6a6f616b696d2e6c696e646772656e40736d6172747365632e7365301e170d3038303132303031353532305a170d3131303131393031353532305a30818c310b30090603550406 EAP-Message = 0x13025345311230100603550408130953746f636b686f6c6d31143012060355040a130b536d617274736563204142312730250603550403131e536d61727473656320436572746966696361746520417574686f72697479312a302806092a864886f70d010901161b6a6f616b696d2e6c696e646772656e40736d6172747365632e736530820222300d06092a864886f70d01010105000382020f003082020a0282020100a6cd1441d8840d138168f5d798fbefe64f5b653b669db82d7fa6a888317660ed980c411ad6440733b416fd598b4dd6283ae4fb1beb3081206ecd46df3baf4e3dc028e134ee949edb35908d9f646131d67754fc57ed4c22b3a0 EAP-Message = 0xde965b3a53c909d677557550d5fe74a19419bc0802b1 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x19946293a6618e7c4a043aeec88d5888 Mon Feb 4 20:52:44 2008 : Debug: Finished request 2 Mon Feb 4 20:52:44 2008 : Debug: Going to the next request Mon Feb 4 20:52:44 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.1.150:32797, id=120, length=182 User-Name = "test@SECURACCESS" NAS-IP-Address = 192.168.1.73 NAS-Port = 1 NAS-Identifier = "10" NAS-Port-Type = Wireless-802.11 Calling-Station-Id = "0012793DFC0C" Called-Station-Id = "000B86600A58" Framed-MTU = 1100 EAP-Message = 0x021200061500 State = 0x19946293a6618e7c4a043aeec88d5888 Aruba-Essid-Name = "demo-wpa-aes-eap-radius" Aruba-Location-Id = "1.1.1" Message-Authenticator = 0x9862beb03494e845f29966a4d4f51a40 Mon Feb 4 20:52:44 2008 : Debug: Processing the authorize section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authorize for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 3 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Looking up realm "SECURACCESS" for User-Name = "test@SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Found realm "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Stripped-User-Name = "test" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Proxying request from user test to realm SECURACCESS Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Realm = "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Authentication realm is LOCAL. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ntdomain (rlm_realm) for request 3 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Request already proxied. Ignoring. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ntdomain (rlm_realm) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ntdomain" returns noop for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 3 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP packet type response id 18 length 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 3 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: - authorize Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing user authorization for test Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: '(uid=test)' Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: 'o=Contonso' Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing search in o=Contonso, with filter (uid=test) Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: object not found or got ambiguous search result Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: search failed Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ldap" returns notfound for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 3 Mon Feb 4 20:52:44 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 3 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authorize (returns updated) for request 3 Mon Feb 4 20:52:44 2008 : Debug: rad_check_password: Found Auth-Type EAP Mon Feb 4 20:52:44 2008 : Debug: auth: type "EAP" Mon Feb 4 20:52:44 2008 : Debug: Processing the authenticate section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authenticate for request 3 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 3 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: Request found, released from the list Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP/ttls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: processing type ttls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_ttls: Authenticate Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: processing TLS Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: Received EAP-TLS ACK message Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: ack handshake fragment handler Mon Feb 4 20:52:44 2008 : Debug: eaptls_verify returned 1 Mon Feb 4 20:52:44 2008 : Debug: eaptls_process returned 13 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 3 Mon Feb 4 20:52:44 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 3 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 3 Sending Access-Challenge of id 120 to 192.168.1.150 port 32797 EAP-Message = 0x0113040a15c000000c333c37cc5bd5e729e15345b647b3aee7210844474111d18f6af49d70add23ef57f38a428819d7a19ebafa0116fefb92c661e04caa3033b5fe69d99025c05b372b62870e2fb5134b0df55750147f5c7bac680a730fb8ea083c372d1116b1c60138effe91489a283ae480578b3d8508d12850426413d1915d90acca3d956396f47806fc321847f7f203d32de882785a5e05904cde3c2b093426599ae3f712eec879d07d56edc18de2bfea55c9ceb6c9dbddc55e3cdb971ad891a32db01a7f2e29190682e6652cf95a6e2f7332112cd5ae5bfb67843c9e33ac7bed315be2585c90cfa12e95319804997b44abab0f9c13917e7a5cc76 EAP-Message = 0xc8a6e8ffd1edd298f4cf4075dd6558de23ab6a1bc5c165e3b442cdc63bee42a9e9b83a629d5c63f5eccf7675d36c4fca76251d73fb614b61a36dbc3fd92bfa16632d633471c66edd20d31126b31747adddb9c14c2b22e3860c4b3cfbd22fea2ae4c9df7271e6ea9a1dc870f8e65fb574dc6997eac891a72d3b1981e5433bf47097975c47190172a413ce3807b1d80060cbf754ae52739d40f51f29e412ff0203010001a37e307c300c0603551d13040530030101ff302c06096086480186f842010d041f161d4f70656e53534c2047656e657261746564204365727469666963617465301d0603551d0e0416041499af94ad394435f978892466dd2b13 EAP-Message = 0x253b42340b301f0603551d2304183016801499af94ad394435f978892466dd2b13253b42340b300d06092a864886f70d0101050500038202010061bfbd71830ff293c5922f3da3d5237a209f1ee434c4f3b934b3a2baaf4a5040c5a6053711d41971312cbb0aef5e36835e7d004b31ca94108aa520793271cd9e7f5127f07a1239659e38939abc2596527533b83dfd8872924a95b7b2f3e104072c67a930086d3b7bf9dbad66be815a05a0f7966b68bbeed5b0ca9e776b8e9d81b127b1a9e03664b2385c5327d8bd6f451a4c7abde1a609c17871037b4d51a989be25a6ccd3848ccc60be7d51587601bdd2c04b02e99531ad05712e53e88d8dad63daab EAP-Message = 0xa0c3b966f5514699f29bc3e6959bca6dccebdb91106931d96364e9068ddbf07ea77a69070790033627926a113883f65b4ef5bfe7e3a8fc344116ef414774cfcbd6c6452ea43078f8bf49107e034517116bef2db6d1746b9cf70ba74bbacbd3cb26574f960c0651cc1deac83f008350ee3cc2d6f10221b77065f67e2ec8402af27a098ff8b056ab756abc55d33616e67bf97f6520337142d8fb5b164e0709cf5192ec78be35f5e00d2c94e196e4a2163f3752e7775c563a469e0cab5a0a968efac6e19250416424364ffb8dc86cda91125305631bf77f701936b792e138b62cf88693ee791c728ecf7e429463fee314b8c9fec8e82a241eea8da8e27aa5 EAP-Message = 0x44f3f314005fc08c678d0e9c55c4b93190a1f1099448 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x94456063a786c1bdfac9f8c7d3134f51 Mon Feb 4 20:52:44 2008 : Debug: Finished request 3 Mon Feb 4 20:52:44 2008 : Debug: Going to the next request Mon Feb 4 20:52:44 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.1.150:32797, id=121, length=182 User-Name = "test@SECURACCESS" NAS-IP-Address = 192.168.1.73 NAS-Port = 1 NAS-Identifier = "10" NAS-Port-Type = Wireless-802.11 Calling-Station-Id = "0012793DFC0C" Called-Station-Id = "000B86600A58" Framed-MTU = 1100 EAP-Message = 0x021300061500 State = 0x94456063a786c1bdfac9f8c7d3134f51 Aruba-Essid-Name = "demo-wpa-aes-eap-radius" Aruba-Location-Id = "1.1.1" Message-Authenticator = 0x6a2841711dce9e6ae84fb24a861b833d Mon Feb 4 20:52:44 2008 : Debug: Processing the authorize section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authorize for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 4 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Looking up realm "SECURACCESS" for User-Name = "test@SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Found realm "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Stripped-User-Name = "test" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Proxying request from user test to realm SECURACCESS Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Realm = "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Authentication realm is LOCAL. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ntdomain (rlm_realm) for request 4 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Request already proxied. Ignoring. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ntdomain (rlm_realm) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ntdomain" returns noop for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 4 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP packet type response id 19 length 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 4 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: - authorize Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing user authorization for test Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: '(uid=test)' Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: 'o=Contonso' Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing search in o=Contonso, with filter (uid=test) Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: object not found or got ambiguous search result Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: search failed Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ldap" returns notfound for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 4 Mon Feb 4 20:52:44 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 4 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authorize (returns updated) for request 4 Mon Feb 4 20:52:44 2008 : Debug: rad_check_password: Found Auth-Type EAP Mon Feb 4 20:52:44 2008 : Debug: auth: type "EAP" Mon Feb 4 20:52:44 2008 : Debug: Processing the authenticate section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authenticate for request 4 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 4 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: Request found, released from the list Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP/ttls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: processing type ttls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_ttls: Authenticate Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: processing TLS Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: Received EAP-TLS ACK message Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: ack handshake fragment handler Mon Feb 4 20:52:44 2008 : Debug: eaptls_verify returned 1 Mon Feb 4 20:52:44 2008 : Debug: eaptls_process returned 13 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 4 Mon Feb 4 20:52:44 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 4 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 4 Sending Access-Challenge of id 121 to 192.168.1.150 port 32797 EAP-Message = 0x0114003d158000000c332b783c9a6aa1d5630cd553fc8c05a6a56d84f0c8c28322feea2824fa177337d937d64005d1d45cdb2c8316030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x599e93eee1c6146812d0b6ddb489ced5 Mon Feb 4 20:52:44 2008 : Debug: Finished request 4 Mon Feb 4 20:52:44 2008 : Debug: Going to the next request Mon Feb 4 20:52:44 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.1.150:32797, id=122, length=764 User-Name = "test@SECURACCESS" NAS-IP-Address = 192.168.1.73 NAS-Port = 1 NAS-Identifier = "10" NAS-Port-Type = Wireless-802.11 Calling-Station-Id = "0012793DFC0C" Called-Station-Id = "000B86600A58" Framed-MTU = 1100 EAP-Message = 0x0214024815800000023e16030102061000020202007bafc884717dda58f2a7526f7b94e46737017dee5647414914920556bab20b5d0e3e27333001cbff966ba04bb09b8dffd82a29b5187fd94d0fe79efc23c5ed398840ece5c282c98d2120eadd85122ba6aa6e3386ecd6b1cdee473c4ad2870cad5b310c2de9b441f10581becf019c8a9ae15f79c00b171d2e08f9d878950cb836247a122c60334d21c051466db824675b412ab9a44c5536b9eecba51e31f5282844f2ba8dbeee4661a7c0034302c20545daacffce9769abf37fc849bb31d124722f74c5a59f765e03cd42bf230cdc0ccca0c45533dc0dfbe49b7818943d2515152bd8e71f3c8140a4 EAP-Message = 0xc005d44efa8064b6e875980bb199f4a9d7f7d25d3d45212a59a72e280c91cbeaa729edea3c998145677ec67ba5044935dd732b699214fb6253913951fe4555b0fe2e6363e2394591dba3bbbbd65d3c02782e33834c36ff4e92694e67ab0b19cfffb2b2b1ee917102f71396040fa8117bc060e70302ed13a79f56e65c2496a772789895ee1bd0acb75ba9f28ad2659ba4bfef35abad606e70967db1562151e2dc634e329cc433db469a7d8e4c33015a6459d6e984edca512c71121b48aec638151aa09af22febb22d39b991bdcd26623927ba586a66ed3d1feddd47c4bd9321cc340d1ba06095c20077d2a4436789addaa24df0d93a26ef8bc8b13456f7 EAP-Message = 0x2a7ba5c984ccb2994deb22e7730ee1c20657536f8533aaf7eceed8140301000101160301002840ddb649d1e7d3f8909340bd0e5e41f22e2c3d4bc2539b75add5c52b63d93481120cf7e30a339cee State = 0x599e93eee1c6146812d0b6ddb489ced5 Aruba-Essid-Name = "demo-wpa-aes-eap-radius" Aruba-Location-Id = "1.1.1" Message-Authenticator = 0xcf2300a6fc5275eabd08b2dcdde2ab74 Mon Feb 4 20:52:44 2008 : Debug: Processing the authorize section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authorize for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 5 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Looking up realm "SECURACCESS" for User-Name = "test@SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Found realm "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Stripped-User-Name = "test" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Proxying request from user test to realm SECURACCESS Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Realm = "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Authentication realm is LOCAL. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ntdomain (rlm_realm) for request 5 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Request already proxied. Ignoring. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ntdomain (rlm_realm) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ntdomain" returns noop for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 5 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP packet type response id 20 length 253 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 5 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: - authorize Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing user authorization for test Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: '(uid=test)' Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: 'o=Contonso' Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing search in o=Contonso, with filter (uid=test) Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: object not found or got ambiguous search result Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: search failed Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ldap" returns notfound for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 5 Mon Feb 4 20:52:44 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 5 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authorize (returns updated) for request 5 Mon Feb 4 20:52:44 2008 : Debug: rad_check_password: Found Auth-Type EAP Mon Feb 4 20:52:44 2008 : Debug: auth: type "EAP" Mon Feb 4 20:52:44 2008 : Debug: Processing the authenticate section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authenticate for request 5 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 5 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: Request found, released from the list Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP/ttls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: processing type ttls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_ttls: Authenticate Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: processing TLS Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: Length Included Mon Feb 4 20:52:44 2008 : Debug: eaptls_verify returned 11 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0206], ClientKeyExchange Mon Feb 4 20:52:44 2008 : Debug: TLS_accept: SSLv3 read client key exchange A Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001] Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished Mon Feb 4 20:52:44 2008 : Debug: TLS_accept: SSLv3 read finished A Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001] Mon Feb 4 20:52:44 2008 : Debug: TLS_accept: SSLv3 write change cipher spec A Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished Mon Feb 4 20:52:44 2008 : Debug: TLS_accept: SSLv3 write finished A Mon Feb 4 20:52:44 2008 : Debug: TLS_accept: SSLv3 flush data Mon Feb 4 20:52:44 2008 : Debug: (other): SSL negotiation finished successfully Mon Feb 4 20:52:44 2008 : Debug: SSL Connection Established Mon Feb 4 20:52:44 2008 : Debug: eaptls_process returned 13 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 5 Mon Feb 4 20:52:44 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 5 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 5 Sending Access-Challenge of id 122 to 192.168.1.150 port 32797 EAP-Message = 0x0115003d1580000000331403010001011603010028c3719315b8d9e6d4eae0bc8c77237ac02f599c00e5034006caa378c5e8a62cf92d7e81fef51bd9a3 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xd05169daef375bd7bda1bea39c45093d Mon Feb 4 20:52:44 2008 : Debug: Finished request 5 Mon Feb 4 20:52:44 2008 : Debug: Going to the next request Mon Feb 4 20:52:44 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.1.150:32797, id=123, length=255 User-Name = "test@SECURACCESS" NAS-IP-Address = 192.168.1.73 NAS-Port = 1 NAS-Identifier = "10" NAS-Port-Type = Wireless-802.11 Calling-Station-Id = "0012793DFC0C" Called-Station-Id = "000B86600A58" Framed-MTU = 1100 EAP-Message = 0x0215004f15800000004517030100409708869751b831d71530de8ac731f09821ddd5969dd9176cf7c6e8e86b722040f15dc945a6553b82fef53957c981964263e3b514325e01934bc41beeb6ef16e8 State = 0xd05169daef375bd7bda1bea39c45093d Aruba-Essid-Name = "demo-wpa-aes-eap-radius" Aruba-Location-Id = "1.1.1" Message-Authenticator = 0xf70130148799389714607eeba85e4820 Mon Feb 4 20:52:44 2008 : Debug: Processing the authorize section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authorize for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Looking up realm "SECURACCESS" for User-Name = "test@SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Found realm "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Stripped-User-Name = "test" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Proxying request from user test to realm SECURACCESS Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Realm = "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Authentication realm is LOCAL. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ntdomain (rlm_realm) for request 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Request already proxied. Ignoring. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ntdomain (rlm_realm) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ntdomain" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP packet type response id 21 length 79 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: - authorize Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing user authorization for test Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: '(uid=test)' Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: 'o=Contonso' Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing search in o=Contonso, with filter (uid=test) Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: object not found or got ambiguous search result Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: search failed Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ldap" returns notfound for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authorize (returns updated) for request 6 Mon Feb 4 20:52:44 2008 : Debug: rad_check_password: Found Auth-Type EAP Mon Feb 4 20:52:44 2008 : Debug: auth: type "EAP" Mon Feb 4 20:52:44 2008 : Debug: Processing the authenticate section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authenticate for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: Request found, released from the list Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: EAP/ttls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: processing type ttls Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_ttls: Authenticate Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: processing TLS Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_tls: Length Included Mon Feb 4 20:52:44 2008 : Debug: eaptls_verify returned 11 Mon Feb 4 20:52:44 2008 : Debug: eaptls_process returned 7 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap_ttls: Session established. Proceeding to decode tunneled attributes. Mon Feb 4 20:52:44 2008 : Debug: Processing the authorize section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group authorize for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Looking up realm "SECURACCESS" for User-Name = "test@SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Found realm "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Stripped-User-Name = "test" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Proxying request from user test to realm SECURACCESS Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Adding Realm = "SECURACCESS" Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Authentication realm is LOCAL. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ntdomain (rlm_realm) for request 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_realm: Request already proxied. Ignoring. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ntdomain (rlm_realm) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ntdomain" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: No EAP-Message, not doing EAP Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "eap" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 6 Mon Feb 4 20:52:44 2008 : Debug: users: Matched entry DEFAULT at line 217 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "files" returns ok for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling ldap (rlm_ldap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: - authorize Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing user authorization for test Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: '(uid=test)' Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: 'o=Contonso' Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0 Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: performing search in o=Contonso, with filter (uid=test) Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: object not found or got ambiguous search result Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: search failed Mon Feb 4 20:52:44 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from ldap (rlm_ldap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "ldap" returns notfound for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authorize (returns ok) for request 6 Mon Feb 4 20:52:44 2008 : Debug: TTLS: Tunneled authentication will be proxied to SECURE Mon Feb 4 20:52:44 2008 : Debug: Tunneled session will be proxied. Not doing EAP. Mon Feb 4 20:52:44 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 6 Mon Feb 4 20:52:44 2008 : Debug: proxy: creating 6401a8c0:1812 Mon Feb 4 20:52:44 2008 : Debug: proxy: allocating 6401a8c0:1812 0 Sending Access-Request of id 0 to 192.168.1.100 port 1812 User-Name = "test" User-Password = "test" NAS-IP-Address = 192.168.1.73 NAS-Port = 1 NAS-Identifier = "10" NAS-Port-Type = Wireless-802.11 Calling-Station-Id = "0012793DFC0C" Called-Station-Id = "000B86600A58" Framed-MTU = 1100 Aruba-Essid-Name = "demo-wpa-aes-eap-radius" Aruba-Location-Id = "1.1.1" Proxy-State = 0x313233 Mon Feb 4 20:52:44 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Accept packet from host 192.168.1.100:1812, id=0, length=79 Mon Feb 4 20:52:44 2008 : Debug: proxy: de-allocating 6401a8c0:1812 0 Proxy-State = 0x313233 Reply-Message = "employee" Framed-Protocol = PPP Service-Type = Framed-User Class = 0x5f8f06b6000001370001c0a8016401c8639ae3c2f7470000000000000006 Mon Feb 4 20:52:44 2008 : Debug: Processing the post-proxy section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group post-proxy for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[post-proxy]: calling eap (rlm_eap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: TTLS: Passing reply from proxy back into the tunnel. Mon Feb 4 20:52:44 2008 : Debug: Processing the post-auth section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group post-auth for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[post-auth]: calling ldap (rlm_ldap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[post-auth]: returned from ldap (rlm_ldap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[post-auth]: module "ldap" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group post-auth (returns noop) for request 6 Mon Feb 4 20:52:44 2008 : Debug: POST-AUTH 2 Mon Feb 4 20:52:44 2008 : Debug: TTLS: Got reply 2 Mon Feb 4 20:52:44 2008 : Debug: TTLS: Got tunneled Access-Accept Mon Feb 4 20:52:44 2008 : Debug: TTLS: Reply was OK Mon Feb 4 20:52:44 2008 : Debug: rlm_eap: Freeing handler Mon Feb 4 20:52:44 2008 : Debug: modsingle[post-proxy]: returned from eap (rlm_eap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[post-proxy]: module "eap" returns ok for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group post-proxy (returns ok) for request 6 Mon Feb 4 20:52:44 2008 : Debug: authorize: Skipping authorize in post-proxy stage Mon Feb 4 20:52:44 2008 : Debug: rad_check_password: Found Auth-Type EAP Mon Feb 4 20:52:44 2008 : Debug: rad_check_password: Found Auth-Type Mon Feb 4 20:52:44 2008 : Error: Warning: Found 2 auth-types on request for user 'test' Mon Feb 4 20:52:44 2008 : Debug: rad_check_password: Auth-Type = Accept, accepting the user Mon Feb 4 20:52:44 2008 : Debug: radius_xlat: 'employee' Mon Feb 4 20:52:44 2008 : Auth: Login OK: [test/<no User-Password attribute>] (from client Aruba-vlan-2 port 1 cli 0012793DFC0C) Mon Feb 4 20:52:44 2008 : Debug: Processing the post-auth section of radiusd.conf Mon Feb 4 20:52:44 2008 : Debug: modcall: entering group post-auth for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[post-auth]: calling ldap (rlm_ldap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modsingle[post-auth]: returned from ldap (rlm_ldap) for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall[post-auth]: module "ldap" returns noop for request 6 Mon Feb 4 20:52:44 2008 : Debug: modcall: leaving group post-auth (returns noop) for request 6 Sending Access-Accept of id 123 to 192.168.1.150 port 32797 Reply-Message = "employee" Framed-Protocol = PPP Service-Type = Framed-User Class = 0x5f8f06b6000001370001c0a8016401c8639ae3c2f7470000000000000006 MS-MPPE-Recv-Key = 0x8d820c1624b99153c6469e0cbfae48edf802af9369cc26d3ac4450438d62e8a7 MS-MPPE-Send-Key = 0x873dac958ab08b3d70331396f8bd44c5423756c2866761f8638473fccb33f007 EAP-Message = 0x03150004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "test" Mon Feb 4 20:52:44 2008 : Debug: Finished request 6 Mon Feb 4 20:52:44 2008 : Debug: Going to the next request Mon Feb 4 20:52:44 2008 : Debug: Waking up in 6 seconds... Mon Feb 4 20:52:50 2008 : Debug: --- Walking the entire request list --- Mon Feb 4 20:52:50 2008 : Debug: Cleaning up request 0 ID 117 with timestamp 47a76d0c Mon Feb 4 20:52:50 2008 : Debug: Cleaning up request 1 ID 118 with timestamp 47a76d0c Mon Feb 4 20:52:50 2008 : Debug: Cleaning up request 2 ID 119 with timestamp 47a76d0c Mon Feb 4 20:52:50 2008 : Debug: Cleaning up request 3 ID 120 with timestamp 47a76d0c Mon Feb 4 20:52:50 2008 : Debug: Cleaning up request 4 ID 121 with timestamp 47a76d0c Mon Feb 4 20:52:50 2008 : Debug: Cleaning up request 5 ID 122 with timestamp 47a76d0c Mon Feb 4 20:52:50 2008 : Debug: Cleaning up request 6 ID 123 with timestamp 47a76d0c Mon Feb 4 20:52:50 2008 : Debug: Nothing to do. Sleeping until we see a request.
==ENDoutput======================================================================
// J
Ivan Kalik wrote:
You are (still) not listening.
======== Proxy.conf ==================================================================== realm NULL { type = radius authhost = LOCAL accthost = LOCAL }
realm LOCAL { type = radius authhost = LOCAL accthost = LOCAL }
realm DOMAIN { type = radius authhost = LOCAL accthost = LOCAL }
realm SECURACCESS { type = radius authhost = 192.168.1.75:1812 accthost = 192.168.1.75:1813 secret = toor # nostrip }
I have told you to split user and server domains. Rename this SECUREACCESS into something like SECURE and make another entry for SECUREACCESS that will be the same as LOCAL.
==== users =========================================================================== DEFAULT FreeRADIUS-Proxied-To !* 127.0.0.1,
Proxy-To-Realm
:= LOCAL SECURACCESS FreeRADIUS-Proxied-To == 127.0.0.1, Proxy-To-Realm := "SECURACCESS" ==ENDusers===================================================================
Is that first entry doing anything? Proxy to (now renamed) SECURE (server realm, leave users realm alone).
======== output: =================================================== rad_recv: Access-Request packet from host 192.168.1.150:32797, id=185, length=199 User-Name = "joakimlindgren@SECURACCESS" NAS-IP-Address = 192.168.1.73 NAS-Port = 1 NAS-Identifier = "10" NAS-Port-Type = Wireless-802.11 Calling-Station-Id = "0012793DFC0C" Called-Station-Id = "000B86600A58" Framed-MTU = 1100 EAP-Message = 0x0201001f016a6f616b696d6c696e646772656e405345435552414343455353 Aruba-Essid-Name = "demo-wpa-aes-eap-radius" Aruba-Location-Id = "1.1.1" Message-Authenticator = 0x4a71e7a8e828c5fbfeba6f153ee22c40
..
Mon Feb 4 13:04:03 2008 : Debug: rlm_realm: Proxying request from user joakimlindgren to realm SECURACCESS Mon Feb 4 13:04:03 2008 : Debug: rlm_realm: Adding Realm = "SECURACCESS" Mon Feb 4 13:04:03 2008 : Debug: rlm_realm: Preparing to proxy authentication request to realm "SECURACCESS" ..
EAP doesn't get terminated - it gets proxied. Or at least that's where this is heading.
.. ..
Mon Feb 4 13:04:03 2008 : Debug: rlm_eap: Request is supposed to be proxied to Realm SECURACCESS. Not doing EAP. ..
Server thinks so too.
..
Mon Feb 4 13:04:04 2008 : Debug: rlm_pap: No clear-text password in the request. Not performing PAP. ..
Because it is an EAP request.
..
Mon Feb 4 13:04:04 2008 : Debug: WARNING: You set Proxy-To-Realm = LOCAL, but it is a LOCAL realm! Cancelling invalid proxy request. ..
Hm, so that first entry in users file does something. Try wihout it. This is why the request doesn't get proxied.
..
Sending Access-Reject of id 185 to 192.168.1.150 port 32797 Reply-Message = "" ..
Without proxying the request at all.
======== My thoughts about the output: ==========================================
Mon Feb 4 13:04:03 2008 : Debug: rlm_eap: Request is supposed to be proxied to Realm >SECURACCESS. Not doing EAP.
Detects that we want to proxy domain SECURACCESS. Terminate EAP and only proxy PAP.
That's not how you terminate EAP. You need to go through the whole TLS negotiation first. Once that is done, inner request will be extracted and that can be proxied.
Mon Feb 4 13:04:03 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 0 Mon Feb 4 13:04:03 2008 : Debug: users: Matched entry DEFAULT at
line
209
Mon Feb 4 13:04:03 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 0 Mon Feb 4 13:04:03 2008 : Debug: modcall[authorize]: module "files" returns ok for request 0
Found the DEFAULT entry in users: DEFAULT FreeRADIUS-Proxied-To !* 127.0.0.1, Proxy-To-Realm := LOCAL
OK, but that's irrelevant. You should make (users) realm SECURACCESS local too.
Mon Feb 4 13:04:04 2008 : Debug: rlm_pap: No clear-text password in the request. Not performing PAP.
Not finding a clear-text password? Why can´t it suddenly use the password stored in the eDirectory (Stored as clear-text?).
Read the debug ==> No clear-text password in the *request*. That's because the request is still EAP.
Mon Feb 4 13:04:04 2008 : Debug: modsingle[authorize]: returned from
pap
(rlm_pap) for request 0
Mon Feb 4 13:04:04 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 0 Mon Feb 4 13:04:04 2008 : Debug: modcall: leaving group authorize (returns updated) for request 0 Mon Feb 4 13:04:04 2008 : Debug: WARNING: You set Proxy-To-Realm = LOCAL, but it is a LOCAL >realm! Cancelling invalid proxy request.
Only a warning right?
Mon Feb 4 13:04:04 2008 : Debug: auth: type Local Mon Feb 4 13:04:04 2008 : Debug: auth: No User-Password or CHAP-Password attribute in the request
Failed due to not finding a User-Password...Why?
Because there is no password in the request - it's an EAP request. You need to finish with EAP first and then PAP attributes will be available.
Ivan Kalik Kalik Informatika ISP
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-- View this message in context: http://www.nabble.com/Terminate-EAP-PEAP-client-connection-at-FreeRadius-Pro... Sent from the FreeRadius - User mailing list archive at Nabble.com.