LDAP auth

17 Jun 2014

      Hello,

I am having some trouble authorizing off ldap from APs - please see the 
debug below, and let me know if there is anything else I can provide. I 
am looking at this snippet from the below:

-------------------------------------------------------------------------------
Tue Jun 17 11:53:43 2014 : Info: [ldap] user jjenkins authorized to use 
remote access
Tue Jun 17 11:53:43 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Jun 17 11:53:43 2014 : Info: ++[ldap] returns ok
Tue Jun 17 11:53:43 2014 : Info: ++[expiration] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[logintime] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[pap] returns noop
Tue Jun 17 11:53:43 2014 : Info: ERROR: No authenticate method 
(Auth-Type) found for the request: Rejecting the

-------------------------------------------------------------------------------
It would seem that my connection to my ldap server is ok, and it finds 
that my user is authorized - the part that plagues me is why ldap 
returns ok but the ERROR shows up about no authentication method 
(Auth-Type) is found. I have made sure that the Auth-Type LDAP section 
within sites-enabled/default is un-commented, so I am confused why I get 
that error.

I appreciate your time and attention.
Best,
Jon

Full Debug:

-------------------------------------------------------------------------------
Tue Jun 17 11:53:32 2014 : Info: FreeRADIUS Version 2.1.12, for host 
x86_64-redhat-linux-gnu, built on Oct  3 2012 at 01:22:51
Tue Jun 17 11:53:32 2014 : Info: Copyright (C) 1999-2009 The FreeRADIUS 
server project and contributors.
Tue Jun 17 11:53:32 2014 : Info: There is NO warranty; not even for 
MERCHANTABILITY or FITNESS FOR A
Tue Jun 17 11:53:32 2014 : Info: PARTICULAR PURPOSE.
Tue Jun 17 11:53:32 2014 : Info: You may redistribute copies of 
FreeRADIUS under the terms of the
Tue Jun 17 11:53:32 2014 : Info: GNU General Public License v2.
Tue Jun 17 11:53:32 2014 : Info: Starting - reading configuration files ...
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/radiusd.conf
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/proxy.conf
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/clients.conf
Tue Jun 17 11:53:32 2014 : Debug: including files in directory 
/etc/raddb/modules/
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/mac2vlan
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/detail
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/passwd
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/pap
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/ldap
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/detail.example.com
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/checkval
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/dynamic_clients
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/radutmp
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/redis
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/expr
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/smbpasswd
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/always
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/counter
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/attr_filter
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/otp
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/chap
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/echo
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/attr_rewrite
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/perl
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/digest
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/mac2ip
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/smsotp
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/linelog
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/detail.log
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/expiration
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/mschap
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/files
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/soh
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/pam
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/opendirectory
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/wimax
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/etc_group
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/ippool
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/replicate
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/rediswho
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/sql_log
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/policy
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/inner-eap
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/sqlcounter_expire_on_login
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/exec
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/ntlm_auth
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/cui
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/realm
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/preprocess
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/unix
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/acct_unique
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/sradutmp
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/modules/logintime
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/eap.conf
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/policy.conf
Tue Jun 17 11:53:32 2014 : Debug: including files in directory 
/etc/raddb/sites-enabled/
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/sites-enabled/inner-tunnel
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:32 2014 : Debug: including configuration file 
/etc/raddb/sites-enabled/control-socket
Tue Jun 17 11:53:32 2014 : Debug: main {
Tue Jun 17 11:53:32 2014 : Debug:       user = "radiusd"
Tue Jun 17 11:53:32 2014 : Debug:       group = "radiusd"
Tue Jun 17 11:53:32 2014 : Debug:       allow_core_dumps = no
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: including dictionary file 
/etc/raddb/dictionary
Tue Jun 17 11:53:32 2014 : Debug: main {
Tue Jun 17 11:53:32 2014 : Debug:       name = "radiusd"
Tue Jun 17 11:53:32 2014 : Debug:       prefix = "/usr"
Tue Jun 17 11:53:32 2014 : Debug:       localstatedir = "/var"
Tue Jun 17 11:53:32 2014 : Debug:       sbindir = "/usr/sbin"
Tue Jun 17 11:53:32 2014 : Debug:       logdir = "/var/log/radius"
Tue Jun 17 11:53:32 2014 : Debug:       run_dir = "/var/run/radiusd"
Tue Jun 17 11:53:32 2014 : Debug:       libdir = "/usr/lib64/freeradius"
Tue Jun 17 11:53:32 2014 : Debug:       radacctdir = 
"/var/log/radius/radacct"
Tue Jun 17 11:53:32 2014 : Debug:       hostname_lookups = no
Tue Jun 17 11:53:32 2014 : Debug:       max_request_time = 30
Tue Jun 17 11:53:32 2014 : Debug:       cleanup_delay = 5
Tue Jun 17 11:53:32 2014 : Debug:       max_requests = 1024
Tue Jun 17 11:53:32 2014 : Debug:       pidfile = 
"/var/run/radiusd/radiusd.pid"
Tue Jun 17 11:53:32 2014 : Debug:       checkrad = "/usr/sbin/checkrad"
Tue Jun 17 11:53:32 2014 : Debug:       debug_level = 0
Tue Jun 17 11:53:32 2014 : Debug:       proxy_requests = yes
Tue Jun 17 11:53:32 2014 : Debug:  log {
Tue Jun 17 11:53:32 2014 : Debug:       stripped_names = no
Tue Jun 17 11:53:32 2014 : Debug:       auth = no
Tue Jun 17 11:53:32 2014 : Debug:       auth_badpass = no
Tue Jun 17 11:53:32 2014 : Debug:       auth_goodpass = no
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  security {
Tue Jun 17 11:53:32 2014 : Debug:       max_attributes = 200
Tue Jun 17 11:53:32 2014 : Debug:       reject_delay = 1
Tue Jun 17 11:53:32 2014 : Debug:       status_server = yes
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: radiusd: #### Loading Realms and Home 
Servers ####
Tue Jun 17 11:53:32 2014 : Debug:  proxy server {
Tue Jun 17 11:53:32 2014 : Debug:       retry_delay = 5
Tue Jun 17 11:53:32 2014 : Debug:       retry_count = 3
Tue Jun 17 11:53:32 2014 : Debug:       default_fallback = no
Tue Jun 17 11:53:32 2014 : Debug:       dead_time = 120
Tue Jun 17 11:53:32 2014 : Debug:       wake_all_if_all_dead = no
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  home_server localhost {
Tue Jun 17 11:53:32 2014 : Debug:       ipaddr = 127.0.0.1
Tue Jun 17 11:53:32 2014 : Debug:       port = 1812
Tue Jun 17 11:53:32 2014 : Debug:       type = "auth"
Tue Jun 17 11:53:32 2014 : Debug:       secret = "testing123"
Tue Jun 17 11:53:32 2014 : Debug:       response_window = 20
Tue Jun 17 11:53:32 2014 : Debug:       max_outstanding = 65536
Tue Jun 17 11:53:32 2014 : Debug: require_message_authenticator = yes
Tue Jun 17 11:53:32 2014 : Debug:       zombie_period = 40
Tue Jun 17 11:53:32 2014 : Debug:       status_check = "status-server"
Tue Jun 17 11:53:32 2014 : Debug:       ping_interval = 30
Tue Jun 17 11:53:32 2014 : Debug:       check_interval = 30
Tue Jun 17 11:53:32 2014 : Debug:       num_answers_to_alive = 3
Tue Jun 17 11:53:32 2014 : Debug:       num_pings_to_alive = 3
Tue Jun 17 11:53:32 2014 : Debug:       revive_interval = 120
Tue Jun 17 11:53:32 2014 : Debug:       status_check_timeout = 4
Tue Jun 17 11:53:32 2014 : Debug:   coa {
Tue Jun 17 11:53:32 2014 : Debug:       irt = 2
Tue Jun 17 11:53:32 2014 : Debug:       mrt = 16
Tue Jun 17 11:53:32 2014 : Debug:       mrc = 5
Tue Jun 17 11:53:32 2014 : Debug:       mrd = 30
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  home_server_pool my_auth_failover {
Tue Jun 17 11:53:32 2014 : Debug:       type = fail-over
Tue Jun 17 11:53:32 2014 : Debug:       home_server = localhost
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  realm example.com {
Tue Jun 17 11:53:32 2014 : Debug:       auth_pool = my_auth_failover
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  realm LOCAL {
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: radiusd: #### Loading Clients ####
Tue Jun 17 11:53:32 2014 : Debug:  client localhost {
Tue Jun 17 11:53:32 2014 : Debug:       ipaddr = 127.0.0.1
Tue Jun 17 11:53:32 2014 : Debug: require_message_authenticator = no
Tue Jun 17 11:53:32 2014 : Debug:       secret = "testing123"
Tue Jun 17 11:53:32 2014 : Debug:       nastype = "other"
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  client 172.16.210.0/24 {
Tue Jun 17 11:53:32 2014 : Debug: require_message_authenticator = no
Tue Jun 17 11:53:32 2014 : Debug:       secret = "1ctllc2"
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: radiusd: #### Instantiating modules ####
Tue Jun 17 11:53:32 2014 : Debug:  instantiate {
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_exec, checking if it's 
valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_exec
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module "exec" 
from file /etc/raddb/modules/exec
Tue Jun 17 11:53:32 2014 : Debug:   exec {
Tue Jun 17 11:53:32 2014 : Debug:       wait = no
Tue Jun 17 11:53:32 2014 : Debug:       input_pairs = "request"
Tue Jun 17 11:53:32 2014 : Debug:       shell_escape = yes
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_expr, checking if it's 
valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_expr
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module "expr" 
from file /etc/raddb/modules/expr
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_expiration, checking 
if it's valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_expiration
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module 
"expiration" from file /etc/raddb/modules/expiration
Tue Jun 17 11:53:32 2014 : Debug:   expiration {
Tue Jun 17 11:53:32 2014 : Debug:       reply-message = "Password Has 
Expired  "
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_logintime, checking if 
it's valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_logintime
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module 
"logintime" from file /etc/raddb/modules/logintime
Tue Jun 17 11:53:32 2014 : Debug:   logintime {
Tue Jun 17 11:53:32 2014 : Debug:       reply-message = "You are calling 
outside your allowed timespan  "
Tue Jun 17 11:53:32 2014 : Debug:       minimum-timeout = 60
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: radiusd: #### Loading Virtual Servers 
####
Tue Jun 17 11:53:32 2014 : Debug: server { # from file 
/etc/raddb/radiusd.conf
Tue Jun 17 11:53:32 2014 : Debug:  modules {
Tue Jun 17 11:53:32 2014 : Debug:   Module: Creating Auth-Type = digest
Tue Jun 17 11:53:32 2014 : Debug:   Module: Creating Auth-Type = LDAP
Tue Jun 17 11:53:32 2014 : Debug:   Module: Creating Post-Auth-Type = 
REJECT
Tue Jun 17 11:53:32 2014 : Debug:  Module: Checking authenticate {...} 
for more modules to load
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_pap, checking if it's 
valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_pap
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module "pap" 
from file /etc/raddb/modules/pap
Tue Jun 17 11:53:32 2014 : Debug:   pap {
Tue Jun 17 11:53:32 2014 : Debug:       encryption_scheme = "auto"
Tue Jun 17 11:53:32 2014 : Debug:       auto_header = no
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_chap, checking if it's 
valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_chap
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module "chap" 
from file /etc/raddb/modules/chap
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_mschap, checking if 
it's valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_mschap
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module "mschap" 
from file /etc/raddb/modules/mschap
Tue Jun 17 11:53:32 2014 : Debug:   mschap {
Tue Jun 17 11:53:32 2014 : Debug:       use_mppe = yes
Tue Jun 17 11:53:32 2014 : Debug:       require_encryption = no
Tue Jun 17 11:53:32 2014 : Debug:       require_strong = no
Tue Jun 17 11:53:32 2014 : Debug:       with_ntdomain_hack = no
Tue Jun 17 11:53:32 2014 : Debug:       allow_retry = yes
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_digest, checking if 
it's valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_digest
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module "digest" 
from file /etc/raddb/modules/digest
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_unix, checking if it's 
valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_unix
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module "unix" 
from file /etc/raddb/modules/unix
Tue Jun 17 11:53:32 2014 : Debug:   unix {
Tue Jun 17 11:53:32 2014 : Debug:       radwtmp = "/var/log/radius/radwtmp"
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_ldap, checking if it's 
valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_ldap
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module "ldap" 
from file /etc/raddb/modules/ldap
Tue Jun 17 11:53:32 2014 : Debug:   ldap {
Tue Jun 17 11:53:32 2014 : Debug:       server = "localhost"
Tue Jun 17 11:53:32 2014 : Debug:       port = 389
Tue Jun 17 11:53:32 2014 : Debug:       password = ""
Tue Jun 17 11:53:32 2014 : Debug:       identity = ""
Tue Jun 17 11:53:32 2014 : Debug:       net_timeout = 1
Tue Jun 17 11:53:32 2014 : Debug:       timeout = 4
Tue Jun 17 11:53:32 2014 : Debug:       timelimit = 3
Tue Jun 17 11:53:32 2014 : Debug:       tls_mode = no
Tue Jun 17 11:53:32 2014 : Debug:       start_tls = no
Tue Jun 17 11:53:32 2014 : Debug:       tls_require_cert = "allow"
Tue Jun 17 11:53:32 2014 : Debug:    tls {
Tue Jun 17 11:53:32 2014 : Debug:       start_tls = yes
Tue Jun 17 11:53:32 2014 : Debug:       cacertfile = "/etc/ipa/ca.crt"
Tue Jun 17 11:53:32 2014 : Debug:       require_cert = "allow"
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:       basedn = 
"cn=accounts,dc=csi,dc=com"
Tue Jun 17 11:53:32 2014 : Debug:       filter = 
"(uid=%{%{Stripped-User-Name}:-%{User-Name}})"
Tue Jun 17 11:53:32 2014 : Debug:       base_filter = 
"(objectclass=radiusprofile)"
Tue Jun 17 11:53:32 2014 : Debug:       auto_header = no
Tue Jun 17 11:53:32 2014 : Debug:       access_attr_used_for_allow = yes
Tue Jun 17 11:53:32 2014 : Debug:       groupname_attribute = "cn"
Tue Jun 17 11:53:32 2014 : Debug:       groupmembership_filter = 
"(|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn})))" 

Tue Jun 17 11:53:32 2014 : Debug:       dictionary_mapping = 
"/etc/raddb/ldap.attrmap"
Tue Jun 17 11:53:32 2014 : Debug:       ldap_debug = 0
Tue Jun 17 11:53:32 2014 : Debug:       ldap_connections_number = 5
Tue Jun 17 11:53:32 2014 : Debug:       compare_check_items = no
Tue Jun 17 11:53:32 2014 : Debug:       do_xlat = yes
Tue Jun 17 11:53:32 2014 : Debug:       set_auth_type = yes
Tue Jun 17 11:53:32 2014 : Debug:    keepalive {
Tue Jun 17 11:53:32 2014 : Debug:       idle = 60
Tue Jun 17 11:53:32 2014 : Debug:       probes = 3
Tue Jun 17 11:53:32 2014 : Debug:       interval = 3
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: Registering ldap_groupcmp 
for Ldap-Group
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: Registering ldap_xlat with 
xlat_name ldap
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: reading ldap<->radius 
mappings from file /etc/raddb/ldap.attrmap
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusCheckItem mapped 
to RADIUS $GENERIC$
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusReplyItem mapped 
to RADIUS $GENERIC$
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusAuthType mapped 
to RADIUS Auth-Type
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusSimultaneousUse 
mapped to RADIUS Simultaneous-Use
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusCalledStationId 
mapped to RADIUS Called-Station-Id
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusCallingStationId 
mapped to RADIUS Calling-Station-Id
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP lmPassword mapped to 
RADIUS LM-Password
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP ntPassword mapped to 
RADIUS NT-Password
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP sambaLmPassword mapped 
to RADIUS LM-Password
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP sambaNtPassword mapped 
to RADIUS NT-Password
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP dBCSPwd mapped to 
RADIUS LM-Password
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP userPassword mapped to 
RADIUS Cleartext-Password
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP acctFlags mapped to 
RADIUS SMB-Account-CTRL-TEXT
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusExpiration mapped 
to RADIUS Expiration
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusNASIpAddress 
mapped to RADIUS NAS-IP-Address
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusServiceType 
mapped to RADIUS Service-Type
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusFramedProtocol 
mapped to RADIUS Framed-Protocol
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusFramedIPAddress 
mapped to RADIUS Framed-IP-Address
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusFramedIPNetmask 
mapped to RADIUS Framed-IP-Netmask
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusFramedRoute 
mapped to RADIUS Framed-Route
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusFramedRouting 
mapped to RADIUS Framed-Routing
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusFilterId mapped 
to RADIUS Filter-Id
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusFramedMTU mapped 
to RADIUS Framed-MTU
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusFramedCompression 
mapped to RADIUS Framed-Compression
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusLoginIPHost 
mapped to RADIUS Login-IP-Host
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusLoginService 
mapped to RADIUS Login-Service
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusLoginTCPPort 
mapped to RADIUS Login-TCP-Port
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusCallbackNumber 
mapped to RADIUS Callback-Number
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusCallbackId mapped 
to RADIUS Callback-Id
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusFramedIPXNetwork 
mapped to RADIUS Framed-IPX-Network
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusClass mapped to 
RADIUS Class
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusSessionTimeout 
mapped to RADIUS Session-Timeout
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusIdleTimeout 
mapped to RADIUS Idle-Timeout
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusTerminationAction 
mapped to RADIUS Termination-Action
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusLoginLATService 
mapped to RADIUS Login-LAT-Service
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusLoginLATNode 
mapped to RADIUS Login-LAT-Node
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusLoginLATGroup 
mapped to RADIUS Login-LAT-Group
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP 
radiusFramedAppleTalkLink mapped to RADIUS Framed-AppleTalk-Link
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP 
radiusFramedAppleTalkNetwork mapped to RADIUS Framed-AppleTalk-Network
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP 
radiusFramedAppleTalkZone mapped to RADIUS Framed-AppleTalk-Zone
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusPortLimit mapped 
to RADIUS Port-Limit
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusLoginLATPort 
mapped to RADIUS Login-LAT-Port
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusReplyMessage 
mapped to RADIUS Reply-Message
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusTunnelType mapped 
to RADIUS Tunnel-Type
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP radiusTunnelMediumType 
mapped to RADIUS Tunnel-Medium-Type
Tue Jun 17 11:53:32 2014 : Debug: rlm_ldap: LDAP 
radiusTunnelPrivateGroupId mapped to RADIUS Tunnel-Private-Group-Id
Tue Jun 17 11:53:32 2014 : Debug: conns: 0x7f3f6ad123f0
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_eap, checking if it's 
valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_eap
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module "eap" 
from file /etc/raddb/eap.conf
Tue Jun 17 11:53:32 2014 : Debug:   eap {
Tue Jun 17 11:53:32 2014 : Debug:       default_eap_type = "md5"
Tue Jun 17 11:53:32 2014 : Debug:       timer_expire = 60
Tue Jun 17 11:53:32 2014 : Debug:       ignore_unknown_eap_types = no
Tue Jun 17 11:53:32 2014 : Debug: cisco_accounting_username_bug = no
Tue Jun 17 11:53:32 2014 : Debug:       max_sessions = 4096
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to sub-module rlm_eap_md5
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating eap-md5
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to sub-module 
rlm_eap_leap
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating eap-leap
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to sub-module rlm_eap_gtc
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating eap-gtc
Tue Jun 17 11:53:32 2014 : Debug:    gtc {
Tue Jun 17 11:53:32 2014 : Debug:       challenge = "Password: "
Tue Jun 17 11:53:32 2014 : Debug:       auth_type = "PAP"
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to sub-module rlm_eap_tls
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating eap-tls
Tue Jun 17 11:53:32 2014 : Debug:    tls {
Tue Jun 17 11:53:32 2014 : Debug:       rsa_key_exchange = no
Tue Jun 17 11:53:32 2014 : Debug:       dh_key_exchange = yes
Tue Jun 17 11:53:32 2014 : Debug:       rsa_key_length = 512
Tue Jun 17 11:53:32 2014 : Debug:       dh_key_length = 512
Tue Jun 17 11:53:32 2014 : Debug:       verify_depth = 0
Tue Jun 17 11:53:32 2014 : Debug:       CA_path = "/etc/raddb/certs"
Tue Jun 17 11:53:32 2014 : Debug:       pem_file_type = yes
Tue Jun 17 11:53:32 2014 : Debug:       private_key_file = 
"/etc/raddb/certs/server.pem"
Tue Jun 17 11:53:32 2014 : Debug:       certificate_file = 
"/etc/raddb/certs/server.pem"
Tue Jun 17 11:53:32 2014 : Debug:       CA_file = "/etc/raddb/certs/ca.pem"
Tue Jun 17 11:53:32 2014 : Debug:       private_key_password = "whatever"
Tue Jun 17 11:53:32 2014 : Debug:       dh_file = "/etc/raddb/certs/dh"
Tue Jun 17 11:53:32 2014 : Debug:       random_file = 
"/etc/raddb/certs/random"
Tue Jun 17 11:53:32 2014 : Debug:       fragment_size = 1024
Tue Jun 17 11:53:32 2014 : Debug:       include_length = yes
Tue Jun 17 11:53:32 2014 : Debug:       check_crl = no
Tue Jun 17 11:53:32 2014 : Debug:       cipher_list = "DEFAULT"
Tue Jun 17 11:53:32 2014 : Debug:     cache {
Tue Jun 17 11:53:32 2014 : Debug:       enable = no
Tue Jun 17 11:53:32 2014 : Debug:       lifetime = 24
Tue Jun 17 11:53:32 2014 : Debug:       max_entries = 255
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:     verify {
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:     ocsp {
Tue Jun 17 11:53:32 2014 : Debug:       enable = no
Tue Jun 17 11:53:32 2014 : Debug:       override_cert_url = yes
Tue Jun 17 11:53:32 2014 : Debug:       url = "http://127.0.0.1/ocsp/"
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to sub-module 
rlm_eap_ttls
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating eap-ttls
Tue Jun 17 11:53:32 2014 : Debug:    ttls {
Tue Jun 17 11:53:32 2014 : Debug:       default_eap_type = "md5"
Tue Jun 17 11:53:32 2014 : Debug:       copy_request_to_tunnel = no
Tue Jun 17 11:53:32 2014 : Debug:       use_tunneled_reply = no
Tue Jun 17 11:53:32 2014 : Debug:       virtual_server = "inner-tunnel"
Tue Jun 17 11:53:32 2014 : Debug:       include_length = yes
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to sub-module 
rlm_eap_peap
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating eap-peap
Tue Jun 17 11:53:32 2014 : Debug:    peap {
Tue Jun 17 11:53:32 2014 : Debug:       default_eap_type = "mschapv2"
Tue Jun 17 11:53:32 2014 : Debug:       copy_request_to_tunnel = no
Tue Jun 17 11:53:32 2014 : Debug:       use_tunneled_reply = no
Tue Jun 17 11:53:32 2014 : Debug: proxy_tunneled_request_as_eap = yes
Tue Jun 17 11:53:32 2014 : Debug:       virtual_server = "inner-tunnel"
Tue Jun 17 11:53:32 2014 : Debug:       soh = no
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to sub-module 
rlm_eap_mschapv2
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating eap-mschapv2
Tue Jun 17 11:53:32 2014 : Debug:    mschapv2 {
Tue Jun 17 11:53:32 2014 : Debug:       with_ntdomain_hack = no
Tue Jun 17 11:53:32 2014 : Debug:       send_error = no
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  Module: Checking authorize {...} for 
more modules to load
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_preprocess, checking 
if it's valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_preprocess
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module 
"preprocess" from file /etc/raddb/modules/preprocess
Tue Jun 17 11:53:32 2014 : Debug:   preprocess {
Tue Jun 17 11:53:32 2014 : Debug:       huntgroups = 
"/etc/raddb/huntgroups"
Tue Jun 17 11:53:32 2014 : Debug:       hints = "/etc/raddb/hints"
Tue Jun 17 11:53:32 2014 : Debug:       with_ascend_hack = no
Tue Jun 17 11:53:32 2014 : Debug:       ascend_channels_per_line = 23
Tue Jun 17 11:53:32 2014 : Debug:       with_ntdomain_hack = no
Tue Jun 17 11:53:32 2014 : Debug: with_specialix_jetstream_hack = no
Tue Jun 17 11:53:32 2014 : Debug:       with_cisco_vsa_hack = no
Tue Jun 17 11:53:32 2014 : Debug:       with_alvarion_vsa_hack = no
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_realm, checking if 
it's valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_realm
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module "suffix" 
from file /etc/raddb/modules/realm
Tue Jun 17 11:53:32 2014 : Debug:   realm suffix {
Tue Jun 17 11:53:32 2014 : Debug:       format = "suffix"
Tue Jun 17 11:53:32 2014 : Debug:       delimiter = "@"
Tue Jun 17 11:53:32 2014 : Debug:       ignore_default = no
Tue Jun 17 11:53:32 2014 : Debug:       ignore_null = no
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_files, checking if 
it's valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_files
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module "files" 
from file /etc/raddb/modules/files
Tue Jun 17 11:53:32 2014 : Debug:   files {
Tue Jun 17 11:53:32 2014 : Debug:       usersfile = "/etc/raddb/users"
Tue Jun 17 11:53:32 2014 : Debug:       acctusersfile = 
"/etc/raddb/acct_users"
Tue Jun 17 11:53:32 2014 : Debug:       preproxy_usersfile = 
"/etc/raddb/preproxy_users"
Tue Jun 17 11:53:32 2014 : Debug:       compat = "no"
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  Module: Checking preacct {...} for 
more modules to load
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_acct_unique, checking 
if it's valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_acct_unique
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module 
"acct_unique" from file /etc/raddb/modules/acct_unique
Tue Jun 17 11:53:32 2014 : Debug:   acct_unique {
Tue Jun 17 11:53:32 2014 : Debug:       key = "User-Name, 
Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  Module: Checking accounting {...} for 
more modules to load
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_detail, checking if 
it's valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_detail
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module "detail" 
from file /etc/raddb/modules/detail
Tue Jun 17 11:53:32 2014 : Debug:   detail {
Tue Jun 17 11:53:32 2014 : Debug:       detailfile = 
"/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" 

Tue Jun 17 11:53:32 2014 : Debug:       header = "%t"
Tue Jun 17 11:53:32 2014 : Debug:       detailperm = 384
Tue Jun 17 11:53:32 2014 : Debug:       dirperm = 493
Tue Jun 17 11:53:32 2014 : Debug:       locking = no
Tue Jun 17 11:53:32 2014 : Debug:       log_packet_header = no
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_radutmp, checking if 
it's valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_radutmp
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module 
"radutmp" from file /etc/raddb/modules/radutmp
Tue Jun 17 11:53:32 2014 : Debug:   radutmp {
Tue Jun 17 11:53:32 2014 : Debug:       filename = 
"/var/log/radius/radutmp"
Tue Jun 17 11:53:32 2014 : Debug:       username = "%{User-Name}"
Tue Jun 17 11:53:32 2014 : Debug:       case_sensitive = yes
Tue Jun 17 11:53:32 2014 : Debug:       check_with_nas = yes
Tue Jun 17 11:53:32 2014 : Debug:       perm = 384
Tue Jun 17 11:53:32 2014 : Debug:       callerid = yes
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:     (Loaded rlm_attr_filter, checking 
if it's valid)
Tue Jun 17 11:53:32 2014 : Debug:  Module: Linked to module rlm_attr_filter
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module 
"attr_filter.accounting_response" from file /etc/raddb/modules/attr_filter
Tue Jun 17 11:53:32 2014 : Debug:   attr_filter 
attr_filter.accounting_response {
Tue Jun 17 11:53:32 2014 : Debug:       attrsfile = 
"/etc/raddb/attrs.accounting_response"
Tue Jun 17 11:53:32 2014 : Debug:       key = "%{User-Name}"
Tue Jun 17 11:53:32 2014 : Debug:       relaxed = no
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  Module: Checking session {...} for 
more modules to load
Tue Jun 17 11:53:32 2014 : Debug:  Module: Checking post-proxy {...} for 
more modules to load
Tue Jun 17 11:53:32 2014 : Debug:  Module: Checking post-auth {...} for 
more modules to load
Tue Jun 17 11:53:32 2014 : Debug:  Module: Instantiating module 
"attr_filter.access_reject" from file /etc/raddb/modules/attr_filter
Tue Jun 17 11:53:32 2014 : Debug:   attr_filter attr_filter.access_reject {
Tue Jun 17 11:53:32 2014 : Debug:       attrsfile = 
"/etc/raddb/attrs.access_reject"
Tue Jun 17 11:53:32 2014 : Debug:       key = "%{User-Name}"
Tue Jun 17 11:53:32 2014 : Debug:       relaxed = no
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug:  } # modules
Tue Jun 17 11:53:32 2014 : Debug: } # server
Tue Jun 17 11:53:32 2014 : Debug: server inner-tunnel { # from file 
/etc/raddb/sites-enabled/inner-tunnel
Tue Jun 17 11:53:32 2014 : Debug:  modules {
Tue Jun 17 11:53:32 2014 : Debug:  Module: Checking authenticate {...} 
for more modules to load
Tue Jun 17 11:53:32 2014 : Debug:  Module: Checking authorize {...} for 
more modules to load
Tue Jun 17 11:53:32 2014 : Debug:  Module: Checking session {...} for 
more modules to load
Tue Jun 17 11:53:32 2014 : Debug:  Module: Checking post-auth {...} for 
more modules to load
Tue Jun 17 11:53:32 2014 : Debug:  } # modules
Tue Jun 17 11:53:32 2014 : Debug: } # server
Tue Jun 17 11:53:32 2014 : Debug: radiusd: #### Opening IP addresses and 
Ports ####
Tue Jun 17 11:53:32 2014 : Debug: listen {
Tue Jun 17 11:53:32 2014 : Debug:       type = "auth"
Tue Jun 17 11:53:32 2014 : Debug:       ipaddr = *
Tue Jun 17 11:53:32 2014 : Debug:       port = 0
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: listen {
Tue Jun 17 11:53:32 2014 : Debug:       type = "acct"
Tue Jun 17 11:53:32 2014 : Debug:       ipaddr = *
Tue Jun 17 11:53:32 2014 : Debug:       port = 0
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: listen {
Tue Jun 17 11:53:32 2014 : Debug:       type = "control"
Tue Jun 17 11:53:32 2014 : Debug:  listen {
Tue Jun 17 11:53:32 2014 : Debug:       socket = 
"/var/run/radiusd/radiusd.sock"
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Debug: listen {
Tue Jun 17 11:53:32 2014 : Debug:       type = "auth"
Tue Jun 17 11:53:32 2014 : Debug:       ipaddr = 127.0.0.1
Tue Jun 17 11:53:32 2014 : Debug:       port = 18120
Tue Jun 17 11:53:32 2014 : Debug: }
Tue Jun 17 11:53:32 2014 : Info:  ... adding new socket proxy address * 
port 32876
Tue Jun 17 11:53:32 2014 : Debug: Listening on authentication address * 
port 1812
Tue Jun 17 11:53:32 2014 : Debug: Listening on accounting address * port 
1813
Tue Jun 17 11:53:32 2014 : Debug: Listening on command file 
/var/run/radiusd/radiusd.sock
Tue Jun 17 11:53:32 2014 : Debug: Listening on authentication address 
127.0.0.1 port 18120 as server inner-tunnel
Tue Jun 17 11:53:32 2014 : Debug: Listening on proxy address * port 1814
Tue Jun 17 11:53:32 2014 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 172.16.210.102 port 1042, 
id=34, length=145
         User-Name = "jjenkins"
         NAS-Port = 0
         Called-Station-Id = "2E-A4-3C-65-D0-22:CSI"
         Calling-Station-Id = "84-A6-C8-EE-38-10"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11"
         EAP-Message = 0x0241000d016a6a656e6b696e73
         Message-Authenticator = 0x32a743ad981f661101a2cd28a0b8000d
Tue Jun 17 11:53:40 2014 : Info: # Executing section authorize from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:40 2014 : Info: +- entering group authorize {...}
Tue Jun 17 11:53:40 2014 : Info: ++[preprocess] returns ok
Tue Jun 17 11:53:40 2014 : Info: ++[chap] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[mschap] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[digest] returns noop
Tue Jun 17 11:53:40 2014 : Info: [suffix] No '@' in User-Name = 
"jjenkins", looking up realm NULL
Tue Jun 17 11:53:40 2014 : Info: [suffix] No such realm "NULL"
Tue Jun 17 11:53:40 2014 : Info: ++[suffix] returns noop
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP packet type response id 65 
length 13
Tue Jun 17 11:53:40 2014 : Info: [eap] No EAP Start, assuming it's an 
on-going EAP conversation
Tue Jun 17 11:53:40 2014 : Info: ++[eap] returns updated
Tue Jun 17 11:53:40 2014 : Info: ++[files] returns noop
Tue Jun 17 11:53:40 2014 : Info: [ldap] performing user authorization 
for jjenkins
Tue Jun 17 11:53:40 2014 : Info: [ldap]         expand: 
%{Stripped-User-Name} ->
Tue Jun 17 11:53:40 2014 : Info: [ldap]         ... expanding second 
conditional
Tue Jun 17 11:53:40 2014 : Info: [ldap]         expand: %{User-Name} -> 
jjenkins
Tue Jun 17 11:53:40 2014 : Info: [ldap]         expand: 
(uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=jjenkins)
Tue Jun 17 11:53:40 2014 : Info: [ldap]         expand: 
cn=accounts,dc=csi,dc=com -> cn=accounts,dc=csi,dc=com
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] attempting LDAP reconnection
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] (re)connect to localhost:389, 
authentication 0
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] setting TLS CACert File to 
/etc/ipa/ca.crt
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] starting TLS
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] bind as / to localhost:389
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] waiting for bind result ...
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] Bind was successful
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] performing search in 
cn=accounts,dc=csi,dc=com, with filter (uid=jjenkins)
Tue Jun 17 11:53:40 2014 : Info: [ldap] looking for check items in 
directory...
Tue Jun 17 11:53:40 2014 : Info: [ldap] looking for reply items in 
directory...
Tue Jun 17 11:53:40 2014 : Debug: WARNING: No "known good" password was 
found in LDAP.  Are you sure that the user is configured correctly?
Tue Jun 17 11:53:40 2014 : Info: [ldap] user jjenkins authorized to use 
remote access
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Jun 17 11:53:40 2014 : Info: ++[ldap] returns ok
Tue Jun 17 11:53:40 2014 : Info: ++[expiration] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[logintime] returns noop
Tue Jun 17 11:53:40 2014 : Info: [pap] WARNING! No "known good" password 
found for the user.  Authentication may fail because of this.
Tue Jun 17 11:53:40 2014 : Info: ++[pap] returns noop
Tue Jun 17 11:53:40 2014 : Info: Found Auth-Type = EAP
Tue Jun 17 11:53:40 2014 : Info: # Executing group from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:40 2014 : Info: +- entering group authenticate {...}
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP Identity
Tue Jun 17 11:53:40 2014 : Info: [eap] processing type md5
Tue Jun 17 11:53:40 2014 : Debug: rlm_eap_md5: Issuing Challenge
Tue Jun 17 11:53:40 2014 : Info: ++[eap] returns handled
Sending Access-Challenge of id 34 to 172.16.210.102 port 1042
         EAP-Message = 0x014200160410317c801f5d97eea9e5403dece06dc9ae
         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xafb682b9aff4865d9c2f9d64fb6bc98c
Tue Jun 17 11:53:40 2014 : Info: Finished request 0.
Tue Jun 17 11:53:40 2014 : Debug: Going to the next request
Tue Jun 17 11:53:40 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.210.102 port 1042, 
id=35, length=159
         User-Name = "jjenkins"
         NAS-Port = 0
         Called-Station-Id = "2E-A4-3C-65-D0-22:CSI"
         Calling-Station-Id = "84-A6-C8-EE-38-10"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11"
         EAP-Message = 0x024200090319152b11
         State = 0xafb682b9aff4865d9c2f9d64fb6bc98c
         Message-Authenticator = 0xc5744302be2f36ef8d669c4dbc6de8b8
Tue Jun 17 11:53:40 2014 : Info: # Executing section authorize from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:40 2014 : Info: +- entering group authorize {...}
Tue Jun 17 11:53:40 2014 : Info: ++[preprocess] returns ok
Tue Jun 17 11:53:40 2014 : Info: ++[chap] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[mschap] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[digest] returns noop
Tue Jun 17 11:53:40 2014 : Info: [suffix] No '@' in User-Name = 
"jjenkins", looking up realm NULL
Tue Jun 17 11:53:40 2014 : Info: [suffix] No such realm "NULL"
Tue Jun 17 11:53:40 2014 : Info: ++[suffix] returns noop
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP packet type response id 66 
length 9
Tue Jun 17 11:53:40 2014 : Info: [eap] No EAP Start, assuming it's an 
on-going EAP conversation
Tue Jun 17 11:53:40 2014 : Info: ++[eap] returns updated
Tue Jun 17 11:53:40 2014 : Info: ++[files] returns noop
Tue Jun 17 11:53:40 2014 : Info: [ldap] performing user authorization 
for jjenkins
Tue Jun 17 11:53:40 2014 : Info: [ldap]         expand: 
%{Stripped-User-Name} ->
Tue Jun 17 11:53:40 2014 : Info: [ldap]         ... expanding second 
conditional
Tue Jun 17 11:53:40 2014 : Info: [ldap]         expand: %{User-Name} -> 
jjenkins
Tue Jun 17 11:53:40 2014 : Info: [ldap]         expand: 
(uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=jjenkins)
Tue Jun 17 11:53:40 2014 : Info: [ldap]         expand: 
cn=accounts,dc=csi,dc=com -> cn=accounts,dc=csi,dc=com
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] performing search in 
cn=accounts,dc=csi,dc=com, with filter (uid=jjenkins)
Tue Jun 17 11:53:40 2014 : Info: [ldap] looking for check items in 
directory...
Tue Jun 17 11:53:40 2014 : Info: [ldap] looking for reply items in 
directory...
Tue Jun 17 11:53:40 2014 : Debug: WARNING: No "known good" password was 
found in LDAP.  Are you sure that the user is configured correctly?
Tue Jun 17 11:53:40 2014 : Info: [ldap] user jjenkins authorized to use 
remote access
Tue Jun 17 11:53:40 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Jun 17 11:53:40 2014 : Info: ++[ldap] returns ok
Tue Jun 17 11:53:40 2014 : Info: ++[expiration] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[logintime] returns noop
Tue Jun 17 11:53:40 2014 : Info: [pap] WARNING! No "known good" password 
found for the user.  Authentication may fail because of this.
Tue Jun 17 11:53:40 2014 : Info: ++[pap] returns noop
Tue Jun 17 11:53:40 2014 : Info: Found Auth-Type = EAP
Tue Jun 17 11:53:40 2014 : Info: # Executing group from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:40 2014 : Info: +- entering group authenticate {...}
Tue Jun 17 11:53:40 2014 : Info: [eap] Request found, released from the 
list
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP NAK
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP-NAK asked for EAP-Type/peap
Tue Jun 17 11:53:40 2014 : Info: [eap] processing type tls
Tue Jun 17 11:53:40 2014 : Info: [tls] Initiate
Tue Jun 17 11:53:40 2014 : Info: [tls] Start returned 1
Tue Jun 17 11:53:40 2014 : Info: ++[eap] returns handled
Sending Access-Challenge of id 35 to 172.16.210.102 port 1042
         EAP-Message = 0x014300061920
         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xafb682b9aef59b5d9c2f9d64fb6bc98c
Tue Jun 17 11:53:40 2014 : Info: Finished request 1.
Tue Jun 17 11:53:40 2014 : Debug: Going to the next request
Tue Jun 17 11:53:40 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.210.102 port 1042, 
id=36, length=268
         User-Name = "jjenkins"
         NAS-Port = 0
         Called-Station-Id = "2E-A4-3C-65-D0-22:CSI"
         Calling-Station-Id = "84-A6-C8-EE-38-10"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11"
         EAP-Message = 
0x0243007619800000006c160301006701000063030153a07295d1f0ceeda0128f71d91cd1d59852ae2badb19c8c7e8b18e718c65380000018c014c0130035002fc00ac00900380032000a00130005000401000022ff01000100000500050100000000000a0006000400170018000b0002010000230000 

         State = 0xafb682b9aef59b5d9c2f9d64fb6bc98c
         Message-Authenticator = 0x89a953413680f47f66c1759a24eeaab1
Tue Jun 17 11:53:40 2014 : Info: # Executing section authorize from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:40 2014 : Info: +- entering group authorize {...}
Tue Jun 17 11:53:40 2014 : Info: ++[preprocess] returns ok
Tue Jun 17 11:53:40 2014 : Info: ++[chap] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[mschap] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[digest] returns noop
Tue Jun 17 11:53:40 2014 : Info: [suffix] No '@' in User-Name = 
"jjenkins", looking up realm NULL
Tue Jun 17 11:53:40 2014 : Info: [suffix] No such realm "NULL"
Tue Jun 17 11:53:40 2014 : Info: ++[suffix] returns noop
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP packet type response id 67 
length 118
Tue Jun 17 11:53:40 2014 : Info: [eap] Continuing tunnel setup.
Tue Jun 17 11:53:40 2014 : Info: ++[eap] returns ok
Tue Jun 17 11:53:40 2014 : Info: Found Auth-Type = EAP
Tue Jun 17 11:53:40 2014 : Info: # Executing group from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:40 2014 : Info: +- entering group authenticate {...}
Tue Jun 17 11:53:40 2014 : Info: [eap] Request found, released from the 
list
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP/peap
Tue Jun 17 11:53:40 2014 : Info: [eap] processing type peap
Tue Jun 17 11:53:40 2014 : Info: [peap] processing EAP-TLS
Tue Jun 17 11:53:40 2014 : Debug:   TLS Length 108
Tue Jun 17 11:53:40 2014 : Info: [peap] Length Included
Tue Jun 17 11:53:40 2014 : Info: [peap] eaptls_verify returned 11
Tue Jun 17 11:53:40 2014 : Info: [peap]     (other): before/accept 
initialization
Tue Jun 17 11:53:40 2014 : Info: [peap]     TLS_accept: before/accept 
initialization
Tue Jun 17 11:53:40 2014 : Info: [peap] <<< TLS 1.0 Handshake [length 
0067], ClientHello
Tue Jun 17 11:53:40 2014 : Info: [peap]     TLS_accept: SSLv3 read 
client hello A
Tue Jun 17 11:53:40 2014 : Info: [peap] >>> TLS 1.0 Handshake [length 
0031], ServerHello
Tue Jun 17 11:53:40 2014 : Info: [peap]     TLS_accept: SSLv3 write 
server hello A
Tue Jun 17 11:53:40 2014 : Info: [peap] >>> TLS 1.0 Handshake [length 
085e], Certificate
Tue Jun 17 11:53:40 2014 : Info: [peap]     TLS_accept: SSLv3 write 
certificate A
Tue Jun 17 11:53:40 2014 : Info: [peap] >>> TLS 1.0 Handshake [length 
0004], ServerHelloDone
Tue Jun 17 11:53:40 2014 : Info: [peap]     TLS_accept: SSLv3 write 
server done A
Tue Jun 17 11:53:40 2014 : Info: [peap]     TLS_accept: SSLv3 flush data
Tue Jun 17 11:53:40 2014 : Info: [peap]     TLS_accept: Need to read 
more data: SSLv3 read client certificate A
Tue Jun 17 11:53:40 2014 : Debug: In SSL Handshake Phase
Tue Jun 17 11:53:40 2014 : Debug: In SSL Accept mode
Tue Jun 17 11:53:40 2014 : Info: [peap] eaptls_process returned 13
Tue Jun 17 11:53:40 2014 : Info: [peap] EAPTLS_HANDLED
Tue Jun 17 11:53:40 2014 : Info: ++[eap] returns handled
Sending Access-Challenge of id 36 to 172.16.210.102 port 1042
         EAP-Message = 
0x0144040019c0000008a216030100310200002d030153a072940f7084c460f042c4530c4b4b37248cf354fad4b19d5808529e01326c000035000005ff01000100160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c65204365727469666963617465204175 

         EAP-Message = 
0x74686f72697479301e170d3134303631373136333134365a170d3134303831363136333134365a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100b6d103838591bad8f5fdfdb4482c6b1ce6d072e5f00b5569c61d7b99df61843c8c6ce854973146935ce173cab659fb7615eed7c58f6590 

         EAP-Message = 
0xb610d54b50bf79cb66ccb185ea599190b03b57d6c79dde2e4802d6452071cbf25df572719e4eb6e51116735a7d29f82f0c35bef93f0467c196f6b4e18ec6d640007f4a170c0a7de4e05196d823734df72d48ddbde78303559aae3a7c98a6934ac573978d6c8bdacf06c42e48bd28bd5126a602ee4c92fb58668b73d80a86972dd4c697421e7d58c7d0ed089db386cf1fdb91cac8af45f61d08b5d4d11c45384eb630d2089ca3f68e91a4f8f764dccc8ef06f59c441479a95690af2b1d77c46a8193b6824bb0c5f4d190203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010105050003820101009cfd 

         EAP-Message = 
0x01369f19a0040c39dc20a8ae2ee30fa334c5516aeb8150799c5b077eefa0d748033c10cb54109482e9e6848b1c111035e8ef41e4d484ccf9e1045ef9052e248c00cbc82a7972b597dff661b1e90f5ef83c3933bb84f35572984bdbc1402feae5a0f95e3902e4edccd0a8094822dc4f93fa392f4a6f6343fe9adba18811e46ef9e35552e4a58e4500a0c2cfc5b0968086a21fdcf7c52d7ed6a64c3f7bdcd61573702b77e2efed8a40cc5e52b2966e3aa5f33d500588aea852021705ea26f1a40ffa21e4615ff37c91c306449fd2777267c658f35f168a2e2169a38538c2aff35d7181df02bf1e350f2a108a584f3d398f614885b525d5fed1ae0e8a3a8b 

         EAP-Message = 0xbd0004ab308204a73082038f
         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xafb682b9adf29b5d9c2f9d64fb6bc98c
Tue Jun 17 11:53:40 2014 : Info: Finished request 2.
Tue Jun 17 11:53:40 2014 : Debug: Going to the next request
Tue Jun 17 11:53:40 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.210.102 port 1042, 
id=37, length=156
         User-Name = "jjenkins"
         NAS-Port = 0
         Called-Station-Id = "2E-A4-3C-65-D0-22:CSI"
         Calling-Station-Id = "84-A6-C8-EE-38-10"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11"
         EAP-Message = 0x024400061900
         State = 0xafb682b9adf29b5d9c2f9d64fb6bc98c
         Message-Authenticator = 0x803a2da55bd0b52450537a3b75839783
Tue Jun 17 11:53:40 2014 : Info: # Executing section authorize from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:40 2014 : Info: +- entering group authorize {...}
Tue Jun 17 11:53:40 2014 : Info: ++[preprocess] returns ok
Tue Jun 17 11:53:40 2014 : Info: ++[chap] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[mschap] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[digest] returns noop
Tue Jun 17 11:53:40 2014 : Info: [suffix] No '@' in User-Name = 
"jjenkins", looking up realm NULL
Tue Jun 17 11:53:40 2014 : Info: [suffix] No such realm "NULL"
Tue Jun 17 11:53:40 2014 : Info: ++[suffix] returns noop
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP packet type response id 68 
length 6
Tue Jun 17 11:53:40 2014 : Info: [eap] Continuing tunnel setup.
Tue Jun 17 11:53:40 2014 : Info: ++[eap] returns ok
Tue Jun 17 11:53:40 2014 : Info: Found Auth-Type = EAP
Tue Jun 17 11:53:40 2014 : Info: # Executing group from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:40 2014 : Info: +- entering group authenticate {...}
Tue Jun 17 11:53:40 2014 : Info: [eap] Request found, released from the 
list
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP/peap
Tue Jun 17 11:53:40 2014 : Info: [eap] processing type peap
Tue Jun 17 11:53:40 2014 : Info: [peap] processing EAP-TLS
Tue Jun 17 11:53:40 2014 : Info: [peap] Received TLS ACK
Tue Jun 17 11:53:40 2014 : Info: [peap] ACK handshake fragment handler
Tue Jun 17 11:53:40 2014 : Info: [peap] eaptls_verify returned 1
Tue Jun 17 11:53:40 2014 : Info: [peap] eaptls_process returned 13
Tue Jun 17 11:53:40 2014 : Info: [peap] EAPTLS_HANDLED
Tue Jun 17 11:53:40 2014 : Info: ++[eap] returns handled
Sending Access-Challenge of id 37 to 172.16.210.102 port 1042
         EAP-Message = 
0x014503fc1940a00302010202090084b6b44c2fbb0908300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3134303631373136333134365a170d3134303831363136333134365a308193310b3009060355040613024652310f300d0603550408130652616469757331 

         EAP-Message = 
0x12301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100d14425faab58dc1903ab46788008fe05a0a455bbbd97448504efffa716defed6e2de9bcea58ddfc43a13a84c180ed57498fb599c85be95fe9907cdb957c374123360930164ae1b071a8e52e3ba3843ab2f06f53b13f60b13de4e36ad326fbbaa4cd3f30ca5ec0e4b 

         EAP-Message = 
0xc2fa0793c7b474755477dc1ddeb90c27ecfbf33af6d0e2edc89cba2b7a6d10684a3e100ca16a489052402b3b30469f1296bff0167c11ddf3a68d746552887dbd2660bad06bbe4033e96b5146b507ef1a384c002dde7ae1a3b15552a58ddc4bbff38331b3c35dffd0c77ed439725a722ebab17dcf44a71e0e76b8509f1640f187d551d1cdb17d80d73836939601f70ea775095cecbe2bcc390203010001a381fb3081f8301d0603551d0e041604148274d814aac9cce5746db2efa8e26ecd5bbdd0453081c80603551d230481c03081bd80148274d814aac9cce5746db2efa8e26ecd5bbdd045a18199a48196308193310b300906035504061302465231 

         EAP-Message = 
0x0f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747982090084b6b44c2fbb0908300c0603551d13040530030101ff300d06092a864886f70d010105050003820101009102d14bd7998fb0396d8cafee62b869c1c313920f16166849e69ec11b63f7f9c36dbf31f5da25f3df1633cb8804e1b7d3591c89bfd7a395c8a12b2ea7682b32da4672dee4932a48825b7e 

         EAP-Message = 0xa0e716d5dc21b548
         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xafb682b9acf39b5d9c2f9d64fb6bc98c
Tue Jun 17 11:53:40 2014 : Info: Finished request 3.
Tue Jun 17 11:53:40 2014 : Debug: Going to the next request
Tue Jun 17 11:53:40 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.210.102 port 1042, 
id=38, length=156
         User-Name = "jjenkins"
         NAS-Port = 0
         Called-Station-Id = "2E-A4-3C-65-D0-22:CSI"
         Calling-Station-Id = "84-A6-C8-EE-38-10"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11"
         EAP-Message = 0x024500061900
         State = 0xafb682b9acf39b5d9c2f9d64fb6bc98c
         Message-Authenticator = 0x8d922699881481d5fe2062bd13e9f56b
Tue Jun 17 11:53:40 2014 : Info: # Executing section authorize from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:40 2014 : Info: +- entering group authorize {...}
Tue Jun 17 11:53:40 2014 : Info: ++[preprocess] returns ok
Tue Jun 17 11:53:40 2014 : Info: ++[chap] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[mschap] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[digest] returns noop
Tue Jun 17 11:53:40 2014 : Info: [suffix] No '@' in User-Name = 
"jjenkins", looking up realm NULL
Tue Jun 17 11:53:40 2014 : Info: [suffix] No such realm "NULL"
Tue Jun 17 11:53:40 2014 : Info: ++[suffix] returns noop
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP packet type response id 69 
length 6
Tue Jun 17 11:53:40 2014 : Info: [eap] Continuing tunnel setup.
Tue Jun 17 11:53:40 2014 : Info: ++[eap] returns ok
Tue Jun 17 11:53:40 2014 : Info: Found Auth-Type = EAP
Tue Jun 17 11:53:40 2014 : Info: # Executing group from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:40 2014 : Info: +- entering group authenticate {...}
Tue Jun 17 11:53:40 2014 : Info: [eap] Request found, released from the 
list
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP/peap
Tue Jun 17 11:53:40 2014 : Info: [eap] processing type peap
Tue Jun 17 11:53:40 2014 : Info: [peap] processing EAP-TLS
Tue Jun 17 11:53:40 2014 : Info: [peap] Received TLS ACK
Tue Jun 17 11:53:40 2014 : Info: [peap] ACK handshake fragment handler
Tue Jun 17 11:53:40 2014 : Info: [peap] eaptls_verify returned 1
Tue Jun 17 11:53:40 2014 : Info: [peap] eaptls_process returned 13
Tue Jun 17 11:53:40 2014 : Info: [peap] EAPTLS_HANDLED
Tue Jun 17 11:53:40 2014 : Info: ++[eap] returns handled
Sending Access-Challenge of id 38 to 172.16.210.102 port 1042
         EAP-Message = 
0x014600bc19002dec37025d8c9de67c1f804d75521b05104fb4ce3a0274f11e301d5c88ca918e04417ffeb4efab394cc3f8c37d0530c9b2bde8408be97ee66b201d53743806031e57f6b27fd8272b3aa43fab118b98787a4fbd4f3fa3a83b7d496133b1711083dd18b1aa34bef580fdf7447801cbe7f4ce13774990d76bfdbca778a08fb1eebad156811815259f182c90b16042f28c7e195efad068e43dca2f408e4f57c1af3635d71e5173e37b9b19411281cb16030100040e000000 

         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xafb682b9abf09b5d9c2f9d64fb6bc98c
Tue Jun 17 11:53:40 2014 : Info: Finished request 4.
Tue Jun 17 11:53:40 2014 : Debug: Going to the next request
Tue Jun 17 11:53:40 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.210.102 port 1042, 
id=39, length=488
         User-Name = "jjenkins"
         NAS-Port = 0
         Called-Station-Id = "2E-A4-3C-65-D0-22:CSI"
         Calling-Station-Id = "84-A6-C8-EE-38-10"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11"
         EAP-Message = 
0x0246015019800000014616030101061000010201004ce8ace299ac5fbf94205af77a39ec4f54a0b30afddc59d8cd4ea2f9b09aa0d0ff259a29db66b77e3b124f5c1b164cd719e6979945643becffdb5d899de1c01b7d8ecd52812700fa6160de5ac87703253fc94e888c9c9db0a815dcc69736fad3947f0c8f9f918a68bf507a82a52e5b653841abee20e825f40d8cb75d54815285f08262b86e9a7cc3121217c73977e7f94a25143d87bd4873195f8b55b9eb3be85d16228bce728ce61eb7215145ca6ddaa496f022c5ae6437f7b461227aed4f1840d4caf9834174c71d5334c547632b00a72559f4b91032aa5289b39f0a008a831c058cd0b46fa222 

         EAP-Message = 
0x00e6170adb9c99dcff3408b76c58dfc0c7daaefb46c116d41403010001011603010030c4d647870943f7859e6dbac47726a85b250024e4225859049b5bdcd4626f9534525c6fe818daf0fd5bfc6e184823c852 

         State = 0xafb682b9abf09b5d9c2f9d64fb6bc98c
         Message-Authenticator = 0x2a75ec1ed749a94aa8882486551aedad
Tue Jun 17 11:53:40 2014 : Info: # Executing section authorize from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:40 2014 : Info: +- entering group authorize {...}
Tue Jun 17 11:53:40 2014 : Info: ++[preprocess] returns ok
Tue Jun 17 11:53:40 2014 : Info: ++[chap] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[mschap] returns noop
Tue Jun 17 11:53:40 2014 : Info: ++[digest] returns noop
Tue Jun 17 11:53:40 2014 : Info: [suffix] No '@' in User-Name = 
"jjenkins", looking up realm NULL
Tue Jun 17 11:53:40 2014 : Info: [suffix] No such realm "NULL"
Tue Jun 17 11:53:40 2014 : Info: ++[suffix] returns noop
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP packet type response id 70 
length 253
Tue Jun 17 11:53:40 2014 : Info: [eap] Continuing tunnel setup.
Tue Jun 17 11:53:40 2014 : Info: ++[eap] returns ok
Tue Jun 17 11:53:40 2014 : Info: Found Auth-Type = EAP
Tue Jun 17 11:53:40 2014 : Info: # Executing group from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:40 2014 : Info: +- entering group authenticate {...}
Tue Jun 17 11:53:40 2014 : Info: [eap] Request found, released from the 
list
Tue Jun 17 11:53:40 2014 : Info: [eap] EAP/peap
Tue Jun 17 11:53:40 2014 : Info: [eap] processing type peap
Tue Jun 17 11:53:40 2014 : Info: [peap] processing EAP-TLS
Tue Jun 17 11:53:40 2014 : Debug:   TLS Length 326
Tue Jun 17 11:53:40 2014 : Info: [peap] Length Included
Tue Jun 17 11:53:40 2014 : Info: [peap] eaptls_verify returned 11
Tue Jun 17 11:53:40 2014 : Info: [peap] <<< TLS 1.0 Handshake [length 
0106], ClientKeyExchange
Tue Jun 17 11:53:40 2014 : Info: [peap]     TLS_accept: SSLv3 read 
client key exchange A
Tue Jun 17 11:53:40 2014 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec 
[length 0001]
Tue Jun 17 11:53:40 2014 : Info: [peap] <<< TLS 1.0 Handshake [length 
0010], Finished
Tue Jun 17 11:53:40 2014 : Info: [peap]     TLS_accept: SSLv3 read 
finished A
Tue Jun 17 11:53:40 2014 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec 
[length 0001]
Tue Jun 17 11:53:40 2014 : Info: [peap]     TLS_accept: SSLv3 write 
change cipher spec A
Tue Jun 17 11:53:40 2014 : Info: [peap] >>> TLS 1.0 Handshake [length 
0010], Finished
Tue Jun 17 11:53:40 2014 : Info: [peap]     TLS_accept: SSLv3 write 
finished A
Tue Jun 17 11:53:40 2014 : Info: [peap]     TLS_accept: SSLv3 flush data
Tue Jun 17 11:53:40 2014 : Info: [peap]     (other): SSL negotiation 
finished successfully
Tue Jun 17 11:53:40 2014 : Debug: SSL Connection Established
Tue Jun 17 11:53:40 2014 : Info: [peap] eaptls_process returned 13
Tue Jun 17 11:53:40 2014 : Info: [peap] EAPTLS_HANDLED
Tue Jun 17 11:53:40 2014 : Info: ++[eap] returns handled
Sending Access-Challenge of id 39 to 172.16.210.102 port 1042
         EAP-Message = 
0x01470041190014030100010116030100306a2f1a53d32ceb1a8d16fe572479250f8e7263950cac2608c31c190fa517ee11c0ff70c73a823af98558a07676a5a118 

         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xafb682b9aaf19b5d9c2f9d64fb6bc98c
Tue Jun 17 11:53:40 2014 : Info: Finished request 5.
Tue Jun 17 11:53:40 2014 : Debug: Going to the next request
Tue Jun 17 11:53:40 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.210.102 port 1042, 
id=40, length=156
         User-Name = "jjenkins"
         NAS-Port = 0
         Called-Station-Id = "2E-A4-3C-65-D0-22:CSI"
         Calling-Station-Id = "84-A6-C8-EE-38-10"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11"
         EAP-Message = 0x024700061900
         State = 0xafb682b9aaf19b5d9c2f9d64fb6bc98c
         Message-Authenticator = 0x7974b678b0b13c90b81a5e6d93f4ecfb
Tue Jun 17 11:53:43 2014 : Info: # Executing section authorize from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:43 2014 : Info: +- entering group authorize {...}
Tue Jun 17 11:53:43 2014 : Info: ++[preprocess] returns ok
Tue Jun 17 11:53:43 2014 : Info: ++[chap] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[mschap] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[digest] returns noop
Tue Jun 17 11:53:43 2014 : Info: [suffix] No '@' in User-Name = 
"jjenkins", looking up realm NULL
Tue Jun 17 11:53:43 2014 : Info: [suffix] No such realm "NULL"
Tue Jun 17 11:53:43 2014 : Info: ++[suffix] returns noop
Tue Jun 17 11:53:43 2014 : Info: [eap] EAP packet type response id 71 
length 6
Tue Jun 17 11:53:43 2014 : Info: [eap] Continuing tunnel setup.
Tue Jun 17 11:53:43 2014 : Info: ++[eap] returns ok
Tue Jun 17 11:53:43 2014 : Info: Found Auth-Type = EAP
Tue Jun 17 11:53:43 2014 : Info: # Executing group from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:43 2014 : Info: +- entering group authenticate {...}
Tue Jun 17 11:53:43 2014 : Info: [eap] Request found, released from the 
list
Tue Jun 17 11:53:43 2014 : Info: [eap] EAP/peap
Tue Jun 17 11:53:43 2014 : Info: [eap] processing type peap
Tue Jun 17 11:53:43 2014 : Info: [peap] processing EAP-TLS
Tue Jun 17 11:53:43 2014 : Info: [peap] Received TLS ACK
Tue Jun 17 11:53:43 2014 : Info: [peap] ACK handshake is finished
Tue Jun 17 11:53:43 2014 : Info: [peap] eaptls_verify returned 3
Tue Jun 17 11:53:43 2014 : Info: [peap] eaptls_process returned 3
Tue Jun 17 11:53:43 2014 : Info: [peap] EAPTLS_SUCCESS
Tue Jun 17 11:53:43 2014 : Info: [peap] Session established. Decoding 
tunneled attributes.
Tue Jun 17 11:53:43 2014 : Info: [peap] Peap state TUNNEL ESTABLISHED
Tue Jun 17 11:53:43 2014 : Info: ++[eap] returns handled
Sending Access-Challenge of id 40 to 172.16.210.102 port 1042
         EAP-Message = 
0x0148002b190017030100208b842487a9ece6c4645dfe6eab53bac347a26b42fef13f924c7ef558604c59fd 

         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xafb682b9a9fe9b5d9c2f9d64fb6bc98c
Tue Jun 17 11:53:43 2014 : Info: Finished request 6.
Tue Jun 17 11:53:43 2014 : Debug: Going to the next request
Tue Jun 17 11:53:43 2014 : Debug: Waking up in 2.2 seconds.
rad_recv: Access-Request packet from host 172.16.210.102 port 1042, 
id=41, length=193
         User-Name = "jjenkins"
         NAS-Port = 0
         Called-Station-Id = "2E-A4-3C-65-D0-22:CSI"
         Calling-Station-Id = "84-A6-C8-EE-38-10"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11"
         EAP-Message = 
0x0248002b1900170301002040e1523f190ad3904b2e70b37864dbebbec2ae9506cc37bc3762b602a7bd6c78 

         State = 0xafb682b9a9fe9b5d9c2f9d64fb6bc98c
         Message-Authenticator = 0xf105b39afb6a257dd6fbf0542fe7ed2a
Tue Jun 17 11:53:43 2014 : Info: # Executing section authorize from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:43 2014 : Info: +- entering group authorize {...}
Tue Jun 17 11:53:43 2014 : Info: ++[preprocess] returns ok
Tue Jun 17 11:53:43 2014 : Info: ++[chap] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[mschap] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[digest] returns noop
Tue Jun 17 11:53:43 2014 : Info: [suffix] No '@' in User-Name = 
"jjenkins", looking up realm NULL
Tue Jun 17 11:53:43 2014 : Info: [suffix] No such realm "NULL"
Tue Jun 17 11:53:43 2014 : Info: ++[suffix] returns noop
Tue Jun 17 11:53:43 2014 : Info: [eap] EAP packet type response id 72 
length 43
Tue Jun 17 11:53:43 2014 : Info: [eap] Continuing tunnel setup.
Tue Jun 17 11:53:43 2014 : Info: ++[eap] returns ok
Tue Jun 17 11:53:43 2014 : Info: Found Auth-Type = EAP
Tue Jun 17 11:53:43 2014 : Info: # Executing group from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:43 2014 : Info: +- entering group authenticate {...}
Tue Jun 17 11:53:43 2014 : Info: [eap] Request found, released from the 
list
Tue Jun 17 11:53:43 2014 : Info: [eap] EAP/peap
Tue Jun 17 11:53:43 2014 : Info: [eap] processing type peap
Tue Jun 17 11:53:43 2014 : Info: [peap] processing EAP-TLS
Tue Jun 17 11:53:43 2014 : Info: [peap] eaptls_verify returned 7
Tue Jun 17 11:53:43 2014 : Info: [peap] Done initial handshake
Tue Jun 17 11:53:43 2014 : Info: [peap] eaptls_process returned 7
Tue Jun 17 11:53:43 2014 : Info: [peap] EAPTLS_OK
Tue Jun 17 11:53:43 2014 : Info: [peap] Session established. Decoding 
tunneled attributes.
Tue Jun 17 11:53:43 2014 : Info: [peap] Peap state WAITING FOR INNER 
IDENTITY
Tue Jun 17 11:53:43 2014 : Info: [peap] Identity - jjenkins
Tue Jun 17 11:53:43 2014 : Info: [peap] Got inner identity 'jjenkins'
Tue Jun 17 11:53:43 2014 : Info: [peap] Setting default EAP type for 
tunneled EAP session.
Tue Jun 17 11:53:43 2014 : Info: [peap] Got tunneled request
         EAP-Message = 0x0248000d016a6a656e6b696e73
server {
Tue Jun 17 11:53:43 2014 : Info: [peap] Setting User-Name to jjenkins
Sending tunneled request
         EAP-Message = 0x0248000d016a6a656e6b696e73
         FreeRADIUS-Proxied-To = 127.0.0.1
         User-Name = "jjenkins"
server inner-tunnel {
Tue Jun 17 11:53:43 2014 : Info: # Executing section authorize from file 
/etc/raddb/sites-enabled/inner-tunnel
Tue Jun 17 11:53:43 2014 : Info: +- entering group authorize {...}
Tue Jun 17 11:53:43 2014 : Info: ++[chap] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[mschap] returns noop
Tue Jun 17 11:53:43 2014 : Info: [suffix] No '@' in User-Name = 
"jjenkins", looking up realm NULL
Tue Jun 17 11:53:43 2014 : Info: [suffix] No such realm "NULL"
Tue Jun 17 11:53:43 2014 : Info: ++[suffix] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[control] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[files] returns noop
Tue Jun 17 11:53:43 2014 : Info: [ldap] performing user authorization 
for jjenkins
Tue Jun 17 11:53:43 2014 : Info: [ldap]         expand: 
%{Stripped-User-Name} ->
Tue Jun 17 11:53:43 2014 : Info: [ldap]         ... expanding second 
conditional
Tue Jun 17 11:53:43 2014 : Info: [ldap]         expand: %{User-Name} -> 
jjenkins
Tue Jun 17 11:53:43 2014 : Info: [ldap]         expand: 
(uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=jjenkins)
Tue Jun 17 11:53:43 2014 : Info: [ldap]         expand: 
cn=accounts,dc=csi,dc=com -> cn=accounts,dc=csi,dc=com
Tue Jun 17 11:53:43 2014 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Tue Jun 17 11:53:43 2014 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Tue Jun 17 11:53:43 2014 : Debug:   [ldap] performing search in 
cn=accounts,dc=csi,dc=com, with filter (uid=jjenkins)
Tue Jun 17 11:53:43 2014 : Info: [ldap] looking for check items in 
directory...
Tue Jun 17 11:53:43 2014 : Info: [ldap] looking for reply items in 
directory...
Tue Jun 17 11:53:43 2014 : Debug: WARNING: No "known good" password was 
found in LDAP.  Are you sure that the user is configured correctly?
Tue Jun 17 11:53:43 2014 : Info: [ldap] user jjenkins authorized to use 
remote access
Tue Jun 17 11:53:43 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Tue Jun 17 11:53:43 2014 : Info: ++[ldap] returns ok
Tue Jun 17 11:53:43 2014 : Info: ++[expiration] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[logintime] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[pap] returns noop
Tue Jun 17 11:53:43 2014 : Info: ERROR: No authenticate method 
(Auth-Type) found for the request: Rejecting the user
Tue Jun 17 11:53:43 2014 : Info: Failed to authenticate the user.
} # server inner-tunnel
Tue Jun 17 11:53:43 2014 : Info: [peap] Got tunneled reply code 3
Tue Jun 17 11:53:43 2014 : Info: [peap] Got tunneled reply RADIUS code 3
Tue Jun 17 11:53:43 2014 : Info: [peap] Tunneled authentication was 
rejected.
Tue Jun 17 11:53:43 2014 : Info: [peap] FAILURE
Tue Jun 17 11:53:43 2014 : Info: ++[eap] returns handled
Sending Access-Challenge of id 41 to 172.16.210.102 port 1042
         EAP-Message = 
0x0149002b1900170301002040e0262abb96586735b5f83d6e99164c46d2bf568f8147a5105e2afa742d1725 

         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xafb682b9a8ff9b5d9c2f9d64fb6bc98c
Tue Jun 17 11:53:43 2014 : Info: Finished request 7.
Tue Jun 17 11:53:43 2014 : Debug: Going to the next request
Tue Jun 17 11:53:43 2014 : Debug: Waking up in 2.2 seconds.
rad_recv: Access-Request packet from host 172.16.210.102 port 1042, 
id=42, length=193
         User-Name = "jjenkins"
         NAS-Port = 0
         Called-Station-Id = "2E-A4-3C-65-D0-22:CSI"
         Calling-Station-Id = "84-A6-C8-EE-38-10"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11"
         EAP-Message = 
0x0249002b19001703010020d4932f0865c11f694a473026923b1187c4fab1e9a1c207df933b817447bb8014
         State = 0xafb682b9a8ff9b5d9c2f9d64fb6bc98c
         Message-Authenticator = 0xc3291af200d8743b9c8296c29b12ca21
Tue Jun 17 11:53:43 2014 : Info: # Executing section authorize from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:43 2014 : Info: +- entering group authorize {...}
Tue Jun 17 11:53:43 2014 : Info: ++[preprocess] returns ok
Tue Jun 17 11:53:43 2014 : Info: ++[chap] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[mschap] returns noop
Tue Jun 17 11:53:43 2014 : Info: ++[digest] returns noop
Tue Jun 17 11:53:43 2014 : Info: [suffix] No '@' in User-Name = 
"jjenkins", looking up realm NULL
Tue Jun 17 11:53:43 2014 : Info: [suffix] No such realm "NULL"
Tue Jun 17 11:53:43 2014 : Info: ++[suffix] returns noop
Tue Jun 17 11:53:43 2014 : Info: [eap] EAP packet type response id 73 
length 43
Tue Jun 17 11:53:43 2014 : Info: [eap] Continuing tunnel setup.
Tue Jun 17 11:53:43 2014 : Info: ++[eap] returns ok
Tue Jun 17 11:53:43 2014 : Info: Found Auth-Type = EAP
Tue Jun 17 11:53:43 2014 : Info: # Executing group from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:43 2014 : Info: +- entering group authenticate {...}
Tue Jun 17 11:53:43 2014 : Info: [eap] Request found, released from the list
Tue Jun 17 11:53:43 2014 : Info: [eap] EAP/peap
Tue Jun 17 11:53:43 2014 : Info: [eap] processing type peap
Tue Jun 17 11:53:43 2014 : Info: [peap] processing EAP-TLS
Tue Jun 17 11:53:43 2014 : Info: [peap] eaptls_verify returned 7
Tue Jun 17 11:53:43 2014 : Info: [peap] Done initial handshake
Tue Jun 17 11:53:43 2014 : Info: [peap] eaptls_process returned 7
Tue Jun 17 11:53:43 2014 : Info: [peap] EAPTLS_OK
Tue Jun 17 11:53:43 2014 : Info: [peap] Session established. Decoding 
tunneled attributes.
Tue Jun 17 11:53:43 2014 : Info: [peap] Peap state send tlv failure
Tue Jun 17 11:53:43 2014 : Info: [peap] Received EAP-TLV response.
Tue Jun 17 11:53:43 2014 : Info: [peap]  The users session was 
previously rejected: returning reject (again.)
Tue Jun 17 11:53:43 2014 : Info: [peap]  *** This means you need to read 
the PREVIOUS messages in the debug output
Tue Jun 17 11:53:43 2014 : Info: [peap]  *** to find out the reason why 
the user was rejected.
Tue Jun 17 11:53:43 2014 : Info: [peap]  *** Look for "reject" or 
"fail".  Those earlier messages will tell you.
Tue Jun 17 11:53:43 2014 : Info: [peap]  *** what went wrong, and how to 
fix the problem.
Tue Jun 17 11:53:43 2014 : Info: [eap] Handler failed in EAP/peap
Tue Jun 17 11:53:43 2014 : Info: [eap] Failed in EAP select
Tue Jun 17 11:53:43 2014 : Info: ++[eap] returns invalid
Tue Jun 17 11:53:43 2014 : Info: Failed to authenticate the user.
Tue Jun 17 11:53:43 2014 : Info: Using Post-Auth-Type Reject
Tue Jun 17 11:53:43 2014 : Info: # Executing group from file 
/etc/raddb/sites-enabled/default
Tue Jun 17 11:53:43 2014 : Info: +- entering group REJECT {...}
Tue Jun 17 11:53:43 2014 : Info: [attr_filter.access_reject] expand: 
%{User-Name} -> jjenkins
Tue Jun 17 11:53:43 2014 : Debug: attr_filter: Matched entry DEFAULT at 
line 11
Tue Jun 17 11:53:43 2014 : Info: ++[attr_filter.access_reject] returns 
updated
Tue Jun 17 11:53:43 2014 : Info: Delaying reject of request 8 for 1 seconds
Tue Jun 17 11:53:43 2014 : Debug: Going to the next request
Tue Jun 17 11:53:43 2014 : Debug: Waking up in 0.9 seconds.
Tue Jun 17 11:53:44 2014 : Info: Sending delayed reject for request 8
Sending Access-Reject of id 42 to 172.16.210.102 port 1042
         EAP-Message = 0x04490004
         Message-Authenticator = 0x00000000000000000000000000000000
Tue Jun 17 11:53:44 2014 : Debug: Waking up in 1.2 seconds.
Tue Jun 17 11:53:45 2014 : Info: Cleaning up request 0 ID 34 with 
timestamp +8
Tue Jun 17 11:53:45 2014 : Info: Cleaning up request 1 ID 35 with 
timestamp +8
Tue Jun 17 11:53:45 2014 : Info: Cleaning up request 2 ID 36 with 
timestamp +8
Tue Jun 17 11:53:45 2014 : Info: Cleaning up request 3 ID 37 with 
timestamp +8
Tue Jun 17 11:53:45 2014 : Info: Cleaning up request 4 ID 38 with 
timestamp +8
Tue Jun 17 11:53:45 2014 : Info: Cleaning up request 5 ID 39 with 
timestamp +8
Tue Jun 17 11:53:45 2014 : Debug: Waking up in 2.6 seconds.
Tue Jun 17 11:53:48 2014 : Info: Cleaning up request 6 ID 40 with 
timestamp +11
Tue Jun 17 11:53:48 2014 : Info: Cleaning up request 7 ID 41 with 
timestamp +11
Tue Jun 17 11:53:48 2014 : Debug: Waking up in 1.0 seconds.
Tue Jun 17 11:53:49 2014 : Info: Cleaning up request 8 ID 42 with 
timestamp +11
Tue Jun 17 11:53:49 2014 : Info: Ready to process requests.

LDAP auth

Jon Jenkins