freeradius 1.1.3 to 2.1.10 migration vlan assignment woes

21 Nov 2011


      So I'm moving from an old 1.1.3 (running on rhel5) to 2.1.10 (rhel6). We use EAP-TTLS > PAP which authenticates against openldap and
dynamically assigns vlans based on ldap group properties. I seem to have gotten the authentication working, but the vlan assignment
doesn't appear to be happening. All of our users end up in the default vlan (60). I'm getting a 'No "known good" password' error,
but the bind still seems to be succeeding. Output of radiusd -X is below.

FreeRADIUS Version 2.1.10, for host x86_64-redhat-linux-gnu, built on Mar 25 2011 at 10:54:38
Copyright (C) 1999-2009 The FreeRADIUS server project and contributors. 
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A 
PARTICULAR PURPOSE. 
You may redistribute copies of FreeRADIUS under the terms of the 
GNU General Public License v2. 
Starting - reading configuration files ...
including configuration file /etc/raddb/radiusd.conf
including configuration file /etc/raddb/proxy.conf
including configuration file /etc/raddb/clients.conf
including files in directory /etc/raddb/modules/
including configuration file /etc/raddb/modules/pap
including configuration file /etc/raddb/modules/pap.rpmsave
including configuration file /etc/raddb/modules/inner-eap
including configuration file /etc/raddb/modules/detail.log
including configuration file /etc/raddb/modules/logintime
including configuration file /etc/raddb/modules/exec
including configuration file /etc/raddb/modules/smbpasswd
including configuration file /etc/raddb/modules/detail
including configuration file /etc/raddb/modules/mschap
including configuration file /etc/raddb/modules/otp
including configuration file /etc/raddb/modules/dynamic_clients
including configuration file /etc/raddb/modules/linelog
including configuration file /etc/raddb/modules/preprocess
including configuration file /etc/raddb/modules/policy
including configuration file /etc/raddb/modules/checkval
including configuration file /etc/raddb/modules/pam
including configuration file /etc/raddb/modules/detail.example.com
including configuration file /etc/raddb/modules/ntlm_auth
including configuration file /etc/raddb/modules/files
including configuration file /etc/raddb/modules/echo
including configuration file /etc/raddb/modules/sradutmp
including configuration file /etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /etc/raddb/modules/smsotp
including configuration file /etc/raddb/modules/etc_group
including configuration file /etc/raddb/modules/chap
including configuration file /etc/raddb/modules/attr_rewrite
including configuration file /etc/raddb/modules/mac2ip
including configuration file /etc/raddb/modules/opendirectory
including configuration file /etc/raddb/modules/unix
including configuration file /etc/raddb/modules/wimax
including configuration file /etc/raddb/modules/digest
including configuration file /etc/raddb/modules/ldap
including configuration file /etc/raddb/modules/realm
including configuration file /etc/raddb/modules/expr
including configuration file /etc/raddb/modules/passwd
including configuration file /etc/raddb/modules/perl
including configuration file /etc/raddb/modules/ippool
including configuration file /etc/raddb/modules/mac2vlan
including configuration file /etc/raddb/modules/cui
including configuration file /etc/raddb/modules/radutmp
including configuration file /etc/raddb/modules/sql_log
including configuration file /etc/raddb/modules/attr_filter
including configuration file /etc/raddb/modules/always
including configuration file /etc/raddb/modules/expiration
including configuration file /etc/raddb/modules/counter
including configuration file /etc/raddb/modules/acct_unique
including configuration file /etc/raddb/eap.conf
including configuration file /etc/raddb/policy.conf
including files in directory /etc/raddb/sites-enabled/
including configuration file /etc/raddb/sites-enabled/inner-tunnel
including configuration file /etc/raddb/sites-enabled/control-socket
including configuration file /etc/raddb/sites-enabled/default
main {
	user = "radiusd"
	group = "radiusd"
	allow_core_dumps = no
}
including dictionary file /etc/raddb/dictionary
main {
	prefix = "/usr"
	localstatedir = "/var"
	logdir = "/var/log/radius"
	libdir = "/usr/lib64/freeradius"
	radacctdir = "/var/log/radius/radacct"
	hostname_lookups = no
	max_request_time = 30
	cleanup_delay = 5
	max_requests = 1024
	pidfile = "/var/run/radiusd/radiusd.pid"
	checkrad = "/usr/sbin/checkrad"
	debug_level = 0
	proxy_requests = yes
 log {
	stripped_names = no
	auth = no
	auth_badpass = no
	auth_goodpass = no
 }
 security {
	max_attributes = 200
	reject_delay = 1
	status_server = yes
 }
}
radiusd: #### Loading Realms and Home Servers ####
 proxy server {
	retry_delay = 5
	retry_count = 3
	default_fallback = no
	dead_time = 120
	wake_all_if_all_dead = no
 }
 home_server localhost {
	ipaddr = 127.0.0.1
	port = 1812
	type = "auth"
	secret = "testsecret"
	response_window = 20
	max_outstanding = 65536
	require_message_authenticator = yes
	zombie_period = 40
	status_check = "status-server"
	ping_interval = 30
	check_interval = 30
	num_answers_to_alive = 3
	num_pings_to_alive = 3
	revive_interval = 120
	status_check_timeout = 4
	irt = 2
	mrt = 16
	mrc = 5
	mrd = 30
 }
 home_server_pool my_auth_failover {
	type = fail-over
	home_server = localhost
 }
 realm example.com {
	auth_pool = my_auth_failover
 }
 realm LOCAL {
 }
radiusd: #### Loading Clients ####
 client DOMAIN-WLC1 {
	ipaddr = 10.5.11.5
	require_message_authenticator = no
	secret = "testsecret"
	nastype = "cisco"
 }
 client DOMAIN-WLC2 {
	ipaddr = 10.5.11.6
	require_message_authenticator = no
	secret = "testsecret"
	nastype = "cisco"
 }
 client bartleby {
	ipaddr = 10.30.2.59
	require_message_authenticator = no
	secret = "testsecret"
	nastype = "other"
 }
 client localhost {
	ipaddr = 127.0.0.1
	require_message_authenticator = no
	secret = "testsecret"
	nastype = "other"
 }
radiusd: #### Instantiating modules ####
 instantiate {
 Module: Linked to module rlm_exec
 Module: Instantiating module "exec" from file /etc/raddb/modules/exec
  exec {
	wait = no
	input_pairs = "request"
	shell_escape = yes
  }
 Module: Linked to module rlm_expr
 Module: Instantiating module "expr" from file /etc/raddb/modules/expr
 Module: Linked to module rlm_expiration
 Module: Instantiating module "expiration" from file /etc/raddb/modules/expiration
  expiration {
	reply-message = "Password Has Expired  "
  }
 Module: Linked to module rlm_logintime
 Module: Instantiating module "logintime" from file /etc/raddb/modules/logintime
  logintime {
	reply-message = "You are calling outside your allowed timespan  "
	minimum-timeout = 60
  }
 }
radiusd: #### Loading Virtual Servers ####
server inner-tunnel { # from file /etc/raddb/sites-enabled/inner-tunnel
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_pap
 Module: Instantiating module "pap" from file /etc/raddb/modules/pap
  pap {
	encryption_scheme = "auto"
	auto_header = no
  }
 Module: Linked to module rlm_chap
 Module: Instantiating module "chap" from file /etc/raddb/modules/chap
 Module: Linked to module rlm_mschap
 Module: Instantiating module "mschap" from file /etc/raddb/modules/mschap
  mschap {
	use_mppe = yes
	require_encryption = no
	require_strong = no
	with_ntdomain_hack = no
  }
 Module: Linked to module rlm_unix
 Module: Instantiating module "unix" from file /etc/raddb/modules/unix
  unix {
	radwtmp = "/var/log/radius/radwtmp"
  }
 Module: Linked to module rlm_ldap
 Module: Instantiating module "ldap" from file /etc/raddb/modules/ldap
  ldap {
	server = "ldap1.domain.edu"
	port = 389
	password = ""
	identity = ""
	net_timeout = 1
	timeout = 4
	timelimit = 3
	tls_mode = no
	start_tls = no
	tls_require_cert = "allow"
   tls {
	start_tls = no
	require_cert = "allow"
   }
	basedn = "dc=domain,dc=edu"
	filter = "(uid=%u)"
	base_filter = "(objectclass=personSR)"
	password_attribute = "userPassword"
	auto_header = no
	access_attr = "uid"
	access_attr_used_for_allow = yes
	groupname_attribute = "groupSR"
	groupmembership_filter = "(&(objectClass=personSR)(uid=%{User-Name}))"
	groupmembership_attribute = "groupSR"
	dictionary_mapping = "/etc/raddb/ldap.attrmap"
	ldap_debug = 0
	ldap_connections_number = 5
	compare_check_items = no
	do_xlat = yes
	set_auth_type = yes
  }
rlm_ldap: Registering ldap_groupcmp for Ldap-Group
rlm_ldap: Registering ldap_xlat with xlat_name ldap
rlm_ldap: reading ldap<->radius mappings from file /etc/raddb/ldap.attrmap
rlm_ldap: LDAP userPassword mapped to RADIUS User-Password
rlm_ldap: LDAP radiusCheckItem mapped to RADIUS $GENERIC$
rlm_ldap: LDAP radiusReplyItem mapped to RADIUS $GENERIC$
rlm_ldap: LDAP radiusAuthType mapped to RADIUS Auth-Type
rlm_ldap: LDAP radiusSimultaneousUse mapped to RADIUS Simultaneous-Use
rlm_ldap: LDAP radiusCalledStationId mapped to RADIUS Called-Station-Id
rlm_ldap: LDAP radiusCallingStationId mapped to RADIUS Calling-Station-Id
rlm_ldap: LDAP lmPassword mapped to RADIUS LM-Password
rlm_ldap: LDAP ntPassword mapped to RADIUS NT-Password
rlm_ldap: LDAP sambaLmPassword mapped to RADIUS LM-Password
rlm_ldap: LDAP sambaNtPassword mapped to RADIUS NT-Password
rlm_ldap: LDAP dBCSPwd mapped to RADIUS LM-Password
rlm_ldap: LDAP userPassword mapped to RADIUS Password-With-Header
rlm_ldap: LDAP acctFlags mapped to RADIUS SMB-Account-CTRL-TEXT
rlm_ldap: LDAP radiusExpiration mapped to RADIUS Expiration
rlm_ldap: LDAP radiusNASIpAddress mapped to RADIUS NAS-IP-Address
rlm_ldap: LDAP radiusServiceType mapped to RADIUS Service-Type
rlm_ldap: LDAP radiusFramedProtocol mapped to RADIUS Framed-Protocol
rlm_ldap: LDAP radiusFramedIPAddress mapped to RADIUS Framed-IP-Address
rlm_ldap: LDAP radiusFramedIPNetmask mapped to RADIUS Framed-IP-Netmask
rlm_ldap: LDAP radiusFramedRoute mapped to RADIUS Framed-Route
rlm_ldap: LDAP radiusFramedRouting mapped to RADIUS Framed-Routing
rlm_ldap: LDAP radiusFilterId mapped to RADIUS Filter-Id
rlm_ldap: LDAP radiusFramedMTU mapped to RADIUS Framed-MTU
rlm_ldap: LDAP radiusFramedCompression mapped to RADIUS Framed-Compression
rlm_ldap: LDAP radiusLoginIPHost mapped to RADIUS Login-IP-Host
rlm_ldap: LDAP radiusLoginService mapped to RADIUS Login-Service
rlm_ldap: LDAP radiusLoginTCPPort mapped to RADIUS Login-TCP-Port
rlm_ldap: LDAP radiusCallbackNumber mapped to RADIUS Callback-Number
rlm_ldap: LDAP radiusCallbackId mapped to RADIUS Callback-Id
rlm_ldap: LDAP radiusFramedIPXNetwork mapped to RADIUS Framed-IPX-Network
rlm_ldap: LDAP radiusClass mapped to RADIUS Class
rlm_ldap: LDAP radiusSessionTimeout mapped to RADIUS Session-Timeout
rlm_ldap: LDAP radiusIdleTimeout mapped to RADIUS Idle-Timeout
rlm_ldap: LDAP radiusTerminationAction mapped to RADIUS Termination-Action
rlm_ldap: LDAP radiusLoginLATService mapped to RADIUS Login-LAT-Service
rlm_ldap: LDAP radiusLoginLATNode mapped to RADIUS Login-LAT-Node
rlm_ldap: LDAP radiusLoginLATGroup mapped to RADIUS Login-LAT-Group
rlm_ldap: LDAP radiusFramedAppleTalkLink mapped to RADIUS Framed-AppleTalk-Link
rlm_ldap: LDAP radiusFramedAppleTalkNetwork mapped to RADIUS Framed-AppleTalk-Network
rlm_ldap: LDAP radiusFramedAppleTalkZone mapped to RADIUS Framed-AppleTalk-Zone
rlm_ldap: LDAP radiusPortLimit mapped to RADIUS Port-Limit
rlm_ldap: LDAP radiusLoginLATPort mapped to RADIUS Login-LAT-Port
rlm_ldap: LDAP radiusReplyMessage mapped to RADIUS Reply-Message
conns: 0x7f62718804e0
 Module: Linked to module rlm_eap
 Module: Instantiating module "eap" from file /etc/raddb/eap.conf
  eap {
	default_eap_type = "md5"
	timer_expire = 60
	ignore_unknown_eap_types = no
	cisco_accounting_username_bug = no
	max_sessions = 4096
  }
 Module: Linked to sub-module rlm_eap_md5
 Module: Instantiating eap-md5
 Module: Linked to sub-module rlm_eap_leap
 Module: Instantiating eap-leap
 Module: Linked to sub-module rlm_eap_gtc
 Module: Instantiating eap-gtc
   gtc {
	challenge = "Password: "
	auth_type = "PAP"
   }
 Module: Linked to sub-module rlm_eap_tls
 Module: Instantiating eap-tls
   tls {
	rsa_key_exchange = no
	dh_key_exchange = yes
	rsa_key_length = 512
	dh_key_length = 512
	verify_depth = 0
	CA_path = "/etc/raddb/certs"
	pem_file_type = yes
	private_key_file = "/etc/raddb/certs/wildcard.pem"
	certificate_file = "/etc/raddb/certs/wildcard.pem"
	CA_file = "/etc/raddb/certs/wildcardca.pem"
	dh_file = "/etc/raddb/certs/dh"
	random_file = "/etc/raddb/certs/random"
	fragment_size = 1024
	include_length = yes
	check_crl = no
	cipher_list = "DEFAULT"
    cache {
	enable = no
	lifetime = 24
	max_entries = 255
    }
    verify {
    }
   }
 Module: Linked to sub-module rlm_eap_ttls
 Module: Instantiating eap-ttls
   ttls {
	default_eap_type = "md5"
	copy_request_to_tunnel = no
	use_tunneled_reply = no
	virtual_server = "inner-tunnel"
	include_length = yes
   }
 Module: Linked to sub-module rlm_eap_peap
 Module: Instantiating eap-peap
   peap {
	default_eap_type = "mschapv2"
	copy_request_to_tunnel = no
	use_tunneled_reply = no
	proxy_tunneled_request_as_eap = yes
	virtual_server = "inner-tunnel"
   }
 Module: Linked to sub-module rlm_eap_mschapv2
 Module: Instantiating eap-mschapv2
   mschapv2 {
	with_ntdomain_hack = no
   }
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_realm
 Module: Instantiating module "suffix" from file /etc/raddb/modules/realm
  realm suffix {
	format = "suffix"
	delimiter = "@"
	ignore_default = no
	ignore_null = no
  }
 Module: Linked to module rlm_files
 Module: Instantiating module "files" from file /etc/raddb/modules/files
  files {
	usersfile = "/etc/raddb/users"
	acctusersfile = "/etc/raddb/acct_users"
	preproxy_usersfile = "/etc/raddb/preproxy_users"
	compat = "no"
  }
 Module: Checking session {...} for more modules to load
 Module: Linked to module rlm_radutmp
 Module: Instantiating module "radutmp" from file /etc/raddb/modules/radutmp
  radutmp {
	filename = "/var/log/radius/radutmp"
	username = "%{User-Name}"
	case_sensitive = yes
	check_with_nas = yes
	perm = 384
	callerid = yes
  }
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 Module: Linked to module rlm_attr_filter
 Module: Instantiating module "attr_filter.access_reject" from file /etc/raddb/modules/attr_filter
  attr_filter attr_filter.access_reject {
	attrsfile = "/etc/raddb/attrs.access_reject"
	key = "%{User-Name}"
  }
 } # modules
} # server
server { # from file /etc/raddb/radiusd.conf
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_digest
 Module: Instantiating module "digest" from file /etc/raddb/modules/digest
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating module "preprocess" from file /etc/raddb/modules/preprocess
  preprocess {
	huntgroups = "/etc/raddb/huntgroups"
	hints = "/etc/raddb/hints"
	with_ascend_hack = no
	ascend_channels_per_line = 23
	with_ntdomain_hack = no
	with_specialix_jetstream_hack = no
	with_cisco_vsa_hack = no
	with_alvarion_vsa_hack = no
  }
 Module: Checking preacct {...} for more modules to load
 Module: Linked to module rlm_acct_unique
 Module: Instantiating module "acct_unique" from file /etc/raddb/modules/acct_unique
  acct_unique {
	key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
  }
 Module: Checking accounting {...} for more modules to load
 Module: Linked to module rlm_detail
 Module: Instantiating module "detail" from file /etc/raddb/modules/detail
  detail {
	detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
	header = "%t"
	detailperm = 384
	dirperm = 493
	locking = no
	log_packet_header = no
  }
 Module: Instantiating module "attr_filter.accounting_response" from file /etc/raddb/modules/attr_filter
  attr_filter attr_filter.accounting_response {
	attrsfile = "/etc/raddb/attrs.accounting_response"
	key = "%{User-Name}"
  }
 Module: Checking session {...} for more modules to load
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 } # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
	type = "auth"
	ipaddr = *
	port = 0
}
listen {
	type = "acct"
	ipaddr = *
	port = 0
}
listen {
	type = "control"
 listen {
	socket = "/var/run/radiusd/radiusd.sock"
 }
}
listen {
	type = "auth"
	ipaddr = 127.0.0.1
	port = 18120
}
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on command file /var/run/radiusd/radiusd.sock
Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel
Listening on proxy address * port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 10.5.11.6 port 32768, id=196, length=222
	User-Name = "testuser"
	Calling-Station-Id = "40-fc-89-f1-a9-c2"
	Called-Station-Id = "00-1f-6c-a9-85-d0:its-test"
	NAS-Port = 29
	Cisco-AVPair = "audit-session-id=0a050b0600013b924eca67ab"
	NAS-IP-Address = 10.5.11.6
	NAS-Identifier = "DOMAIN-WLC2"
	Airespace-Wlan-Id = 3
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "60"
	EAP-Message = 0x020100090174737475
	Message-Authenticator = 0xb9df6207236d61485cc6e3ec6f854285
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "testuser", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 1 length 9
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (uid=%u) -> (uid=testuser)
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] attempting LDAP reconnection
  [ldap] (re)connect to ldap1.domain.edu:389, authentication 0
  [ldap] bind as / to ldap1.domain.edu:389
  [ldap] waiting for bind result ...
  [ldap] Bind was successful
  [ldap] performing search in dc=domain,dc=edu, with filter (uid=testuser)
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=student)(&(objectClass=personSR)(uid=testuser)))
rlm_ldap::ldap_groupcmp: User found in group student
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=staff)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group staff not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=faculty)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group faculty not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=faculty)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group faculty not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=staff)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group staff not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=student)(&(objectClass=personSR)(uid=testuser)))
rlm_ldap::ldap_groupcmp: User found in group student
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=faculty)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group faculty not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=staff)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group staff not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=student)(&(objectClass=personSR)(uid=testuser)))
rlm_ldap::ldap_groupcmp: User found in group student
  [ldap] ldap_release_conn: Release Id: 0
[files] users: Matched entry DEFAULT at line 244
++[files] returns ok
[ldap] performing user authorization for testuser
[ldap] 	expand: (uid=%u) -> (uid=testuser)
[ldap] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (uid=testuser)
[ldap] checking if remote access for testuser is allowed by uid
[ldap] looking for check items in directory...
[ldap] looking for reply items in directory...
WARNING: No "known good" password was found in LDAP.  Are you sure that the user is configured correctly?
[ldap] user testuser authorized to use remote access
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 196 to 10.5.11.6 port 32768
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "360"
	EAP-Message = 0x010200160410d42afb9857f9eb60d2a963f11b6f02a6
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x0a0be8430a09ec3409af9106d0fa8ef1
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.5.11.6 port 32768, id=197, length=237
	User-Name = "testuser"
	Calling-Station-Id = "40-fc-89-f1-a9-c2"
	Called-Station-Id = "00-1f-6c-a9-85-d0:its-test"
	NAS-Port = 29
	Cisco-AVPair = "audit-session-id=0a050b0600013b924eca67ab"
	NAS-IP-Address = 10.5.11.6
	NAS-Identifier = "DOMAIN-WLC2"
	Airespace-Wlan-Id = 3
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "60"
	EAP-Message = 0x020200060315
	State = 0x0a0be8430a09ec3409af9106d0fa8ef1
	Message-Authenticator = 0xc891b270527a9a333810bd7328d251e7
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "testuser", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 2 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (uid=%u) -> (uid=testuser)
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (uid=testuser)
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=student)(&(objectClass=personSR)(uid=testuser)))
rlm_ldap::ldap_groupcmp: User found in group student
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=staff)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group staff not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=faculty)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group faculty not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=faculty)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group faculty not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=staff)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group staff not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=student)(&(objectClass=personSR)(uid=testuser)))
rlm_ldap::ldap_groupcmp: User found in group student
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=faculty)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group faculty not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=staff)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group staff not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=student)(&(objectClass=personSR)(uid=testuser)))
rlm_ldap::ldap_groupcmp: User found in group student
  [ldap] ldap_release_conn: Release Id: 0
[files] users: Matched entry DEFAULT at line 244
++[files] returns ok
[ldap] performing user authorization for testuser
[ldap] 	expand: (uid=%u) -> (uid=testuser)
[ldap] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (uid=testuser)
[ldap] checking if remote access for testuser is allowed by uid
[ldap] looking for check items in directory...
[ldap] looking for reply items in directory...
WARNING: No "known good" password was found in LDAP.  Are you sure that the user is configured correctly?
[ldap] user testuser authorized to use remote access
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/ttls
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 197 to 10.5.11.6 port 32768
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "360"
	EAP-Message = 0x010300061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x0a0be8430b08fd3409af9106d0fa8ef1
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.5.11.6 port 32768, id=198, length=427
	User-Name = "testuser"
	Calling-Station-Id = "40-fc-89-f1-a9-c2"
	Called-Station-Id = "00-1f-6c-a9-85-d0:its-test"
	NAS-Port = 29
	Cisco-AVPair = "audit-session-id=0a050b0600013b924eca67ab"
	NAS-IP-Address = 10.5.11.6
	NAS-Identifier = "DOMAIN-WLC2"
	Airespace-Wlan-Id = 3
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "60"
	EAP-Message =
0x020300c4150016030100b9010000b503014eca6b5e350b03240373c7268372081bed76da6d538ae12ae8ef5339c5f0f892000048c014c00a00390038c00fc00500
35c012c00800160013c00dc003000ac013c00900330032c00ec004002fc011c007c00cc002000500040015001200090014001100080006000300ff01000044000b00
0403000102000a00340032000100020003000400050006000700080009000a000b000c000d000e000f001000110012001300140015001600170018001900230000
	State = 0x0a0be8430b08fd3409af9106d0fa8ef1
	Message-Authenticator = 0x5545a479957963890d971798517934fc
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "testuser", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 3 length 196
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7 
[ttls] Done initial handshake
[ttls]     (other): before/accept initialization
[ttls]     TLS_accept: before/accept initialization
[ttls] <<< TLS 1.0 Handshake [length 00b9], ClientHello  
[ttls]     TLS_accept: SSLv3 read client hello A
[ttls] >>> TLS 1.0 Handshake [length 0031], ServerHello  
[ttls]     TLS_accept: SSLv3 write server hello A
[ttls] >>> TLS 1.0 Handshake [length 08cf], Certificate  
[ttls]     TLS_accept: SSLv3 write certificate A
[ttls] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange  
[ttls]     TLS_accept: SSLv3 write key exchange A
[ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
[ttls]     TLS_accept: SSLv3 write server done A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase 
In SSL Accept mode  
[ttls] eaptls_process returned 13 
++[eap] returns handled
Sending Access-Challenge of id 198 to 10.5.11.6 port 32768
	EAP-Message =
0x0104040015c000000b2516030100310200002d03014eca6b50e31d3f24527611e298d6386147aacde41f93ba9a6c637450b4ca1904000039000005ff0100010016
030108cf0b0008cb0008c80004e9308204e5308203cda003020102020300a0a6300d06092a864886f70d0101050500303c310b300906035504061302555331173015
060355040a130e47656f54727573742c20496e632e311430120603550403130b526170696453534c204341301e170d3131303230383134343634395a170d31323032
31313034343832315a3081e93129302706035504051320547356443351576d4f5375624b2f61636c7a5956362d34494a546d593246666e31
	EAP-Message =
0x0b3009060355040613025553311a3018060355040a0c112a2e73696d6f6e732d726f636b2e65647531133011060355040b130a475433373637383036313131302f
060355040b1328536565207777772e726170696473736c2e636f6d2f7265736f75726365732f637073202863293131312f302d060355040b1326446f6d61696e2043
6f6e74726f6c2056616c696461746564202d20526170696453534c285229311a301806035504030c112a2e73696d6f6e732d726f636b2e65647530820122300d0609
2a864886f70d01010105000382010f003082010a0282010100c0f30f8782033a767389b3332db5402bd026f8b4ebcc40370cbd0156aaa160
	EAP-Message =
0x7edd569c6f2ccb0082047df379da7f15d3dfed45ee3e54820b214ac4c670e518d1b9a31081dd5fd1ae96d8c4040354f41200e0e2e5594d9f65bb2ed047f87321dd
5ae4a563e9797c87a824189ce91eafe7e0425698d11d9231bb55483ef0c61348f6bd41b9dfcf812d66346f21f4844809c53dfe3cc76414dc9381e628020912e81c44
be4db400c993d2a686ace564337da60fd69882b593c7889cafdae1da4ef9d0d9b2139deac664ede2f57eeeb98f87647e836cfc1fa9ca504bf01b91e52ce0f068ae8e
3b9511ad3eea8fd69f47b77a1289dec7c47ae04664e172fb82c9019b0203010001a38201403082013c301f0603551d230418301680146b69
	EAP-Message =
0x3d6a18424add8f026539fd35248678911630300e0603551d0f0101ff0404030205a0301d0603551d250416301406082b0601050507030106082b06010505070302
302d0603551d110426302482112a2e73696d6f6e732d726f636b2e656475820f73696d6f6e732d726f636b2e65647530430603551d1f043c303a3038a036a0348632
687474703a2f2f726170696473736c2d63726c2e67656f74727573742e636f6d2f63726c732f726170696473736c2e63726c301d0603551d0e0416041445e2df8f88
5950a6beaf35ea658dd27a718ac71b300c0603551d130101ff04023000304906082b06010505070101043d303b303906082b060105050730
	EAP-Message = 0x02862d687474703a2f2f7261
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x0a0be843080ffd3409af9106d0fa8ef1
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.5.11.6 port 32768, id=199, length=237
	User-Name = "testuser"
	Calling-Station-Id = "40-fc-89-f1-a9-c2"
	Called-Station-Id = "00-1f-6c-a9-85-d0:its-test"
	NAS-Port = 29
	Cisco-AVPair = "audit-session-id=0a050b0600013b924eca67ab"
	NAS-IP-Address = 10.5.11.6
	NAS-Identifier = "DOMAIN-WLC2"
	Airespace-Wlan-Id = 3
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "60"
	EAP-Message = 0x020400061500
	State = 0x0a0be843080ffd3409af9106d0fa8ef1
	Message-Authenticator = 0x457578b0e97befc7fd131b6cac5499bf
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "testuser", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 4 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1 
[ttls] eaptls_process returned 13 
++[eap] returns handled
Sending Access-Challenge of id 199 to 10.5.11.6 port 32768
	EAP-Message =
0x0105040015c000000b2570696473736c2d6169612e67656f74727573742e636f6d2f726170696473736c2e637274300d06092a864886f70d010105050003820101
007e914b340ecdb5263a2bce3617cea8ee8a0d20a50d9ecffb9a65c693007c0e81a4366903c1859f80778184d6a8127b007fb89aa19bc0e9ae382e45d360fa5c89fe
94ec1cdf2425bcad7d224112753d5fac3c2cf4dc210f699a65200fddfb396bd478fa24b9f525d8924b6e28b2e6b7c3a4c8f16833c7fa22d4c890a05430117b79b861
17100903c85265c77e5db62c874dcd27a902cb3037d64d16972b6f7201b81c39f8f4b7363f5c2c4fb00acad8995af4fa18dae9762824e7b0
	EAP-Message =
0x354a4a1f2ed1d182908078f978067a06d8fdadd06c082ac0f1ce9a9cbfea9fb2062521654c63d0fa16f07dd8d079aa08b80b7c4266b08cc8a1a5f6f684e1af40ce
738d1f870003d9308203d5308202bda00302010202030236d1300d06092a864886f70d01010505003042310b300906035504061302555331163014060355040a130d
47656f547275737420496e632e311b30190603550403131247656f547275737420476c6f62616c204341301e170d3130303231393232343530355a170d3230303231
383232343530355a303c310b300906035504061302555331173015060355040a130e47656f54727573742c20496e632e3114301206035504
	EAP-Message =
0x03130b526170696453534c20434130820122300d06092a864886f70d01010105000382010f003082010a0282010100c771f856c71ed9ccb5adf6b497a3fba1e60b
505f50aa3ada0ffc3d292443c61029c1fc554072eebdeadf9fb641f4484bc86efe4f57128b5bfa92dd5ee8adf3f01bb17b4dfbcffdd1e5f8e3dce7f5737fdf0149cf
8c56c1bd37e35bbeb54f8b8bf0da4fc7e3dd554769dff25b7b074f3de5ac21c1c81d7ae8e7f60fa1aaf56fdea8654f10899c03f3897aa55e017233eda9e95a1e79f3
87c8dfc8c5fc37c89a9ad7b876ccb03ee7fde654eadf5f5241785957adf112d67fbcd59f70d3056cfaa37d6758dd26621d31920c79791c8e
	EAP-Message =
0xcfca7bc166afa87448fb8e82c29e2c995c7b2d5d9bbc5b579e7c3a7a13adf2a3185b2b590fcd5c3aeb6833c6281d82d1508b0203010001a381d93081d6300e0603
551d0f0101ff040403020106301d0603551d0e041604146b693d6a18424add8f026539fd35248678911630301f0603551d23041830168014c07a98688d89fbab0564
0c117daa7d65b8cacc4e30120603551d130101ff040830060101ff020100303a0603551d1f04333031302fa02da02b8629687474703a2f2f63726c2e67656f747275
73742e636f6d2f63726c732f6774676c6f62616c2e63726c303406082b0601050507010104283026302406082b0601050507300186186874
	EAP-Message = 0x74703a2f2f6f6373702e6765
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x0a0be843090efd3409af9106d0fa8ef1
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.5.11.6 port 32768, id=200, length=237
	User-Name = "testuser"
	Calling-Station-Id = "40-fc-89-f1-a9-c2"
	Called-Station-Id = "00-1f-6c-a9-85-d0:its-test"
	NAS-Port = 29
	Cisco-AVPair = "audit-session-id=0a050b0600013b924eca67ab"
	NAS-IP-Address = 10.5.11.6
	NAS-Identifier = "DOMAIN-WLC2"
	Airespace-Wlan-Id = 3
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "60"
	EAP-Message = 0x020500061500
	State = 0x0a0be843090efd3409af9106d0fa8ef1
	Message-Authenticator = 0x02c3914c1936f53d85fce7e3eada0cc9
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "testuser", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 5 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1 
[ttls] eaptls_process returned 13 
++[eap] returns handled
Sending Access-Challenge of id 200 to 10.5.11.6 port 32768
	EAP-Message =
0x01060343158000000b256f74727573742e636f6d300d06092a864886f70d01010505000382010100abbcbc0a5d1894e3c1b1c3a84c55d6beb498f1ee3c1ccdcff3
24245c96032758fc36aea22f8ff1feda2b02c333bdc8dd48222b600fa50310fd77f8d0ed96674ffdea47207054dca90c557ee196258ad9b5da574abe8d8e494363a5
6c4e278725eb5b6dfea27f3828e036abad39a5a562c4b75c582caa5d0160a66267a3c0c76223f4e76c46eeb5d3806a2213d22d3f744feaaf8c5fb4389cdbaeceaf84
1ea6f634515979d3e375dcbcd7f373df92ecd220596f9cfb95f89276180a7c0f2ca6cade8a627bd8f3ce5f68bd8f3ec174bb15723a1683a9
	EAP-Message =
0x0be64d999cd857eca80151c76f57345eab4a2c42f64f1c8978de264ef56f934c156b27564d00546c7ab7b7160301020d0c0002090080a1810a407ff888a31717a6
3696e01bf55e486bdf12ecc27c18a2ec47a94b32dfafef888372a71f4c927340383f0b72888fb3c7ef26216ca20b117bb94d0032fd7c6a314ce9c4dc15c97998ad86
8699522ed5d57239c545db9579f240839706144cb0f7d946b58f39da09b83337238b4c5111cf38f7ff82a60ed8e41391220773000102008095f57e46374bb6cc0c0f
89651ab67fa9d8d61f26ea082e4118303c4b724f3bcb1c98d57c00008a5d4a8c655db0fc8d2034669d272665f91bc93e11a7986b5547efc0
	EAP-Message =
0x7d29707485c55170f9f36c47c7770ae0d241fa70fe6529ab517e617c05eef3440a8e88a246708818ee2378d26edf1721dcddff81394ae203cb4ba62992e2010074
f4c94696fbc5b114ffd0cea27dcff3ac6ee96e3e96f1746894a8f267db9c3ed89d2a257635bc4fe2686e2f5ef5ddd79fb2b205f050a1e8e75f4cfdc2434c529a3bce
9b7f318abd89284f2617570f991e880c76b32f21eea6ac6d0e47775f7c5e3b0c76a7818725676add85d5b75b33f51954194bb6f12dfd77165685c3d5ee43eb09008c
ab916e3c6e121e703cf5918a960b31cc28b94195f5bebb4a7a699f29db31e7b7ad492233b97a25b5e5a991b469c01a5daf394a11b8fac978
	EAP-Message =
0xe467f5a8c1d1e1d0476e91dfff20bde527b2a7005cd031bd16fa1ba4bd22215d54ea9f0b8f18edb5485a7b5c6fd05174a0aa796b71c33e22c642ac889df7a16069
58e416030100040e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x0a0be8430e0dfd3409af9106d0fa8ef1
Finished request 4.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.5.11.6 port 32768, id=201, length=435
	User-Name = "testuser"
	Calling-Station-Id = "40-fc-89-f1-a9-c2"
	Called-Station-Id = "00-1f-6c-a9-85-d0:its-test"
	NAS-Port = 29
	Cisco-AVPair = "audit-session-id=0a050b0600013b924eca67ab"
	NAS-IP-Address = 10.5.11.6
	NAS-Identifier = "DOMAIN-WLC2"
	Airespace-Wlan-Id = 3
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "60"
	EAP-Message =
0x020600cc15001603010086100000820080895aa1f1e2c158f2ef399b618bfe153544811fde53aa80013f658eca48b59aae0c782068eac38020068ebad55ba1801f
a110f977f409ccef7bb8dfbc201abed7097dfa5b718b132e3af50b8af59cd671e484a7d14a341430ac95daeb7fcebc8cefde80f80320f1613b59e152ac90cb42adf5
7808e3a8a602294055ad2be51cc714030100010116030100307cfd16b52bc73156f9c5d00eeab53abf45cf8582ad8a4f9cfe6c048e77c7e924b1aaa8142d194fc684
b52b403644ffdd
	State = 0x0a0be8430e0dfd3409af9106d0fa8ef1
	Message-Authenticator = 0xab5b1b2c976d0b723053afe970c5dafa
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "testuser", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 6 length 204
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7 
[ttls] Done initial handshake
[ttls] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange  
[ttls]     TLS_accept: SSLv3 read client key exchange A
[ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001]  
[ttls] <<< TLS 1.0 Handshake [length 0010], Finished  
[ttls]     TLS_accept: SSLv3 read finished A
[ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001]  
[ttls]     TLS_accept: SSLv3 write change cipher spec A
[ttls] >>> TLS 1.0 Handshake [length 0010], Finished  
[ttls]     TLS_accept: SSLv3 write finished A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     (other): SSL negotiation finished successfully
SSL Connection Established 
[ttls] eaptls_process returned 13 
++[eap] returns handled
Sending Access-Challenge of id 201 to 10.5.11.6 port 32768
	EAP-Message =
0x0107004515800000003b1403010001011603010030dd1e7ae880ee3dd0b17e648fc5e46b8cc3e846b83743e50f7a82385fe151786e8d335c0a9842aaeda0940734
b4697f80
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x0a0be8430f0cfd3409af9106d0fa8ef1
Finished request 5.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 10.5.11.6 port 32768, id=202, length=343
	User-Name = "testuser"
	Calling-Station-Id = "40-fc-89-f1-a9-c2"
	Called-Station-Id = "00-1f-6c-a9-85-d0:its-test"
	NAS-Port = 29
	Cisco-AVPair = "audit-session-id=0a050b0600013b924eca67ab"
	NAS-IP-Address = 10.5.11.6
	NAS-Identifier = "DOMAIN-WLC2"
	Airespace-Wlan-Id = 3
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "60"
	EAP-Message =
0x020700701500170301002023c880010afbaca985b3723f392eaa549658ffcc6d434634bfd3e1e276d3da9317030100407f9236bc7b9e5825a580b427c865635f48
a407f7e9cffade23387c3d5ea350a01de2b68138b21fb39a9cd9acd1b75cdd43010775e3fa1ef8d1658dd40080a571
	State = 0x0a0be8430f0cfd3409af9106d0fa8ef1
	Message-Authenticator = 0x488b5387ee423eb6c94778c7410c84b7
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "testuser", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 7 length 112
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7 
[ttls] Done initial handshake
[ttls] eaptls_process returned 7 
[ttls] Session established.  Proceeding to decode tunneled attributes.
[ttls] Got tunneled request
	User-Name = "testuser"
	User-Password = "testpass"
	FreeRADIUS-Proxied-To = 127.0.0.1
[ttls] Sending tunneled request
	User-Name = "testuser"
	User-Password = "testpass"
	FreeRADIUS-Proxied-To = 127.0.0.1
server inner-tunnel {
# Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel
+- entering group authorize {...}
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "testuser", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (uid=%u) -> (uid=testuser)
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (uid=testuser)
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=student)(&(objectClass=personSR)(uid=testuser)))
rlm_ldap::ldap_groupcmp: User found in group student
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=staff)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group staff not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=faculty)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group faculty not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=faculty)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group faculty not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=staff)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group staff not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=student)(&(objectClass=personSR)(uid=testuser)))
rlm_ldap::ldap_groupcmp: User found in group student
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=faculty)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group faculty not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=staff)(&(objectClass=personSR)(uid=testuser)))
  [ldap] object not found
  [ldap] ldap_release_conn: Release Id: 0
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in uid=testuser,ou=people,dc=domain,dc=edu, with filter (objectclass=*)
rlm_ldap::groupcmp: Group staff not found or user not a member
  [ldap] ldap_release_conn: Release Id: 0
[files] 	expand: %{Client-IP-Address} -> 10.5.11.6
  [ldap] Entering ldap_groupcmp()
[files] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
[files] 	expand: (&(objectClass=personSR)(uid=%{User-Name})) -> (&(objectClass=personSR)(uid=testuser))
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (&(groupSR=student)(&(objectClass=personSR)(uid=testuser)))
rlm_ldap::ldap_groupcmp: User found in group student
  [ldap] ldap_release_conn: Release Id: 0
[files] users: Matched entry DEFAULT at line 244
++[files] returns ok
[ldap] performing user authorization for testuser
[ldap] 	expand: (uid=%u) -> (uid=testuser)
[ldap] 	expand: dc=domain,dc=edu -> dc=domain,dc=edu
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=domain,dc=edu, with filter (uid=testuser)
[ldap] checking if remote access for testuser is allowed by uid
[ldap] looking for check items in directory...
[ldap] looking for reply items in directory...
WARNING: No "known good" password was found in LDAP.  Are you sure that the user is configured correctly?
[ldap] Setting Auth-Type = LDAP
[ldap] user testuser authorized to use remote access
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
Found Auth-Type = LDAP
# Executing group from file /etc/raddb/sites-enabled/inner-tunnel
+- entering group LDAP {...}
[ldap] login attempt by "testuser" with password "testpass"
[ldap] user DN: uid=testuser,ou=people,dc=domain,dc=edu
  [ldap] (re)connect to ldap1.domain.edu:389, authentication 1
  [ldap] bind as uid=testuser,ou=people,dc=domain,dc=edu/testpass to ldap1.domain.edu:389
  [ldap] waiting for bind result ...
  [ldap] Bind was successful
[ldap] user testuser authenticated succesfully
++[ldap] returns ok
  WARNING: Empty post-auth section.  Using default return values.
# Executing section post-auth from file /etc/raddb/sites-enabled/inner-tunnel
} # server inner-tunnel
[ttls] Got tunneled reply code 2
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "360"
[ttls] Got tunneled Access-Accept
[eap] Freeing handler
++[eap] returns ok
# Executing section post-auth from file /etc/raddb/sites-enabled/default
+- entering group post-auth {...}
++[exec] returns noop
Sending Access-Accept of id 202 to 10.5.11.6 port 32768
	MS-MPPE-Recv-Key = 0xef328a0494874f4b9e2c0278014e3f9467c949761073da5cb7b9d6d382699fd9
	MS-MPPE-Send-Key = 0xa2796321aa8e0d9014ae3e67c079427a29a82c0851a34ab98d554ea6b41bc8c7
	EAP-Message = 0x03070004
	Message-Authenticator = 0x00000000000000000000000000000000
	User-Name = "testuser"
Finished request 6.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Accounting-Request packet from host 10.5.11.6 port 32768, id=39, length=263
	User-Name = "testuser"
	NAS-Port = 29
	NAS-IP-Address = 10.5.11.6
	Framed-IP-Address = 10.5.14.192
	NAS-Identifier = "DOMAIN-WLC2"
	Airespace-Wlan-Id = 3
	Acct-Session-Id = "4eca67af/40:fc:89:f1:a9:c2/89488"
	Cisco-AVPair = "audit-session-id=0a050b0600013b924eca67ab"
	Acct-Authentic = RADIUS
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "60"
	Acct-Status-Type = Interim-Update
	Acct-Input-Octets = 907218
	Acct-Output-Octets = 3106458
	Acct-Input-Packets = 11383
	Acct-Output-Packets = 5326
	Acct-Session-Time = 929
	Acct-Delay-Time = 0
	Calling-Station-Id = "10.5.14.192"
	Called-Station-Id = "10.5.11.6"
	Cisco-AVPair = "nas-update=true"
# Executing section preacct from file /etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 29,Client-IP-Address = 10.5.11.6,NAS-IP-Address = 10.5.11.6,Acct-Session-Id =
"4eca67af/40:fc:89:f1:a9:c2/89488",User-Name = "testuser"'
[acct_unique] Acct-Unique-Session-ID = "e441483aa5eda403".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "testuser", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
# Executing section accounting from file /etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] 	expand: /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d ->
/var/log/radius/radacct/10.5.11.6/detail-20111121
[detail] /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radius/radacct/10.5.11.6/detail-20111121
[detail] 	expand: %t -> Mon Nov 21 10:16:32 2011
++[detail] returns ok
++[unix] returns noop
[radutmp] 	expand: /var/log/radius/radutmp -> /var/log/radius/radutmp
[radutmp] 	expand: %{User-Name} -> testuser
++[radutmp] returns ok
++[exec] returns noop
[attr_filter.accounting_response] 	expand: %{User-Name} -> testuser
 attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 39 to 10.5.11.6 port 32768
Finished request 7.
Cleaning up request 7 ID 39 with timestamp +6
Going to the next request
Waking up in 4.7 seconds.
Cleaning up request 0 ID 196 with timestamp +6
Cleaning up request 1 ID 197 with timestamp +6
Cleaning up request 2 ID 198 with timestamp +6
Cleaning up request 3 ID 199 with timestamp +6
Cleaning up request 4 ID 200 with timestamp +6
Waking up in 0.1 seconds.
Cleaning up request 5 ID 201 with timestamp +6
Cleaning up request 6 ID 202 with timestamp +6
Ready to process requests.

Brian Gold
System Administrator
Bard College at Simon's Rock