I have collected logs for full session of host authentication, log is pasted below. As mentioned in my previous mail I just want to proxy the host authentication request to the home server, is it possible? Please throw some light on how I achieve it? --------LOG START -------------- Thu Oct 21 07:07:11 2010 : Debug: main { Thu Oct 21 07:07:11 2010 : Debug: allow_core_dumps = no Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: including dictionary file /usr/local/etc/raddb/dictionary Thu Oct 21 07:07:11 2010 : Debug: main { Thu Oct 21 07:07:11 2010 : Debug: prefix = "/usr/local" Thu Oct 21 07:07:11 2010 : Debug: localstatedir = "/var" Thu Oct 21 07:07:11 2010 : Debug: logdir = "/var/log/radius" Thu Oct 21 07:07:11 2010 : Debug: libdir = "/usr/local/raddb/lib" Thu Oct 21 07:07:11 2010 : Debug: radacctdir = "/var/log/radius/radacct" Thu Oct 21 07:07:11 2010 : Debug: hostname_lookups = no Thu Oct 21 07:07:11 2010 : Debug: max_request_time = 30 Thu Oct 21 07:07:11 2010 : Debug: cleanup_delay = 5 Thu Oct 21 07:07:11 2010 : Debug: max_requests = 1024 Thu Oct 21 07:07:11 2010 : Debug: pidfile = "/var/run/radiusd/radiusd.pid" Thu Oct 21 07:07:11 2010 : Debug: checkrad = "/usr/local/sbin/checkrad" Thu Oct 21 07:07:11 2010 : Debug: debug_level = 0 Thu Oct 21 07:07:11 2010 : Debug: proxy_requests = yes Thu Oct 21 07:07:11 2010 : Debug: log { Thu Oct 21 07:07:11 2010 : Debug: stripped_names = no Thu Oct 21 07:07:11 2010 : Debug: auth = no Thu Oct 21 07:07:11 2010 : Debug: auth_badpass = no Thu Oct 21 07:07:11 2010 : Debug: auth_goodpass = no Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: security { Thu Oct 21 07:07:11 2010 : Debug: max_attributes = 200 Thu Oct 21 07:07:11 2010 : Debug: reject_delay = 1 Thu Oct 21 07:07:11 2010 : Debug: status_server = yes Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: radiusd: #### Loading Realms and Home Servers #### Thu Oct 21 07:07:11 2010 : Debug: proxy server { Thu Oct 21 07:07:11 2010 : Debug: retry_delay = 5 Thu Oct 21 07:07:11 2010 : Debug: retry_count = 3 Thu Oct 21 07:07:11 2010 : Debug: default_fallback = no Thu Oct 21 07:07:11 2010 : Debug: dead_time = 120 Thu Oct 21 07:07:11 2010 : Debug: wake_all_if_all_dead = no Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: home_server localhost { Thu Oct 21 07:07:11 2010 : Debug: ipaddr = 127.0.0.1 Thu Oct 21 07:07:11 2010 : Debug: port = 1812 Thu Oct 21 07:07:11 2010 : Debug: type = "auth" Thu Oct 21 07:07:11 2010 : Debug: secret = "testing123" Thu Oct 21 07:07:11 2010 : Debug: response_window = 20 Thu Oct 21 07:07:11 2010 : Debug: max_outstanding = 65536 Thu Oct 21 07:07:11 2010 : Debug: require_message_authenticator = no Thu Oct 21 07:07:11 2010 : Debug: zombie_period = 40 Thu Oct 21 07:07:11 2010 : Debug: status_check = "status-server" Thu Oct 21 07:07:11 2010 : Debug: ping_interval = 30 Thu Oct 21 07:07:11 2010 : Debug: check_interval = 30 Thu Oct 21 07:07:11 2010 : Debug: num_answers_to_alive = 3 Thu Oct 21 07:07:11 2010 : Debug: num_pings_to_alive = 3 Thu Oct 21 07:07:11 2010 : Debug: revive_interval = 120 Thu Oct 21 07:07:11 2010 : Debug: status_check_timeout = 4 Thu Oct 21 07:07:11 2010 : Debug: irt = 2 Thu Oct 21 07:07:11 2010 : Debug: mrt = 16 Thu Oct 21 07:07:11 2010 : Debug: mrc = 5 Thu Oct 21 07:07:11 2010 : Debug: mrd = 30 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: home_server_pool my_auth_failover { Thu Oct 21 07:07:11 2010 : Debug: type = fail-over Thu Oct 21 07:07:11 2010 : Debug: home_server = localhost Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: realm example.com { Thu Oct 21 07:07:11 2010 : Debug: auth_pool = my_auth_failover Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: home_server testad763 { Thu Oct 21 07:07:11 2010 : Debug: ipaddr = 192.168.7.63 Thu Oct 21 07:07:11 2010 : Debug: port = 1812 Thu Oct 21 07:07:11 2010 : Debug: type = "auth" Thu Oct 21 07:07:11 2010 : Debug: secret = "nevis123" Thu Oct 21 07:07:11 2010 : Debug: response_window = 20 Thu Oct 21 07:07:11 2010 : Debug: max_outstanding = 65536 Thu Oct 21 07:07:11 2010 : Debug: require_message_authenticator = no Thu Oct 21 07:07:11 2010 : Debug: zombie_period = 40 Thu Oct 21 07:07:11 2010 : Debug: status_check = "status-server" Thu Oct 21 07:07:11 2010 : Debug: ping_interval = 30 Thu Oct 21 07:07:11 2010 : Debug: check_interval = 30 Thu Oct 21 07:07:11 2010 : Debug: num_answers_to_alive = 3 Thu Oct 21 07:07:11 2010 : Debug: num_pings_to_alive = 3 Thu Oct 21 07:07:11 2010 : Debug: revive_interval = 120 Thu Oct 21 07:07:11 2010 : Debug: status_check_timeout = 4 Thu Oct 21 07:07:11 2010 : Debug: irt = 2 Thu Oct 21 07:07:11 2010 : Debug: mrt = 16 Thu Oct 21 07:07:11 2010 : Debug: mrc = 5 Thu Oct 21 07:07:11 2010 : Debug: mrd = 30 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: home_server_pool testad763 { Thu Oct 21 07:07:11 2010 : Debug: type = fail-over Thu Oct 21 07:07:11 2010 : Debug: home_server = testad763 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: realm testad1.com { Thu Oct 21 07:07:11 2010 : Debug: auth_pool = testad763 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: realm testad1 { Thu Oct 21 07:07:11 2010 : Debug: auth_pool = testad763 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: home_server si_test_dssc { Thu Oct 21 07:07:11 2010 : Debug: ipaddr = 192.168.4.138 Thu Oct 21 07:07:11 2010 : Debug: port = 1812 Thu Oct 21 07:07:11 2010 : Debug: type = "auth" Thu Oct 21 07:07:11 2010 : Debug: secret = "nevis123" Thu Oct 21 07:07:11 2010 : Debug: response_window = 20 Thu Oct 21 07:07:11 2010 : Debug: max_outstanding = 65536 Thu Oct 21 07:07:11 2010 : Debug: require_message_authenticator = no Thu Oct 21 07:07:11 2010 : Debug: zombie_period = 40 Thu Oct 21 07:07:11 2010 : Debug: status_check = "status-server" Thu Oct 21 07:07:11 2010 : Debug: ping_interval = 30 Thu Oct 21 07:07:11 2010 : Debug: check_interval = 30 Thu Oct 21 07:07:11 2010 : Debug: num_answers_to_alive = 3 Thu Oct 21 07:07:11 2010 : Debug: num_pings_to_alive = 3 Thu Oct 21 07:07:11 2010 : Debug: revive_interval = 120 Thu Oct 21 07:07:11 2010 : Debug: status_check_timeout = 4 Thu Oct 21 07:07:11 2010 : Debug: irt = 2 Thu Oct 21 07:07:11 2010 : Debug: mrt = 16 Thu Oct 21 07:07:11 2010 : Debug: mrc = 5 Thu Oct 21 07:07:11 2010 : Debug: mrd = 30 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: home_server_pool si_test_dssc { Thu Oct 21 07:07:11 2010 : Debug: type = fail-over Thu Oct 21 07:07:11 2010 : Debug: home_server = si_test_dssc Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: realm si-test.dssc.nevis.com { Thu Oct 21 07:07:11 2010 : Debug: auth_pool = si_test_dssc Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: realm LOCAL { Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: realm DEFAULT { Thu Oct 21 07:07:11 2010 : Debug: authhost = testad763 Thu Oct 21 07:07:11 2010 : Debug: secret = nevis123 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: radiusd: #### Loading Clients #### Thu Oct 21 07:07:11 2010 : Debug: client localhost { Thu Oct 21 07:07:11 2010 : Debug: ipaddr = 127.0.0.1 Thu Oct 21 07:07:11 2010 : Debug: require_message_authenticator = no Thu Oct 21 07:07:11 2010 : Debug: secret = "testing123" Thu Oct 21 07:07:11 2010 : Debug: nastype = "other" Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: client 192.168.6.181 { Thu Oct 21 07:07:11 2010 : Debug: require_message_authenticator = no Thu Oct 21 07:07:11 2010 : Debug: secret = "testing123" Thu Oct 21 07:07:11 2010 : Debug: shortname = "liv1" Thu Oct 21 07:07:11 2010 : Debug: nastype = "livingston" Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: client 192.168.6.200 { Thu Oct 21 07:07:11 2010 : Debug: require_message_authenticator = no Thu Oct 21 07:07:11 2010 : Debug: secret = "testing123" Thu Oct 21 07:07:11 2010 : Debug: shortname = "cisco" Thu Oct 21 07:07:11 2010 : Debug: nastype = "cisco2960" Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: radiusd: #### Instantiating modules #### Thu Oct 21 07:07:11 2010 : Debug: instantiate { Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_exec, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_exec Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "exec" from file /usr/local/etc/raddb/modules/exec Thu Oct 21 07:07:11 2010 : Debug: exec { Thu Oct 21 07:07:11 2010 : Debug: wait = yes Thu Oct 21 07:07:11 2010 : Debug: input_pairs = "request" Thu Oct 21 07:07:11 2010 : Debug: shell_escape = yes Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "my_exec" from file /usr/local/etc/raddb/modules/my_exec Thu Oct 21 07:07:11 2010 : Debug: exec my_exec { Thu Oct 21 07:07:11 2010 : Debug: wait = yes Thu Oct 21 07:07:11 2010 : Debug: input_pairs = "proxy-request" Thu Oct 21 07:07:11 2010 : Debug: output_pairs = "proxy-reply" Thu Oct 21 07:07:11 2010 : Debug: packet_type = "Access-Accept" Thu Oct 21 07:07:11 2010 : Debug: shell_escape = yes Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_expr, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_expr Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "expr" from file /usr/local/etc/raddb/modules/expr Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_expiration, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_expiration Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "expiration" from file /usr/local/etc/raddb/modules/expiration Thu Oct 21 07:07:11 2010 : Debug: expiration { Thu Oct 21 07:07:11 2010 : Debug: reply-message = "Password Has Expired " Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_logintime, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_logintime Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "logintime" from file /usr/local/etc/raddb/modules/logintime Thu Oct 21 07:07:11 2010 : Debug: logintime { Thu Oct 21 07:07:11 2010 : Debug: reply-message = "You are calling outside your allowed timespan " Thu Oct 21 07:07:11 2010 : Debug: minimum-timeout = 60 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: radiusd: #### Loading Virtual Servers #### Thu Oct 21 07:07:11 2010 : Debug: server inner-tunnel { # from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Thu Oct 21 07:07:11 2010 : Debug: modules { Thu Oct 21 07:07:11 2010 : Debug: Module: Checking authenticate {...} for more modules to load Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_pap, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_pap Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "pap" from file /usr/local/etc/raddb/modules/pap Thu Oct 21 07:07:11 2010 : Debug: pap { Thu Oct 21 07:07:11 2010 : Debug: encryption_scheme = "auto" Thu Oct 21 07:07:11 2010 : Debug: auto_header = no Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_chap, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_chap Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "chap" from file /usr/local/etc/raddb/modules/chap Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_mschap, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_mschap Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "mschap" from file /usr/local/etc/raddb/modules/mschap Thu Oct 21 07:07:11 2010 : Debug: mschap { Thu Oct 21 07:07:11 2010 : Debug: use_mppe = yes Thu Oct 21 07:07:11 2010 : Debug: require_encryption = no Thu Oct 21 07:07:11 2010 : Debug: require_strong = no Thu Oct 21 07:07:11 2010 : Debug: with_ntdomain_hack = no Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_unix, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_unix Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "unix" from file /usr/local/etc/raddb/modules/unix Thu Oct 21 07:07:11 2010 : Debug: unix { Thu Oct 21 07:07:11 2010 : Debug: radwtmp = "/var/log/radius/radwtmp" Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_eap, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_eap Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "eap" from file /usr/local/etc/raddb/eap.conf Thu Oct 21 07:07:11 2010 : Debug: eap { Thu Oct 21 07:07:11 2010 : Debug: default_eap_type = "md5" Thu Oct 21 07:07:11 2010 : Debug: timer_expire = 60 Thu Oct 21 07:07:11 2010 : Debug: ignore_unknown_eap_types = no Thu Oct 21 07:07:11 2010 : Debug: cisco_accounting_username_bug = no Thu Oct 21 07:07:11 2010 : Debug: max_sessions = 4096 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to sub-module rlm_eap_md5 Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating eap-md5 Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to sub-module rlm_eap_leap Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating eap-leap Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to sub-module rlm_eap_gtc Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating eap-gtc Thu Oct 21 07:07:11 2010 : Debug: gtc { Thu Oct 21 07:07:11 2010 : Debug: challenge = "Password: " Thu Oct 21 07:07:11 2010 : Debug: auth_type = "PAP" Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to sub-module rlm_eap_tls Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating eap-tls Thu Oct 21 07:07:11 2010 : Debug: tls { Thu Oct 21 07:07:11 2010 : Debug: rsa_key_exchange = no Thu Oct 21 07:07:11 2010 : Debug: dh_key_exchange = yes Thu Oct 21 07:07:11 2010 : Debug: rsa_key_length = 512 Thu Oct 21 07:07:11 2010 : Debug: dh_key_length = 512 Thu Oct 21 07:07:11 2010 : Debug: verify_depth = 0 Thu Oct 21 07:07:11 2010 : Debug: pem_file_type = yes Thu Oct 21 07:07:11 2010 : Debug: private_key_file = "/usr/local/etc/raddb/certs/server.key" Thu Oct 21 07:07:11 2010 : Debug: certificate_file = "/usr/local/etc/raddb/certs/server.pem" Thu Oct 21 07:07:11 2010 : Debug: CA_file = "/usr/local/etc/raddb/certs/ca.pem" Thu Oct 21 07:07:11 2010 : Debug: private_key_password = "whatever" Thu Oct 21 07:07:11 2010 : Debug: dh_file = "/usr/local/etc/raddb/certs/dh" Thu Oct 21 07:07:11 2010 : Debug: random_file = "/usr/local/etc/raddb/certs/random" Thu Oct 21 07:07:11 2010 : Debug: fragment_size = 1024 Thu Oct 21 07:07:11 2010 : Debug: include_length = yes Thu Oct 21 07:07:11 2010 : Debug: check_crl = no Thu Oct 21 07:07:11 2010 : Debug: cipher_list = "DEFAULT" Thu Oct 21 07:07:11 2010 : Debug: make_cert_command = "/usr/local/etc/raddb/certs/bootstrap" Thu Oct 21 07:07:11 2010 : Debug: cache { Thu Oct 21 07:07:11 2010 : Debug: enable = no Thu Oct 21 07:07:11 2010 : Debug: lifetime = 24 Thu Oct 21 07:07:11 2010 : Debug: max_entries = 255 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to sub-module rlm_eap_ttls Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating eap-ttls Thu Oct 21 07:07:11 2010 : Debug: ttls { Thu Oct 21 07:07:11 2010 : Debug: default_eap_type = "md5" Thu Oct 21 07:07:11 2010 : Debug: copy_request_to_tunnel = no Thu Oct 21 07:07:11 2010 : Debug: use_tunneled_reply = no Thu Oct 21 07:07:11 2010 : Debug: virtual_server = "inner-tunnel" Thu Oct 21 07:07:11 2010 : Debug: include_length = yes Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to sub-module rlm_eap_peap Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating eap-peap Thu Oct 21 07:07:11 2010 : Debug: peap { Thu Oct 21 07:07:11 2010 : Debug: default_eap_type = "mschapv2" Thu Oct 21 07:07:11 2010 : Debug: copy_request_to_tunnel = no Thu Oct 21 07:07:11 2010 : Debug: use_tunneled_reply = no Thu Oct 21 07:07:11 2010 : Debug: proxy_tunneled_request_as_eap = yes Thu Oct 21 07:07:11 2010 : Debug: virtual_server = "inner-tunnel" Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating eap-mschapv2 Thu Oct 21 07:07:11 2010 : Debug: mschapv2 { Thu Oct 21 07:07:11 2010 : Debug: with_ntdomain_hack = no Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Checking authorize {...} for more modules to load Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_realm, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_realm Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "suffix" from file /usr/local/etc/raddb/modules/realm Thu Oct 21 07:07:11 2010 : Debug: realm suffix { Thu Oct 21 07:07:11 2010 : Debug: format = "suffix" Thu Oct 21 07:07:11 2010 : Debug: delimiter = "@" Thu Oct 21 07:07:11 2010 : Debug: ignore_default = no Thu Oct 21 07:07:11 2010 : Debug: ignore_null = yes Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_files, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_files Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "files" from file /usr/local/etc/raddb/modules/files Thu Oct 21 07:07:11 2010 : Debug: files { Thu Oct 21 07:07:11 2010 : Debug: usersfile = "/usr/local/etc/raddb/users" Thu Oct 21 07:07:11 2010 : Debug: acctusersfile = "/usr/local/etc/raddb/acct_users" Thu Oct 21 07:07:11 2010 : Debug: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users" Thu Oct 21 07:07:11 2010 : Debug: compat = "no" Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Checking session {...} for more modules to load Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_radutmp, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_radutmp Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "radutmp" from file /usr/local/etc/raddb/modules/radutmp Thu Oct 21 07:07:11 2010 : Debug: radutmp { Thu Oct 21 07:07:11 2010 : Debug: filename = "/var/log/radius/radutmp" Thu Oct 21 07:07:11 2010 : Debug: username = "%{User-Name}" Thu Oct 21 07:07:11 2010 : Debug: case_sensitive = yes Thu Oct 21 07:07:11 2010 : Debug: check_with_nas = yes Thu Oct 21 07:07:11 2010 : Debug: perm = 384 Thu Oct 21 07:07:11 2010 : Debug: callerid = yes Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Checking post-proxy {...} for more modules to load Thu Oct 21 07:07:11 2010 : Debug: Module: Checking post-auth {...} for more modules to load Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_attr_filter Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "attr_filter.access_reject" from file /usr/local/etc/raddb/modules/attr_filter Thu Oct 21 07:07:11 2010 : Debug: attr_filter attr_filter.access_reject { Thu Oct 21 07:07:11 2010 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.access_reject" Thu Oct 21 07:07:11 2010 : Debug: key = "%{User-Name}" Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: } # modules Thu Oct 21 07:07:11 2010 : Debug: } # server Thu Oct 21 07:07:11 2010 : Debug: server { # from file /usr/local/etc/raddb/radiusd.conf Thu Oct 21 07:07:11 2010 : Debug: modules { Thu Oct 21 07:07:11 2010 : Debug: Module: Checking authenticate {...} for more modules to load Thu Oct 21 07:07:11 2010 : Debug: Module: Checking authorize {...} for more modules to load Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_preprocess, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_preprocess Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "preprocess" from file /usr/local/etc/raddb/modules/preprocess Thu Oct 21 07:07:11 2010 : Debug: preprocess { Thu Oct 21 07:07:11 2010 : Debug: huntgroups = "/usr/local/etc/raddb/huntgroups" Thu Oct 21 07:07:11 2010 : Debug: hints = "/usr/local/etc/raddb/hints" Thu Oct 21 07:07:11 2010 : Debug: with_ascend_hack = no Thu Oct 21 07:07:11 2010 : Debug: ascend_channels_per_line = 23 Thu Oct 21 07:07:11 2010 : Debug: with_ntdomain_hack = no Thu Oct 21 07:07:11 2010 : Debug: with_specialix_jetstream_hack = no Thu Oct 21 07:07:11 2010 : Debug: with_cisco_vsa_hack = no Thu Oct 21 07:07:11 2010 : Debug: with_alvarion_vsa_hack = no Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "ntdomain" from file /usr/local/etc/raddb/modules/realm Thu Oct 21 07:07:11 2010 : Debug: realm ntdomain { Thu Oct 21 07:07:11 2010 : Debug: format = "prefix" Thu Oct 21 07:07:11 2010 : Debug: delimiter = "\" Thu Oct 21 07:07:11 2010 : Debug: ignore_default = no Thu Oct 21 07:07:11 2010 : Debug: ignore_null = yes Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "realmpercent" from file /usr/local/etc/raddb/modules/realm Thu Oct 21 07:07:11 2010 : Debug: realm realmpercent { Thu Oct 21 07:07:11 2010 : Debug: format = "suffix" Thu Oct 21 07:07:11 2010 : Debug: delimiter = "%" Thu Oct 21 07:07:11 2010 : Debug: ignore_default = no Thu Oct 21 07:07:11 2010 : Debug: ignore_null = yes Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Checking preacct {...} for more modules to load Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_acct_unique Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "acct_unique" from file /usr/local/etc/raddb/modules/acct_unique Thu Oct 21 07:07:11 2010 : Debug: acct_unique { Thu Oct 21 07:07:11 2010 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Checking accounting {...} for more modules to load Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_detail, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_detail Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "detail" from file /usr/local/etc/raddb/modules/detail Thu Oct 21 07:07:11 2010 : Debug: detail { Thu Oct 21 07:07:11 2010 : Debug: detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" Thu Oct 21 07:07:11 2010 : Debug: header = "%t" Thu Oct 21 07:07:11 2010 : Debug: detailperm = 384 Thu Oct 21 07:07:11 2010 : Debug: dirperm = 493 Thu Oct 21 07:07:11 2010 : Debug: locking = no Thu Oct 21 07:07:11 2010 : Debug: log_packet_header = no Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "attr_filter.accounting_response" from file /usr/local/etc/raddb/modules/attr_filter Thu Oct 21 07:07:11 2010 : Debug: attr_filter attr_filter.accounting_response { Thu Oct 21 07:07:11 2010 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.accounting_response" Thu Oct 21 07:07:11 2010 : Debug: key = "%{User-Name}" Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Checking session {...} for more modules to load Thu Oct 21 07:07:11 2010 : Debug: Module: Checking post-proxy {...} for more modules to load Thu Oct 21 07:07:11 2010 : Debug: (Loaded rlm_attr_rewrite, checking if it's valid) Thu Oct 21 07:07:11 2010 : Debug: Module: Linked to module rlm_attr_rewrite Thu Oct 21 07:07:11 2010 : Debug: Module: Instantiating module "force_tunnel_vlanid" from file /usr/local/etc/raddb/modules/attr_rewrite Thu Oct 21 07:07:11 2010 : Debug: attr_rewrite force_tunnel_vlanid { Thu Oct 21 07:07:11 2010 : Debug: attribute = "Tunnel-Private-Group-ID" Thu Oct 21 07:07:11 2010 : Debug: searchfor = "NULL" Thu Oct 21 07:07:11 2010 : Debug: searchin = "proxy_reply" Thu Oct 21 07:07:11 2010 : Debug: replacewith = "%{my_exec:/tmp/master_exec}" Thu Oct 21 07:07:11 2010 : Debug: append = no Thu Oct 21 07:07:11 2010 : Debug: ignore_case = no Thu Oct 21 07:07:11 2010 : Debug: new_attribute = yes Thu Oct 21 07:07:11 2010 : Debug: max_matches = 1 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Module: Checking post-auth {...} for more modules to load Thu Oct 21 07:07:11 2010 : Debug: } # modules Thu Oct 21 07:07:11 2010 : Debug: } # server Thu Oct 21 07:07:11 2010 : Debug: radiusd: #### Opening IP addresses and Ports #### Thu Oct 21 07:07:11 2010 : Debug: listen { Thu Oct 21 07:07:11 2010 : Debug: type = "auth" Thu Oct 21 07:07:11 2010 : Debug: ipaddr = * Thu Oct 21 07:07:11 2010 : Debug: port = 0 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: listen { Thu Oct 21 07:07:11 2010 : Debug: type = "acct" Thu Oct 21 07:07:11 2010 : Debug: ipaddr = * Thu Oct 21 07:07:11 2010 : Debug: port = 0 Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: listen { Thu Oct 21 07:07:11 2010 : Debug: type = "control" Thu Oct 21 07:07:11 2010 : Debug: listen { Thu Oct 21 07:07:11 2010 : Debug: socket = "/var/run/radiusd/radiusd.sock" Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: } Thu Oct 21 07:07:11 2010 : Debug: Listening on authentication address * port 1812 Thu Oct 21 07:07:11 2010 : Debug: Listening on accounting address * port 1813 Thu Oct 21 07:07:11 2010 : Debug: Listening on command file /var/run/radiusd/radiusd.sock Thu Oct 21 07:07:11 2010 : Debug: Listening on proxy address * port 1814 Thu Oct 21 07:07:11 2010 : Info: Ready to process requests. rad_recv: Access-Request packet from host 192.168.6.200 port 1645, id=220, length=165 User-Name = "host/radhost1.testad1.com" Service-Type = Framed-User Framed-MTU = 1500 Called-Station-Id = "00-21-D7-00-51-89" Calling-Station-Id = "00-13-20-38-33-27" EAP-Message = 0x020d001e01686f73742f726164686f7374312e746573746164312e636f6d Message-Authenticator = 0x83e730b90d5945355c44adabb90dd574 NAS-Port-Type = Ethernet NAS-Port = 50009 NAS-IP-Address = 192.168.6.200 Thu Oct 21 07:07:31 2010 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authorize {...} Thu Oct 21 07:07:31 2010 : Info: ++[preprocess] returns ok Thu Oct 21 07:07:31 2010 : Info: ++[chap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns noop Thu Oct 21 07:07:31 2010 : Info: [suffix] No '@' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[suffix] returns noop Thu Oct 21 07:07:31 2010 : Info: [ntdomain] No '\' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[ntdomain] returns noop Thu Oct 21 07:07:31 2010 : Info: [realmpercent] No '%' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[realmpercent] returns noop Thu Oct 21 07:07:31 2010 : Info: [eap] EAP packet type response id 13 length 30 Thu Oct 21 07:07:31 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns updated Thu Oct 21 07:07:31 2010 : Info: ++[unix] returns notfound Thu Oct 21 07:07:31 2010 : Info: ++[files] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[expiration] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[logintime] returns noop Thu Oct 21 07:07:31 2010 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Thu Oct 21 07:07:31 2010 : Info: ++[pap] returns noop Thu Oct 21 07:07:31 2010 : Info: Found Auth-Type = EAP Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authenticate {...} Thu Oct 21 07:07:31 2010 : Info: [eap] EAP Identity Thu Oct 21 07:07:31 2010 : Info: [eap] processing type md5 Thu Oct 21 07:07:31 2010 : Debug: rlm_eap_md5: Issuing Challenge Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 220 to 192.168.6.200 port 1645 EAP-Message = 0x010e00160410a06588f4e2ae50483b36360923d655d7 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x088772240889767144d41c726612cd30 Thu Oct 21 07:07:31 2010 : Info: Finished request 0. Thu Oct 21 07:07:31 2010 : Debug: Going to the next request Thu Oct 21 07:07:31 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.200 port 1645, id=221, length=159 User-Name = "host/radhost1.testad1.com" Service-Type = Framed-User Framed-MTU = 1500 Called-Station-Id = "00-21-D7-00-51-89" Calling-Station-Id = "00-13-20-38-33-27" EAP-Message = 0x020e00060319 Message-Authenticator = 0x07cd5bd15c2933b805814027dae20147 NAS-Port-Type = Ethernet NAS-Port = 50009 State = 0x088772240889767144d41c726612cd30 NAS-IP-Address = 192.168.6.200 Thu Oct 21 07:07:31 2010 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authorize {...} Thu Oct 21 07:07:31 2010 : Info: ++[preprocess] returns ok Thu Oct 21 07:07:31 2010 : Info: ++[chap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns noop Thu Oct 21 07:07:31 2010 : Info: [suffix] No '@' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[suffix] returns noop Thu Oct 21 07:07:31 2010 : Info: [ntdomain] No '\' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[ntdomain] returns noop Thu Oct 21 07:07:31 2010 : Info: [realmpercent] No '%' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[realmpercent] returns noop Thu Oct 21 07:07:31 2010 : Info: [eap] EAP packet type response id 14 length 6 Thu Oct 21 07:07:31 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns updated Thu Oct 21 07:07:31 2010 : Info: ++[unix] returns notfound Thu Oct 21 07:07:31 2010 : Info: ++[files] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[expiration] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[logintime] returns noop Thu Oct 21 07:07:31 2010 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Thu Oct 21 07:07:31 2010 : Info: ++[pap] returns noop Thu Oct 21 07:07:31 2010 : Info: Found Auth-Type = EAP Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authenticate {...} Thu Oct 21 07:07:31 2010 : Info: [eap] Request found, released from the list Thu Oct 21 07:07:31 2010 : Info: [eap] EAP NAK Thu Oct 21 07:07:31 2010 : Info: [eap] EAP-NAK asked for EAP-Type/peap Thu Oct 21 07:07:31 2010 : Info: [eap] processing type tls Thu Oct 21 07:07:31 2010 : Info: [tls] Initiate Thu Oct 21 07:07:31 2010 : Info: [tls] Start returned 1 Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 221 to 192.168.6.200 port 1645 EAP-Message = 0x010f00061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0887722409886b7144d41c726612cd30 Thu Oct 21 07:07:31 2010 : Info: Finished request 1. Thu Oct 21 07:07:31 2010 : Debug: Going to the next request Thu Oct 21 07:07:31 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.200 port 1645, id=222, length=233 User-Name = "host/radhost1.testad1.com" Service-Type = Framed-User Framed-MTU = 1500 Called-Station-Id = "00-21-D7-00-51-89" Calling-Station-Id = "00-13-20-38-33-27" EAP-Message = 0x020f005019800000004616030100410100003d03014cbfe598ba52f6fefe624a40f10e03a73cc535de7528f4c257c4b987977a269b00001600040005000a000900640062000300060013001200630100 Message-Authenticator = 0x923568a42734774a5d99673b38deaaf8 NAS-Port-Type = Ethernet NAS-Port = 50009 State = 0x0887722409886b7144d41c726612cd30 NAS-IP-Address = 192.168.6.200 Thu Oct 21 07:07:31 2010 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authorize {...} Thu Oct 21 07:07:31 2010 : Info: ++[preprocess] returns ok Thu Oct 21 07:07:31 2010 : Info: ++[chap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns noop Thu Oct 21 07:07:31 2010 : Info: [suffix] No '@' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[suffix] returns noop Thu Oct 21 07:07:31 2010 : Info: [ntdomain] No '\' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[ntdomain] returns noop Thu Oct 21 07:07:31 2010 : Info: [realmpercent] No '%' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[realmpercent] returns noop Thu Oct 21 07:07:31 2010 : Info: [eap] EAP packet type response id 15 length 80 Thu Oct 21 07:07:31 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns ok Thu Oct 21 07:07:31 2010 : Info: Found Auth-Type = EAP Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authenticate {...} Thu Oct 21 07:07:31 2010 : Info: [eap] Request found, released from the list Thu Oct 21 07:07:31 2010 : Info: [eap] EAP/peap Thu Oct 21 07:07:31 2010 : Info: [eap] processing type peap Thu Oct 21 07:07:31 2010 : Info: [peap] processing EAP-TLS Thu Oct 21 07:07:31 2010 : Debug: TLS Length 70 Thu Oct 21 07:07:31 2010 : Info: [peap] Length Included Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_verify returned 11 Thu Oct 21 07:07:31 2010 : Info: [peap] (other): before/accept initialization Thu Oct 21 07:07:31 2010 : Info: [peap] TLS_accept: before/accept initialization Thu Oct 21 07:07:31 2010 : Info: [peap] <<< TLS 1.0 Handshake [length 0041], ClientHello Thu Oct 21 07:07:31 2010 : Info: [peap] TLS_accept: SSLv3 read client hello A Thu Oct 21 07:07:31 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 002a], ServerHello Thu Oct 21 07:07:31 2010 : Info: [peap] TLS_accept: SSLv3 write server hello A Thu Oct 21 07:07:31 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 084e], Certificate Thu Oct 21 07:07:31 2010 : Info: [peap] TLS_accept: SSLv3 write certificate A Thu Oct 21 07:07:31 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Thu Oct 21 07:07:31 2010 : Info: [peap] TLS_accept: SSLv3 write server done A Thu Oct 21 07:07:31 2010 : Info: [peap] TLS_accept: SSLv3 flush data Thu Oct 21 07:07:31 2010 : Info: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A Thu Oct 21 07:07:31 2010 : Debug: In SSL Handshake Phase Thu Oct 21 07:07:31 2010 : Debug: In SSL Accept mode Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_process returned 13 Thu Oct 21 07:07:31 2010 : Info: [peap] EAPTLS_HANDLED Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 222 to 192.168.6.200 port 1645 EAP-Message = 0x0110040019c00000088b160301002a0200002603014cbfe6b3abfabffbb832f3e861a0b30c2d343d28aebf518d2343850e6043751300000400160301084e0b00084a0008470003a6308203a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479 EAP-Message = 0x301e170d3130303932393038343532365a170d3131303932393038343532365a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100e42f6aa75de6daaf7d479e2bbcd6297a706cc3ad5b2f4cec33d3691205bb03263cb44cec4dd5326e86efb6c30c182a8c50e11c6d23bf0b37aa34d15a1671 EAP-Message = 0x75a74e1ed78e477f23ff2721612d370dbc5b8821795e653e0a0f80a911cec46be51fac1025c42247f340cfa8de26acb5583dc4a4b0c8f3c775d55532cf351d1ad4a1d7863e1260f3b4b094338dd484ca64b1633d389993090a7ddd37925aaf89dc17fcb95e6dacec216be21c67d623a76b0b22593c794e96b6d2b85b73e6af62fb038094d950285fd12644a62e196b162405b23b1a47862b530cd359da54c58629e13210ba5ba00992439ee5703210662c38eaa2987227c60746b5cc267b65c59a230203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003820101007c44fa7594562647e4 EAP-Message = 0xfbe943560a5867883ac1957d183a31b8ac7684f11beb5a06d86c50e1932c1a3cf42553e64f4d4959021930b0cd5c3159417349dc974ba4ed0ff37c06054c861768d68736a1823b3f3cbeeacf58ee6de024caea880091b0793d280c23f1d6132120a1effd48032c0c1065794386878327df98e3a143709a4fbd23bf698d9347a3a1b8cfcbe317a43b967ec0afc6b2baf9f5902c21500d52981c24ee9b998d7434420194a82fe75cb1784bc08a78244ffd66d0f04dda24b5d3db94d44610771f307b7a0a348f7399fea4076aa074d3836baba9b5c939b7d1f32c32c09d26a7a2c7d6b36bf51ddb3d4d7d758a045196de5e0846c8b18aa01500049b308204 EAP-Message = 0x973082037fa0030201020201 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x088772240a976b7144d41c726612cd30 Thu Oct 21 07:07:31 2010 : Info: Finished request 2. Thu Oct 21 07:07:31 2010 : Debug: Going to the next request Thu Oct 21 07:07:31 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.200 port 1645, id=223, length=159 User-Name = "host/radhost1.testad1.com" Service-Type = Framed-User Framed-MTU = 1500 Called-Station-Id = "00-21-D7-00-51-89" Calling-Station-Id = "00-13-20-38-33-27" EAP-Message = 0x021000061900 Message-Authenticator = 0x923dff1ce3daa278d9b1884119931d53 NAS-Port-Type = Ethernet NAS-Port = 50009 State = 0x088772240a976b7144d41c726612cd30 NAS-IP-Address = 192.168.6.200 Thu Oct 21 07:07:31 2010 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authorize {...} Thu Oct 21 07:07:31 2010 : Info: ++[preprocess] returns ok Thu Oct 21 07:07:31 2010 : Info: ++[chap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns noop Thu Oct 21 07:07:31 2010 : Info: [suffix] No '@' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[suffix] returns noop Thu Oct 21 07:07:31 2010 : Info: [ntdomain] No '\' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[ntdomain] returns noop Thu Oct 21 07:07:31 2010 : Info: [realmpercent] No '%' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[realmpercent] returns noop Thu Oct 21 07:07:31 2010 : Info: [eap] EAP packet type response id 16 length 6 Thu Oct 21 07:07:31 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns ok Thu Oct 21 07:07:31 2010 : Info: Found Auth-Type = EAP Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authenticate {...} Thu Oct 21 07:07:31 2010 : Info: [eap] Request found, released from the list Thu Oct 21 07:07:31 2010 : Info: [eap] EAP/peap Thu Oct 21 07:07:31 2010 : Info: [eap] processing type peap Thu Oct 21 07:07:31 2010 : Info: [peap] processing EAP-TLS Thu Oct 21 07:07:31 2010 : Info: [peap] Received TLS ACK Thu Oct 21 07:07:31 2010 : Info: [peap] ACK handshake fragment handler Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_verify returned 1 Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_process returned 13 Thu Oct 21 07:07:31 2010 : Info: [peap] EAPTLS_HANDLED Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 223 to 192.168.6.200 port 1645 EAP-Message = 0x011103fc194000300d06092a864886f70d0101040500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3130303932393038343532365a170d3131303932393038343532365a308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d6577 EAP-Message = 0x6865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100e8369354079e6b7c8b7303960a8be682adb4229e415ad34aa545b8fe6a71a8edc5d0be3e3954eed19eca8a90780d608324dd2c94abdcae0bc1dc74da5dc4809ca37e3dcff0d7540aa94a4e0074d484ec4757b6f9dcbe967d7117686408bdb01f369b4652efdfa721b642ba0d343e7203a6e5f5efb5a69d EAP-Message = 0x822d23eddd95c78c95e993cd1f4053a995b6ee00b32d49aadf9c476ffbc1d9fcd14fbbeb70394e212e4343625d851d45135be306e9bbf83fbff11ecbccc77efeb15f1f305078343b12376871a0d463d6fa6e628de6efaa56715960216556c113ce31eb130469bd7adfdf257b42b80ba49cf33f4e66e35c146b0c61b27af9b3cfdd288ca7e6a0c58df10203010001a381f33081f0301d0603551d0e0416041490335fdaa1c5a2648e74ef38f15cf5cc4d01f6dc3081c00603551d230481b83081b5801490335fdaa1c5a2648e74ef38f15cf5cc4d01f6dca18199a48196308193310b3009060355040613024652310f300d060355040813065261646975 EAP-Message = 0x733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479820100300c0603551d13040530030101ff300d06092a864886f70d0101040500038201010062ee01209c6e06abcd324e929810f154aa52bfb4ef711b4cdfa6a0b40b2d296492130323e8d92f7a2674ff8c9beca1e2fe502e57f79ae957131763703c3c0e69cba680cc3b340c3236eed097576d961166de1d689dab12a3cc46eab2236cc870a016 EAP-Message = 0x90f252d0f78ab3cc Message-Authenticator = 0x00000000000000000000000000000000 State = 0x088772240b966b7144d41c726612cd30 Thu Oct 21 07:07:31 2010 : Info: Finished request 3. Thu Oct 21 07:07:31 2010 : Debug: Going to the next request Thu Oct 21 07:07:31 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.200 port 1645, id=224, length=159 User-Name = "host/radhost1.testad1.com" Service-Type = Framed-User Framed-MTU = 1500 Called-Station-Id = "00-21-D7-00-51-89" Calling-Station-Id = "00-13-20-38-33-27" EAP-Message = 0x021100061900 Message-Authenticator = 0xe8be3d94dc9d041e706c846f2f083ca6 NAS-Port-Type = Ethernet NAS-Port = 50009 State = 0x088772240b966b7144d41c726612cd30 NAS-IP-Address = 192.168.6.200 Thu Oct 21 07:07:31 2010 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authorize {...} Thu Oct 21 07:07:31 2010 : Info: ++[preprocess] returns ok Thu Oct 21 07:07:31 2010 : Info: ++[chap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns noop Thu Oct 21 07:07:31 2010 : Info: [suffix] No '@' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[suffix] returns noop Thu Oct 21 07:07:31 2010 : Info: [ntdomain] No '\' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[ntdomain] returns noop Thu Oct 21 07:07:31 2010 : Info: [realmpercent] No '%' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[realmpercent] returns noop Thu Oct 21 07:07:31 2010 : Info: [eap] EAP packet type response id 17 length 6 Thu Oct 21 07:07:31 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns ok Thu Oct 21 07:07:31 2010 : Info: Found Auth-Type = EAP Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authenticate {...} Thu Oct 21 07:07:31 2010 : Info: [eap] Request found, released from the list Thu Oct 21 07:07:31 2010 : Info: [eap] EAP/peap Thu Oct 21 07:07:31 2010 : Info: [eap] processing type peap Thu Oct 21 07:07:31 2010 : Info: [peap] processing EAP-TLS Thu Oct 21 07:07:31 2010 : Info: [peap] Received TLS ACK Thu Oct 21 07:07:31 2010 : Info: [peap] ACK handshake fragment handler Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_verify returned 1 Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_process returned 13 Thu Oct 21 07:07:31 2010 : Info: [peap] EAPTLS_HANDLED Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 224 to 192.168.6.200 port 1645 EAP-Message = 0x011200a519003095523c465026a0644a1f911bd68bb6eb0f73dadb4fb109fb51c4d763a390588cd9986cbaa6da98afa223ef026b4f868885553dfec9df3914fcbc7058a172de70923b8eb61a3bac875c4c99972d704c2afb0d0cb58e55944175ff0e25876eeb32645e95e99b06c228ba3b8ae52d19cbc4fe0e96f1b713413bf17c9196f71d1c28c216238ec98133e178ee02206c2599c3c3bfd257b216030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x088772240c956b7144d41c726612cd30 Thu Oct 21 07:07:31 2010 : Info: Finished request 4. Thu Oct 21 07:07:31 2010 : Debug: Going to the next request Thu Oct 21 07:07:31 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.200 port 1645, id=225, length=475 User-Name = "host/radhost1.testad1.com" Service-Type = Framed-User Framed-MTU = 1500 Called-Station-Id = "00-21-D7-00-51-89" Calling-Station-Id = "00-13-20-38-33-27" EAP-Message = 0x02120140198000000136160301010610000102010024c01c1d5944f3b4e6b7c555a40a53fbcfcc7be85cac17ef6b1ed734a8a63eccfbc7434cb020434f19a2a4b1a9152bdea30e65c50982865d9c4bc0c3fab89e767cb6c46fcdd1251bee57943c56636686c68406d34546eb5f1c714e467bd846071e6db831099dae673d8c085e0154c1df3b1d604bf212e71acb6eda5e9e9d6880fb5a2a8f222cdb28a5c5f27f9b36101ca86d84945fd160fee09d0f3640c5daab5e48ef07915012de02cfc84d6bca88734dbad171346cadbdba19d8030209c34ee24a38a3a7363e521bfa96dc97bf62e0bcbcb5c3a0b011391671da2bea1e924696cd0057cea24193 EAP-Message = 0xcb8b3364c9c3d9fb16a796b36a1757b1013f48e9748c80ec14030100010116030100206ae832f1ba1894c13780532cce092fd91b4f3c2157a0dd977d2424d1bda6ef61 Message-Authenticator = 0x75c2b9adfc0e7ceb6a2a2cb1347b4c8c NAS-Port-Type = Ethernet NAS-Port = 50009 State = 0x088772240c956b7144d41c726612cd30 NAS-IP-Address = 192.168.6.200 Thu Oct 21 07:07:31 2010 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authorize {...} Thu Oct 21 07:07:31 2010 : Info: ++[preprocess] returns ok Thu Oct 21 07:07:31 2010 : Info: ++[chap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns noop Thu Oct 21 07:07:31 2010 : Info: [suffix] No '@' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[suffix] returns noop Thu Oct 21 07:07:31 2010 : Info: [ntdomain] No '\' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[ntdomain] returns noop Thu Oct 21 07:07:31 2010 : Info: [realmpercent] No '%' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[realmpercent] returns noop Thu Oct 21 07:07:31 2010 : Info: [eap] EAP packet type response id 18 length 253 Thu Oct 21 07:07:31 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns ok Thu Oct 21 07:07:31 2010 : Info: Found Auth-Type = EAP Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authenticate {...} Thu Oct 21 07:07:31 2010 : Info: [eap] Request found, released from the list Thu Oct 21 07:07:31 2010 : Info: [eap] EAP/peap Thu Oct 21 07:07:31 2010 : Info: [eap] processing type peap Thu Oct 21 07:07:31 2010 : Info: [peap] processing EAP-TLS Thu Oct 21 07:07:31 2010 : Debug: TLS Length 310 Thu Oct 21 07:07:31 2010 : Info: [peap] Length Included Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_verify returned 11 Thu Oct 21 07:07:31 2010 : Info: [peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange Thu Oct 21 07:07:31 2010 : Info: [peap] TLS_accept: SSLv3 read client key exchange A Thu Oct 21 07:07:31 2010 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] Thu Oct 21 07:07:31 2010 : Info: [peap] <<< TLS 1.0 Handshake [length 0010], Finished Thu Oct 21 07:07:31 2010 : Info: [peap] TLS_accept: SSLv3 read finished A Thu Oct 21 07:07:31 2010 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] Thu Oct 21 07:07:31 2010 : Info: [peap] TLS_accept: SSLv3 write change cipher spec A Thu Oct 21 07:07:31 2010 : Info: [peap] >>> TLS 1.0 Handshake [length 0010], Finished Thu Oct 21 07:07:31 2010 : Info: [peap] TLS_accept: SSLv3 write finished A Thu Oct 21 07:07:31 2010 : Info: [peap] TLS_accept: SSLv3 flush data Thu Oct 21 07:07:31 2010 : Info: [peap] (other): SSL negotiation finished successfully Thu Oct 21 07:07:31 2010 : Debug: SSL Connection Established Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_process returned 13 Thu Oct 21 07:07:31 2010 : Info: [peap] EAPTLS_HANDLED Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 225 to 192.168.6.200 port 1645 EAP-Message = 0x0113003119001403010001011603010020a972be9f46c7fc7dbc05a89074ef41f9e841d3da02a8ec66aac3f039e9ab5251 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x088772240d946b7144d41c726612cd30 Thu Oct 21 07:07:31 2010 : Info: Finished request 5. Thu Oct 21 07:07:31 2010 : Debug: Going to the next request Thu Oct 21 07:07:31 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.200 port 1645, id=226, length=159 User-Name = "host/radhost1.testad1.com" Service-Type = Framed-User Framed-MTU = 1500 Called-Station-Id = "00-21-D7-00-51-89" Calling-Station-Id = "00-13-20-38-33-27" EAP-Message = 0x021300061900 Message-Authenticator = 0xd0d1f2cc9472c1283c73c47171954f69 NAS-Port-Type = Ethernet NAS-Port = 50009 State = 0x088772240d946b7144d41c726612cd30 NAS-IP-Address = 192.168.6.200 Thu Oct 21 07:07:31 2010 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authorize {...} Thu Oct 21 07:07:31 2010 : Info: ++[preprocess] returns ok Thu Oct 21 07:07:31 2010 : Info: ++[chap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns noop Thu Oct 21 07:07:31 2010 : Info: [suffix] No '@' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[suffix] returns noop Thu Oct 21 07:07:31 2010 : Info: [ntdomain] No '\' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[ntdomain] returns noop Thu Oct 21 07:07:31 2010 : Info: [realmpercent] No '%' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[realmpercent] returns noop Thu Oct 21 07:07:31 2010 : Info: [eap] EAP packet type response id 19 length 6 Thu Oct 21 07:07:31 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns ok Thu Oct 21 07:07:31 2010 : Info: Found Auth-Type = EAP Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authenticate {...} Thu Oct 21 07:07:31 2010 : Info: [eap] Request found, released from the list Thu Oct 21 07:07:31 2010 : Info: [eap] EAP/peap Thu Oct 21 07:07:31 2010 : Info: [eap] processing type peap Thu Oct 21 07:07:31 2010 : Info: [peap] processing EAP-TLS Thu Oct 21 07:07:31 2010 : Info: [peap] Received TLS ACK Thu Oct 21 07:07:31 2010 : Info: [peap] ACK handshake is finished Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_verify returned 3 Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_process returned 3 Thu Oct 21 07:07:31 2010 : Info: [peap] EAPTLS_SUCCESS Thu Oct 21 07:07:31 2010 : Info: [peap] Session established. Decoding tunneled attributes. Thu Oct 21 07:07:31 2010 : Info: [peap] Peap state TUNNEL ESTABLISHED Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 226 to 192.168.6.200 port 1645 EAP-Message = 0x0114002019001703010015a866a2ffa985108ce0b4a2f11634823687305781fc Message-Authenticator = 0x00000000000000000000000000000000 State = 0x088772240e936b7144d41c726612cd30 Thu Oct 21 07:07:31 2010 : Info: Finished request 6. Thu Oct 21 07:07:31 2010 : Debug: Going to the next request Thu Oct 21 07:07:31 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.200 port 1645, id=227, length=206 User-Name = "host/radhost1.testad1.com" Service-Type = Framed-User Framed-MTU = 1500 Called-Station-Id = "00-21-D7-00-51-89" Calling-Station-Id = "00-13-20-38-33-27" EAP-Message = 0x021400351900170301002a7cdbb920040741e6050ad3b16b4d61045999a5c6f6c59d7fbdb3d47165ca495216cf0c9e5f1d840ababb Message-Authenticator = 0xf0c68fdc3bf236e016d0b4af01ad6304 NAS-Port-Type = Ethernet NAS-Port = 50009 State = 0x088772240e936b7144d41c726612cd30 NAS-IP-Address = 192.168.6.200 Thu Oct 21 07:07:31 2010 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authorize {...} Thu Oct 21 07:07:31 2010 : Info: ++[preprocess] returns ok Thu Oct 21 07:07:31 2010 : Info: ++[chap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns noop Thu Oct 21 07:07:31 2010 : Info: [suffix] No '@' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[suffix] returns noop Thu Oct 21 07:07:31 2010 : Info: [ntdomain] No '\' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[ntdomain] returns noop Thu Oct 21 07:07:31 2010 : Info: [realmpercent] No '%' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[realmpercent] returns noop Thu Oct 21 07:07:31 2010 : Info: [eap] EAP packet type response id 20 length 53 Thu Oct 21 07:07:31 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns ok Thu Oct 21 07:07:31 2010 : Info: Found Auth-Type = EAP Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authenticate {...} Thu Oct 21 07:07:31 2010 : Info: [eap] Request found, released from the list Thu Oct 21 07:07:31 2010 : Info: [eap] EAP/peap Thu Oct 21 07:07:31 2010 : Info: [eap] processing type peap Thu Oct 21 07:07:31 2010 : Info: [peap] processing EAP-TLS Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_verify returned 7 Thu Oct 21 07:07:31 2010 : Info: [peap] Done initial handshake Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_process returned 7 Thu Oct 21 07:07:31 2010 : Info: [peap] EAPTLS_OK Thu Oct 21 07:07:31 2010 : Info: [peap] Session established. Decoding tunneled attributes. Thu Oct 21 07:07:31 2010 : Info: [peap] Peap state WAITING FOR INNER IDENTITY Thu Oct 21 07:07:31 2010 : Info: [peap] Identity - host/radhost1.testad1.com Thu Oct 21 07:07:31 2010 : Info: [peap] Got inner identity 'host/radhost1.testad1.com' Thu Oct 21 07:07:31 2010 : Info: [peap] Setting default EAP type for tunneled EAP session. Thu Oct 21 07:07:31 2010 : Info: [peap] Got tunneled request EAP-Message = 0x0214001e01686f73742f726164686f7374312e746573746164312e636f6d server { Thu Oct 21 07:07:31 2010 : Debug: PEAP: Setting User-Name to host/radhost1.testad1.com Sending tunneled request EAP-Message = 0x0214001e01686f73742f726164686f7374312e746573746164312e636f6d FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "host/radhost1.testad1.com" server inner-tunnel { Thu Oct 21 07:07:31 2010 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Thu Oct 21 07:07:31 2010 : Info: +- entering group authorize {...} Thu Oct 21 07:07:31 2010 : Info: ++[chap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[unix] returns notfound Thu Oct 21 07:07:31 2010 : Info: [suffix] No '@' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[suffix] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[control] returns noop Thu Oct 21 07:07:31 2010 : Info: [eap] EAP packet type response id 20 length 30 Thu Oct 21 07:07:31 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns updated Thu Oct 21 07:07:31 2010 : Info: ++[files] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[expiration] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[logintime] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[pap] returns noop Thu Oct 21 07:07:31 2010 : Info: Found Auth-Type = EAP Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Thu Oct 21 07:07:31 2010 : Info: +- entering group authenticate {...} Thu Oct 21 07:07:31 2010 : Info: [eap] EAP Identity Thu Oct 21 07:07:31 2010 : Info: [eap] processing type mschapv2 Thu Oct 21 07:07:31 2010 : Debug: rlm_eap_mschapv2: Issuing Challenge Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns handled } # server inner-tunnel Thu Oct 21 07:07:31 2010 : Info: [peap] Got tunneled reply code 11 EAP-Message = 0x011500331a0115002e103155d66f10c66f2fe4fd3e8f4d817a00686f73742f726164686f7374312e746573746164312e636f6d Message-Authenticator = 0x00000000000000000000000000000000 State = 0x68e1b2a268f4a8d71d330c99073c1f9c Thu Oct 21 07:07:31 2010 : Info: [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x011500331a0115002e103155d66f10c66f2fe4fd3e8f4d817a00686f73742f726164686f7374312e746573746164312e636f6d Message-Authenticator = 0x00000000000000000000000000000000 State = 0x68e1b2a268f4a8d71d330c99073c1f9c Thu Oct 21 07:07:31 2010 : Info: [peap] Got tunneled Access-Challenge PEAP tunnel data out 0000: 1a 01 15 00 2e 10 31 55 d6 6f 10 c6 6f 2f e4 fd PEAP tunnel data out 0010: 3e 8f 4d 81 7a 00 68 6f 73 74 2f 72 61 64 68 6f PEAP tunnel data out 0020: 73 74 31 2e 74 65 73 74 61 64 31 2e 63 6f 6d Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 227 to 192.168.6.200 port 1645 EAP-Message = 0x0115004a1900170301003f9897a2c1d4c46c17d1f0ae98e88148e78918b231f8fe0340fbea733ec17ae2a3063a6e360d57678ba01372e88cfa70d46a5f89255c4185a680f261d2d4cf68 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x088772240f926b7144d41c726612cd30 Thu Oct 21 07:07:31 2010 : Info: Finished request 7. Thu Oct 21 07:07:31 2010 : Debug: Going to the next request Thu Oct 21 07:07:31 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.200 port 1645, id=228, length=260 User-Name = "host/radhost1.testad1.com" Service-Type = Framed-User Framed-MTU = 1500 Called-Station-Id = "00-21-D7-00-51-89" Calling-Station-Id = "00-13-20-38-33-27" EAP-Message = 0x0215006b190017030100603534cc1e596e6cf2151f617ef3322b43641e5d92c9518cc03fe1dac0a660dfb8b1f5f2b4e5c6ef5aeab16acafde0e4e59822f9b95c4ae9330e571071eca8b240376eb9de4bdc0cfb6372f28546741725aa36934a502de5d9da8658e8892357b7 Message-Authenticator = 0xa7202f48277ea32fa409a758dae5a5a9 NAS-Port-Type = Ethernet NAS-Port = 50009 State = 0x088772240f926b7144d41c726612cd30 NAS-IP-Address = 192.168.6.200 Thu Oct 21 07:07:31 2010 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authorize {...} Thu Oct 21 07:07:31 2010 : Info: ++[preprocess] returns ok Thu Oct 21 07:07:31 2010 : Info: ++[chap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns noop Thu Oct 21 07:07:31 2010 : Info: [suffix] No '@' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[suffix] returns noop Thu Oct 21 07:07:31 2010 : Info: [ntdomain] No '\' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[ntdomain] returns noop Thu Oct 21 07:07:31 2010 : Info: [realmpercent] No '%' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[realmpercent] returns noop Thu Oct 21 07:07:31 2010 : Info: [eap] EAP packet type response id 21 length 107 Thu Oct 21 07:07:31 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns ok Thu Oct 21 07:07:31 2010 : Info: Found Auth-Type = EAP Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authenticate {...} Thu Oct 21 07:07:31 2010 : Info: [eap] Request found, released from the list Thu Oct 21 07:07:31 2010 : Info: [eap] EAP/peap Thu Oct 21 07:07:31 2010 : Info: [eap] processing type peap Thu Oct 21 07:07:31 2010 : Info: [peap] processing EAP-TLS Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_verify returned 7 Thu Oct 21 07:07:31 2010 : Info: [peap] Done initial handshake Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_process returned 7 Thu Oct 21 07:07:31 2010 : Info: [peap] EAPTLS_OK Thu Oct 21 07:07:31 2010 : Info: [peap] Session established. Decoding tunneled attributes. Thu Oct 21 07:07:31 2010 : Info: [peap] Peap state phase2 Thu Oct 21 07:07:31 2010 : Info: [peap] EAP type mschapv2 Thu Oct 21 07:07:31 2010 : Info: [peap] Got tunneled request EAP-Message = 0x021500541a0215004f318b71d0f61aa55185120858c3b3c5011f0000000000000000de17ddcd19c380e11949ffbd7e208a686bacc1afd9f50b9400686f73742f726164686f7374312e746573746164312e636f6d server { Thu Oct 21 07:07:31 2010 : Debug: PEAP: Setting User-Name to host/radhost1.testad1.com Sending tunneled request EAP-Message = 0x021500541a0215004f318b71d0f61aa55185120858c3b3c5011f0000000000000000de17ddcd19c380e11949ffbd7e208a686bacc1afd9f50b9400686f73742f726164686f7374312e746573746164312e636f6d FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "host/radhost1.testad1.com" State = 0x68e1b2a268f4a8d71d330c99073c1f9c server inner-tunnel { Thu Oct 21 07:07:31 2010 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Thu Oct 21 07:07:31 2010 : Info: +- entering group authorize {...} Thu Oct 21 07:07:31 2010 : Info: ++[chap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[unix] returns notfound Thu Oct 21 07:07:31 2010 : Info: [suffix] No '@' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[suffix] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[control] returns noop Thu Oct 21 07:07:31 2010 : Info: [eap] EAP packet type response id 21 length 84 Thu Oct 21 07:07:31 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns updated Thu Oct 21 07:07:31 2010 : Info: ++[files] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[expiration] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[logintime] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[pap] returns noop Thu Oct 21 07:07:31 2010 : Info: Found Auth-Type = EAP Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Thu Oct 21 07:07:31 2010 : Info: +- entering group authenticate {...} Thu Oct 21 07:07:31 2010 : Info: [eap] Request found, released from the list Thu Oct 21 07:07:31 2010 : Info: [eap] EAP/mschapv2 Thu Oct 21 07:07:31 2010 : Info: [eap] processing type mschapv2 Thu Oct 21 07:07:31 2010 : Info: [mschapv2] # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Thu Oct 21 07:07:31 2010 : Info: [mschapv2] +- entering group MS-CHAP {...} Thu Oct 21 07:07:31 2010 : Info: [mschap] No Cleartext-Password configured. Cannot create LM-Password. Thu Oct 21 07:07:31 2010 : Info: [mschap] No Cleartext-Password configured. Cannot create NT-Password. Thu Oct 21 07:07:31 2010 : Info: [mschap] Creating challenge hash with username: host/radhost1.testad1.com Thu Oct 21 07:07:31 2010 : Info: [mschap] Told to do MS-CHAPv2 for host/radhost1.testad1.com with NT-Password Thu Oct 21 07:07:31 2010 : Info: [mschap] FAILED: No NT/LM-Password. Cannot perform authentication. Thu Oct 21 07:07:31 2010 : Info: [mschap] FAILED: MS-CHAP2-Response is incorrect Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns reject Thu Oct 21 07:07:31 2010 : Info: [eap] Freeing handler Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns reject Thu Oct 21 07:07:31 2010 : Info: Failed to authenticate the user. } # server inner-tunnel Thu Oct 21 07:07:31 2010 : Info: [peap] Got tunneled reply code 3 MS-CHAP-Error = "\025E=691 R=1" EAP-Message = 0x04150004 Message-Authenticator = 0x00000000000000000000000000000000 Thu Oct 21 07:07:31 2010 : Info: [peap] Got tunneled reply RADIUS code 3 MS-CHAP-Error = "\025E=691 R=1" EAP-Message = 0x04150004 Message-Authenticator = 0x00000000000000000000000000000000 Thu Oct 21 07:07:31 2010 : Info: [peap] Tunneled authentication was rejected. Thu Oct 21 07:07:31 2010 : Info: [peap] FAILURE Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns handled Sending Access-Challenge of id 228 to 192.168.6.200 port 1645 EAP-Message = 0x011600261900170301001b5040df84e710c1c864d45c0dc2abc4983d5548e9312156bc1885a7 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0887722400916b7144d41c726612cd30 Thu Oct 21 07:07:31 2010 : Info: Finished request 8. Thu Oct 21 07:07:31 2010 : Debug: Going to the next request Thu Oct 21 07:07:31 2010 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.6.200 port 1645, id=229, length=191 User-Name = "host/radhost1.testad1.com" Service-Type = Framed-User Framed-MTU = 1500 Called-Station-Id = "00-21-D7-00-51-89" Calling-Station-Id = "00-13-20-38-33-27" EAP-Message = 0x021600261900170301001b1727baa4b50893a0183eaa586ec6777c5adf54d491acaa3898225e Message-Authenticator = 0x4d46e78530c4b35e900314c21bffc0f9 NAS-Port-Type = Ethernet NAS-Port = 50009 State = 0x0887722400916b7144d41c726612cd30 NAS-IP-Address = 192.168.6.200 Thu Oct 21 07:07:31 2010 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authorize {...} Thu Oct 21 07:07:31 2010 : Info: ++[preprocess] returns ok Thu Oct 21 07:07:31 2010 : Info: ++[chap] returns noop Thu Oct 21 07:07:31 2010 : Info: ++[mschap] returns noop Thu Oct 21 07:07:31 2010 : Info: [suffix] No '@' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[suffix] returns noop Thu Oct 21 07:07:31 2010 : Info: [ntdomain] No '\' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[ntdomain] returns noop Thu Oct 21 07:07:31 2010 : Info: [realmpercent] No '%' in User-Name = "host/radhost1.testad1.com", skipping NULL due to config. Thu Oct 21 07:07:31 2010 : Info: ++[realmpercent] returns noop Thu Oct 21 07:07:31 2010 : Info: [eap] EAP packet type response id 22 length 38 Thu Oct 21 07:07:31 2010 : Info: [eap] Continuing tunnel setup. Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns ok Thu Oct 21 07:07:31 2010 : Info: Found Auth-Type = EAP Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group authenticate {...} Thu Oct 21 07:07:31 2010 : Info: [eap] Request found, released from the list Thu Oct 21 07:07:31 2010 : Info: [eap] EAP/peap Thu Oct 21 07:07:31 2010 : Info: [eap] processing type peap Thu Oct 21 07:07:31 2010 : Info: [peap] processing EAP-TLS Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_verify returned 7 Thu Oct 21 07:07:31 2010 : Info: [peap] Done initial handshake Thu Oct 21 07:07:31 2010 : Info: [peap] eaptls_process returned 7 Thu Oct 21 07:07:31 2010 : Info: [peap] EAPTLS_OK Thu Oct 21 07:07:31 2010 : Info: [peap] Session established. Decoding tunneled attributes. Thu Oct 21 07:07:31 2010 : Info: [peap] Peap state send tlv failure Thu Oct 21 07:07:31 2010 : Info: [peap] Received EAP-TLV response. Thu Oct 21 07:07:31 2010 : Info: [peap] The users session was previously rejected: returning reject (again.) Thu Oct 21 07:07:31 2010 : Info: [peap] *** This means you need to read the PREVIOUS messages in the debug output Thu Oct 21 07:07:31 2010 : Info: [peap] *** to find out the reason why the user was rejected. Thu Oct 21 07:07:31 2010 : Info: [peap] *** Look for "reject" or "fail". Those earlier messages will tell you. Thu Oct 21 07:07:31 2010 : Info: [peap] *** what went wrong, and how to fix the problem. Thu Oct 21 07:07:31 2010 : Info: [eap] Handler failed in EAP/peap Thu Oct 21 07:07:31 2010 : Info: [eap] Failed in EAP select Thu Oct 21 07:07:31 2010 : Info: ++[eap] returns invalid Thu Oct 21 07:07:31 2010 : Info: Failed to authenticate the user. Thu Oct 21 07:07:31 2010 : Info: Using Post-Auth-Type Reject Thu Oct 21 07:07:31 2010 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Oct 21 07:07:31 2010 : Info: +- entering group REJECT {...} Thu Oct 21 07:07:31 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> host/radhost1.testad1.com Thu Oct 21 07:07:31 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11 Thu Oct 21 07:07:31 2010 : Info: ++[attr_filter.access_reject] returns updated Thu Oct 21 07:07:31 2010 : Info: Delaying reject of request 9 for 1 seconds Thu Oct 21 07:07:31 2010 : Debug: Going to the next request Thu Oct 21 07:07:31 2010 : Debug: Waking up in 0.9 seconds. Thu Oct 21 07:07:32 2010 : Info: Sending delayed reject for request 9 Sending Access-Reject of id 229 to 192.168.6.200 port 1645 EAP-Message = 0x04160004 Message-Authenticator = 0x00000000000000000000000000000000 Thu Oct 21 07:07:32 2010 : Debug: Waking up in 3.9 seconds. Thu Oct 21 07:07:36 2010 : Info: Cleaning up request 0 ID 220 with timestamp +20 -----LOG END ------ On Wed, Oct 20, 2010 at 11:09 PM, Chidanand Gangur <chidanand.gangur@gmail.com> wrote:
Thanks Phil. I am still not clear.. I just want to proxy the host authentication request to the actual RADIUS server which is Microsoft AD. In such cases what configuration is required on proxy server? Can it be done?
Well I mentioned realm type as IPASS as IPASS type is of format realm/username as mentioned in modules/realm file. Hence forth I will post full logs. Thanks, Chidanand
On Wed, Oct 20, 2010 at 7:47 PM, Phil Mayers <p.mayers@imperial.ac.uk> wrote:
On 20/10/10 12:22, Chidanand Gangur wrote:
Hi,
I have following setup
where windows host is connected to Cisco 2960 which is connected to Microsoft AD via RADIUS proxy
Windows host (XP SP3) -> Cisco 2960 -> freeRADIUS proxy (2.1.10) -> Microsoft AD (2003)
In the above setup user authentication goes fine. I am using PEAP v1 authentication.
I am struggling hard to make host authentication successful.
When the machine boots I see radius Access-Request with User-Name = "host/radhost1.testad1.com" which qualifies to IPASS type realm and searches for realm as "host" and things do not work.
No - it's not an IPASS realm. You need to disable the IPASS module.
host/machine.domain.com
corresponds to:
DOMAIN\machine$
i.e. the machine account.
The "mschap" module can expand this, for example if you have the "ntlm_auth" helper to authenticate MS-CHAP against a windows domain using samba as a helper:
ntlm_auth = "... --username=%{mschap:User-Name} ..."
...will do the right thing.
Please point me to links/docs or give me pointer where/how to start.
Post the full debug output, not an edited version.
Wed Oct 20 07:27:48 2010 : Info: [eap] EAP Identity Wed Oct 20 07:27:48 2010 : Info: [eap] processing type md5 Wed Oct 20 07:27:48 2010 : Debug: rlm_eap_md5: Issuing Challenge
This is EAP-MD5. You have not configured your windows client correctly. Configure it correctly for PEAP/MS-CHAP. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-- Chidanand Gangur Pune.
-- Chidanand Gangur Pune.