Terminate EAP-PEAP client connection at FreeRadiusProxyandproxy(forward) request as PAP
Jayal1972
joakim.lindgren at gmail.com
Mon Feb 4 22:01:06 CET 2008
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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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-Proxy-and-proxy%28forward%29-request-as-PAP-tp15218593p15277410.html
Sent from the FreeRadius - User mailing list archive at Nabble.com.
More information about the Freeradius-Users
mailing list