All, I have a number of NASs - wireless APs running hostapd. I am setting up a freeradius 2.1.10 server to control the authentication of username@net.example.com to the wireless network; the decision is to be made by a Kerberos server. The setup is not working as intended, which I think stems either from my misunderstanding of the protocols involved or of how to set up freeradius correctly. Or both. Later, all authentication requests of username@example.com (without the net.) are to be forwarded to another Radius server. There will likely be more services integrated in the same vein later, so I would like to branch out into separate virtual servers based on realm. My understanding is that the communication between a user@net.example.com and freeradius needs to involve EAP-TTLS, because of the cleartext password which is required to be passed on to kerberos. The required keytab is set up and configured correctly. modules/krb5 is set up accordingly. bootstrap in raddb/certs has been run to create self-signed certs. I have an entry in the users file: DEFAULT Realm == "net.example.com", Auth-Type = Kerberos The realm is set up like this: realm net.example.com { virtual_server = net.example.com } And the virtual server as well as the inner-tunnel have Auth-Type Kerberos { krb5 } in their authenticate section, right after Auth-Type PAP. Key changes in eap.conf: eap { default_eap_type = ttls ttls { default_eap_type = md5 copy_request_to_tunnel = yes use_tunneled_reply = yes } } Local tests succeed as follows: $ radtest -t pap thorsten@net.example.com pwd 127.0.0.1 0 testing123 $ radtest -t eap-md5 thorsten@net.example.com pwd 127.0.0.1 0 testing123 $ radtest -t pap thorsten@net.example.com pwd 127.0.0.1:18120 0 testing123 In each of these cases, the reason for success is successful communication with Kerberos, as exemplified by the following lines (and wrong kerberos passwords let authentication fail): Wed Feb 2 15:59:06 2011 : Info: Found Auth-Type = Kerberos Wed Feb 2 15:59:06 2011 : Info: # Executing group from file /etc/freeradius/sites-enabled/net.example.com Wed Feb 2 15:59:06 2011 : Info: +- entering group Kerberos {...} Wed Feb 2 15:59:06 2011 : Info: ++[krb5] returns ok Wed Feb 2 15:59:06 2011 : Auth: Login OK: [thorsten] (from client localhost port 0 via TLS tunnel) However, tests with eapol_test locally as well as with the actual access points fail: $ cat eap-ttls.conf network={ ssid="myssid" key_mgmt=WPA-EAP eap=TTLS identity="thorsten@net.example.com" password="pwd" phase2="auth=PAP" } $ eapol_test -c eap-ttls.conf -s testing123 produces: rad_recv: Access-Request packet from host 127.0.0.1 port 60596, id=0, length=172 User-Name = "thorsten@net.example.com" NAS-IP-Address = 127.0.0.1 Calling-Station-Id = "02-00-00-00-00-01" Framed-MTU = 1400 Calling-Station-Id ="02-00-00-00-00-01" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020000250174686f727374656e406e65742e742d6c6162732e74752d6265726c696e2e6465 Message-Authenticator = 0x3f0be4354cfc77a6285a0ad074341101 Wed Feb 2 15:33:32 2011 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Wed Feb 2 15:33:32 2011 : Info: +- entering group authorize {...} Wed Feb 2 15:33:32 2011 : Info: ++[preprocess] returns ok Wed Feb 2 15:33:32 2011 : Info: ++[chap] returns noop Wed Feb 2 15:33:32 2011 : Info: ++[mschap] returns noop Wed Feb 2 15:33:32 2011 : Info: ++[digest] returns noop Wed Feb 2 15:33:32 2011 : Info: [suffix] Looking up realm "net.example.com" for User-Name = "thorsten@net.example.com" Wed Feb 2 15:33:32 2011 : Info: [suffix] Found realm "net.example.com" Wed Feb 2 15:33:32 2011 : Info: [suffix] Adding Stripped-User-Name = "thorsten" Wed Feb 2 15:33:32 2011 : Info: [suffix] Adding Realm = "net.example.com" Wed Feb 2 15:33:32 2011 : Info: [suffix] Proxying request from user thorsten to realm net.example.com Wed Feb 2 15:33:32 2011 : Info: [suffix] Preparing to proxy authentication request to realm "net.example.com" Wed Feb 2 15:33:32 2011 : Info: ++[suffix] returns updated Wed Feb 2 15:33:32 2011 : Info: [eap] Request is supposed to be proxied to Realm net.example.com. Not doing EAP. Wed Feb 2 15:33:32 2011 : Info: ++[eap] returns noop Wed Feb 2 15:33:32 2011 : Info: [files] users: Matched entry DEFAULT at line 71 Wed Feb 2 15:33:32 2011 : Info: ++[files] returns ok Wed Feb 2 15:33:32 2011 : Info: ++[expiration] returns noop Wed Feb 2 15:33:32 2011 : Info: ++[logintime] returns noop Wed Feb 2 15:33:32 2011 : Info: ++[pap] returns noop Wed Feb 2 15:33:32 2011 : Info: WARNING: Empty pre-proxy section. Using default return values. Wed Feb 2 15:33:32 2011 : Info: >>> Sending proxied request internally to virtual server. Wed Feb 2 15:33:32 2011 : Info: server net.example.com { Wed Feb 2 15:33:32 2011 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/net.example.com Wed Feb 2 15:33:32 2011 : Info: +- entering group authorize {...} Wed Feb 2 15:33:32 2011 : Info: ++[preprocess] returns ok Wed Feb 2 15:33:32 2011 : Info: ++[digest] returns noop Wed Feb 2 15:33:32 2011 : Info: [suffix] Request already proxied. Ignoring. Wed Feb 2 15:33:32 2011 : Info: ++[suffix] returns ok Wed Feb 2 15:33:32 2011 : Info: [files] users: Matched entry DEFAULT at line 71 Wed Feb 2 15:33:32 2011 : Info: ++[files] returns ok Wed Feb 2 15:33:32 2011 : Info: ++[expiration] returns noop Wed Feb 2 15:33:32 2011 : Info: ++[logintime] returns noop Wed Feb 2 15:33:32 2011 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Feb 2 15:33:32 2011 : Info: ++[pap] returns noop Wed Feb 2 15:33:32 2011 : Info: Found Auth-Type = Kerberos Wed Feb 2 15:33:32 2011 : Info: # Executing group from file /etc/freeradius/sites-enabled/net.example.com Wed Feb 2 15:33:32 2011 : Info: +- entering group Kerberos {...} Wed Feb 2 15:33:32 2011 : Auth: rlm_krb5: Attribute "User-Password" is required for authentication. Wed Feb 2 15:33:32 2011 : Info: ++[krb5] returns invalid Wed Feb 2 15:33:32 2011 : Info: Failed to authenticate the user. [...] Apparently, the cleartext password does not get passed on. And I need to figure out why. This is were you come in, mailing list ;) Thank you in advance for suggestions. Cheers, t -- Thorsten Fischer, BOWL Project Administrator <thorsten@net.t-labs.tu-berlin.de> Technische Universität Berlin, FG INET, TEL16, 18th floor Ernst-Reuter-Platz 7, 10587 Berlin, Germany Tel: +49 30 835358542, Fax: +49 391 53478347
On 02/02/11 16:29, Thorsten Fischer wrote:
All,
I have a number of NASs - wireless APs running hostapd. I am setting up a freeradius 2.1.10 server to control the authentication of username@net.example.com to the wireless network; the decision is to be made by a Kerberos server. The setup is not working as intended, which I think stems either from my misunderstanding of the protocols involved or of how to set up freeradius correctly. Or both.
Later, all authentication requests of username@example.com (without the net.) are to be forwarded to another Radius server. There will likely be more services integrated in the same vein later, so I would like to branch out into separate virtual servers based on realm.
My understanding is that the communication between a user@net.example.com and freeradius needs to involve EAP-TTLS, because of the cleartext password which is required to be passed on to kerberos. The required keytab is set up and configured correctly. modules/krb5 is set up accordingly. bootstrap in raddb/certs has been run to create self-signed certs.
I have an entry in the users file:
DEFAULT Realm == "net.example.com", Auth-Type = Kerberos
Yeah, that won't work; it is forcing the server to try Kerberos, even when the request is EAP. You want something like this in /etc/raddb/sites-enabled/inner-tunnel: authorize { ... ... # let the PAP module detect that it's PAP pap } authenticate { Auth-Type PAP { # ...but check PAP via kerberos krb5 } } ...or: authorize { ... # if we get here, set Auth-Type if (User-Password) { update control { # (unless a higher-up module has set it) Auth-Type = Kerberos } } } authenticate { Auth-Type Kerberos { krb5 } }
Hello, Using the above script I was able to get a clean install to contact my kerberos server via 'inner-tunnel' and 802.1x. Unfortunately, Kerberos is reporting that it needs the User-Password attribute. I've modified the script to show that the User-Password is empty in 'inner-tunnel'. As usual, the radtest to localhost works as expected. eap.conf only has eap-default-type set to tls, client.conf has the access point loaded, and 'inner-tunnel' is as above, except that if (!User-Password) {...} is added. All other files are clean reinstall on centos 5. Below is the obligatory Debug -X file. joe Apr 20 14:18:25 2011 : Info: Starting - reading configuration files ... Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/radiusd.conf Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/proxy.conf Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/clients.conf Wed Apr 20 14:18:25 2011 : Debug: including files in directory /etc/raddb/modules/ Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/checkval Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/perl Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/radutmp Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/smbpasswd Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/inner-eap Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/always Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/sradutmp Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/krb5 Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/realm Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/sql_log Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/passwd Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/echo Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/mschap Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/expr Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/pam Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/detail.example.com Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/otp Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/logintime Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/attr_rewrite Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/acct_unique Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/exec Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/unix Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/chap Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/policy Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/counter Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/sqlcounter_expire_on_login Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/detail.log Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/digest Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/files Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/attr_filter Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/ippool Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/pap Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/wimax Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/etc_group Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/linelog Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/cui Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/mac2vlan Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/expiration Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/detail Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/ldap Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/smsotp Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/preprocess Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/modules/mac2ip Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/eap.conf Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/policy.conf Wed Apr 20 14:18:25 2011 : Debug: including files in directory /etc/raddb/sites-enabled/ Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/sites-enabled/default Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/sites-enabled/inner-tunnel Wed Apr 20 14:18:25 2011 : Debug: including configuration file /etc/raddb/sites-enabled/control-socket Wed Apr 20 14:18:25 2011 : Debug: group = radiusd Wed Apr 20 14:18:25 2011 : Debug: user = radiusd Wed Apr 20 14:18:25 2011 : Debug: including dictionary file /etc/raddb/dictionary Wed Apr 20 14:18:25 2011 : Debug: main { Wed Apr 20 14:18:25 2011 : Debug: prefix = "/usr" Wed Apr 20 14:18:25 2011 : Debug: localstatedir = "/var" Wed Apr 20 14:18:25 2011 : Debug: logdir = "/var/log/radius" Wed Apr 20 14:18:25 2011 : Debug: libdir = "/usr/lib64/freeradius" Wed Apr 20 14:18:25 2011 : Debug: radacctdir = "/var/log/radius/radacct" Wed Apr 20 14:18:25 2011 : Debug: hostname_lookups = no Wed Apr 20 14:18:25 2011 : Debug: max_request_time = 30 Wed Apr 20 14:18:25 2011 : Debug: cleanup_delay = 5 Wed Apr 20 14:18:25 2011 : Debug: max_requests = 1024 Wed Apr 20 14:18:25 2011 : Debug: allow_core_dumps = no Wed Apr 20 14:18:25 2011 : Debug: pidfile = "/var/run/radiusd/radiusd.pid" Wed Apr 20 14:18:25 2011 : Debug: checkrad = "/usr/sbin/checkrad" Wed Apr 20 14:18:25 2011 : Debug: debug_level = 0 Wed Apr 20 14:18:25 2011 : Debug: proxy_requests = yes Wed Apr 20 14:18:25 2011 : Debug: log { Wed Apr 20 14:18:25 2011 : Debug: stripped_names = no Wed Apr 20 14:18:25 2011 : Debug: auth = no Wed Apr 20 14:18:25 2011 : Debug: auth_badpass = no Wed Apr 20 14:18:25 2011 : Debug: auth_goodpass = no Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: security { Wed Apr 20 14:18:25 2011 : Debug: max_attributes = 200 Wed Apr 20 14:18:25 2011 : Debug: reject_delay = 1 Wed Apr 20 14:18:25 2011 : Debug: status_server = yes Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: radiusd: #### Loading Realms and Home Servers #### Wed Apr 20 14:18:25 2011 : Debug: proxy server { Wed Apr 20 14:18:25 2011 : Debug: retry_delay = 5 Wed Apr 20 14:18:25 2011 : Debug: retry_count = 3 Wed Apr 20 14:18:25 2011 : Debug: default_fallback = no Wed Apr 20 14:18:25 2011 : Debug: dead_time = 120 Wed Apr 20 14:18:25 2011 : Debug: wake_all_if_all_dead = no Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: home_server localhost { Wed Apr 20 14:18:25 2011 : Debug: ipaddr = 127.0.0.1 Wed Apr 20 14:18:25 2011 : Debug: port = 1812 Wed Apr 20 14:18:25 2011 : Debug: type = "auth" Wed Apr 20 14:18:25 2011 : Debug: secret = "testing123" Wed Apr 20 14:18:25 2011 : Debug: response_window = 20 Wed Apr 20 14:18:25 2011 : Debug: max_outstanding = 65536 Wed Apr 20 14:18:25 2011 : Debug: require_message_authenticator = no Wed Apr 20 14:18:25 2011 : Debug: zombie_period = 40 Wed Apr 20 14:18:25 2011 : Debug: status_check = "status-server" Wed Apr 20 14:18:25 2011 : Debug: ping_interval = 30 Wed Apr 20 14:18:25 2011 : Debug: check_interval = 30 Wed Apr 20 14:18:25 2011 : Debug: num_answers_to_alive = 3 Wed Apr 20 14:18:25 2011 : Debug: num_pings_to_alive = 3 Wed Apr 20 14:18:25 2011 : Debug: revive_interval = 120 Wed Apr 20 14:18:25 2011 : Debug: status_check_timeout = 4 Wed Apr 20 14:18:25 2011 : Debug: irt = 2 Wed Apr 20 14:18:25 2011 : Debug: mrt = 16 Wed Apr 20 14:18:25 2011 : Debug: mrc = 5 Wed Apr 20 14:18:25 2011 : Debug: mrd = 30 Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: home_server_pool my_auth_failover { Wed Apr 20 14:18:25 2011 : Debug: type = fail-over Wed Apr 20 14:18:25 2011 : Debug: home_server = localhost Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: realm example.com { Wed Apr 20 14:18:25 2011 : Debug: auth_pool = my_auth_failover Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: realm LOCAL { Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: radiusd: #### Loading Clients #### Wed Apr 20 14:18:25 2011 : Debug: client localhost { Wed Apr 20 14:18:25 2011 : Debug: ipaddr = 127.0.0.1 Wed Apr 20 14:18:25 2011 : Debug: require_message_authenticator = no Wed Apr 20 14:18:25 2011 : Debug: secret = "testing123" Wed Apr 20 14:18:25 2011 : Debug: nastype = "other" Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: client AccessPoint { Wed Apr 20 14:18:25 2011 : Debug: ipaddr = 10.x.x.x Wed Apr 20 14:18:25 2011 : Debug: require_message_authenticator = no Wed Apr 20 14:18:25 2011 : Debug: secret = "newmexicoconsortium" Wed Apr 20 14:18:25 2011 : Debug: shortname = "NMCproBe" Wed Apr 20 14:18:25 2011 : Debug: nastype = "other" Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: radiusd: #### Instantiating modules #### Wed Apr 20 14:18:25 2011 : Debug: instantiate { Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_exec, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_exec Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating exec Wed Apr 20 14:18:25 2011 : Debug: exec { Wed Apr 20 14:18:25 2011 : Debug: wait = no Wed Apr 20 14:18:25 2011 : Debug: input_pairs = "request" Wed Apr 20 14:18:25 2011 : Debug: shell_escape = yes Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_expr, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_expr Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating expr Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_expiration, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_expiration Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating expiration Wed Apr 20 14:18:25 2011 : Debug: expiration { Wed Apr 20 14:18:25 2011 : Debug: reply-message = "Password Has Expired " Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_logintime, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_logintime Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating logintime Wed Apr 20 14:18:25 2011 : Debug: logintime { Wed Apr 20 14:18:25 2011 : Debug: reply-message = "You are calling outside your allowed timespan " Wed Apr 20 14:18:25 2011 : Debug: minimum-timeout = 60 Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: radiusd: #### Loading Virtual Servers #### Wed Apr 20 14:18:25 2011 : Debug: server inner-tunnel { Wed Apr 20 14:18:25 2011 : Debug: modules { Wed Apr 20 14:18:25 2011 : Debug: Module: Checking authenticate {...} for more modules to load Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_pap, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_pap Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating pap Wed Apr 20 14:18:25 2011 : Debug: pap { Wed Apr 20 14:18:25 2011 : Debug: encryption_scheme = "auto" Wed Apr 20 14:18:25 2011 : Debug: auto_header = no Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_krb5, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_krb5 Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating krb5 Wed Apr 20 14:18:25 2011 : Debug: krb5 { Wed Apr 20 14:18:25 2011 : Debug: keytab = "/path/to/keytab" Wed Apr 20 14:18:25 2011 : Debug: service_principal = "name_of_principle" Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Auth: rlm_krb5: krb5_init ok Wed Apr 20 14:18:25 2011 : Debug: Module: Checking authorize {...} for more modules to load Wed Apr 20 14:18:25 2011 : Debug: Module: Checking session {...} for more modules to load Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_radutmp, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_radutmp Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating radutmp Wed Apr 20 14:18:25 2011 : Debug: radutmp { Wed Apr 20 14:18:25 2011 : Debug: filename = "/var/log/radius/radutmp" Wed Apr 20 14:18:25 2011 : Debug: username = "%{User-Name}" Wed Apr 20 14:18:25 2011 : Debug: case_sensitive = yes Wed Apr 20 14:18:25 2011 : Debug: check_with_nas = yes Wed Apr 20 14:18:25 2011 : Debug: perm = 384 Wed Apr 20 14:18:25 2011 : Debug: callerid = yes Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Module: Checking post-proxy {...} for more modules to load Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_eap, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_eap Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating eap Wed Apr 20 14:18:25 2011 : Debug: eap { Wed Apr 20 14:18:25 2011 : Debug: default_eap_type = "tls" Wed Apr 20 14:18:25 2011 : Debug: timer_expire = 60 Wed Apr 20 14:18:25 2011 : Debug: ignore_unknown_eap_types = no Wed Apr 20 14:18:25 2011 : Debug: cisco_accounting_username_bug = no Wed Apr 20 14:18:25 2011 : Debug: max_sessions = 2048 Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to sub-module rlm_eap_md5 Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating eap-md5 Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to sub-module rlm_eap_leap Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating eap-leap Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to sub-module rlm_eap_gtc Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating eap-gtc Wed Apr 20 14:18:25 2011 : Debug: gtc { Wed Apr 20 14:18:25 2011 : Debug: challenge = "Password: " Wed Apr 20 14:18:25 2011 : Debug: auth_type = "PAP" Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to sub-module rlm_eap_tls Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating eap-tls Wed Apr 20 14:18:25 2011 : Debug: tls { Wed Apr 20 14:18:25 2011 : Debug: rsa_key_exchange = no Wed Apr 20 14:18:25 2011 : Debug: dh_key_exchange = yes Wed Apr 20 14:18:25 2011 : Debug: rsa_key_length = 512 Wed Apr 20 14:18:25 2011 : Debug: dh_key_length = 512 Wed Apr 20 14:18:25 2011 : Debug: verify_depth = 0 Wed Apr 20 14:18:25 2011 : Debug: pem_file_type = yes Wed Apr 20 14:18:25 2011 : Debug: private_key_file = "/etc/raddb/certs/server.pem" Wed Apr 20 14:18:25 2011 : Debug: certificate_file = "/etc/raddb/certs/server.pem" Wed Apr 20 14:18:25 2011 : Debug: CA_file = "/etc/raddb/certs/ca.pem" Wed Apr 20 14:18:25 2011 : Debug: private_key_password = "whatever" Wed Apr 20 14:18:25 2011 : Debug: dh_file = "/etc/raddb/certs/dh" Wed Apr 20 14:18:25 2011 : Debug: random_file = "/etc/raddb/certs/random" Wed Apr 20 14:18:25 2011 : Debug: fragment_size = 1024 Wed Apr 20 14:18:25 2011 : Debug: include_length = yes Wed Apr 20 14:18:25 2011 : Debug: check_crl = no Wed Apr 20 14:18:25 2011 : Debug: cipher_list = "DEFAULT" Wed Apr 20 14:18:25 2011 : Debug: make_cert_command = "/etc/raddb/certs/bootstrap" Wed Apr 20 14:18:25 2011 : Debug: cache { Wed Apr 20 14:18:25 2011 : Debug: enable = no Wed Apr 20 14:18:25 2011 : Debug: lifetime = 24 Wed Apr 20 14:18:25 2011 : Debug: max_entries = 255 Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to sub-module rlm_eap_ttls Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating eap-ttls Wed Apr 20 14:18:25 2011 : Debug: ttls { Wed Apr 20 14:18:25 2011 : Debug: default_eap_type = "tls" Wed Apr 20 14:18:25 2011 : Debug: copy_request_to_tunnel = no Wed Apr 20 14:18:25 2011 : Debug: use_tunneled_reply = no Wed Apr 20 14:18:25 2011 : Debug: virtual_server = "inner-tunnel" Wed Apr 20 14:18:25 2011 : Debug: include_length = yes Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to sub-module rlm_eap_peap Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating eap-peap Wed Apr 20 14:18:25 2011 : Debug: peap { Wed Apr 20 14:18:25 2011 : Debug: default_eap_type = "mschapv2" Wed Apr 20 14:18:25 2011 : Debug: copy_request_to_tunnel = no Wed Apr 20 14:18:25 2011 : Debug: use_tunneled_reply = no Wed Apr 20 14:18:25 2011 : Debug: proxy_tunneled_request_as_eap = yes Wed Apr 20 14:18:25 2011 : Debug: virtual_server = "inner-tunnel" Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating eap-mschapv2 Wed Apr 20 14:18:25 2011 : Debug: mschapv2 { Wed Apr 20 14:18:25 2011 : Debug: with_ntdomain_hack = no Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Module: Checking post-auth {...} for more modules to load Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_attr_filter Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating attr_filter.access_reject Wed Apr 20 14:18:25 2011 : Debug: attr_filter attr_filter.access_reject { Wed Apr 20 14:18:25 2011 : Debug: attrsfile = "/etc/raddb/attrs.access_reject" Wed Apr 20 14:18:25 2011 : Debug: key = "%{User-Name}" Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: } # modules Wed Apr 20 14:18:25 2011 : Debug: } # server Wed Apr 20 14:18:25 2011 : Debug: server { Wed Apr 20 14:18:25 2011 : Debug: modules { Wed Apr 20 14:18:25 2011 : Debug: Module: Checking authenticate {...} for more modules to load Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_chap, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_chap Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating chap Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_mschap, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_mschap Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating mschap Wed Apr 20 14:18:25 2011 : Debug: mschap { Wed Apr 20 14:18:25 2011 : Debug: use_mppe = yes Wed Apr 20 14:18:25 2011 : Debug: require_encryption = no Wed Apr 20 14:18:25 2011 : Debug: require_strong = no Wed Apr 20 14:18:25 2011 : Debug: with_ntdomain_hack = no Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_unix, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_unix Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating unix Wed Apr 20 14:18:25 2011 : Debug: unix { Wed Apr 20 14:18:25 2011 : Debug: radwtmp = "/var/log/radius/radwtmp" Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Module: Checking authorize {...} for more modules to load Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_preprocess, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_preprocess Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating preprocess Wed Apr 20 14:18:25 2011 : Debug: preprocess { Wed Apr 20 14:18:25 2011 : Debug: huntgroups = "/etc/raddb/huntgroups" Wed Apr 20 14:18:25 2011 : Debug: hints = "/etc/raddb/hints" Wed Apr 20 14:18:25 2011 : Debug: with_ascend_hack = no Wed Apr 20 14:18:25 2011 : Debug: ascend_channels_per_line = 23 Wed Apr 20 14:18:25 2011 : Debug: with_ntdomain_hack = no Wed Apr 20 14:18:25 2011 : Debug: with_specialix_jetstream_hack = no Wed Apr 20 14:18:25 2011 : Debug: with_cisco_vsa_hack = no Wed Apr 20 14:18:25 2011 : Debug: with_alvarion_vsa_hack = no Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_realm, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_realm Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating suffix Wed Apr 20 14:18:25 2011 : Debug: realm suffix { Wed Apr 20 14:18:25 2011 : Debug: format = "suffix" Wed Apr 20 14:18:25 2011 : Debug: delimiter = "@" Wed Apr 20 14:18:25 2011 : Debug: ignore_default = no Wed Apr 20 14:18:25 2011 : Debug: ignore_null = no Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_files, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_files Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating files Wed Apr 20 14:18:25 2011 : Debug: files { Wed Apr 20 14:18:25 2011 : Debug: usersfile = "/etc/raddb/users" Wed Apr 20 14:18:25 2011 : Debug: acctusersfile = "/etc/raddb/acct_users" Wed Apr 20 14:18:25 2011 : Debug: preproxy_usersfile = "/etc/raddb/preproxy_users" Wed Apr 20 14:18:25 2011 : Debug: compat = "no" Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Module: Checking preacct {...} for more modules to load Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_acct_unique Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating acct_unique Wed Apr 20 14:18:25 2011 : Debug: acct_unique { Wed Apr 20 14:18:25 2011 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Module: Checking accounting {...} for more modules to load Wed Apr 20 14:18:25 2011 : Debug: (Loaded rlm_detail, checking if it's valid) Wed Apr 20 14:18:25 2011 : Debug: Module: Linked to module rlm_detail Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating detail Wed Apr 20 14:18:25 2011 : Debug: detail { Wed Apr 20 14:18:25 2011 : Debug: detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" Wed Apr 20 14:18:25 2011 : Debug: header = "%t" Wed Apr 20 14:18:25 2011 : Debug: detailperm = 384 Wed Apr 20 14:18:25 2011 : Debug: dirperm = 493 Wed Apr 20 14:18:25 2011 : Debug: locking = no Wed Apr 20 14:18:25 2011 : Debug: log_packet_header = no Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Module: Instantiating attr_filter.accounting_response Wed Apr 20 14:18:25 2011 : Debug: attr_filter attr_filter.accounting_response { Wed Apr 20 14:18:25 2011 : Debug: attrsfile = "/etc/raddb/attrs.accounting_response" Wed Apr 20 14:18:25 2011 : Debug: key = "%{User-Name}" Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Module: Checking session {...} for more modules to load Wed Apr 20 14:18:25 2011 : Debug: Module: Checking post-proxy {...} for more modules to load Wed Apr 20 14:18:25 2011 : Debug: Module: Checking post-auth {...} for more modules to load Wed Apr 20 14:18:25 2011 : Debug: } # modules Wed Apr 20 14:18:25 2011 : Debug: } # server Wed Apr 20 14:18:25 2011 : Debug: radiusd: #### Opening IP addresses and Ports #### Wed Apr 20 14:18:25 2011 : Debug: listen { Wed Apr 20 14:18:25 2011 : Debug: type = "auth" Wed Apr 20 14:18:25 2011 : Debug: ipaddr = * Wed Apr 20 14:18:25 2011 : Debug: port = 0 Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: listen { Wed Apr 20 14:18:25 2011 : Debug: type = "acct" Wed Apr 20 14:18:25 2011 : Debug: ipaddr = * Wed Apr 20 14:18:25 2011 : Debug: port = 0 Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: listen { Wed Apr 20 14:18:25 2011 : Debug: type = "control" Wed Apr 20 14:18:25 2011 : Debug: listen { Wed Apr 20 14:18:25 2011 : Debug: socket = "/var/run/radiusd/radiusd.sock" Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: } Wed Apr 20 14:18:25 2011 : Debug: Listening on authentication address * port 1812 Wed Apr 20 14:18:25 2011 : Debug: Listening on accounting address * port 1813 Wed Apr 20 14:18:25 2011 : Debug: Listening on command file /var/run/radiusd/radiusd.sock Wed Apr 20 14:18:25 2011 : Debug: Listening on proxy address * port 1814 Wed Apr 20 14:18:25 2011 : Debug: Ready to process requests. rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0, length=123 User-Name = "joe" NAS-IP-Address = 10.x.x.x Called-Station-Id = "021c104128f3" Calling-Station-Id = "78ca39bc0256" NAS-Identifier = "021c104128f3" NAS-Port = 40 Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0200000a01746f747465 Message-Authenticator = 0x89ac236886e773c0c4d5ab2a8a8c3289 Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...} Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe", looking up realm NULL Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL" Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 0 length 10 Wed Apr 20 14:19:28 2011 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns updated Wed Apr 20 14:19:28 2011 : Info: ++[unix] returns notfound Wed Apr 20 14:19:28 2011 : Info: [files] users: Matched entry DEFAULT at line 204 Wed Apr 20 14:19:28 2011 : Info: ++[files] returns ok Wed Apr 20 14:19:28 2011 : Info: ++[expiration] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[logintime] returns noop Wed Apr 20 14:19:28 2011 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Apr 20 14:19:28 2011 : Info: ++[pap] returns noop Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...} Wed Apr 20 14:19:28 2011 : Info: [eap] EAP Identity Wed Apr 20 14:19:28 2011 : Info: [eap] processing type tls Wed Apr 20 14:19:28 2011 : Info: [tls] Requiring client certificate Wed Apr 20 14:19:28 2011 : Info: [tls] Initiate Wed Apr 20 14:19:28 2011 : Info: [tls] Start returned 1 Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 0 to 10.x.x.x port 2099 EAP-Message = 0x010100060d20 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xdd105c2bdd11510762e93958e0c3f1d3 Wed Apr 20 14:19:28 2011 : Info: Finished request 0. Wed Apr 20 14:19:28 2011 : Debug: Going to the next request Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0, length=137 Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 0 ID 0 with timestamp +63 User-Name = "joe" NAS-IP-Address = 10.x.x.x Called-Station-Id = "021c104128f3" Calling-Station-Id = "78ca39bc0256" NAS-Identifier = "021c104128f3" NAS-Port = 40 Framed-MTU = 1400 State = 0xdd105c2bdd11510762e93958e0c3f1d3 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020100060319 Message-Authenticator = 0xba61fba10d6a196c3808ac451c9b8057 Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...} Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe", looking up realm NULL Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL" Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 1 length 6 Wed Apr 20 14:19:28 2011 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns updated Wed Apr 20 14:19:28 2011 : Info: ++[unix] returns notfound Wed Apr 20 14:19:28 2011 : Info: [files] users: Matched entry DEFAULT at line 204 Wed Apr 20 14:19:28 2011 : Info: ++[files] returns ok Wed Apr 20 14:19:28 2011 : Info: ++[expiration] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[logintime] returns noop Wed Apr 20 14:19:28 2011 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Apr 20 14:19:28 2011 : Info: ++[pap] returns noop Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...} Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list Wed Apr 20 14:19:28 2011 : Info: [eap] EAP NAK Wed Apr 20 14:19:28 2011 : Info: [eap] EAP-NAK asked for EAP-Type/peap Wed Apr 20 14:19:28 2011 : Info: [eap] processing type tls Wed Apr 20 14:19:28 2011 : Info: [tls] Initiate Wed Apr 20 14:19:28 2011 : Info: [tls] Start returned 1 Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 0 to 10.x.x.x port 2099 EAP-Message = 0x010200061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xdd105c2bdc12450762e93958e0c3f1d3 Wed Apr 20 14:19:28 2011 : Info: Finished request 1. Wed Apr 20 14:19:28 2011 : Debug: Going to the next request Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0, length=295 Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 1 ID 0 with timestamp +63 User-Name = "joe" NAS-IP-Address = 10.x.x.x Called-Station-Id = "021c104128f3" Calling-Station-Id = "78ca39bc0256" NAS-Identifier = "021c104128f3" NAS-Port = 40 Framed-MTU = 1400 State = 0xdd105c2bdc12450762e93958e0c3f1d3 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020200a419800000009a16030100950100009103014daf3fd25dbaeecc6fd0481aaaa97bc6550d4f8410305d48510dbd68d00d1090000056c00ac009c007c008c013c014c011c012c004c005c002c003c00ec00fc00cc00d002f000500040035000a000900030008000600320033003800390016001500140013001200110034003a0018001b001a00170019000101000012000a00080006001700180019000b00020100 Message-Authenticator = 0x4047b0bc80d020d772aa38cd5422c8a1 Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...} Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "10.x.x.x", looking up realm NULL Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL" Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 2 length 164 Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup. Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...} Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS Wed Apr 20 14:19:28 2011 : Debug: TLS Length 154 Wed Apr 20 14:19:28 2011 : Info: [peap] Length Included Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 11 Wed Apr 20 14:19:28 2011 : Info: [peap] (other): before/accept initialization Wed Apr 20 14:19:28 2011 : Info: [peap] TLS_accept: before/accept initialization Wed Apr 20 14:19:28 2011 : Info: [peap] <<< TLS 1.0 Handshake [length 0095], ClientHello Wed Apr 20 14:19:28 2011 : Info: [peap] TLS_accept: SSLv3 read client hello A Wed Apr 20 14:19:28 2011 : Info: [peap] >>> TLS 1.0 Handshake [length 002a], ServerHello Wed Apr 20 14:19:28 2011 : Info: [peap] TLS_accept: SSLv3 write server hello A Wed Apr 20 14:19:28 2011 : Info: [peap] >>> TLS 1.0 Handshake [length 085e], Certificate Wed Apr 20 14:19:28 2011 : Info: [peap] TLS_accept: SSLv3 write certificate A Wed Apr 20 14:19:28 2011 : Info: [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Wed Apr 20 14:19:28 2011 : Info: [peap] TLS_accept: SSLv3 write server done A Wed Apr 20 14:19:28 2011 : Info: [peap] TLS_accept: SSLv3 flush data Wed Apr 20 14:19:28 2011 : Info: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A Wed Apr 20 14:19:28 2011 : Debug: In SSL Handshake Phase Wed Apr 20 14:19:28 2011 : Debug: In SSL Accept mode Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 13 Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_HANDLED Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 0 to 10.x.x.x port 2099 EAP-Message = 0x0103040019c00000089b160301002a0200002603014daf3fd01907bdd33b7d36411279bd6ba34b676bcded0c51aeea9016f4aa62cd00002f00160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479 EAP-Message = 0x301e170d3131303432303137333433325a170d3132303431393137333433325a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100a66b73a4f0edb13c2ee7a2bad5a7d68480898ea958f7e910d3f98b327ffb99ec22d9ce06f239df8397705fd08f2c224707ac97de482bf2885fdac7203116 EAP-Message = 0xbe906d4c1b1092ec9953cb80d153cbf3386789605d6e80aefa9c44497fa7df5cc4ac6ed8178fdbedbdddd79b5bc071ba2a001a9978c2eaaeae754c73cacb643cf16d399334b8444df96c39cc0c8294cc9b5fc1902f770c50df7d23b6c29926752facbee3c192c27d1ca74606f34cefadc89dd292a4bf3e95662dc29cfe1fa393a41e8d3491241cc85819a890336bf7f969e44bab85c7034b3ee9c2b435958fc64dcae0dba5e69f288c0f5d767c3684537961b224ea1876859fa66693d56b65f986c70203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010405000382010100baac5a704642dea672 EAP-Message = 0xf793ebdbf19512f838f5aae9b4d4ac9371e0415ecf6093cf11209e515bfacba06566dfbaf2cb8084e40aa17cb8c91abcf673fc95c0057c67e75e1f063442d484ca598c72843bb45eed25c36971b0c7054d7580505426d72f9e6bde547bac67db3512ec087858cb65bbed3255361ea9de3100a9459c0945cdd499b7e5c46ea1b835d104289557ea43642c1ec4a52bebdcc8ef10425dcb39ee2de7d5cec817f14d9995b870a079e4dacf106dc5396eedabbf45a22e5a9f4eb5463172be5ddd9ba639b634783e8c14f53ea817956bed3e4bac1fdbee818771316949c8667c82358babfaf27fbbd7c65de76cb7a38522e50c11f5b292ca6a180004ab308204 EAP-Message = 0xa73082038fa0030201020209 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xdd105c2bdf13450762e93958e0c3f1d3 Wed Apr 20 14:19:28 2011 : Info: Finished request 2. Wed Apr 20 14:19:28 2011 : Debug: Going to the next request Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0, length=137 Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 2 ID 0 with timestamp +63 User-Name = "joe" NAS-IP-Address = 10.x.x.x Called-Station-Id = "021c104128f3" Calling-Station-Id = "78ca39bc0256" NAS-Identifier = "021c104128f3" NAS-Port = 40 Framed-MTU = 1400 State = 0xdd105c2bdf13450762e93958e0c3f1d3 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020300061900 Message-Authenticator = 0x7c035bbf6b241a95d2a22f744a102f03 Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...} Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe", looking up realm NULL Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL" Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 3 length 6 Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup. Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...} Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS Wed Apr 20 14:19:28 2011 : Info: [peap] Received TLS ACK Wed Apr 20 14:19:28 2011 : Info: [peap] ACK handshake fragment handler Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 1 Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 13 Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_HANDLED Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 0 to 10.x.x.x port 2099 EAP-Message = 0x010403fc194000fdc25082a03098fd300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3131303432303137333433325a170d3132303431393137333433325a308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504 EAP-Message = 0x071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100ec507dbcc0cf48a24e08bbfecc416c8648719655dd901d023ddbc2ff604819752a21ed64029ed1762d2abbbcbfd6c49702a873ced95144d7b08268b0574cb618e8e9794b16707e8b85ae799cd112b0ac9f06cfaf7d0386f9d8b2fbb46adade8a159dbb92dac84d06247b714c227cd3 EAP-Message = 0xea3f91ffa26b62886cacacf3d8c87418e3619fd33020e4877ae61d298aa0ab23df2c0eea0012e07228409884f3ab9d256c664a17b5d8352e0e01cce202847b895c2f17b7e7984f069d73c1e36063e85c8a5ea80ee47891e5a67d566e15fa065dc4440baaa89efb371a04193593d1efe062575dece95d2b729ac997309e8b7a964aef029fee7101a37ea13d0eda5c42e76f0203010001a381fb3081f8301d0603551d0e0416041458dc04911e60bdfece1ced5d9ccb591f613a9ea83081c80603551d230481c03081bd801458dc04911e60bdfece1ced5d9ccb591f613a9ea8a18199a48196308193310b3009060355040613024652310f300d06035504 EAP-Message = 0x0813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479820900fdc25082a03098fd300c0603551d13040530030101ff300d06092a864886f70d01010505000382010100a6d09c3a6e5bfb70fbe4728ded653e3db77e8bd53eae3b2233477c0c78c5b8969d77416542a500a7b412058cd5d06d546839489c67c94327ecb68f85ae7d69284b6efc9f6bc06d22a1e9c48a903f28fb9988 EAP-Message = 0xc1bd1cf2f83eb432 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xdd105c2bde14450762e93958e0c3f1d3 Wed Apr 20 14:19:28 2011 : Info: Finished request 3. Wed Apr 20 14:19:28 2011 : Debug: Going to the next request Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0, length=137 Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 3 ID 0 with timestamp +63 User-Name = "joe" NAS-IP-Address = 10.x.x.x Called-Station-Id = "021c104128f3" Calling-Station-Id = "78ca39bc0256" NAS-Identifier = "021c104128f3" NAS-Port = 40 Framed-MTU = 1400 State = 0xdd105c2bde14450762e93958e0c3f1d3 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020400061900 Message-Authenticator = 0x53ed16f1e518e85e03755d94da317033 Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...} Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe", looking up realm NULL Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL" Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 4 length 6 Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup. Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...} Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS Wed Apr 20 14:19:28 2011 : Info: [peap] Received TLS ACK Wed Apr 20 14:19:28 2011 : Info: [peap] ACK handshake fragment handler Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 1 Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 13 Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_HANDLED Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 0 to 10.x.x.x port 2099 EAP-Message = 0x010500b519002f4b578c9cb29c7e4c4efd654179aa8af5133ec300b56bcb0d962423eb357efb49a3242bb5c70bc9359a8a49456d6f2c8543e645247e8fc58336f1a796ee1f59d1591268e348b8688cf978a48541ce50f715f173d935a3e9a611414ff670717c45c29f002ef8ecd5cd987a315d3da307f4ee9e5b252411234b6414a4ebb99b8bc933e85af7cebcc83ff11febd4d881dbdb02f604620321fdbee10dccf0c6d53a40606759f92e16030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xdd105c2bd915450762e93958e0c3f1d3 Wed Apr 20 14:19:28 2011 : Info: Finished request 4. Wed Apr 20 14:19:28 2011 : Debug: Going to the next request Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0, length=469 Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 4 ID 0 with timestamp +63 User-Name = "joe" NAS-IP-Address = 10.x.x.x Called-Station-Id = "021c104128f3" Calling-Station-Id = "78ca39bc0256" NAS-Identifier = "021c104128f3" NAS-Port = 40 Framed-MTU = 1400 State = 0xdd105c2bd915450762e93958e0c3f1d3 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0205015019800000014616030101061000010201005ff03a87a0137ac0ad3d30d889be6290d586fe4f8774d04a281fce89ab478bd7ca78d17dd10bf634210465ea16900c200895a7e5bf72bac2ec49a0d58dc73c6f73f0a7f9f7d7d3126e2cd36d4abdcc9d11d8511eb7e181213e05c79d2f412ee87b5466b45d4f8fc7fd4dda6823a5e05ab80b2b1c99d949cfffade2ffe14b383d8df00a2e0a7f29b0102231bb942e6850f815f062183512ec5cf29a25af967190a443038bbecaa71936c7f2b23ee815c2bc41aa4ba1e1bbead97f03fc0de3817564be247b6a7af8529f5d2f2833ea01d902c760be8c4380a7ea758ad8eee9ab6bd9117e4494431b40 EAP-Message = 0xdab05b2e027376bbd9c7d336e111eb765e75c65080c4d6571403010001011603010030de7128d079ec3a74a608b7ad34a52e70200bc5524ff54d6a3c265f1a8d9de489ce6ce763f2fb3c7afcd22959cb4e5dfd Message-Authenticator = 0xd728400175580c5a526116bf2f1b1a8f Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...} Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe", looking up realm NULL Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL" Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 5 length 253 Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup. Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...} Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS Wed Apr 20 14:19:28 2011 : Debug: TLS Length 326 Wed Apr 20 14:19:28 2011 : Info: [peap] Length Included Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 11 Wed Apr 20 14:19:28 2011 : Info: [peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange Wed Apr 20 14:19:28 2011 : Info: [peap] TLS_accept: SSLv3 read client key exchange A Wed Apr 20 14:19:28 2011 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] Wed Apr 20 14:19:28 2011 : Info: [peap] <<< TLS 1.0 Handshake [length 0010], Finished Wed Apr 20 14:19:28 2011 : Info: [peap] TLS_accept: SSLv3 read finished A Wed Apr 20 14:19:28 2011 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] Wed Apr 20 14:19:28 2011 : Info: [peap] TLS_accept: SSLv3 write change cipher spec A Wed Apr 20 14:19:28 2011 : Info: [peap] >>> TLS 1.0 Handshake [length 0010], Finished Wed Apr 20 14:19:28 2011 : Info: [peap] TLS_accept: SSLv3 write finished A Wed Apr 20 14:19:28 2011 : Info: [peap] TLS_accept: SSLv3 flush data Wed Apr 20 14:19:28 2011 : Info: [peap] (other): SSL negotiation finished successfully Wed Apr 20 14:19:28 2011 : Debug: SSL Connection Established Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 13 Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_HANDLED Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 0 to 10.x.x.x port 2099 EAP-Message = 0x0106004119001403010001011603010030099c636cd573aaf67853ce908c03124c44da0b7887fdbfc4fb7dcf77fce218a6a0a94a3fef781df5632cb80eb8e5370f Message-Authenticator = 0x00000000000000000000000000000000 State = 0xdd105c2bd816450762e93958e0c3f1d3 Wed Apr 20 14:19:28 2011 : Info: Finished request 5. Wed Apr 20 14:19:28 2011 : Debug: Going to the next request Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0, length=137 Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 5 ID 0 with timestamp +63 User-Name = "joe" NAS-IP-Address = 10.x.x.x Called-Station-Id = "021c104128f3" Calling-Station-Id = "78ca39bc0256" NAS-Identifier = "021c104128f3" NAS-Port = 40 Framed-MTU = 1400 State = 0xdd105c2bd816450762e93958e0c3f1d3 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020600061900 Message-Authenticator = 0x8f1642e15961150878f41f38f1df7fec Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...} Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe", looking up realm NULL Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL" Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 6 length 6 Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup. Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...} Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS Wed Apr 20 14:19:28 2011 : Info: [peap] Received TLS ACK Wed Apr 20 14:19:28 2011 : Info: [peap] ACK handshake is finished Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 3 Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 3 Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_SUCCESS Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 0 to 10.x.x.x port 2099 EAP-Message = 0x0107002b190017030100203cb1c1276777a2a1f4f1fe7625e0dc14beeac2811bd82eb05b38147ee4ba34c7 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xdd105c2bdb17450762e93958e0c3f1d3 Wed Apr 20 14:19:28 2011 : Info: Finished request 6. Wed Apr 20 14:19:28 2011 : Debug: Going to the next request Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0, length=174 Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 6 ID 0 with timestamp +63 User-Name = "joe" NAS-IP-Address = 10.x.x.x Called-Station-Id = "021c104128f3" Calling-Station-Id = "78ca39bc0256" NAS-Identifier = "021c104128f3" NAS-Port = 40 Framed-MTU = 1400 State = 0xdd105c2bdb17450762e93958e0c3f1d3 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0207002b19001703010020d3d2a3f046f09cdd567ad9cd3626c14e1e136ddba422e9a81f4fab0b70acf4c0 Message-Authenticator = 0xd882a36ea1058c0dac06f385abebdaab Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...} Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe", looking up realm NULL Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL" Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 7 length 43 Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup. Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...} Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 7 Wed Apr 20 14:19:28 2011 : Info: [peap] Done initial handshake Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 7 Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_OK Wed Apr 20 14:19:28 2011 : Info: [peap] Session established. Decoding tunneled attributes. Wed Apr 20 14:19:28 2011 : Info: [peap] Identity - joe Wed Apr 20 14:19:28 2011 : Info: [peap] Got tunneled request EAP-Message = 0x0207000a01746f747465 server { Wed Apr 20 14:19:28 2011 : Debug: PEAP: Got tunneled identity of joe Wed Apr 20 14:19:28 2011 : Debug: PEAP: Setting default EAP type for tunneled EAP session. Wed Apr 20 14:19:28 2011 : Debug: PEAP: Setting User-Name to joe Sending tunneled request EAP-Message = 0x0207000a01746f747465 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "joe" server inner-tunnel { Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...} Wed Apr 20 14:19:28 2011 : Info: ++[expiration] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[logintime] returns noop Wed Apr 20 14:19:28 2011 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Apr 20 14:19:28 2011 : Info: ++[pap] returns noop Wed Apr 20 14:19:28 2011 : Info: ++? if (User-Password) Wed Apr 20 14:19:28 2011 : Info: ? Evaluating (User-Password) -> FALSE Wed Apr 20 14:19:28 2011 : Info: ++? if (User-Password) -> FALSE Wed Apr 20 14:19:28 2011 : Info: ++? if (!User-Password) Wed Apr 20 14:19:28 2011 : Info: ? Evaluating !(User-Password) -> TRUE Wed Apr 20 14:19:28 2011 : Info: ++? if (!User-Password) -> TRUE Wed Apr 20 14:19:28 2011 : Info: ++- entering if (!User-Password) {...} Wed Apr 20 14:19:28 2011 : Info: +++[control] returns noop Wed Apr 20 14:19:28 2011 : Info: ++- if (!User-Password) returns noop Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = Kerberos Wed Apr 20 14:19:28 2011 : Info: +- entering group Kerberos {...} Wed Apr 20 14:19:28 2011 : Auth: rlm_krb5: Attribute "User-Password" is required for authentication. Wed Apr 20 14:19:28 2011 : Info: ++[krb5] returns invalid Wed Apr 20 14:19:28 2011 : Info: Failed to authenticate the user. } # server inner-tunnel Wed Apr 20 14:19:28 2011 : Info: [peap] Got tunneled reply code 3 Wed Apr 20 14:19:28 2011 : Info: [peap] Got tunneled reply RADIUS code 3 Wed Apr 20 14:19:28 2011 : Info: [peap] Tunneled authentication was rejected. Wed Apr 20 14:19:28 2011 : Info: [peap] FAILURE Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled Sending Access-Challenge of id 0 to 10.x.x.x port 2099 EAP-Message = 0x0108002b19001703010020da58f6451bae89da36c894c1c6b16c6895257d7c354dfa0eb09a833a0fa3768b Message-Authenticator = 0x00000000000000000000000000000000 State = 0xdd105c2bda18450762e93958e0c3f1d3 Wed Apr 20 14:19:28 2011 : Info: Finished request 7. Wed Apr 20 14:19:28 2011 : Debug: Going to the next request Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0, length=174 Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 7 ID 0 with timestamp +63 User-Name = "joe" NAS-IP-Address = 10.x.x.x Called-Station-Id = "021c104128f3" Calling-Station-Id = "78ca39bc0256" NAS-Identifier = "021c104128f3" NAS-Port = 40 Framed-MTU = 1400 State = 0xdd105c2bda18450762e93958e0c3f1d3 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0208002b19001703010020c1754eafe7cea50b9cfb512e9d7f44e826d21d5b3405a9a3d56ff6f95ff424de Message-Authenticator = 0x16184e6807f8406dd2a6454fe102d325 Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...} Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe", looking up realm NULL Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL" Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 8 length 43 Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup. Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...} Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 7 Wed Apr 20 14:19:28 2011 : Info: [peap] Done initial handshake Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 7 Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_OK Wed Apr 20 14:19:28 2011 : Info: [peap] Session established. Decoding tunneled attributes. Wed Apr 20 14:19:28 2011 : Info: [peap] Received EAP-TLV response. Wed Apr 20 14:19:28 2011 : Info: [peap] Had sent TLV failure. User was rejected earlier in this session. Wed Apr 20 14:19:28 2011 : Info: [eap] Handler failed in EAP/peap Wed Apr 20 14:19:28 2011 : Info: [eap] Failed in EAP select Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns invalid Wed Apr 20 14:19:28 2011 : Info: Failed to authenticate the user. Wed Apr 20 14:19:28 2011 : Info: Using Post-Auth-Type Reject Wed Apr 20 14:19:28 2011 : Info: +- entering group REJECT {...} Wed Apr 20 14:19:28 2011 : Info: [attr_filter.access_reject] expand: %{User-Name} -> joe Wed Apr 20 14:19:28 2011 : Debug: attr_filter: Matched entry DEFAULT at line 11 Wed Apr 20 14:19:28 2011 : Info: ++[attr_filter.access_reject] returns updated Wed Apr 20 14:19:28 2011 : Info: Delaying reject of request 8 for 1 seconds Wed Apr 20 14:19:28 2011 : Debug: Going to the next request Wed Apr 20 14:19:28 2011 : Debug: Waking up in 0.9 seconds. Wed Apr 20 14:19:29 2011 : Info: Sending delayed reject for request 8 Sending Access-Reject of id 0 to 10.x.x.x port 2099 EAP-Message = 0x04080004 Message-Authenticator = 0x00000000000000000000000000000000 Wed Apr 20 14:19:29 2011 : Debug: Waking up in 4.9 seconds. Wed Apr 20 14:19:34 2011 : Info: Cleaning up request 8 ID 0 with timestamp +63 Wed Apr 20 14:19:34 2011 : Debug: Ready to process requests. -- View this message in context: http://freeradius.1045715.n5.nabble.com/EAP-TTLS-Kerberos-tp3368060p4329503.... Sent from the FreeRadius - User mailing list archive at Nabble.com.
On 04/20/2011 11:56 PM, tod wrote:
Wed Apr 20 14:19:28 2011 : Debug: PEAP: Setting User-Name to joe Sending tunneled request EAP-Message = 0x0207000a01746f747465 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "joe" server inner-tunnel { Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...} Wed Apr 20 14:19:28 2011 : Info: ++[expiration] returns noop Wed Apr 20 14:19:28 2011 : Info: ++[logintime] returns noop Wed Apr 20 14:19:28 2011 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Apr 20 14:19:28 2011 : Info: ++[pap] returns noop Wed Apr 20 14:19:28 2011 : Info: ++? if (User-Password) Wed Apr 20 14:19:28 2011 : Info: ? Evaluating (User-Password) -> FALSE Wed Apr 20 14:19:28 2011 : Info: ++? if (User-Password) -> FALSE Wed Apr 20 14:19:28 2011 : Info: ++? if (!User-Password) Wed Apr 20 14:19:28 2011 : Info: ? Evaluating !(User-Password) -> TRUE Wed Apr 20 14:19:28 2011 : Info: ++? if (!User-Password) -> TRUE Wed Apr 20 14:19:28 2011 : Info: ++- entering if (!User-Password) {...} Wed Apr 20 14:19:28 2011 : Info: +++[control] returns noop Wed Apr 20 14:19:28 2011 : Info: ++- if (!User-Password) returns noop Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = Kerberos Wed Apr 20 14:19:28 2011 : Info: +- entering group Kerberos {...} Wed Apr 20 14:19:28 2011 : Auth: rlm_krb5: Attribute "User-Password" is required for authentication. Wed Apr 20 14:19:28 2011 : Info: ++[krb5] returns invalid Wed Apr 20 14:19:28 2011 : Info: Failed to authenticate the user. } # server inner-tunnel
This is PEAP, not TTLS as was discussed in the original thread. PEAP uses MS-CHAP as the "inner" auth. rlm_krb5 cannot be used, because the client does not supply plaintext passwords with PEAP. See: http://deployingradius.com/documents/protocols/compatibility.html Also, you've broken the config by removing modules from "inner-tunnel". Specifically, you've removed the "eap" module, meaning that the inner EAP will never be handled. Finally, this thread is months old. If you aren't the original poster, and don't have the same problem (which you don't) please start a new thread.
participants (3)
-
Phil Mayers -
Thorsten Fischer -
tod