Hi Everybody. We are having some issues in setting up freeradius to support EAP-TLS, EAP-TTLS and EAP-PEAP. Our goal is to have our authentication server providing those three Auth-Type simultaneously. To support EAP-TLS, we generate our CA and certificates via TinyCA. Here are our configurations files : ######radiusd.conf########## prefix = /usr/local exec_prefix = ${prefix} sysconfdir = ${prefix}/etc localstatedir = ${prefix}/var sbindir = ${exec_prefix}/sbin logdir = ${localstatedir}/log/radius raddbdir = ${sysconfdir}/raddb radacctdir = ${logdir}/radacct confdir = ${raddbdir} run_dir = ${localstatedir}/run/radiusd db_dir = $(raddbdir) libdir = ${exec_prefix}/lib pidfile = ${run_dir}/radiusd.pid max_request_time = 30 cleanup_delay = 5 max_requests = 1024 listen { type = auth ipaddr = * port = 0 } listen { ipaddr = * port = 0 type = acct } hostname_lookups = no allow_core_dumps = no regular_expressions = yes extended_expressions = yes log { destination = files file = ${logdir}/radius.log syslog_facility = daemon stripped_names = no auth = no auth_badpass = no auth_goodpass = no } checkrad = ${sbindir}/checkrad security { max_attributes = 200 reject_delay = 1 status_server = yes } proxy_requests = yes $INCLUDE proxy.conf $INCLUDE clients.conf snmp = no $INCLUDE snmp.conf thread pool { start_servers = 5 max_servers = 32 min_spare_servers = 3 max_spare_servers = 10 max_requests_per_server = 0 } modules { $INCLUDE ${confdir}/modules/ $INCLUDE eap.conf $INCLUDE sql.conf $INCLUDE sql/mysql/counter.conf } instantiate { exec expr expiration logintime } $INCLUDE policy.conf $INCLUDE sites-enabled/ #######sites-enabled/behanzin.uac.bj############### authorize { preprocess chap mschap digest suffix eap { ok = return } unix expiration logintime pap passwd } authenticate { Auth-Type PAP { pap } Auth-Type CHAP { chap } Auth-Type MS-CHAP { mschap } digest unix eap } preacct { preprocess acct_unique suffix files } accounting { detail unix radutmp attr_filter.accounting_response } session { radutmp } post-auth { exec Post-Auth-Type REJECT { attr_filter.access_reject } } pre-proxy { } post-proxy { eap } We also add radius' log after an authentication attempt from windows XP OS using windows built in supplicant by supplying a username and password stored in our /etc/passwd file. But the authentication failed with this error message : rlm_eap: identity does not match User-Name, setting from EAP identity ########Radius logs ################ ...............Thu Dec 11 14:59:10 2008 : Debug: main { Thu Dec 11 14:59:10 2008 : Debug: prefix = "/usr/local" Thu Dec 11 14:59:10 2008 : Debug: localstatedir = "/usr/local/var" Thu Dec 11 14:59:10 2008 : Debug: logdir = "/usr/local/var/log/radius" Thu Dec 11 14:59:10 2008 : Debug: libdir = "/usr/local/lib" Thu Dec 11 14:59:10 2008 : Debug: radacctdir = "/usr/local/var/log/radius/radacct" Thu Dec 11 14:59:10 2008 : Debug: hostname_lookups = no Thu Dec 11 14:59:10 2008 : Debug: max_request_time = 30 Thu Dec 11 14:59:10 2008 : Debug: cleanup_delay = 5 Thu Dec 11 14:59:10 2008 : Debug: max_requests = 1024 Thu Dec 11 14:59:10 2008 : Debug: allow_core_dumps = no Thu Dec 11 14:59:10 2008 : Debug: pidfile = "/usr/local/var/run/radiusd/radiusd.pid" Thu Dec 11 14:59:10 2008 : Debug: checkrad = "/usr/local/sbin/checkrad" Thu Dec 11 14:59:10 2008 : Debug: debug_level = 0 Thu Dec 11 14:59:10 2008 : Debug: proxy_requests = yes Thu Dec 11 14:59:10 2008 : Debug: log { Thu Dec 11 14:59:10 2008 : Debug: stripped_names = no Thu Dec 11 14:59:10 2008 : Debug: auth = no Thu Dec 11 14:59:10 2008 : Debug: auth_badpass = no Thu Dec 11 14:59:10 2008 : Debug: auth_goodpass = no Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: client localhost { Thu Dec 11 14:59:10 2008 : Debug: ipaddr = 127.0.0.1 Thu Dec 11 14:59:10 2008 : Debug: require_message_authenticator = no Thu Dec 11 14:59:10 2008 : Debug: secret = "testing123" Thu Dec 11 14:59:10 2008 : Debug: nastype = "other" Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: client 172.21.0.9 { Thu Dec 11 14:59:10 2008 : Debug: require_message_authenticator = no Thu Dec 11 14:59:10 2008 : Debug: secret = "testing123" Thu Dec 11 14:59:10 2008 : Debug: shortname = "Behanzin" Thu Dec 11 14:59:10 2008 : Debug: nastype = "other" Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: client 172.21.1.251 { Thu Dec 11 14:59:10 2008 : Debug: require_message_authenticator = no Thu Dec 11 14:59:10 2008 : Debug: secret = "testing123" Thu Dec 11 14:59:10 2008 : Debug: shortname = "TestingAP" Thu Dec 11 14:59:10 2008 : Debug: nastype = "other" Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: radiusd: #### Loading Realms and Home Servers #### Thu Dec 11 14:59:10 2008 : Debug: proxy server { Thu Dec 11 14:59:10 2008 : Debug: retry_delay = 5 Thu Dec 11 14:59:10 2008 : Debug: retry_count = 3 Thu Dec 11 14:59:10 2008 : Debug: default_fallback = no Thu Dec 11 14:59:10 2008 : Debug: dead_time = 120 Thu Dec 11 14:59:10 2008 : Debug: wake_all_if_all_dead = no Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: home_server localhost { Thu Dec 11 14:59:10 2008 : Debug: ipaddr = 127.0.0.1 Thu Dec 11 14:59:10 2008 : Debug: port = 1812 Thu Dec 11 14:59:10 2008 : Debug: type = "auth" Thu Dec 11 14:59:10 2008 : Debug: secret = "testing123" Thu Dec 11 14:59:10 2008 : Debug: response_window = 20 Thu Dec 11 14:59:10 2008 : Debug: max_outstanding = 65536 Thu Dec 11 14:59:10 2008 : Debug: zombie_period = 40 Thu Dec 11 14:59:10 2008 : Debug: status_check = "status-server" Thu Dec 11 14:59:10 2008 : Debug: ping_check = "none" Thu Dec 11 14:59:10 2008 : Debug: ping_interval = 30 Thu Dec 11 14:59:10 2008 : Debug: check_interval = 30 Thu Dec 11 14:59:10 2008 : Debug: num_answers_to_alive = 3 Thu Dec 11 14:59:10 2008 : Debug: num_pings_to_alive = 3 Thu Dec 11 14:59:10 2008 : Debug: revive_interval = 120 Thu Dec 11 14:59:10 2008 : Debug: status_check_timeout = 4 Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: home_server_pool my_auth_failover { Thu Dec 11 14:59:10 2008 : Debug: type = fail-over Thu Dec 11 14:59:10 2008 : Debug: home_server = localhost Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: realm uac.bj { Thu Dec 11 14:59:10 2008 : Debug: auth_pool = my_auth_failover Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: realm LOCAL { Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: radiusd: #### Instantiating modules #### Thu Dec 11 14:59:10 2008 : Debug: instantiate { Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_exec, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_exec Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating exec Thu Dec 11 14:59:10 2008 : Debug: exec { Thu Dec 11 14:59:10 2008 : Debug: wait = no Thu Dec 11 14:59:10 2008 : Debug: input_pairs = "request" Thu Dec 11 14:59:10 2008 : Debug: shell_escape = yes Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_expr, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_expr Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating expr Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_expiration, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_expiration Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating expiration Thu Dec 11 14:59:10 2008 : Debug: expiration { Thu Dec 11 14:59:10 2008 : Debug: reply-message = "Password Has Expired " Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_logintime, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_logintime Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating logintime Thu Dec 11 14:59:10 2008 : Debug: logintime { Thu Dec 11 14:59:10 2008 : Debug: reply-message = "You are calling outside your allowed timespan " Thu Dec 11 14:59:10 2008 : Debug: minimum-timeout = 60 Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: radiusd: #### Loading Virtual Servers #### Thu Dec 11 14:59:10 2008 : Debug: server { Thu Dec 11 14:59:10 2008 : Debug: modules { Thu Dec 11 14:59:10 2008 : Debug: Module: Checking authenticate {...} for more modules to load Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_pap, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_pap Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating pap Thu Dec 11 14:59:10 2008 : Debug: pap { Thu Dec 11 14:59:10 2008 : Debug: encryption_scheme = "auto" Thu Dec 11 14:59:10 2008 : Debug: auto_header = no Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_chap, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_chap Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating chap Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_mschap, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_mschap Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating mschap Thu Dec 11 14:59:10 2008 : Debug: mschap { Thu Dec 11 14:59:10 2008 : Debug: use_mppe = yes Thu Dec 11 14:59:10 2008 : Debug: require_encryption = no Thu Dec 11 14:59:10 2008 : Debug: require_strong = no Thu Dec 11 14:59:10 2008 : Debug: with_ntdomain_hack = no Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_digest, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_digest Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating digest Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_unix, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_unix Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating unix Thu Dec 11 14:59:10 2008 : Debug: unix { Thu Dec 11 14:59:10 2008 : Debug: radwtmp = "/usr/local/var/log/radius/radwtmp" Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_eap, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_eap Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating eap Thu Dec 11 14:59:10 2008 : Debug: eap { Thu Dec 11 14:59:10 2008 : Debug: default_eap_type = "md5" Thu Dec 11 14:59:10 2008 : Debug: timer_expire = 60 Thu Dec 11 14:59:10 2008 : Debug: ignore_unknown_eap_types = yes Thu Dec 11 14:59:10 2008 : Debug: cisco_accounting_username_bug = no Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to sub-module rlm_eap_md5 Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating eap-md5 Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to sub-module rlm_eap_leap Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating eap-leap Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to sub-module rlm_eap_gtc Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating eap-gtc Thu Dec 11 14:59:10 2008 : Debug: gtc { Thu Dec 11 14:59:10 2008 : Debug: challenge = "Password: " Thu Dec 11 14:59:10 2008 : Debug: auth_type = "PAP" Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to sub-module rlm_eap_tls Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating eap-tls Thu Dec 11 14:59:10 2008 : Debug: tls { Thu Dec 11 14:59:10 2008 : Debug: rsa_key_exchange = no Thu Dec 11 14:59:10 2008 : Debug: dh_key_exchange = yes Thu Dec 11 14:59:10 2008 : Debug: rsa_key_length = 512 Thu Dec 11 14:59:10 2008 : Debug: dh_key_length = 512 Thu Dec 11 14:59:10 2008 : Debug: verify_depth = 0 Thu Dec 11 14:59:10 2008 : Debug: pem_file_type = yes Thu Dec 11 14:59:10 2008 : Debug: private_key_file = "/usr/local/etc/raddb/certs/behanzin@uac.bj-cert.pem" Thu Dec 11 14:59:10 2008 : Debug: certificate_file = "/usr/local/etc/raddb/certs/behanzin@uac.bj-cert.pem" Thu Dec 11 14:59:10 2008 : Debug: CA_file = "/usr/local/etc/raddb/certs/UAC_CA-cacert.pem" Thu Dec 11 14:59:10 2008 : Debug: private_key_password = "UacCertificate07" Thu Dec 11 14:59:10 2008 : Debug: dh_file = "/usr/local/etc/raddb/certs/dh" Thu Dec 11 14:59:10 2008 : Debug: random_file = "/usr/local/etc/raddb/certs/random" Thu Dec 11 14:59:10 2008 : Debug: fragment_size = 1024 Thu Dec 11 14:59:10 2008 : Debug: include_length = yes Thu Dec 11 14:59:10 2008 : Debug: check_crl = no Thu Dec 11 14:59:10 2008 : Debug: cipher_list = "DEFAULT" Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to sub-module rlm_eap_ttls Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating eap-ttls Thu Dec 11 14:59:10 2008 : Debug: ttls { Thu Dec 11 14:59:10 2008 : Debug: default_eap_type = "md5" Thu Dec 11 14:59:10 2008 : Debug: copy_request_to_tunnel = no Thu Dec 11 14:59:10 2008 : Debug: use_tunneled_reply = no Thu Dec 11 14:59:10 2008 : Debug: virtual_server = "inner-tunnel" Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to sub-module rlm_eap_peap Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating eap-peap Thu Dec 11 14:59:10 2008 : Debug: peap { Thu Dec 11 14:59:10 2008 : Debug: default_eap_type = "mschapv2" Thu Dec 11 14:59:10 2008 : Debug: copy_request_to_tunnel = no Thu Dec 11 14:59:10 2008 : Debug: use_tunneled_reply = no Thu Dec 11 14:59:10 2008 : Debug: proxy_tunneled_request_as_eap = yes Thu Dec 11 14:59:10 2008 : Debug: virtual_server = "inner-tunnel" Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating eap-mschapv2 Thu DThu Dec 11 14:59:10 2008 : Debug: with_ntdomain_hack = no Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: Module: Checking authorize {...} for more modules to load Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_preprocess, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_preprocess Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating preprocess Thu Dec 11 14:59:10 2008 : Debug: preprocess { Thu Dec 11 14:59:10 2008 : Debug: huntgroups = "/usr/local/etc/raddb/huntgroups" Thu Dec 11 14:59:10 2008 : Debug: hints = "/usr/local/etc/raddb/hints" Thu Dec 11 14:59:10 2008 : Debug: with_ascend_hack = no Thu Dec 11 14:59:10 2008 : Debug: ascend_channels_per_line = 23 Thu Dec 11 14:59:10 2008 : Debug: with_ntdomain_hack = no Thu Dec 11 14:59:10 2008 : Debug: with_specialix_jetstream_hack = no Thu Dec 11 14:59:10 2008 : Debug: with_cisco_vsa_hack = no Thu Dec 11 14:59:10 2008 : Debug: with_alvarion_vsa_hack = no Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_realm, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_realm Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating suffix Thu Dec 11 14:59:10 2008 : Debug: realm suffix { Thu Dec 11 14:59:10 2008 : Debug: format = "suffix" Thu Dec 11 14:59:10 2008 : Debug: delimiter = "@" Thu Dec 11 14:59:10 2008 : Debug: ignore_default = no Thu Dec 11 14:59:10 2008 : Debug: ignore_null = no Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_passwd, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_passwd Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating passwd Thu Dec 11 14:59:10 2008 : Debug: passwd passwd { Thu Dec 11 14:59:10 2008 : Debug: filename = "/etc/shadow" Thu Dec 11 14:59:10 2008 : Debug: format = "*=User-Name:MD5-Password" Thu Dec 11 14:59:10 2008 : Debug: delimiter = ":" Thu Dec 11 14:59:10 2008 : Debug: ignorenislike = yes Thu Dec 11 14:59:10 2008 : Debug: ignoreempty = yes Thu Dec 11 14:59:10 2008 : Debug: allowmultiplekeys = yes Thu Dec 11 14:59:10 2008 : Debug: hashsize = 50 Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: rlm_passwd: nfields: 2 keyfield 0(User-Name) listable: no Thu Dec 11 14:59:10 2008 : Debug: Module: Checking preacct {...} for more modules to load Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_acct_unique Thu Dec 11 14:59:10 2008 : Debug: mschapv2 { Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating acct_unique Thu Dec 11 14:59:10 2008 : Debug: acct_unique { Thu Dec 11 14:59:10 2008 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_files, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_files Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating files Thu Dec 11 14:59:10 2008 : Debug: files { Thu Dec 11 14:59:10 2008 : Debug: usersfile = "/usr/local/etc/raddb/users" Thu Dec 11 14:59:10 2008 : Debug: acctusersfile = "/usr/local/etc/raddb/acct_users" Thu Dec 11 14:59:10 2008 : Debug: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users" Thu Dec 11 14:59:10 2008 : Debug: compat = "no" Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: Module: Checking accounting {...} for more modules to load Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_detail, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_detail Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating detail Thu Dec 11 14:59:10 2008 : Debug: detail { Thu Dec 11 14:59:10 2008 : Debug: detailfile = "/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" Thu Dec 11 14:59:10 2008 : Debug: header = "%t" Thu Dec 11 14:59:10 2008 : Debug: detailperm = 384 Thu Dec 11 14:59:10 2008 : Debug: dirperm = 493 Thu Dec 11 14:59:10 2008 : Debug: locking = no Thu Dec 11 14:59:10 2008 : Debug: log_packet_header = no Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_radutmp, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_radutmp Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating radutmp Thu Dec 11 14:59:10 2008 : Debug: radutmp { Thu Dec 11 14:59:10 2008 : Debug: filename = "/usr/local/var/log/radius/radutmp" Thu Dec 11 14:59:10 2008 : Debug: username = "%{User-Name}" Thu Dec 11 14:59:10 2008 : Debug: case_sensitive = yes Thu Dec 11 14:59:10 2008 : Debug: check_with_nas = yes Thu Dec 11 14:59:10 2008 : Debug: perm = 384 Thu Dec 11 14:59:10 2008 : Debug: callerid = yes Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Thu Dec 11 14:59:10 2008 : Debug: Module: Linked to module rlm_attr_filter Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating attr_filter.accounting_response Thu Dec 11 14:59:10 2008 : Debug: attr_filter attr_filter.accounting_response { Thu Dec 11 14:59:10 2008 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.accounting_response" Thu Dec 11 14:59:10 2008 : Debug: key = "%{User-Name}" Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: Module: Checking session {...} for more modules to load Thu Dec 11 14:59:10 2008 : Debug: Module: Checking post-proxy {...} for more modules to load Thu Dec 11 14:59:10 2008 : Debug: Module: Checking post-auth {...} for more modules to load Thu Dec 11 14:59:10 2008 : Debug: Module: Instantiating attr_filter.access_reject Thu Dec 11 14:59:10 2008 : Debug: attr_filter attr_filter.access_reject { Thu Dec 11 14:59:10 2008 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.access_reject" Thu Dec 11 14:59:10 2008 : Debug: key = "%{User-Name}" Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: radiusd: #### Opening IP addresses and Ports #### Thu Dec 11 14:59:10 2008 : Debug: listen { Thu Dec 11 14:59:10 2008 : Debug: type = "auth" Thu Dec 11 14:59:10 2008 : Debug: ipaddr = * Thu Dec 11 14:59:10 2008 : Debug: port = 0 Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: listen { Thu Dec 11 14:59:10 2008 : Debug: type = "acct" Thu Dec 11 14:59:10 2008 : Debug: ipaddr = * Thu Dec 11 14:59:10 2008 : Debug: port = 0 Thu Dec 11 14:59:10 2008 : Debug: } Thu Dec 11 14:59:10 2008 : Debug: Listening on authentication address * port 1812 Thu Dec 11 14:59:10 2008 : Debug: Listening on accounting address * port 1813 Thu Dec 11 14:59:10 2008 : Debug: Listening on proxy address * port 1814 Thu Dec 11 14:59:10 2008 : Debug: Ready to process requests. rad_recv: Access-Request packet from host 172.21.1.251 port 1035, id=233, length=145 User-Name = "toto@uac.bj" NAS-IP-Address = 172.21.1.251 Connect-Info = "CONNECT 802.11" Called-Station-Id = "0060b33573b4" Calling-Station-Id = "000e35dfc4c9" NAS-Identifier = "ap" NAS-Port-Type = Wireless-802.11 NAS-Port = 40 NAS-Port-Id = "40" Framed-MTU = 1400 EAP-Message = 0x0269001001746f746f407561632e626a Message-Authenticator = 0x4047d95682a4670d24da3c2fa434814e Thu Dec 11 15:00:37 2008 : Debug: +- entering group authorize Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[preprocess] returns ok Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 0 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[chap] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 0 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[mschap] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling digest (rlm_digest) for request 0 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from digest (rlm_digest) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[digest] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 0 Thu Dec 11 15:00:37 2008 : Debug: rlm_realm: Looking up realm "uac.bj" for User-Name = "toto@uac.bj" Thu Dec 11 15:00:37 2008 : Debug: rlm_realm: Found realm "uac.bj" Thu Dec 11 15:00:37 2008 : Debug: rlm_realm: Adding Stripped-User-Name = "toto" Thu Dec 11 15:00:37 2008 : Debug: rlm_realm: Adding Realm = "uac.bj" Thu Dec 11 15:00:37 2008 : Debug: rlm_realm: Proxying request from user toto to realm uac.bj Thu Dec 11 15:00:37 2008 : Debug: rlm_realm: Preparing to proxy authentication request to realm "uac.bj" Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[suffix] returns updated Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 0 Thu Dec 11 15:00:37 2008 : Debug: rlm_eap: Request is supposed to be proxied to Realm uac.bj. Not doing EAP. Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[eap] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling unix (rlm_unix) for request 0 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from unix (rlm_unix) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[unix] returns updated Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling expiration (rlm_expiration) for request 0 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from expiration (rlm_expiration) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[expiration] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling logintime (rlm_logintime) for request 0 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from logintime (rlm_logintime) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[logintime] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 0 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[pap] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling passwd (rlm_passwd) for request 0 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from passwd (rlm_passwd) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[passwd] returns notfound Thu Dec 11 15:00:37 2008 : Debug: proxy: allocating destination 127.0.0.1 port 1812 - Id 200 Sending Access-Request of id 200 to 127.0.0.1 port 1812 User-Name = "toto" NAS-IP-Address = 172.21.1.251 Connect-Info = "CONNECT 802.11" Called-Station-Id = "0060b33573b4" Calling-Station-Id = "000e35dfc4c9" NAS-Identifier = "ap" NAS-Port-Type = Wireless-802.11 NAS-Port = 40 NAS-Port-Id = "40" Framed-MTU = 1400 EAP-Message = 0x0269001001746f746f407561632e626a Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x323333 Thu Dec 11 15:00:37 2008 : Debug: Proxying request 0 to home server 127.0.0.1 port 1812 Sending Access-Request of id 200 to 127.0.0.1 port 1812 User-Name = "toto" NAS-IP-Address = 172.21.1.251 Connect-Info = "CONNECT 802.11" Called-Station-Id = "0060b33573b4" Calling-Station-Id = "000e35dfc4c9" NAS-Identifier = "ap" NAS-Port-Type = Wireless-802.11 NAS-Port = 40 NAS-Port-Id = "40" Framed-MTU = 1400 EAP-Message = 0x0269001001746f746f407561632e626a Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x323333 Thu Dec 11 15:00:37 2008 : Debug: Going to the next request Thu Dec 11 15:00:37 2008 : Debug: Waking up in 0.9 seconds. rad_recv: Access-Request packet from host 127.0.0.1 port 1814, id=200, length=143 User-Name = "toto" NAS-IP-Address = 172.21.1.251 Connect-Info = "CONNECT 802.11" Called-Station-Id = "0060b33573b4" Calling-Station-Id = "000e35dfc4c9" NAS-Identifier = "ap" NAS-Port-Type = Wireless-802.11 NAS-Port = 40 NAS-Port-Id = "40" Framed-MTU = 1400 EAP-Message = 0x0269001001746f746f407561632e626a Message-Authenticator = 0x37c8e239d08fc96baa9a8711c785a234 Proxy-State = 0x323333 Thu Dec 11 15:00:37 2008 : Debug: +- entering group authorize Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1 Thu Dec 11 15:00:37 2008 : Debug: ++[preprocess] returns ok Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 1 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 1 Thu Dec 11 15:00:37 2008 : Debug: ++[chap] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 1 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 1 Thu Dec 11 15:00:37 2008 : Debug: ++[mschap] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling digest (rlm_digest) for request 1 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from digest (rlm_digest) for request 1 Thu Dec 11 15:00:37 2008 : Debug: ++[digest] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 1 Thu Dec 11 15:00:37 2008 : Debug: rlm_realm: No '@' in User-Name = "toto", looking up realm NULL Thu Dec 11 15:00:37 2008 : Debug: rlm_realm: No such realm "NULL" Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 1 Thu Dec 11 15:00:37 2008 : Debug: ++[suffix] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 1 Thu Dec 11 15:00:37 2008 : Debug: rlm_eap: EAP packet type response id 105 length 16 Thu Dec 11 15:00:37 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 1 Thu Dec 11 15:00:37 2008 : Debug: ++[eap] returns updated Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling unix (rlm_unix) for request 1 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from unix (rlm_unix) for request 1 Thu Dec 11 15:00:37 2008 : Debug: ++[unix] returns updated Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling expiration (rlm_expiration) for request 1 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from expiration (rlm_expiration) for request 1 Thu Dec 11 15:00:37 2008 : Debug: ++[expiration] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling logintime (rlm_logintime) for request 1 Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from logintime (rlm_logintime) for request 1 Thu Dec 11 15:00:37 2008 : Debug: ++[logintime] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 1 Thu Dec 11 15:00:37 2008 : Debug: rlm_pap: Found existing Auth-Type, not changing it. Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 1 Thu Dec 11 15:00:37 2008 : Debug: ++[pap] returns noop Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: calling passwd (rlm_passwd) for request 1 Thu Dec 11 15:00:37 2008 : Debug: rlm_passwd: Added MD5-Password: 'HsrtQesmWHodM:14211::::::' to config_items Thu Dec 11 15:00:37 2008 : Debug: modsingle[authorize]: returned from passwd (rlm_passwd) for request 1 Thu Dec 11 15:00:37 2008 : Debug: ++[passwd] returns ok Thu Dec 11 15:00:37 2008 : Debug: rad_check_password: Found Auth-Type EAP Thu Dec 11 15:00:37 2008 : Debug: auth: type "EAP" Thu Dec 11 15:00:37 2008 : Debug: +- entering group authenticate Thu Dec 11 15:00:37 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 1 Thu Dec 11 15:00:37 2008 : Error: rlm_eap: Identity does not match User-Name, setting from EAP Identity. Thu Dec 11 15:00:37 2008 : Debug: rlm_eap: Failed in handler Thu Dec 11 15:00:37 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 1 Thu Dec 11 15:00:37 2008 : Debug: ++[eap] returns invalid Thu Dec 11 15:00:37 2008 : Debug: auth: Failed to validate the user. Thu Dec 11 15:00:37 2008 : Debug: Found Post-Auth-Type Reject Thu Dec 11 15:00:37 2008 : Debug: +- entering group REJECT Thu Dec 11 15:00:37 2008 : Debug: modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 1 Thu Dec 11 15:00:37 2008 : Debug: expand: %{User-Name} -> toto Thu Dec 11 15:00:37 2008 : Debug: attr_filter: Matched entry DEFAULT at line 11 Thu Dec 11 15:00:37 2008 : Debug: modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for reque st 1 Thu Dec 11 15:00:37 2008 : Debug: ++[attr_filter.access_reject] returns updated Sending Access-Reject of id 200 to 127.0.0.1 port 1814 Proxy-State = 0x323333 Thu Dec 11 15:00:37 2008 : Debug: Finished request 1. Thu Dec 11 15:00:37 2008 : Debug: Going to the next request Thu Dec 11 15:00:37 2008 : Debug: Waking up in 0.9 seconds. rad_recv: Access-Reject packet from host 127.0.0.1 port 1812, id=200, length=25 Proxy-State = 0x323333 Thu Dec 11 15:00:37 2008 : Debug: +- entering group post-proxy Thu Dec 11 15:00:37 2008 : Debug: modsingle[post-proxy]: calling eap (rlm_eap) for request 0 Thu Dec 11 15:00:37 2008 : Debug: rlm_eap: No pre-existing handler found Thu Dec 11 15:00:37 2008 : Debug: modsingle[post-proxy]: returned from eap (rlm_eap) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[eap] returns noop Thu Dec 11 15:00:37 2008 : Debug: Found Post-Auth-Type Reject Thu Dec 11 15:00:37 2008 : Debug: +- entering group REJECT Thu Dec 11 15:00:37 2008 : Debug: modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 0 Thu Dec 11 15:00:37 2008 : Debug: expand: %{User-Name} -> toto@uac.bj Thu Dec 11 15:00:37 2008 : Debug: attr_filter: Matched entry DEFAULT at line 11 Thu Dec 11 15:00:37 2008 : Debug: modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for request 0 Thu Dec 11 15:00:37 2008 : Debug: ++[attr_filter.access_reject] returns updated Sending Access-Reject of id 233 to 172.21.1.251 port 1035 Thu Dec 11 15:00:37 2008 : Debug: Finished request 0. Thu Dec 11 15:00:37 2008 : Debug: Going to the next request Thu Dec 11 15:00:37 2008 : Debug: Waking up in 4.9 seconds. Thu Dec 11 15:00:42 2008 : Debug: Cleaning up request 1 ID 200 with timestamp +87 Thu Dec 11 15:00:42 2008 : Debug: Cleaning up request 0 ID 233 with timestamp +87 Thu Dec 11 15:00:42 2008 : Debug: Ready to process requests. Is there something wrong in our configurations? Is tit normal that there is no User-Password attribute in Access-Request packet? Thanks very much to help us solve these problems.