
Fri Sep  4 17:52:56 2009 : Info: FreeRADIUS Version 2.0.4, for host i486-pc-linux-gnu, built on Sep  3 2009 at 21:54:46
Fri Sep  4 17:52:56 2009 : Info: Copyright (C) 1999-2008 The FreeRADIUS server project and contributors.
Fri Sep  4 17:52:56 2009 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Fri Sep  4 17:52:56 2009 : Info: PARTICULAR PURPOSE.
Fri Sep  4 17:52:56 2009 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Fri Sep  4 17:52:56 2009 : Info: GNU General Public License.
Fri Sep  4 17:52:56 2009 : Info: Starting - reading configuration files ...
Fri Sep  4 17:52:56 2009 : Debug: including configuration file /etc/freeradius/radiusd.conf
Fri Sep  4 17:52:56 2009 : Debug: including configuration file /etc/freeradius/proxy.conf
Fri Sep  4 17:52:56 2009 : Debug: including configuration file /etc/freeradius/clients.conf
Fri Sep  4 17:52:56 2009 : Debug: including configuration file /etc/freeradius/snmp.conf
Fri Sep  4 17:52:56 2009 : Debug: including configuration file /etc/freeradius/eap.conf
Fri Sep  4 17:52:56 2009 : Debug: including configuration file /etc/freeradius/policy.conf
Fri Sep  4 17:52:56 2009 : Debug: including files in directory /etc/freeradius/sites-enabled/
Fri Sep  4 17:52:56 2009 : Debug: including configuration file /etc/freeradius/sites-enabled/default
Fri Sep  4 17:52:56 2009 : Debug: including configuration file /etc/freeradius/sites-enabled/inner-tunnel
Fri Sep  4 17:52:56 2009 : Debug: including dictionary file /etc/freeradius/dictionary
Fri Sep  4 17:52:56 2009 : Debug: main {
Fri Sep  4 17:52:56 2009 : Debug:       prefix = "/usr"
Fri Sep  4 17:52:56 2009 : Debug:       localstatedir = "/var"
Fri Sep  4 17:52:56 2009 : Debug:       logdir = "/var/log/freeradius"
Fri Sep  4 17:52:56 2009 : Debug:       libdir = "/usr/lib/freeradius"
Fri Sep  4 17:52:56 2009 : Debug:       radacctdir = "/var/log/freeradius/radacct"
Fri Sep  4 17:52:56 2009 : Debug:       hostname_lookups = no
Fri Sep  4 17:52:56 2009 : Debug:       max_request_time = 30
Fri Sep  4 17:52:56 2009 : Debug:       cleanup_delay = 5
Fri Sep  4 17:52:56 2009 : Debug:       max_requests = 1024
Fri Sep  4 17:52:56 2009 : Debug:       allow_core_dumps = no
Fri Sep  4 17:52:56 2009 : Debug:       pidfile = "/var/run/freeradius/freeradius.pid"
Fri Sep  4 17:52:56 2009 : Debug:       user = "freerad"
Fri Sep  4 17:52:56 2009 : Debug:       group = "freerad"
Fri Sep  4 17:52:56 2009 : Debug:       checkrad = "/usr/sbin/checkrad"
Fri Sep  4 17:52:56 2009 : Debug:       debug_level = 0
Fri Sep  4 17:52:56 2009 : Debug:       proxy_requests = yes
Fri Sep  4 17:52:56 2009 : Debug:  security {
Fri Sep  4 17:52:56 2009 : Debug:       max_attributes = 200
Fri Sep  4 17:52:56 2009 : Debug:       reject_delay = 1
Fri Sep  4 17:52:56 2009 : Debug:       status_server = yes
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug: }
Fri Sep  4 17:52:56 2009 : Debug:  client localhost {
Fri Sep  4 17:52:56 2009 : Debug:       ipaddr = 127.0.0.1
Fri Sep  4 17:52:56 2009 : Debug:       require_message_authenticator = no
Fri Sep  4 17:52:56 2009 : Debug:       secret = "testing123"
Fri Sep  4 17:52:56 2009 : Debug:       nastype = "other"
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug:  client 10.98.243.0/24 {
Fri Sep  4 17:52:56 2009 : Debug:       require_message_authenticator = no
Fri Sep  4 17:52:56 2009 : Debug:       secret = "ciscoDomainAD123"
Fri Sep  4 17:52:56 2009 : Debug:       shortname = "LANDomainADNeydens"
Fri Sep  4 17:52:56 2009 : Debug:       nastype = "cisco"
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug:  client 10.98.239.0/24 {
Fri Sep  4 17:52:56 2009 : Debug:       require_message_authenticator = no
Fri Sep  4 17:52:56 2009 : Debug:       secret = "ciscoDomainAD123"
Fri Sep  4 17:52:56 2009 : Debug:       shortname = "LANDomainADNeydensRC"
Fri Sep  4 17:52:56 2009 : Debug:       nastype = "cisco"
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug:  client 10.103.0.0/21 {
Fri Sep  4 17:52:56 2009 : Debug:       require_message_authenticator = no
Fri Sep  4 17:52:56 2009 : Debug:       secret = "ciscoDomainAD123"
Fri Sep  4 17:52:56 2009 : Debug:       shortname = "LANDomainADNeydensRC"
Fri Sep  4 17:52:56 2009 : Debug:       nastype = "cisco"
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug: radiusd: #### Loading Realms and Home Servers ####
Fri Sep  4 17:52:56 2009 : Debug:  proxy server {
Fri Sep  4 17:52:56 2009 : Debug:       retry_delay = 5
Fri Sep  4 17:52:56 2009 : Debug:       retry_count = 3
Fri Sep  4 17:52:56 2009 : Debug:       default_fallback = no
Fri Sep  4 17:52:56 2009 : Debug:       dead_time = 120
Fri Sep  4 17:52:56 2009 : Debug:       wake_all_if_all_dead = no
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug:  home_server localhost {
Fri Sep  4 17:52:56 2009 : Debug:       ipaddr = 127.0.0.1
Fri Sep  4 17:52:56 2009 : Debug:       port = 1812
Fri Sep  4 17:52:56 2009 : Debug:       type = "auth"
Fri Sep  4 17:52:56 2009 : Debug:       secret = "testing123"
Fri Sep  4 17:52:56 2009 : Debug:       response_window = 20
Fri Sep  4 17:52:56 2009 : Debug:       max_outstanding = 65536
Fri Sep  4 17:52:56 2009 : Debug:       zombie_period = 40
Fri Sep  4 17:52:56 2009 : Debug:       status_check = "status-server"
Fri Sep  4 17:52:56 2009 : Debug:       ping_check = "none"
Fri Sep  4 17:52:56 2009 : Debug:       ping_interval = 30
Fri Sep  4 17:52:56 2009 : Debug:       check_interval = 30
Fri Sep  4 17:52:56 2009 : Debug:       num_answers_to_alive = 3
Fri Sep  4 17:52:56 2009 : Debug:       num_pings_to_alive = 3
Fri Sep  4 17:52:56 2009 : Debug:       revive_interval = 120
Fri Sep  4 17:52:56 2009 : Debug:       status_check_timeout = 4
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug:  home_server_pool my_auth_failover {
Fri Sep  4 17:52:56 2009 : Debug:       type = fail-over
Fri Sep  4 17:52:56 2009 : Debug:       home_server = localhost
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug:  realm example.com {
Fri Sep  4 17:52:56 2009 : Debug:       auth_pool = my_auth_failover
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug:  realm LOCAL {
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug: radiusd: #### Instantiating modules ####
Fri Sep  4 17:52:56 2009 : Debug:  instantiate {
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_exec, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_exec
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating exec
Fri Sep  4 17:52:56 2009 : Debug:   exec {
Fri Sep  4 17:52:56 2009 : Debug:       wait = yes
Fri Sep  4 17:52:56 2009 : Debug:       input_pairs = "request"
Fri Sep  4 17:52:56 2009 : Debug:       shell_escape = yes
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_expr, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_expr
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating expr
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_expiration, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_expiration
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating expiration
Fri Sep  4 17:52:56 2009 : Debug:   expiration {
Fri Sep  4 17:52:56 2009 : Debug:       reply-message = "Password Has Expired  "
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_logintime, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_logintime
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating logintime
Fri Sep  4 17:52:56 2009 : Debug:   logintime {
Fri Sep  4 17:52:56 2009 : Debug:       reply-message = "You are calling outside your allowed timespan  "
Fri Sep  4 17:52:56 2009 : Debug:       minimum-timeout = 60
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug: radiusd: #### Loading Virtual Servers ####
Fri Sep  4 17:52:56 2009 : Debug: server inner-tunnel {
Fri Sep  4 17:52:56 2009 : Debug:  modules {
Fri Sep  4 17:52:56 2009 : Debug:  Module: Checking authenticate {...} for more modules to load
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_pap, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_pap
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating pap
Fri Sep  4 17:52:56 2009 : Debug:   pap {
Fri Sep  4 17:52:56 2009 : Debug:       encryption_scheme = "auto"
Fri Sep  4 17:52:56 2009 : Debug:       auto_header = no
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_chap, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_chap
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating chap
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_mschap, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_mschap
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating mschap
Fri Sep  4 17:52:56 2009 : Debug:   mschap {
Fri Sep  4 17:52:56 2009 : Debug:       use_mppe = yes
Fri Sep  4 17:52:56 2009 : Debug:       require_encryption = no
Fri Sep  4 17:52:56 2009 : Debug:       require_strong = yes
Fri Sep  4 17:52:56 2009 : Debug:       with_ntDomainAD_hack = yes
Fri Sep  4 17:52:56 2009 : Debug:       ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key --username=%{mschap:User-Name:-None} --DomainAD=%{mschap:NT-DomainAD:-DomainAD} --challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}"
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_unix, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_unix
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating unix
Fri Sep  4 17:52:56 2009 : Debug:   unix {
Fri Sep  4 17:52:56 2009 : Debug:       radwtmp = "/var/log/freeradius/radwtmp"
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_eap, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_eap
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating eap
Fri Sep  4 17:52:56 2009 : Debug:   eap {
Fri Sep  4 17:52:56 2009 : Debug:       default_eap_type = "peap"
Fri Sep  4 17:52:56 2009 : Debug:       timer_expire = 60
Fri Sep  4 17:52:56 2009 : Debug:       ignore_unknown_eap_types = no
Fri Sep  4 17:52:56 2009 : Debug:       cisco_accounting_username_bug = no
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to sub-module rlm_eap_md5
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating eap-md5
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to sub-module rlm_eap_leap
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating eap-leap
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to sub-module rlm_eap_gtc
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating eap-gtc
Fri Sep  4 17:52:56 2009 : Debug:    gtc {
Fri Sep  4 17:52:56 2009 : Debug:       challenge = "Password: "
Fri Sep  4 17:52:56 2009 : Debug:       auth_type = "PAP"
Fri Sep  4 17:52:56 2009 : Debug:    }
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to sub-module rlm_eap_tls
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating eap-tls
Fri Sep  4 17:52:56 2009 : Debug:    tls {
Fri Sep  4 17:52:56 2009 : Debug:       rsa_key_exchange = no
Fri Sep  4 17:52:56 2009 : Debug:       dh_key_exchange = yes
Fri Sep  4 17:52:56 2009 : Debug:       rsa_key_length = 512
Fri Sep  4 17:52:56 2009 : Debug:       dh_key_length = 512
Fri Sep  4 17:52:56 2009 : Debug:       verify_depth = 0
Fri Sep  4 17:52:56 2009 : Debug:       pem_file_type = yes
Fri Sep  4 17:52:56 2009 : Debug:       private_key_file = "/etc/freeradius/certs/server.pem"
Fri Sep  4 17:52:56 2009 : Debug:       certificate_file = "/etc/freeradius/certs/server.pem"
Fri Sep  4 17:52:56 2009 : Debug:       CA_file = "/etc/freeradius/certs/ca.pem"
Fri Sep  4 17:52:56 2009 : Debug:       private_key_password = "ADFknadfidfi4r7akAgf083249wT"
Fri Sep  4 17:52:56 2009 : Debug:       dh_file = "/etc/freeradius/certs/dh"
Fri Sep  4 17:52:56 2009 : Debug:       random_file = "/etc/freeradius/certs/random"
Fri Sep  4 17:52:56 2009 : Debug:       fragment_size = 1024
Fri Sep  4 17:52:56 2009 : Debug:       include_length = yes
Fri Sep  4 17:52:56 2009 : Debug:       check_crl = no
Fri Sep  4 17:52:56 2009 : Debug:       cipher_list = "DEFAULT"
Fri Sep  4 17:52:56 2009 : Debug:       make_cert_command = "/etc/freeradius/certs/bootstrap"
Fri Sep  4 17:52:56 2009 : Debug:    }
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to sub-module rlm_eap_ttls
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating eap-ttls
Fri Sep  4 17:52:56 2009 : Debug:    ttls {
Fri Sep  4 17:52:56 2009 : Debug:       default_eap_type = "md5"
Fri Sep  4 17:52:56 2009 : Debug:       copy_request_to_tunnel = no
Fri Sep  4 17:52:56 2009 : Debug:       use_tunneled_reply = no
Fri Sep  4 17:52:56 2009 : Debug:       virtual_server = "inner-tunnel"
Fri Sep  4 17:52:56 2009 : Debug:    }
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to sub-module rlm_eap_peap
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating eap-peap
Fri Sep  4 17:52:56 2009 : Debug:    peap {
Fri Sep  4 17:52:56 2009 : Debug:       default_eap_type = "mschapv2"
Fri Sep  4 17:52:56 2009 : Debug:       copy_request_to_tunnel = no
Fri Sep  4 17:52:56 2009 : Debug:       use_tunneled_reply = no
Fri Sep  4 17:52:56 2009 : Debug:       proxy_tunneled_request_as_eap = yes
Fri Sep  4 17:52:56 2009 : Debug:       virtual_server = "inner-tunnel"
Fri Sep  4 17:52:56 2009 : Debug:    }
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to sub-module rlm_eap_mschapv2
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating eap-mschapv2
Fri Sep  4 17:52:56 2009 : Debug:    mschapv2 {
Fri Sep  4 17:52:56 2009 : Debug:       with_ntDomainAD_hack = no
Fri Sep  4 17:52:56 2009 : Debug:    }
Fri Sep  4 17:52:56 2009 : Debug:  Module: Checking authorize {...} for more modules to load
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_realm, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_realm
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating suffix
Fri Sep  4 17:52:56 2009 : Debug:   realm suffix {
Fri Sep  4 17:52:56 2009 : Debug:       format = "suffix"
Fri Sep  4 17:52:56 2009 : Debug:       delimiter = "@"
Fri Sep  4 17:52:56 2009 : Debug:       ignore_default = no
Fri Sep  4 17:52:56 2009 : Debug:       ignore_null = no
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_files, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_files
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating files
Fri Sep  4 17:52:56 2009 : Debug:   files {
Fri Sep  4 17:52:56 2009 : Debug:       usersfile = "/etc/freeradius/users"
Fri Sep  4 17:52:56 2009 : Debug:       acctusersfile = "/etc/freeradius/acct_users"
Fri Sep  4 17:52:56 2009 : Debug:       preproxy_usersfile = "/etc/freeradius/preproxy_users"
Fri Sep  4 17:52:56 2009 : Debug:       compat = "no"
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:  Module: Checking session {...} for more modules to load
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_radutmp, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_radutmp
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating radutmp
Fri Sep  4 17:52:56 2009 : Debug:   radutmp {
Fri Sep  4 17:52:56 2009 : Debug:       filename = "/var/log/freeradius/radutmp"
Fri Sep  4 17:52:56 2009 : Debug:       username = "%{User-Name}"
Fri Sep  4 17:52:56 2009 : Debug:       case_sensitive = yes
Fri Sep  4 17:52:56 2009 : Debug:       check_with_nas = yes
Fri Sep  4 17:52:56 2009 : Debug:       perm = 384
Fri Sep  4 17:52:56 2009 : Debug:       callerid = yes
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:  Module: Checking post-proxy {...} for more modules to load
Fri Sep  4 17:52:56 2009 : Debug:  Module: Checking post-auth {...} for more modules to load
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_attr_filter, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_attr_filter
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating attr_filter.access_reject
Fri Sep  4 17:52:56 2009 : Debug:   attr_filter attr_filter.access_reject {
Fri Sep  4 17:52:56 2009 : Debug:       attrsfile = "/etc/freeradius/attrs.access_reject"
Fri Sep  4 17:52:56 2009 : Debug:       key = "%{User-Name}"
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug: }
Fri Sep  4 17:52:56 2009 : Debug: server {
Fri Sep  4 17:52:56 2009 : Debug:  modules {
Fri Sep  4 17:52:56 2009 : Debug:  Module: Checking authenticate {...} for more modules to load
Fri Sep  4 17:52:56 2009 : Debug:  Module: Checking authorize {...} for more modules to load
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_preprocess, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_preprocess
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating preprocess
Fri Sep  4 17:52:56 2009 : Debug:   preprocess {
Fri Sep  4 17:52:56 2009 : Debug:       huntgroups = "/etc/freeradius/huntgroups"
Fri Sep  4 17:52:56 2009 : Debug:       hints = "/etc/freeradius/hints"
Fri Sep  4 17:52:56 2009 : Debug:       with_ascend_hack = no
Fri Sep  4 17:52:56 2009 : Debug:       ascend_channels_per_line = 23
Fri Sep  4 17:52:56 2009 : Debug:       with_ntDomainAD_hack = no
Fri Sep  4 17:52:56 2009 : Debug:       with_specialix_jetstream_hack = no
Fri Sep  4 17:52:56 2009 : Debug:       with_cisco_vsa_hack = no
Fri Sep  4 17:52:56 2009 : Debug:       with_alvarion_vsa_hack = no
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:  Module: Checking preacct {...} for more modules to load
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_acct_unique, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_acct_unique
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating acct_unique
Fri Sep  4 17:52:56 2009 : Debug:   acct_unique {
Fri Sep  4 17:52:56 2009 : Debug:       key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:  Module: Checking accounting {...} for more modules to load
Fri Sep  4 17:52:56 2009 : Debug:     (Loaded rlm_detail, checking if it's valid)
Fri Sep  4 17:52:56 2009 : Debug:  Module: Linked to module rlm_detail
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating detail
Fri Sep  4 17:52:56 2009 : Debug:   detail {
Fri Sep  4 17:52:56 2009 : Debug:       detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Fri Sep  4 17:52:56 2009 : Debug:       header = "%t"
Fri Sep  4 17:52:56 2009 : Debug:       detailperm = 384
Fri Sep  4 17:52:56 2009 : Debug:       dirperm = 493
Fri Sep  4 17:52:56 2009 : Debug:       locking = no
Fri Sep  4 17:52:56 2009 : Debug:       log_packet_header = no
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:  Module: Instantiating attr_filter.accounting_response
Fri Sep  4 17:52:56 2009 : Debug:   attr_filter attr_filter.accounting_response {
Fri Sep  4 17:52:56 2009 : Debug:       attrsfile = "/etc/freeradius/attrs.accounting_response"
Fri Sep  4 17:52:56 2009 : Debug:       key = "%{User-Name}"
Fri Sep  4 17:52:56 2009 : Debug:   }
Fri Sep  4 17:52:56 2009 : Debug:  Module: Checking session {...} for more modules to load
Fri Sep  4 17:52:56 2009 : Debug:  Module: Checking post-proxy {...} for more modules to load
Fri Sep  4 17:52:56 2009 : Debug:  Module: Checking post-auth {...} for more modules to load
Fri Sep  4 17:52:56 2009 : Debug:  }
Fri Sep  4 17:52:56 2009 : Debug: }
Fri Sep  4 17:52:56 2009 : Debug: radiusd: #### Opening IP addresses and Ports ####
Fri Sep  4 17:52:56 2009 : Debug: listen {
Fri Sep  4 17:52:56 2009 : Debug:       type = "auth"
Fri Sep  4 17:52:56 2009 : Debug:       ipaddr = *
Fri Sep  4 17:52:56 2009 : Debug:       port = 0
Fri Sep  4 17:52:56 2009 : Debug: }
Fri Sep  4 17:52:56 2009 : Debug: listen {
Fri Sep  4 17:52:56 2009 : Debug:       type = "acct"
Fri Sep  4 17:52:56 2009 : Debug:       ipaddr = *
Fri Sep  4 17:52:56 2009 : Debug:       port = 0
Fri Sep  4 17:52:56 2009 : Debug: }
Fri Sep  4 17:52:56 2009 : Debug: main {
Fri Sep  4 17:52:56 2009 : Debug:       snmp = no
Fri Sep  4 17:52:56 2009 : Debug:       smux_password = ""
Fri Sep  4 17:52:56 2009 : Debug:       snmp_write_access = no
Fri Sep  4 17:52:56 2009 : Debug: }
Fri Sep  4 17:52:56 2009 : Debug: Listening on authentication address * port 1812
Fri Sep  4 17:52:56 2009 : Debug: Listening on accounting address * port 1813
Fri Sep  4 17:52:56 2009 : Debug: Listening on proxy address * port 1814
Fri Sep  4 17:52:56 2009 : Debug: Ready to process requests.
rad_recv: Access-Request packet from host 10.98.243.81 port 1645, id=241, length=148
        User-Name = "DomainAD\\UserAD"
        Framed-MTU = 1400
        Called-Station-Id = "0023.5e03.1d9c"
        Calling-Station-Id = "001e.6519.44a0"
        Service-Type = Login-User
        Message-Authenticator = 0xedde9fda8afe0a67b7bc85375df4fc36
        EAP-Message = 0x02010010016d66725c74657374637278
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 2753
        NAS-Port-Id = "2753"
        NAS-IP-Address = 10.98.243.81
        NAS-Identifier = "frneyap81"
Fri Sep  4 17:53:12 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0
Fri Sep  4 17:53:12 2009 : Debug: ++[preprocess] returns ok
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 0
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 0
Fri Sep  4 17:53:12 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 0
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 0
Fri Sep  4 17:53:12 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 0
Fri Sep  4 17:53:12 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:12 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 0
Fri Sep  4 17:53:12 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 0
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: EAP packet type response id 1 length 16
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 0
Fri Sep  4 17:53:12 2009 : Debug: ++[eap] returns updated
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling unix (rlm_unix) for request 0
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from unix (rlm_unix) for request 0
Fri Sep  4 17:53:12 2009 : Debug: ++[unix] returns notfound
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 0
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 0
Fri Sep  4 17:53:12 2009 : Debug: ++[files] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling expiration (rlm_expiration) for request 0
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from expiration (rlm_expiration) for request 0
Fri Sep  4 17:53:12 2009 : Debug: ++[expiration] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling logintime (rlm_logintime) for request 0
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from logintime (rlm_logintime) for request 0
Fri Sep  4 17:53:12 2009 : Debug: ++[logintime] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 0
Fri Sep  4 17:53:12 2009 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 0
Fri Sep  4 17:53:12 2009 : Debug: ++[pap] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:12 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:12 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 0
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: EAP Identity
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: processing type tls
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_tls: Initiate
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_tls: Start returned 1
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 0
Fri Sep  4 17:53:12 2009 : Debug: ++[eap] returns handled
Sending Access-Challenge of id 241 to 10.98.243.81 port 1645
        EAP-Message = 0x010200061920
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xca915ae3ca9343b6eecaa1ff7211032e
Fri Sep  4 17:53:12 2009 : Debug: Finished request 0.
Fri Sep  4 17:53:12 2009 : Debug: Going to the next request
Fri Sep  4 17:53:12 2009 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.98.243.81 port 1645, id=242, length=262
        User-Name = "DomainAD\\UserAD"
        Framed-MTU = 1400
        Called-Station-Id = "0023.5e03.1d9c"
        Calling-Station-Id = "001e.6519.44a0"
        Service-Type = Login-User
        Message-Authenticator = 0x430f4ccc8be49d594de389bf668eada1
        EAP-Message = 0x0202007019800000006616030100610100005d03014aa137e8daf1aa62d62170eb860cc39d8ec49d785e41efedfe99a92349e6413a00003600390038003500160013000a00330032002f0007006600050004006300620061001500120009006500640060001400110008000600030100
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 2753
        NAS-Port-Id = "2753"
        State = 0xca915ae3ca9343b6eecaa1ff7211032e
        NAS-IP-Address = 10.98.243.81
        NAS-Identifier = "frneyap81"
Fri Sep  4 17:53:12 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1
Fri Sep  4 17:53:12 2009 : Debug: ++[preprocess] returns ok
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 1
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 1
Fri Sep  4 17:53:12 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 1
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 1
Fri Sep  4 17:53:12 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 1
Fri Sep  4 17:53:12 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:12 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 1
Fri Sep  4 17:53:12 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 1
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: EAP packet type response id 2 length 112
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: Continuing tunnel setup.
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 1
Fri Sep  4 17:53:12 2009 : Debug: ++[eap] returns ok
Fri Sep  4 17:53:12 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:12 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:12 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 1
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: Request found, released from the list
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: EAP/peap
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: processing type peap
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_peap: Authenticate
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_tls: processing TLS
Fri Sep  4 17:53:12 2009 : Debug:   TLS Length 102
Fri Sep  4 17:53:12 2009 : Debug: rlm_eap_tls:  Length Included
Fri Sep  4 17:53:12 2009 : Debug:   eaptls_verify returned 11
Fri Sep  4 17:53:12 2009 : Debug:     (other): before/accept initialization
Fri Sep  4 17:53:12 2009 : Debug:     TLS_accept: before/accept initialization
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0061], ClientHello
Fri Sep  4 17:53:12 2009 : Debug:     TLS_accept: SSLv3 read client hello A
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello
Fri Sep  4 17:53:12 2009 : Debug:     TLS_accept: SSLv3 write server hello A
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake [length 085f], Certificate
Fri Sep  4 17:53:12 2009 : Debug:     TLS_accept: SSLv3 write certificate A
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake [length 018d], ServerKeyExchange
Fri Sep  4 17:53:12 2009 : Debug:     TLS_accept: SSLv3 write key exchange A
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
Fri Sep  4 17:53:12 2009 : Debug:     TLS_accept: SSLv3 write server done A
Fri Sep  4 17:53:12 2009 : Debug:     TLS_accept: SSLv3 flush data
Fri Sep  4 17:53:12 2009 : Debug:     TLS_accept: Need to read more data: SSLv3 read client certificate A
Fri Sep  4 17:53:12 2009 : Debug: In SSL Handshake Phase
Fri Sep  4 17:53:12 2009 : Debug: In SSL Accept mode
Fri Sep  4 17:53:12 2009 : Debug:   eaptls_process returned 13
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_peap: EAPTLS_HANDLED
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 1
Fri Sep  4 17:53:12 2009 : Debug: ++[eap] returns handled
Sending Access-Challenge of id 242 to 10.98.243.81 port 1645
        EAP-Message = 0x0103040019c000000a4e160301004a0200004603014aa137e8ef55e3457657a954bde83f018e1f7cfa217a5838d061413cad5cbf6620b47b045935cab7abc733c4064f836b6ff39548e4daa5510251ccb6d2204b336d003900160301085f0b00085b0008580003aa308203a63082028ea003020102020103300d06092a864886f70d0101040500308192310b3009060355040613024652311530130603550408130c48415554452d5341564f49453110300e060355040713074e455944454e5331163014060355040a130d4d4947524f53204672616e63653125302306092a864886f70d0109011616696e666f726d617469717565406d6967726f732e
        EAP-Message = 0x6672311b30190603550403131266726e65796c696e38352e6d66722e6e6574301e170d3039303930333231333035365a170d3130303930333231333035365a308180310b3009060355040613024652311530130603550408130c48415554452d5341564f494531163014060355040a130d4d4947524f53204672616e6365311b30190603550403131266726e65796c696e38352e6d66722e6e65743125302306092a864886f70d0109011616696e666f726d617469717565406d6967726f732e667230820122300d06092a864886f70d01010105000382010f003082010a0282010100b43f85aeae7b987f21762308841b5316c4f804afe182acb1b51d
        EAP-Message = 0x9d87676dfaba76aa9f7382e6915ee4f335b655a5c2b332fdb8f535ce8c61694b20e82c1eee523415a5ba95efcb8b3cd1ae0383377b6c6fdee1bcb9c9a36a27eea00f22b695ae9dcd5ab4bb5c1f403e37d98e0af4226acd08192defeb9609fcdc37476163e1b962b2368d9a475fd7ac65a9c68e492e37f773b5abb5c1565267278a53f71b21a5e81f4e30c36ffd8e706045b57e461d1ae66886ad74aa5c7315c5a2a62b1ce34477f0d66886458a37bebfa78a80b05d848162a38b62015bf0a02c0e3e9c13f14127c15063f7571182f5bdd376139be6eb8ac3900add6a4c339fedb85ce680c97b0203010001a317301530130603551d25040c300a06082b
        EAP-Message = 0x06010505070301300d06092a864886f70d010104050003820101006737eebdb97d335b98dba87681c61236882bcc4152519e6d96d4064e8c866e40a9abac89faf264243ad436fb6be9f7957e95e74b985f0b5401e38d159767e9e10a01aec93dcab68c3507f2b99c111db476c0b89181454dead4acefd4364e7ad6cedad34aad5d94bdf6d4ae834cd02345c71e2ac8d2738f45c41cd72e98a26efe6ec5d55e5c8aac43610196a3badf3b63e83fe46299c9c4413d3f064464cfeb640c0804ebff3ef58b51bb7a04956bfaf49660e0fcc3e375fd47d7e8ac5b684c06e0ccc642233721ea59029621a0ec82fb37429b4efd3007231011c932d68654e82736
        EAP-Message = 0x1e1802a50cc9d96e88a2d7c0
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xca915ae3cb9243b6eecaa1ff7211032e
Fri Sep  4 17:53:12 2009 : Debug: Finished request 1.
Fri Sep  4 17:53:12 2009 : Debug: Going to the next request
Fri Sep  4 17:53:12 2009 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.98.243.81 port 1645, id=243, length=156
        User-Name = "DomainAD\\UserAD"
        Framed-MTU = 1400
        Called-Station-Id = "0023.5e03.1d9c"
        Calling-Station-Id = "001e.6519.44a0"
        Service-Type = Login-User
        Message-Authenticator = 0x8674f854cb61b3a0ba92e930a5d0c88b
        EAP-Message = 0x020300061900
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 2753
        NAS-Port-Id = "2753"
        State = 0xca915ae3cb9243b6eecaa1ff7211032e
        NAS-IP-Address = 10.98.243.81
        NAS-Identifier = "frneyap81"
Fri Sep  4 17:53:12 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2
Fri Sep  4 17:53:12 2009 : Debug: ++[preprocess] returns ok
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 2
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 2
Fri Sep  4 17:53:12 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 2
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 2
Fri Sep  4 17:53:12 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 2
Fri Sep  4 17:53:12 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:12 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 2
Fri Sep  4 17:53:12 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 2
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: EAP packet type response id 3 length 6
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: Continuing tunnel setup.
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 2
Fri Sep  4 17:53:12 2009 : Debug: ++[eap] returns ok
Fri Sep  4 17:53:12 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:12 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:12 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 2
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: Request found, released from the list
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: EAP/peap
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap: processing type peap
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_peap: Authenticate
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_tls: processing TLS
Fri Sep  4 17:53:12 2009 : Debug: rlm_eap_tls: Received EAP-TLS ACK message
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_tls: ack handshake fragment handler
Fri Sep  4 17:53:12 2009 : Debug:   eaptls_verify returned 1
Fri Sep  4 17:53:12 2009 : Debug:   eaptls_process returned 13
Fri Sep  4 17:53:12 2009 : Debug:   rlm_eap_peap: EAPTLS_HANDLED
Fri Sep  4 17:53:12 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 2
Fri Sep  4 17:53:12 2009 : Debug: ++[eap] returns handled
Sending Access-Challenge of id 243 to 10.98.243.81 port 1645
        EAP-Message = 0x010403fc1940f550614428329e4d2209e385c68c917982590004a8308204a43082038ca00302010202090086c7ae8e4098664d300d06092a864886f70d0101050500308192310b3009060355040613024652311530130603550408130c48415554452d5341564f49453110300e060355040713074e455944454e5331163014060355040a130d4d4947524f53204672616e63653125302306092a864886f70d0109011616696e666f726d617469717565406d6967726f732e6672311b30190603550403131266726e65796c696e38352e6d66722e6e6574301e170d3039303930333231333030305a170d3130303930333231333030305a308192310b30
        EAP-Message = 0x09060355040613024652311530130603550408130c48415554452d5341564f49453110300e060355040713074e455944454e5331163014060355040a130d4d4947524f53204672616e63653125302306092a864886f70d0109011616696e666f726d617469717565406d6967726f732e6672311b30190603550403131266726e65796c696e38352e6d66722e6e657430820122300d06092a864886f70d01010105000382010f003082010a0282010100dd1cde1bbaa86534a76a2bd1aee295e6446e2113434d4d4e5c36a73dd50e8b5048af3be8e040d03a314acf7549953fe77f03a54124b36cfb9ebc485f92e6bdd94612f67f91fea405f59ce703e6
        EAP-Message = 0xb12772c5ab370cc470ccd84db1aedfd4c437eb860dc804bca36edc2e4873058a9e3aed7df35cba51891c6cbf1b4b8d3939034c45e5cadc8c656c63cb0d971ed277ea545200bee9b0ae781796fac26b91bd42c3bda09eab6583843e2f11bd71e225c1b233066b8b7dabba86eb8d0253a4e0bad978b3ff75eb6f521d77f8847146f4f83dc2a94f4d056d420d5624d2d8920a67f4ee432bd0ba7b48c445f573134fe842b9d45fbee4081517a5804cd6bcb9ec51e30203010001a381fa3081f7301d0603551d0e041604149e8217bc6e0ecedc9d2d73b3374a9d5d7f691b653081c70603551d230481bf3081bc80149e8217bc6e0ecedc9d2d73b3374a9d5d
        EAP-Message = 0x7f691b65a18198a48195308192310b3009060355040613024652311530130603550408130c48415554452d5341564f49453110300e060355040713074e455944454e5331163014060355040a130d4d4947524f53204672616e63653125302306092a864886f70d0109011616696e666f726d617469717565406d6967726f732e6672311b30190603550403131266726e65796c696e38352e6d66722e6e657482090086c7ae8e4098664d300c0603551d13040530030101ff300d06092a864886f70d0101050500038201010085ce4aa1ef4d1cef57a18cf872e4a3db0dd76bfccf776205cad975627b54ca3e6d0d75732afdc9fd6ae19a6f6fe26d1c99
        EAP-Message = 0x5cff701fab69728f
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xca915ae3c89543b6eecaa1ff7211032e
Fri Sep  4 17:53:12 2009 : Debug: Finished request 2.
Fri Sep  4 17:53:12 2009 : Debug: Going to the next request
Fri Sep  4 17:53:12 2009 : Debug: Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 10.98.243.81 port 1645, id=244, length=156
        User-Name = "DomainAD\\UserAD"
        Framed-MTU = 1400
        Called-Station-Id = "0023.5e03.1d9c"
        Calling-Station-Id = "001e.6519.44a0"
        Service-Type = Login-User
        Message-Authenticator = 0xdd3e8ad6c3bdcc9ab25dc028c68b4118
        EAP-Message = 0x020400061900
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 2753
        NAS-Port-Id = "2753"
        State = 0xca915ae3c89543b6eecaa1ff7211032e
        NAS-IP-Address = 10.98.243.81
        NAS-Identifier = "frneyap81"
Fri Sep  4 17:53:13 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:13 2009 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 3
Fri Sep  4 17:53:13 2009 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 3
Fri Sep  4 17:53:13 2009 : Debug: ++[preprocess] returns ok
Fri Sep  4 17:53:13 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 3
Fri Sep  4 17:53:13 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 3
Fri Sep  4 17:53:13 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:13 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 3
Fri Sep  4 17:53:13 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 3
Fri Sep  4 17:53:13 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:13 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 3
Fri Sep  4 17:53:13 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:13 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:13 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 3
Fri Sep  4 17:53:13 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:13 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 3
Fri Sep  4 17:53:13 2009 : Debug:   rlm_eap: EAP packet type response id 4 length 6
Fri Sep  4 17:53:13 2009 : Debug:   rlm_eap: Continuing tunnel setup.
Fri Sep  4 17:53:13 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 3
Fri Sep  4 17:53:13 2009 : Debug: ++[eap] returns ok
Fri Sep  4 17:53:13 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:13 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:13 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:13 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 3
Fri Sep  4 17:53:13 2009 : Debug:   rlm_eap: Request found, released from the list
Fri Sep  4 17:53:13 2009 : Debug:   rlm_eap: EAP/peap
Fri Sep  4 17:53:13 2009 : Debug:   rlm_eap: processing type peap
Fri Sep  4 17:53:13 2009 : Debug:   rlm_eap_peap: Authenticate
Fri Sep  4 17:53:13 2009 : Debug:   rlm_eap_tls: processing TLS
Fri Sep  4 17:53:13 2009 : Debug: rlm_eap_tls: Received EAP-TLS ACK message
Fri Sep  4 17:53:13 2009 : Debug:   rlm_eap_tls: ack handshake fragment handler
Fri Sep  4 17:53:13 2009 : Debug:   eaptls_verify returned 1
Fri Sep  4 17:53:13 2009 : Debug:   eaptls_process returned 13
Fri Sep  4 17:53:13 2009 : Debug:   rlm_eap_peap: EAPTLS_HANDLED
Fri Sep  4 17:53:13 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 3
Fri Sep  4 17:53:13 2009 : Debug: ++[eap] returns handled
Sending Access-Challenge of id 244 to 10.98.243.81 port 1645
        EAP-Message = 0x01050268190022b206940b9541e57d67f729fa0caebc0acaad609817438ada119c738834cdd2b138e34dd02156b9de07d6fce587e2bad24926c0bfae0e8f9bec93552e01eca0136a6b5bbe40e5d125ca3bb7a48f9e2957e7e396462c5e1ba601c6862a48f98c1860ba5f0d1f491d5df93d43069d3041bc89c80d4ac12e6687a3b785c584d4589fdefc180fe433ca66efa06e48d9777d7b965c4332ad4e4fc7770c9fad8a3058d1ed7f57b79d706e5c9722fed417c97101399567b703c8deab474d7132b7d2c3cd4b28015822e4160301018d0c0001890040c9cd0f4994190469ad72d1b942d2a8480ac429cc24e04db06eac3c6e92becee0b0324a6cf1
        EAP-Message = 0x1a0686d1f94e19ddfc2b25e5e47ded306237fa0e998487bbb8b6f70001050040b34cd7deacb28bb5915a69d78fb2146f331e8d34d76d7e838848c48dabaa9ec84c70e8143712588cd91836c404afe6d5675f9f2485721daa3818987d18a1207201003efbf03214b796ee356b6b19784084e5a96ca60d2e00bee490704b1d6226fbeb35166d0dce8ab310f34d8795da5ab04e0a6c5726f209a06b0ab801ca56b4d50b396ea1c4651b172e7d053e6e24f3886abac96e0e2ee00048789e237be883de9a8a9aca4610555888d7c753a9b55c2bb9e66dab1b5dc6c5bb25fadb8a396931fc7ce20233bddd72630487ddff31e807a589302801ba5466c11f7230
        EAP-Message = 0xc7486a8d8ab9493a5c9e50a8f31b2576a06fc37880a1259f098516228992b5d104f0f7d64de322f7a69db50783ec9d8175e839543a024e664be814cd043ee688a4a34bdc68d6895b0bf7a5c994ee02c6306f83dcc4f17732428fcff169db657b27b1b4ba5416030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xca915ae3c99443b6eecaa1ff7211032e
Fri Sep  4 17:53:13 2009 : Debug: Finished request 3.
Fri Sep  4 17:53:13 2009 : Debug: Going to the next request
Fri Sep  4 17:53:13 2009 : Debug: Waking up in 4.5 seconds.
rad_recv: Access-Request packet from host 10.98.243.81 port 1645, id=245, length=294
        User-Name = "DomainAD\\UserAD"
        Framed-MTU = 1400
        Called-Station-Id = "0023.5e03.1d9c"
        Calling-Station-Id = "001e.6519.44a0"
        Service-Type = Login-User
        Message-Authenticator = 0x2806f15e4572e456a15ca49b76bfed58
        EAP-Message = 0x020500901980000000861603010046100000420040917c8f374b42406b916b107ac663b90a0f5bc114beecaf4fd28de76ed0899db527897e321982a4acef6cb4316e0ac3c6905330d8eb6e415acf2988872fd22a1d14030100010116030100302dba4c1337e8cebdb2fbd12e8260b0abf13b0d4165ded2e7b1d18a761311cb91c785260546a46e7d7c173dfd4a762ed6
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 2753
        NAS-Port-Id = "2753"
        State = 0xca915ae3c99443b6eecaa1ff7211032e
        NAS-IP-Address = 10.98.243.81
        NAS-Identifier = "frneyap81"
Fri Sep  4 17:53:14 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 4
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 4
Fri Sep  4 17:53:14 2009 : Debug: ++[preprocess] returns ok
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 4
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 4
Fri Sep  4 17:53:14 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 4
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 4
Fri Sep  4 17:53:14 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 4
Fri Sep  4 17:53:14 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:14 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 4
Fri Sep  4 17:53:14 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 4
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: EAP packet type response id 5 length 144
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: Continuing tunnel setup.
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 4
Fri Sep  4 17:53:14 2009 : Debug: ++[eap] returns ok
Fri Sep  4 17:53:14 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:14 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:14 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 4
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: Request found, released from the list
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: EAP/peap
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: processing type peap
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_peap: Authenticate
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_tls: processing TLS
Fri Sep  4 17:53:14 2009 : Debug:   TLS Length 134
Fri Sep  4 17:53:14 2009 : Debug: rlm_eap_tls:  Length Included
Fri Sep  4 17:53:14 2009 : Debug:   eaptls_verify returned 11
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange
Fri Sep  4 17:53:14 2009 : Debug:     TLS_accept: SSLv3 read client key exchange A
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
Fri Sep  4 17:53:14 2009 : Debug:     TLS_accept: SSLv3 read finished A
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
Fri Sep  4 17:53:14 2009 : Debug:     TLS_accept: SSLv3 write change cipher spec A
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
Fri Sep  4 17:53:14 2009 : Debug:     TLS_accept: SSLv3 write finished A
Fri Sep  4 17:53:14 2009 : Debug:     TLS_accept: SSLv3 flush data
Fri Sep  4 17:53:14 2009 : Debug:     (other): SSL negotiation finished successfully
Fri Sep  4 17:53:14 2009 : Debug: SSL Connection Established
Fri Sep  4 17:53:14 2009 : Debug:   eaptls_process returned 13
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_peap: EAPTLS_HANDLED
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 4
Fri Sep  4 17:53:14 2009 : Debug: ++[eap] returns handled
Sending Access-Challenge of id 245 to 10.98.243.81 port 1645
        EAP-Message = 0x010600411900140301000101160301003003bf2b33e81adccd3d85bfa03f1d12bb799b3c5d19d94b1d3466c46496285e5995662a16d799d1550e1b18051d7cda1f
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xca915ae3ce9743b6eecaa1ff7211032e
Fri Sep  4 17:53:14 2009 : Debug: Finished request 4.
Fri Sep  4 17:53:14 2009 : Debug: Going to the next request
Fri Sep  4 17:53:14 2009 : Debug: Waking up in 3.5 seconds.
rad_recv: Access-Request packet from host 10.98.243.81 port 1645, id=246, length=156
        User-Name = "DomainAD\\UserAD"
        Framed-MTU = 1400
        Called-Station-Id = "0023.5e03.1d9c"
        Calling-Station-Id = "001e.6519.44a0"
        Service-Type = Login-User
        Message-Authenticator = 0x069997db4a8ffbd16670f2554f7d59f3
        EAP-Message = 0x020600061900
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 2753
        NAS-Port-Id = "2753"
        State = 0xca915ae3ce9743b6eecaa1ff7211032e
        NAS-IP-Address = 10.98.243.81
        NAS-Identifier = "frneyap81"
Fri Sep  4 17:53:14 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 5
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 5
Fri Sep  4 17:53:14 2009 : Debug: ++[preprocess] returns ok
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 5
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 5
Fri Sep  4 17:53:14 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 5
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 5
Fri Sep  4 17:53:14 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 5
Fri Sep  4 17:53:14 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:14 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 5
Fri Sep  4 17:53:14 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 5
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: EAP packet type response id 6 length 6
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: Continuing tunnel setup.
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 5
Fri Sep  4 17:53:14 2009 : Debug: ++[eap] returns ok
Fri Sep  4 17:53:14 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:14 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:14 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 5
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: Request found, released from the list
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: EAP/peap
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: processing type peap
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_peap: Authenticate
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_tls: processing TLS
Fri Sep  4 17:53:14 2009 : Debug: rlm_eap_tls: Received EAP-TLS ACK message
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_tls: ack handshake is finished
Fri Sep  4 17:53:14 2009 : Debug:   eaptls_verify returned 3
Fri Sep  4 17:53:14 2009 : Debug:   eaptls_process returned 3
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_peap: EAPTLS_SUCCESS
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 5
Fri Sep  4 17:53:14 2009 : Debug: ++[eap] returns handled
Sending Access-Challenge of id 246 to 10.98.243.81 port 1645
        EAP-Message = 0x0107002b190017030100208441215e7906fe928f291639417b48936174dd57393bfda5d30a6c23e72d92eb
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xca915ae3cf9643b6eecaa1ff7211032e
Fri Sep  4 17:53:14 2009 : Debug: Finished request 5.
Fri Sep  4 17:53:14 2009 : Debug: Going to the next request
Fri Sep  4 17:53:14 2009 : Debug: Waking up in 3.5 seconds.
rad_recv: Access-Request packet from host 10.98.243.81 port 1645, id=247, length=246
        User-Name = "DomainAD\\UserAD"
        Framed-MTU = 1400
        Called-Station-Id = "0023.5e03.1d9c"
        Calling-Station-Id = "001e.6519.44a0"
        Service-Type = Login-User
        Message-Authenticator = 0x4092e6306a5de8066862a2fedf591261
        EAP-Message = 0x0207006019001703010020611828975047ead54e60af2bfac4781573d35bf51cd7e36d563c25d230f3eee1170301003057538450058d673b60dc10d8da6516b0492b361c0c91364f81a2d5d1056fc9be55341f8ee2a9cdbd72b62adaa7c3918a
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 2753
        NAS-Port-Id = "2753"
        State = 0xca915ae3cf9643b6eecaa1ff7211032e
        NAS-IP-Address = 10.98.243.81
        NAS-Identifier = "frneyap81"
Fri Sep  4 17:53:14 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[preprocess] returns ok
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 6
Fri Sep  4 17:53:14 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:14 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: EAP packet type response id 7 length 96
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: Continuing tunnel setup.
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[eap] returns ok
Fri Sep  4 17:53:14 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:14 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:14 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: Request found, released from the list
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: EAP/peap
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: processing type peap
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_peap: Authenticate
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_tls: processing TLS
Fri Sep  4 17:53:14 2009 : Debug:   eaptls_verify returned 7
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_tls: Done initial handshake
Fri Sep  4 17:53:14 2009 : Debug:   eaptls_process returned 7
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_peap: EAPTLS_OK
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_peap: Session established.  Decoding tunneled attributes.
  PEAP tunnel data in 0000: 01 6d 66 72 5c 74 65 73 74 63 72 78
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap_peap: Identity - DomainAD\UserAD
  PEAP: Got tunneled EAP-Message
        EAP-Message = 0x02070010016d66725c74657374637278
Fri Sep  4 17:53:14 2009 : Debug:   PEAP: Got tunneled identity of DomainAD\UserAD
Fri Sep  4 17:53:14 2009 : Debug:   PEAP: Setting default EAP type for tunneled EAP session.
Fri Sep  4 17:53:14 2009 : Debug:   PEAP: Setting User-Name to DomainAD\UserAD
  PEAP: Sending tunneled request
        EAP-Message = 0x02070010016d66725c74657374637278
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "DomainAD\\UserAD"
server inner-tunnel {
Fri Sep  4 17:53:14 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling unix (rlm_unix) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from unix (rlm_unix) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[unix] returns notfound
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 6
Fri Sep  4 17:53:14 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:14 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:14 2009 : Debug: ::: FROM 1 TO 1 MAX 2
Fri Sep  4 17:53:14 2009 : Debug: ::: Examining Proxy-To-Realm
Fri Sep  4 17:53:14 2009 : Debug: ::: APPENDING Proxy-To-Realm FROM 0 TO 1
Fri Sep  4 17:53:14 2009 : Debug: ::: TO in 1 out 2
Fri Sep  4 17:53:14 2009 : Debug: ::: to[0] = EAP-Type
Fri Sep  4 17:53:14 2009 : Debug: ::: to[1] = Proxy-To-Realm
Fri Sep  4 17:53:14 2009 : Debug: ++[control] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: EAP packet type response id 7 length 16
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[eap] returns updated
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[files] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling expiration (rlm_expiration) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from expiration (rlm_expiration) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[expiration] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling logintime (rlm_logintime) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from logintime (rlm_logintime) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[logintime] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[pap] returns noop
Fri Sep  4 17:53:14 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:14 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:14 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 6
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: EAP Identity
Fri Sep  4 17:53:14 2009 : Debug:   rlm_eap: processing type mschapv2
Fri Sep  4 17:53:14 2009 : Debug: rlm_eap_mschapv2: Issuing Challenge
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[eap] returns handled
} # server inner-tunnel
  PEAP: Got tunneled reply RADIUS code 11
        EAP-Message = 0x010800251a010800201027ddbc3b911ca32f1eb70dbb5c83e59c6d66725c74657374637278
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9f14021d9f1c1836752cef25051043be
  PEAP: Processing from tunneled session code 0x8312808 11
        EAP-Message = 0x010800251a010800201027ddbc3b911ca32f1eb70dbb5c83e59c6d66725c74657374637278
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9f14021d9f1c1836752cef25051043be
Fri Sep  4 17:53:14 2009 : Debug:   PEAP: Got tunneled Access-Challenge
  PEAP tunnel data out 0000: 1a 01 08 00 20 10 27 dd bc 3b 91 1c a3 2f 1e b7
  PEAP tunnel data out 0010: 0d bb 5c 83 e5 9c 6d 66 72 5c 74 65 73 74 63 72
  PEAP tunnel data out 0020: 78
Fri Sep  4 17:53:14 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 6
Fri Sep  4 17:53:14 2009 : Debug: ++[eap] returns handled
Sending Access-Challenge of id 247 to 10.98.243.81 port 1645
        EAP-Message = 0x0108004b190017030100408687f910d7498bf245ccb7706f5a1bdce8b15ca2ae83d7c6adb77587e42eada39999339683576a8c332b608022eb35f9a0e8174dd01f063f6449f7e8672e0a9f
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xca915ae3cc9943b6eecaa1ff7211032e
Fri Sep  4 17:53:14 2009 : Debug: Finished request 6.
Fri Sep  4 17:53:14 2009 : Debug: Going to the next request
Fri Sep  4 17:53:14 2009 : Debug: Waking up in 3.1 seconds.
rad_recv: Access-Request packet from host 10.98.243.81 port 1645, id=248, length=294
        User-Name = "DomainAD\\UserAD"
        Framed-MTU = 1400
        Called-Station-Id = "0023.5e03.1d9c"
        Calling-Station-Id = "001e.6519.44a0"
        Service-Type = Login-User
        Message-Authenticator = 0x633c5c78072c551f31b36db9a6997752
        EAP-Message = 0x0208009019001703010020f3a55e56f4c062a3187ab10c5e8ad33fb42a9bbc928132a42a4aa5aa3ee13f48170301006066e4f883428bfbc7597627a64a793ec2bccbd4ac12f9f319c1cc4dd1483f8383e627c5ff1760b1bf43969eac7b822db855cd78b4efe5326c2689d027e3027d0a5b598b12e9d93abc04b5ed8269ba0386232a946e6b523084f4a2aa3698571d57
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 2753
        NAS-Port-Id = "2753"
        State = 0xca915ae3cc9943b6eecaa1ff7211032e
        NAS-IP-Address = 10.98.243.81
        NAS-Identifier = "frneyap81"
Fri Sep  4 17:53:15 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[preprocess] returns ok
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 7
Fri Sep  4 17:53:15 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:15 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap: EAP packet type response id 8 length 144
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap: Continuing tunnel setup.
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[eap] returns ok
Fri Sep  4 17:53:15 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:15 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:15 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap: Request found, released from the list
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap: EAP/peap
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap: processing type peap
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap_peap: Authenticate
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap_tls: processing TLS
Fri Sep  4 17:53:15 2009 : Debug:   eaptls_verify returned 7
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap_tls: Done initial handshake
Fri Sep  4 17:53:15 2009 : Debug:   eaptls_process returned 7
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap_peap: EAPTLS_OK
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap_peap: Session established.  Decoding tunneled attributes.
  PEAP tunnel data in 0000: 1a 02 08 00 41 31 30 df e5 f9 6f f2 6b 90 f0 33
  PEAP tunnel data in 0010: df bb 85 b1 fb 33 00 00 00 00 00 00 00 00 3d 7b
  PEAP tunnel data in 0020: 6d 01 f2 18 ee 06 b8 16 d1 1f fb 5b b7 61 16 00
  PEAP tunnel data in 0030: 8c 0c 3b 29 0c 54 00 6d 66 72 5c 74 65 73 74 63
  PEAP tunnel data in 0040: 72 78
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap_peap: EAP type mschapv2
  PEAP: Got tunneled EAP-Message
        EAP-Message = 0x020800461a020800413130dfe5f96ff26b90f033dfbb85b1fb3300000000000000003d7b6d01f218ee06b816d11ffb5bb76116008c0c3b290c54006d66725c74657374637278
Fri Sep  4 17:53:15 2009 : Debug:   PEAP: Setting User-Name to DomainAD\UserAD
  PEAP: Sending tunneled request
        EAP-Message = 0x020800461a020800413130dfe5f96ff26b90f033dfbb85b1fb3300000000000000003d7b6d01f218ee06b816d11ffb5bb76116008c0c3b290c54006d66725c74657374637278
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "DomainAD\\UserAD"
        State = 0x9f14021d9f1c1836752cef25051043be
server inner-tunnel {
Fri Sep  4 17:53:15 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling unix (rlm_unix) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from unix (rlm_unix) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[unix] returns notfound
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 7
Fri Sep  4 17:53:15 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:15 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:15 2009 : Debug: ::: FROM 1 TO 0 MAX 1
Fri Sep  4 17:53:15 2009 : Debug: ::: Examining Proxy-To-Realm
Fri Sep  4 17:53:15 2009 : Debug: ::: APPENDING Proxy-To-Realm FROM 0 TO 0
Fri Sep  4 17:53:15 2009 : Debug: ::: TO in 0 out 1
Fri Sep  4 17:53:15 2009 : Debug: ::: to[0] = Proxy-To-Realm
Fri Sep  4 17:53:15 2009 : Debug: ++[control] returns noop
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap: EAP packet type response id 8 length 70
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[eap] returns updated
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[files] returns noop
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling expiration (rlm_expiration) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from expiration (rlm_expiration) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[expiration] returns noop
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling logintime (rlm_logintime) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from logintime (rlm_logintime) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[logintime] returns noop
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[pap] returns noop
Fri Sep  4 17:53:15 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:15 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:15 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap: Request found, released from the list
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap: EAP/mschapv2
Fri Sep  4 17:53:15 2009 : Debug:   rlm_eap: processing type mschapv2
Fri Sep  4 17:53:15 2009 : Debug: +- entering group MS-CHAP
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authenticate]: calling mschap (rlm_mschap) for request 7
Fri Sep  4 17:53:15 2009 : Debug:   rlm_mschap: No Cleartext-Password configured.  Cannot create LM-Password.
Fri Sep  4 17:53:15 2009 : Debug:   rlm_mschap: No Cleartext-Password configured.  Cannot create NT-Password.
Fri Sep  4 17:53:15 2009 : Debug:   rlm_mschap: Told to do MS-CHAPv2 for UserAD with NT-Password
Fri Sep  4 17:53:15 2009 : Debug: radius_xlat: Running registered xlat function of module mschap for string 'User-Name'
Fri Sep  4 17:53:15 2009 : Debug:       expand: --username=%{mschap:User-Name:-None} -> --username=UserAD
Fri Sep  4 17:53:15 2009 : Debug: radius_xlat: Running registered xlat function of module mschap for string 'NT-DomainAD'
Fri Sep  4 17:53:15 2009 : Debug:       expand: --DomainAD=%{mschap:NT-DomainAD:-DomainAD} -> --DomainAD=DomainAD
Fri Sep  4 17:53:15 2009 : Debug: radius_xlat: Running registered xlat function of module mschap for string 'Challenge'
Fri Sep  4 17:53:15 2009 : Debug:  mschap2: 27
Fri Sep  4 17:53:15 2009 : Debug:       expand: --challenge=%{mschap:Challenge:-00} -> --challenge=e773c07b6a390412
Fri Sep  4 17:53:15 2009 : Debug: radius_xlat: Running registered xlat function of module mschap for string 'NT-Response'
Fri Sep  4 17:53:15 2009 : Debug:       expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=3d7b6d01f218ee06b816d11ffb5bb76116008c0c3b290c54
Fri Sep  4 17:53:15 2009 : Debug: Exec-Program output: NT_KEY: 252299AA10CCD0093057A89B2343E52B
Fri Sep  4 17:53:15 2009 : Debug: Exec-Program-Wait: plaintext: NT_KEY: 252299AA10CCD0093057A89B2343E52B
Fri Sep  4 17:53:15 2009 : Debug: Exec-Program: returned: 0
Fri Sep  4 17:53:15 2009 : Debug: rlm_mschap: adding MS-CHAPv2 MPPE keys
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authenticate]: returned from mschap (rlm_mschap) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[mschap] returns ok
Fri Sep  4 17:53:15 2009 : Debug: MSCHAP Success
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[eap] returns handled
} # server inner-tunnel
  PEAP: Got tunneled reply RADIUS code 11
        EAP-Message = 0x010900331a0308002e533d42433635334442384642453245334141363145383032463931463034433030344642364145423534
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9f14021d9e1d1836752cef25051043be
  PEAP: Processing from tunneled session code 0x8312808 11
        EAP-Message = 0x010900331a0308002e533d42433635334442384642453245334141363145383032463931463034433030344642364145423534
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9f14021d9e1d1836752cef25051043be
Fri Sep  4 17:53:15 2009 : Debug:   PEAP: Got tunneled Access-Challenge
  PEAP tunnel data out 0000: 1a 03 08 00 2e 53 3d 42 43 36 35 33 44 42 38 46
  PEAP tunnel data out 0010: 42 45 32 45 33 41 41 36 31 45 38 30 32 46 39 31
  PEAP tunnel data out 0020: 46 30 34 43 30 30 34 46 42 36 41 45 42 35 34
Fri Sep  4 17:53:15 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 7
Fri Sep  4 17:53:15 2009 : Debug: ++[eap] returns handled
Sending Access-Challenge of id 248 to 10.98.243.81 port 1645
        EAP-Message = 0x0109005b19001703010050d4ce41ff33bc89f3fdbdb97b032fdf68c1a2a3bda5a42ca0b89f3db8f5ae7ea64ebcf3631342bdbb65fc73429581180250daf9d7d3bc6e739b7a4701befd897ad17775bfae3a427015e3caafd46c798e
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xca915ae3cd9843b6eecaa1ff7211032e
Fri Sep  4 17:53:15 2009 : Debug: Finished request 7.
Fri Sep  4 17:53:15 2009 : Debug: Going to the next request
Fri Sep  4 17:53:15 2009 : Debug: Waking up in 2.1 seconds.
rad_recv: Access-Request packet from host 10.98.243.81 port 1645, id=249, length=230
        User-Name = "DomainAD\\UserAD"
        Framed-MTU = 1400
        Called-Station-Id = "0023.5e03.1d9c"
        Calling-Station-Id = "001e.6519.44a0"
        Service-Type = Login-User
        Message-Authenticator = 0x2c3e2c1ff4e991f9312175cd8b8d5cb7
        EAP-Message = 0x02090050190017030100204caacb3bfd30e0d1de28e5930d2b32abffda8a304782eafc836180b3afeb7fb7170301002034aadcfa9ef5dc1ba1d5852661f4246c66f541e0b96e425fc3beb6502e712bfe
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 2753
        NAS-Port-Id = "2753"
        State = 0xca915ae3cd9843b6eecaa1ff7211032e
        NAS-IP-Address = 10.98.243.81
        NAS-Identifier = "frneyap81"
Fri Sep  4 17:53:16 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[preprocess] returns ok
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 8
Fri Sep  4 17:53:16 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:16 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: EAP packet type response id 9 length 80
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: Continuing tunnel setup.
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[eap] returns ok
Fri Sep  4 17:53:16 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:16 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:16 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: Request found, released from the list
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: EAP/peap
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: processing type peap
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_peap: Authenticate
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_tls: processing TLS
Fri Sep  4 17:53:16 2009 : Debug:   eaptls_verify returned 7
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_tls: Done initial handshake
Fri Sep  4 17:53:16 2009 : Debug:   eaptls_process returned 7
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_peap: EAPTLS_OK
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_peap: Session established.  Decoding tunneled attributes.
  PEAP tunnel data in 0000: 1a 03
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_peap: EAP type mschapv2
  PEAP: Got tunneled EAP-Message
        EAP-Message = 0x020900061a03
Fri Sep  4 17:53:16 2009 : Debug:   PEAP: Setting User-Name to DomainAD\UserAD
  PEAP: Sending tunneled request
        EAP-Message = 0x020900061a03
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "DomainAD\\UserAD"
        State = 0x9f14021d9e1d1836752cef25051043be
server inner-tunnel {
Fri Sep  4 17:53:16 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling unix (rlm_unix) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from unix (rlm_unix) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[unix] returns notfound
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 8
Fri Sep  4 17:53:16 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:16 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:16 2009 : Debug: ::: FROM 1 TO 0 MAX 1
Fri Sep  4 17:53:16 2009 : Debug: ::: Examining Proxy-To-Realm
Fri Sep  4 17:53:16 2009 : Debug: ::: APPENDING Proxy-To-Realm FROM 0 TO 0
Fri Sep  4 17:53:16 2009 : Debug: ::: TO in 0 out 1
Fri Sep  4 17:53:16 2009 : Debug: ::: to[0] = Proxy-To-Realm
Fri Sep  4 17:53:16 2009 : Debug: ++[control] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: EAP packet type response id 9 length 6
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[eap] returns updated
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[files] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling expiration (rlm_expiration) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from expiration (rlm_expiration) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[expiration] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling logintime (rlm_logintime) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from logintime (rlm_logintime) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[logintime] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[pap] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:16 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:16 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 8
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: Request found, released from the list
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: EAP/mschapv2
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: processing type mschapv2
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: Freeing handler
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[eap] returns ok
Fri Sep  4 17:53:16 2009 : Auth: Login OK: [DomainAD\\UserAD/<via Auth-Type = EAP>] (from client LANDomainADNeydens port 0 via TLS tunnel)
} # server inner-tunnel
  PEAP: Got tunneled reply RADIUS code 2
        EAP-Message = 0x03090004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "DomainAD\UserAD"
  PEAP: Processing from tunneled session code 0x8337f50 2
        EAP-Message = 0x03090004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "DomainAD\UserAD"
Fri Sep  4 17:53:16 2009 : Debug:   PEAP: Tunneled authentication was successful.
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_peap: SUCCESS
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 8
Fri Sep  4 17:53:16 2009 : Debug: ++[eap] returns handled
Sending Access-Challenge of id 249 to 10.98.243.81 port 1645
        EAP-Message = 0x010a002b19001703010020d2fc2c3833ee103a49a978f95bcecb80a7924cefb6ec18bb578c31b515a0e072
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xca915ae3c29b43b6eecaa1ff7211032e
Fri Sep  4 17:53:16 2009 : Debug: Finished request 8.
Fri Sep  4 17:53:16 2009 : Debug: Going to the next request
Fri Sep  4 17:53:16 2009 : Debug: Waking up in 1.3 seconds.
rad_recv: Access-Request packet from host 10.98.243.81 port 1645, id=250, length=230
        User-Name = "DomainAD\\UserAD"
        Framed-MTU = 1400
        Called-Station-Id = "0023.5e03.1d9c"
        Calling-Station-Id = "001e.6519.44a0"
        Service-Type = Login-User
        Message-Authenticator = 0xc76d08bc019292dfe5c7648fa0b2f083
        EAP-Message = 0x020a005019001703010020c6fd60f57bf45a907b545facbb481582b92f4d96997f63f54c83ea6b4e8d7f2a17030100201b6fecaa10ee0f99bc3a75b50da1939b6d62d067b625d132794aad27eafb2611
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 2753
        NAS-Port-Id = "2753"
        State = 0xca915ae3c29b43b6eecaa1ff7211032e
        NAS-IP-Address = 10.98.243.81
        NAS-Identifier = "frneyap81"
Fri Sep  4 17:53:16 2009 : Debug: +- entering group authorize
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 9
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 9
Fri Sep  4 17:53:16 2009 : Debug: ++[preprocess] returns ok
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 9
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 9
Fri Sep  4 17:53:16 2009 : Debug: ++[chap] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 9
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 9
Fri Sep  4 17:53:16 2009 : Debug: ++[mschap] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 9
Fri Sep  4 17:53:16 2009 : Debug:     rlm_realm: No '@' in User-Name = "DomainAD\UserAD", looking up realm NULL
Fri Sep  4 17:53:16 2009 : Debug:     rlm_realm: No such realm "NULL"
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 9
Fri Sep  4 17:53:16 2009 : Debug: ++[suffix] returns noop
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 9
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: EAP packet type response id 10 length 80
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: Continuing tunnel setup.
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 9
Fri Sep  4 17:53:16 2009 : Debug: ++[eap] returns ok
Fri Sep  4 17:53:16 2009 : Debug:   rad_check_password:  Found Auth-Type EAP
Fri Sep  4 17:53:16 2009 : Debug: auth: type "EAP"
Fri Sep  4 17:53:16 2009 : Debug: +- entering group authenticate
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 9
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: Request found, released from the list
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: EAP/peap
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: processing type peap
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_peap: Authenticate
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_tls: processing TLS
Fri Sep  4 17:53:16 2009 : Debug:   eaptls_verify returned 7
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_tls: Done initial handshake
Fri Sep  4 17:53:16 2009 : Debug:   eaptls_process returned 7
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_peap: EAPTLS_OK
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_peap: Session established.  Decoding tunneled attributes.
  PEAP tunnel data in 0000: 02 0a 00 0b 21 80 03 00 02 00 01
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_peap: Received EAP-TLV response.
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap_peap: Success
Fri Sep  4 17:53:16 2009 : Debug:   rlm_eap: Freeing handler
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 9
Fri Sep  4 17:53:16 2009 : Debug: ++[eap] returns ok
Fri Sep  4 17:53:16 2009 : Auth: Login OK: [DomainAD\\UserAD/<via Auth-Type = EAP>] (from client LANDomainADNeydens port 2753 cli 001e.6519.44a0)
Fri Sep  4 17:53:16 2009 : Debug: +- entering group post-auth
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[post-auth]: calling exec (rlm_exec) for request 9
Fri Sep  4 17:53:16 2009 : Debug:   modsingle[post-auth]: returned from exec (rlm_exec) for request 9
Fri Sep  4 17:53:16 2009 : Debug: ++[exec] returns noop
Sending Access-Accept of id 250 to 10.98.243.81 port 1645
        MS-MPPE-Recv-Key = 0xf65c8867d42a266dbc31983a4b1eaf3e76d7126407583fbe1dafc86ed565af15
        MS-MPPE-Send-Key = 0xaadea9ecd1536b5116b17875d705b38df8e1d8b5922a18167ed63c10c9189e6b
        EAP-Message = 0x030a0004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "DomainAD\UserAD"
Fri Sep  4 17:53:16 2009 : Debug: Finished request 9.
Fri Sep  4 17:53:16 2009 : Debug: Going to the next request
Fri Sep  4 17:53:16 2009 : Debug: Waking up in 1.2 seconds.
Fri Sep  4 17:53:17 2009 : Debug: Cleaning up request 0 ID 241 with timestamp +16
Fri Sep  4 17:53:17 2009 : Debug: Cleaning up request 1 ID 242 with timestamp +16
Fri Sep  4 17:53:17 2009 : Debug: Cleaning up request 2 ID 243 with timestamp +16
Fri Sep  4 17:53:17 2009 : Debug: Waking up in 0.3 seconds.
Fri Sep  4 17:53:18 2009 : Debug: Cleaning up request 3 ID 244 with timestamp +17
Fri Sep  4 17:53:18 2009 : Debug: Waking up in 1.0 seconds.
Fri Sep  4 17:53:19 2009 : Debug: Cleaning up request 4 ID 245 with timestamp +18
Fri Sep  4 17:53:19 2009 : Debug: Cleaning up request 5 ID 246 with timestamp +18
Fri Sep  4 17:53:19 2009 : Debug: Waking up in 0.3 seconds.
Fri Sep  4 17:53:19 2009 : Debug: Cleaning up request 6 ID 247 with timestamp +18
Fri Sep  4 17:53:19 2009 : Debug: Waking up in 0.9 seconds.
Fri Sep  4 17:53:20 2009 : Debug: Cleaning up request 7 ID 248 with timestamp +19
Fri Sep  4 17:53:20 2009 : Debug: Waking up in 0.8 seconds.
Fri Sep  4 17:53:21 2009 : Debug: Cleaning up request 8 ID 249 with timestamp +20
Fri Sep  4 17:53:21 2009 : Debug: Cleaning up request 9 ID 250 with timestamp +20
Fri Sep  4 17:53:21 2009 : Debug: Ready to process requests.
