Re: EAP-TTLS PAP Mysql problems

[emmcosta <emmcosta@gmail.com>]

A.L.M.Buxey@lboro.ac.uk wrote:

Hi,

  

Wed Jun 20 19:46:47 2007 : Error: Trying to look up name of unknown
client 127.0.0.1.
Wed Jun 20 19:46:47 2007 : Auth: Login OK: [teste/secret] (from client
UNKNOWN-CLIENT port 327 cli 0040.96a2.24f3)
Wed Jun 20 19:46:47 2007 : Auth: Login OK: [teste/<no User-Password
attribute>] (from client ap2 port 327 cli 0040.96a2.24f3)

but if I use cli with command radtest authentication is sucessefull and receive reply attributes.

I'm to use a Cisco ap1100 configurated with wpa-tkip and for client use
a pc with windows XP with supplicant securew2 configured with eap-ttls pap.
    

send us you naslist table and clients.conf

alan
- 
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

  

See in attach naslist, clients.conf and radius -xx log.

-- 
/emmc

#
# clients.conf - client configuration directives
#
#######################################################################

#######################################################################
#
#  Definition of a RADIUS client (usually a NAS).
#
#  The information given here over rides anything given in the
#  'clients' file, or in the 'naslist' file.  The configuration here
#  contains all of the information from those two files, and allows
#  for more configuration items.
#
#  The "shortname" is be used for logging.  The "nastype", "login" and
#  "password" fields are mainly used for checkrad and are optional.
#

#
#  Defines a RADIUS client.  The format is 'client [hostname|ip-address]'
#
#  '127.0.0.1' is another name for 'localhost'.  It is enabled by default,
#  to allow testing of the server after an initial installation.  If you
#  are not going to be permitting RADIUS queries from localhost, we suggest
#  that you delete, or comment out, this entry.
#
client 10.10.10.4 {
	#
	#  The shared secret use to "encrypt" and "sign" packets between
	#  the NAS and FreeRADIUS.  You MUST change this secret from the
	#  default, otherwise it's not a secret any more!
	#
	#  The secret can be any string, up to 31 characters in length.
	#
	secret		= teste123

	#
	#  The short name is used as an alias for the fully qualified
	#  domain name, or the IP address.
	#
	shortname	= fonte

	#
	# the following three fields are optional, but may be used by
	# checkrad.pl for simultaneous use checks
	#

	#
	# The nastype tells 'checkrad.pl' which NAS-specific method to
	#  use to query the NAS for simultaneous use.
	#
	#  Permitted NAS types are:
	#
	#	cisco
	#	computone
	#	livingston
	#	max40xx
	#	multitech
	#	netserver
	#	pathras
	#	patton
	#	portslave
	#	tc
	#	usrhiper
	#	other		# for all other types

	#
	#nastype     = other	# localhost isn't usually a NAS...

	#
	#  The following two configurations are for future use.
	#  The 'naspasswd' file is currently used to store the NAS
	#  login name and password, which is used by checkrad.pl
	#  when querying the NAS for simultaneous use.
	#
#	login       = !root
#	password    = someadminpas
}

#client 192.168.1.68{
#	secret		= xFRKWJwelf23#"4DSFFEWfdsfjweEEE
#	shortname	= 192.168.1.68
#	nastype		= cisco
#}

client 10.10.10.5{
	secret		= xFRKGJwelf24#"4DSJFEWfdsfjweEEE
	shortname	= ap2
}
#client some.host.org {
#	secret		= testing123
#	shortname	= localhost
#}

#
#  You can now specify one secret for a network of clients.
#  When a client request comes in, the BEST match is chosen.
#  i.e. The entry from the smallest possible network.
#
#client 192.168.0.0/24 {
#	secret		= testing123-1
#	shortname	= private-network-1
#}
#
#client 192.168.0.0/16 {
#	secret		= testing123-2
#	shortname	= private-network-2
#}


#client 10.10.10.10 {
#	# secret and password are mapped through the "secrets" file.
#	secret      = testing123
#	shortname   = liv1
#       # the following three fields are optional, but may be used by
#       # checkrad.pl for simultaneous usage checks
#	nastype     = livingston
#	login       = !root
#	password    = someadminpas
#}


#
#	THIS FILE IS DEPRECATED.
#
#	You should NOT be using this file to configure the server.
#	It is here ONLY for backwards compatibility.
#
#	See 'clients.conf' for the new configuration.
#
#
# naslist	This file contains a list of NASes (Network Access Servers,
#		also known as terminal servers) which we know.
#
#		Description of the fields:
#
#		* The first field is a valid hostname or IP address
#		  for the client.
#		* The second field (seperated by blanks or tabs) is the 
#		  short name we use in the logfiles for this NAS.
#		* The third field defines what type of device it is. Valid
#		  values are "cisco", "computone", "livingston", "max40xx", 
#                 "multitech", "netserver", "pathras", "patton", "portslave", 
#                 "tc", "usrhiper" or "other".
#
#		This is used to find out how to detect double logins.
#

# NAS Name		Short Name	Type
#----------------	----------	----
#portmaster1.isp.com	pm1.NY		livingston
#portmaster2.isp.com	pm1.LA		livingston
localhost		local		portslave

Starting - reading configuration files ...
reread_config:  reading radiusd.conf
Config:   including file: /usr/local/etc/raddb/clients.conf
Config:   including file: /usr/local/etc/raddb/eap.conf
Config:   including file: /usr/local/etc/raddb/sql.conf
 main: prefix = "/usr/local"
 main: localstatedir = "/usr/local/var"
 main: logdir = "/usr/local/var/log/radius"
 main: libdir = "/usr/local/lib"
 main: radacctdir = "/usr/local/var/log/radius/radacct"
 main: hostname_lookups = no
 main: max_request_time = 30
 main: cleanup_delay = 5
 main: max_requests = 1024
 main: delete_blocked_requests = 0
 main: port = 0
 main: allow_core_dumps = no
 main: log_stripped_names = no
 main: log_file = "/usr/local/var/log/radius/radius.log"
 main: log_auth = yes
 main: log_auth_badpass = yes
 main: log_auth_goodpass = yes
 main: pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
 main: user = "(null)"
 main: group = "(null)"
 main: usercollide = yes
 main: lower_user = "no"
 main: lower_pass = "no"
 main: nospace_user = "no"
 main: nospace_pass = "no"
 main: checkrad = "/usr/local/sbin/checkrad"
 main: proxy_requests = no
 security: max_attributes = 200
 security: reject_delay = 1
 security: status_server = no
 main: debug_level = 0
read_config_files:  reading dictionary
read_config_files:  reading naslist
Using deprecated naslist file.  Support for this will go away soon.
read_config_files:  reading clients
read_config_files:  reading realms
 listen: ipaddr = 10.10.10.4 IP address [10.10.10.4]
 listen: port = 1812
 listen: type = "auth"
 listen: ipaddr = 10.10.10.4 IP address [10.10.10.4]
 listen: port = 1813
 listen: type = "acct"
radiusd:  entering modules setup
Module: Library search path is /usr/local/lib
Module: Loaded expr 
Module: Instantiated expr (expr) 
Module: Loaded PAP 
 pap: encryption_scheme = "crypt"
 pap: auto_header = no
Module: Instantiated pap (pap) 
Module: Loaded eap 
 eap: default_eap_type = "ttls"
 eap: timer_expire = 60
 eap: ignore_unknown_eap_types = no
 eap: cisco_accounting_username_bug = yes
 gtc: challenge = "Password: "
 gtc: auth_type = "PAP"
rlm_eap: Loaded and initialized type gtc
 tls: rsa_key_exchange = no
 tls: dh_key_exchange = yes
 tls: rsa_key_length = 512
 tls: dh_key_length = 512
 tls: verify_depth = 0
 tls: CA_path = "(null)"
 tls: pem_file_type = yes
 tls: private_key_file = "/usr/local/etc/raddb/certs/cert-srv.pem"
 tls: certificate_file = "/usr/local/etc/raddb/certs/cert-srv.pem"
 tls: CA_file = "/usr/local/etc/raddb/certs/demoCA/cacert.pem"
 tls: private_key_password = "whatever"
 tls: dh_file = "/usr/local/etc/raddb/certs/dh"
 tls: random_file = "/usr/local/etc/raddb/certs/random"
 tls: fragment_size = 1024
 tls: include_length = yes
 tls: check_crl = no
 tls: check_cert_cn = "(null)"
 tls: cipher_list = "(null)"
 tls: check_cert_issuer = "(null)"
rlm_eap_tls: Loading the certificate file as a chain
rlm_eap: Loaded and initialized type tls
 ttls: default_eap_type = "gtc"
 ttls: copy_request_to_tunnel = no
 ttls: use_tunneled_reply = yes
rlm_eap: Loaded and initialized type ttls
Module: Instantiated eap (eap) 
Module: Loaded SQL 
 sql: driver = "rlm_sql_mysql"
 sql: server = "localhost"
 sql: port = ""
 sql: login = "radius"
 sql: password = "teste"
 sql: radius_db = "radius"
 sql: nas_table = "nas"
 sql: sqltrace = no
 sql: sqltracefile = "/usr/local/var/log/radius/sqltrace.sql"
 sql: readclients = no
 sql: deletestalesessions = yes
 sql: num_sql_socks = 5
 sql: sql_user_name = "%{User-Name}"
 sql: default_user_profile = ""
 sql: query_on_not_found = no
 sql: authorize_check_query = "SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = '%{SQL-User-Name}'          ORDER BY id"
 sql: authorize_reply_query = "SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = '%{SQL-User-Name}'           ORDER BY id"
 sql: authorize_group_check_query = ""
 sql: authorize_group_reply_query = ""
 sql: accounting_onoff_query = "UPDATE radacct SET AcctStopTime='%S', AcctSessionTime=unix_timestamp('%S') - unix_timestamp(AcctStartTime), AcctTerminateCause='%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}' WHERE AcctSessionTime=0 AND AcctStopTime=0 AND NASIPAddress= '%{NAS-IP-Address}' AND AcctStartTime <= '%S'"
 sql: accounting_update_query = "UPDATE radacct           SET FramedIPAddress = '%{Framed-IP-Address}',           AcctSessionTime = '%{Acct-Session-Time}',           AcctInputOctets = '%{Acct-Input-Octets}',           AcctOutputOctets = '%{Acct-Output-Octets}'           WHERE AcctSessionId = '%{Acct-Session-Id}'           AND UserName = '%{SQL-User-Name}'           AND NASIPAddress= '%{NAS-IP-Address}'"
 sql: accounting_update_query_alt = "INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S',INTERVAL (%{Acct-Session-Time:-0} + %{Acct-Delay-Time:-0}) SECOND), '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0')"
 sql: accounting_start_query = "INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, AcctStopDelay) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', '0', '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{Acct-Delay-Time}', '0')"
 sql: accounting_start_query_alt = "UPDATE radacct SET AcctStartTime = '%S', AcctStartDelay = '%{Acct-Delay-Time}', ConnectInfo_start = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress = '%{NAS-IP-Address}'"
 sql: accounting_stop_query = "UPDATE radacct SET AcctStopTime = '%S', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets = '%{Acct-Input-Octets}', AcctOutputOctets = '%{Acct-Output-Octets}', AcctTerminateCause = '%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}', ConnectInfo_stop = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress = '%{NAS-IP-Address}'"
 sql: accounting_stop_query_alt = "INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, AcctStopDelay) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{Acct-Session-Time:-0} + %{Acct-Delay-Time:-0}) SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{Acct-Delay-Time}')"
 sql: group_membership_query = "SELECT GroupName FROM usergroup WHERE UserName='%{SQL-User-Name}'"
 sql: connect_failure_retry_delay = 60
 sql: simul_count_query = "SELECT COUNT(*) FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime = 0"
 sql: simul_verify_query = "SELECT RadAcctId, AcctSessionId, UserName, NASIPAddress, NASPortId, FramedIPAddress, CallingStationId, FramedProtocol FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime = 0"
 sql: postauth_query = "INSERT into radpostauth (id, user, pass, reply, date) values ('', '%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', NOW())"
 sql: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (sql): Attempting to connect to root@localhost:/radius
rlm_sql (sql): starting 0
rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
rlm_sql_mysql: Starting connect to MySQL server for #0
rlm_sql (sql): Connected new DB handle, #0
rlm_sql (sql): starting 1
rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
rlm_sql_mysql: Starting connect to MySQL server for #1
rlm_sql (sql): Connected new DB handle, #1
rlm_sql (sql): starting 2
rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
rlm_sql_mysql: Starting connect to MySQL server for #2
rlm_sql (sql): Connected new DB handle, #2
rlm_sql (sql): starting 3
rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
rlm_sql_mysql: Starting connect to MySQL server for #3
rlm_sql (sql): Connected new DB handle, #3
rlm_sql (sql): starting 4
rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
rlm_sql_mysql: Starting connect to MySQL server for #4
rlm_sql (sql): Connected new DB handle, #4
Module: Instantiated sql (sql) 
Module: Loaded preprocess 
 preprocess: huntgroups = "/usr/local/etc/raddb/huntgroups"
 preprocess: hints = "/usr/local/etc/raddb/hints"
 preprocess: with_ascend_hack = no
 preprocess: ascend_channels_per_line = 23
 preprocess: with_ntdomain_hack = no
 preprocess: with_specialix_jetstream_hack = no
 preprocess: with_cisco_vsa_hack = no
 preprocess: with_alvarion_vsa_hack = no
Module: Instantiated preprocess (preprocess) 
Module: Loaded realm 
 realm: format = "suffix"
 realm: delimiter = "@"
 realm: ignore_default = no
 realm: ignore_null = no
Module: Instantiated realm (suffix) 
Module: Loaded detail 
 detail: detailfile = "/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
 detail: detailperm = 384
 detail: dirperm = 493
 detail: locking = no
Module: Instantiated detail (detail) 
Module: Loaded System 
 unix: cache = no
 unix: passwd = "(null)"
 unix: shadow = "(null)"
 unix: group = "(null)"
 unix: radwtmp = "/usr/local/var/log/radius/radwtmp"
 unix: usegroup = no
 unix: cache_reload = 600
Module: Instantiated unix (unix) 
Module: Loaded radutmp 
 radutmp: filename = "/usr/local/var/log/radius/radutmp"
 radutmp: username = "%{User-Name}"
 radutmp: case_sensitive = yes
 radutmp: check_with_nas = yes
 radutmp: perm = 384
 radutmp: callerid = yes
Module: Instantiated radutmp (radutmp) 
Module: Loaded sql_log 
 sql_log: path = "/usr/local/var/log/radius/radacct/sql-relay"
 sql_log: Post-Auth = "INSERT INTO radpostauth                   ?? (user, pass, reply, date) VALUES                            ?? ('%{User-Name}', '%{User-Password:-Chap-Password}',         ?? '%{reply:Packet-Type}', '%S');"
 sql_log: sql_user_name = ""
 sql_log: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Module: Instantiated sql_log (sql_log) 
Initializing the thread pool...
 thread: start_servers = 5
 thread: max_servers = 32
 thread: min_spare_servers = 3
 thread: max_spare_servers = 10
 thread: max_requests_per_server = 0
 thread: cleanup_delay = 5
Thread spawned new child 1. Total threads in pool: 1
Thread spawned new child 2. Total threads in pool: 2
Thread spawned new child 3. Total threads in pool: 3
Thread spawned new child 4. Total threads in pool: 4
Thread spawned new child 5. Total threads in pool: 5
Thread pool initialized
Listening on authentication 10.10.10.4:1812
Listening on accounting 10.10.10.4:1813
Ready to process requests.
Thread 1 waiting to be assigned a request
Thread 2 waiting to be assigned a request
Thread 3 waiting to be assigned a request
Thread 4 waiting to be assigned a request
Thread 5 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=1, length=159
--- Walking the entire request list ---
Thread 1 got semaphore
Waking up in 31 seconds...
Thread 1 handling request 0, (1 handled so far)
Threads: total/active/spare threads = 5/1/4
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0xf3a96c9310ab5ff81307e7ffbefcfd99
	EAP-Message = 0x0202000d0167696c626572746f
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "263"
	NAS-Port = 263
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
  rlm_eap: EAP packet type response id 2 length 13
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 0
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 4
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 4
  modcall[authorize]: module "sql" returns ok for request 0
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 0
modcall: leaving group authorize (returns updated) for request 0
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 0
  rlm_eap: EAP Identity
  rlm_eap: processing type tls
  rlm_eap_tls: Initiate
  rlm_eap_tls: Start returned 1
  modcall[authenticate]: module "eap" returns handled for request 0
modcall: leaving group authenticate (returns handled) for request 0
Sending Access-Challenge of id 1 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x010300061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x070b1f9f28ca2b353b583da51af2fc55
Finished request 0
Going to the next request
Thread 1 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=2, length=224
Thread 2 got semaphore
Waking up in 31 seconds...
Thread 2 handling request 1, (1 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0x1000703418cbb6ff0326772522bf4521
	EAP-Message = 0x0203003c158000000032160301002d010000290301aa2822869a88176a306deccee520ff6b856d0cd75a62af06b5e293548301d5d3000002000a0100
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "263"
	NAS-Port = 263
	State = 0x070b1f9f28ca2b353b583da51af2fc55
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 1
  rlm_eap: EAP packet type response id 3 length 60
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 1
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 3
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 3
  modcall[authorize]: module "sql" returns ok for request 1
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 1
modcall: leaving group authorize (returns updated) for request 1
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 1
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/ttls
  rlm_eap: processing type ttls
  rlm_eap_ttls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11 
    (other): before/accept initialization 
    TLS_accept: before/accept initialization 
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 002d], ClientHello  
    TLS_accept: SSLv3 read client hello A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello  
    TLS_accept: SSLv3 write server hello A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0694], Certificate  
    TLS_accept: SSLv3 write certificate A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
    TLS_accept: SSLv3 write server done A 
    TLS_accept: SSLv3 flush data 
    TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase 
In SSL Accept mode  
  eaptls_process returned 13 
  modcall[authenticate]: module "eap" returns handled for request 1
modcall: leaving group authenticate (returns handled) for request 1
Sending Access-Challenge of id 2 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x0104040a15c0000006f1160301004a020000460301467ade11f9353d60155b39ea640e0277363e66addbcfe3a1684890f15e11f88a201861b6bb2f420668d6fbcc2783558fb6810050aabab55338abd03a37c56af65d000a0016030106940b00069000068d0002cd308202c930820232a003020102020102300d06092a864886f70d010104050030819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e74206365
	EAP-Message = 0x7274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d301e170d3034303132353133323631305a170d3035303132343133323631305a30819b310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f73743119301706035504031310526f6f74206365727469666963617465311f301d06092a864886f70d0109011610726f6f74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003
	EAP-Message = 0x818d0030818902818100dac525422bfedb082629a2cba44b3449c90d0ab462fb72c8434a782098863d7eb7d7e70028c2b7ad555a51cc756cf4fa1d7091615ab450d5289553ae6616aff014a55085d6b8fb4aee98638e426175cdd36c665c63cda177d34920eb30585edc8773999c2980f81ad4638bbbea1c82d054023db7ef24a3ec1c3f6241a903d7f30203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d0101040500038181007a2d921b1cf13bf2982a9178ec9ede6d88edc178a2e8bd40a0a06fb6f0769957884cd7084537083496fd184165293f583c8e8240eb68e042c94b15752e4c07e80d09
	EAP-Message = 0x779afa3dd55c24fa54ac292d77205d1c2477ed30d59f57caf9bd21ff2a8d16cc0911c50e4f295763fcb60efa3c3d2d0e43850f6e6fbe284902f6e83503650003ba308203b63082031fa003020102020100300d06092a864886f70d010104050030819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c
	EAP-Message = 0x652e636f6d301e170d3034303132353133323630375a
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xd67ba0cc7c0b93a0db85f7792589b733
Finished request 1
Going to the next request
Thread 2 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=3, length=170
Waking up in 31 seconds...
Thread 3 got semaphore
Threads: total/active/spare threads = 5/0/5
Thread 3 handling request 2, (1 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0xfcec03c136b4211b289714283380d8c1
	EAP-Message = 0x020400061500
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "263"
	NAS-Port = 263
	State = 0xd67ba0cc7c0b93a0db85f7792589b733
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 2
  rlm_eap: EAP packet type response id 4 length 6
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 2
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 2
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 2
  modcall[authorize]: module "sql" returns ok for request 2
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 2
modcall: leaving group authorize (returns updated) for request 2
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 2
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/ttls
  rlm_eap: processing type ttls
  rlm_eap_ttls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
  rlm_eap_tls: ack handshake fragment handler
  eaptls_verify returned 1 
  eaptls_process returned 13 
  modcall[authenticate]: module "eap" returns handled for request 2
modcall: leaving group authenticate (returns handled) for request 2
Sending Access-Challenge of id 3 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x010502fb1580000006f1170d3036303132343133323630375a30819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100d4c5b19724f164acf1ffb189db1c8fbff4f14396ea7cb1e90f78d69451725377895dfe52cc
	EAP-Message = 0xb99b41e80ddeb58b127a943f4f58cbc562878192fbdc6fece9f871e7c130d35cf5188817e9b133249edd2a1c75d31043ae87553cec7a77ef26aa7d74281db9b77e17c6446c5dd9b188b43250ca0229963722a123a726b00b4027fd0203010001a381ff3081fc301d0603551d0e0416041468d36d3e1ee7bc9d5a057021c363da1365d1ade33081cc0603551d230481c43081c1801468d36d3e1ee7bc9d5a057021c363da1365d1ade3a181a5a481a230819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e
	EAP-Message = 0x31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d820100300c0603551d13040530030101ff300d06092a864886f70d01010405000381810033c00b66b1e579ef73a06798252dab8d5e5511fc00fd276d80d12f834777c6743fdc2743fca1507704e4bc0979e4f60ac3ad9ee83e6f347369229d1f77229ba2e982359da563024a00163dba6d6c986c0bad28af85132ff8f0d76501bf1b7c2dff658ce1e62c01997b6e64e3e8d4373354ce9912847651539063b85bbc5485c51603010004
	EAP-Message = 0x0e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x8bbf86428550e7fc507e0805fced3d34
Finished request 2
Going to the next request
Thread 3 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=4, length=364
Waking up in 31 seconds...
Thread 4 got semaphore
Thread 4 handling request 3, (1 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0xa3b5384673056ff7c63c704679d3fc00
	EAP-Message = 0x020500c81580000000be16030100861000008200807d8d43fd17312f970566b92ecf2b99e62cf8779d2644018ff3f53d4656ea759b253d32dacff8fadbf2d6763bba970d86d01788c06933514ce775f30c86c8a87a3757fe9f8284a08916e6cc88e141268d9c6b848ef8e86c1043939bec9569738a75324e31172268e98c4fb3ed44d98f89e8e93b35a72cd2b86a3d13bbfafd2cc91403010001011603010028202bdfa014e749e3bc91034f1dfb883c3172161fd6069c497ae782f3e0a55f7d3f626fd227aa1ce0
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "263"
	NAS-Port = 263
	State = 0x8bbf86428550e7fc507e0805fced3d34
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 3
  rlm_eap: EAP packet type response id 5 length 200
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 3
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 1
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 1
  modcall[authorize]: module "sql" returns ok for request 3
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 3
modcall: leaving group authorize (returns updated) for request 3
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 3
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/ttls
  rlm_eap: processing type ttls
  rlm_eap_ttls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11 
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange  
    TLS_accept: SSLv3 read client key exchange A 
  rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]  
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished  
    TLS_accept: SSLv3 read finished A 
  rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]  
    TLS_accept: SSLv3 write change cipher spec A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished  
    TLS_accept: SSLv3 write finished A 
    TLS_accept: SSLv3 flush data 
    (other): SSL negotiation finished successfully 
SSL Connection Established 
  eaptls_process returned 13 
  modcall[authenticate]: module "eap" returns handled for request 3
modcall: leaving group authenticate (returns handled) for request 3
Sending Access-Challenge of id 4 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x0106003d1580000000331403010001011603010028bfe6f70abd9816ad3865d6a3cfb5aa269d6b65b5e2894e9d5b0b8e13944b59ae212d9ec769b48ddf
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xada45ffb8df56ab1bf358060f5d98e13
Finished request 3
Going to the next request
Thread 4 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=5, length=235
Waking up in 31 seconds...
Thread 5 got semaphore
Thread 5 handling request 4, (1 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0xde4e9b0ba023cfd0834689ff0cf166cc
	EAP-Message = 0x0206004715800000003d1703010038d324d10de83ce53c602de5eb9035ac83399801ebfb569f139e00b4c4f7b59564a2ce2e4c2889210482d9ea28fab17911108a216a1708e677
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "263"
	NAS-Port = 263
	State = 0xada45ffb8df56ab1bf358060f5d98e13
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 4
  rlm_eap: EAP packet type response id 6 length 71
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 4
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 0
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 0
  modcall[authorize]: module "sql" returns ok for request 4
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 4
modcall: leaving group authorize (returns updated) for request 4
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 4
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/ttls
  rlm_eap: processing type ttls
  rlm_eap_ttls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11 
  eaptls_process returned 7 
  rlm_eap_ttls: Session established.  Proceeding to decode tunneled attributes.
  TTLS: Got tunneled request
	User-Name = "gilberto"
	User-Password = "teste"
	FreeRADIUS-Proxied-To = 127.0.0.1
  TTLS: Sending tunneled request
	User-Name = "gilberto"
	User-Password = "teste"
	FreeRADIUS-Proxied-To = 127.0.0.1
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 4
  rlm_eap: No EAP-Message, not doing EAP
  modcall[authorize]: module "eap" returns noop for request 4
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 4
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 4
  modcall[authorize]: module "sql" returns ok for request 4
  modcall[authorize]: module "pap" returns updated for request 4
modcall: leaving group authorize (returns updated) for request 4
  rad_check_password:  Found Auth-Type pap
auth: type "PAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group PAP for request 4
rlm_pap: login attempt with password teste
rlm_pap: Using CRYPT encryption.
rlm_pap: User authenticated successfully
  modcall[authenticate]: module "pap" returns ok for request 4
modcall: leaving group PAP (returns ok) for request 4
Trying to look up name of unknown client 127.0.0.1. 
Login OK: [gilberto/teste] (from client UNKNOWN-CLIENT port 0)
  TTLS: Got tunneled reply RADIUS code 2
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
  TTLS: Got tunneled Access-Accept
  rlm_eap: Freeing handler
  modcall[authenticate]: module "eap" returns ok for request 4
modcall: leaving group authenticate (returns ok) for request 4
Login OK: [gilberto/<no User-Password attribute>] (from client ap2 port 263 cli 0040.96a2.24f3)
Sending Access-Accept of id 5 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	MS-MPPE-Recv-Key = 0x8e4df35d44f36b5bcc98631d5ccd5a5b8d2837b1b12cf75b27463bfa64a1f637
	MS-MPPE-Send-Key = 0x30f2d9b099bf780dfcce30cd91fa5d586c3791d7c38826ab8770ec08d9e40ca0
	EAP-Message = 0x03060004
	Message-Authenticator = 0x00000000000000000000000000000000
	User-Name = "gilberto"
Finished request 4
Going to the next request
Thread 5 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=6, length=159
--- Walking the entire request list ---
Thread 1 got semaphore
Waking up in 2 seconds...
Thread 1 handling request 5, (2 handled so far)
Threads: total/active/spare threads = 5/1/4
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0x089742cd1b4f4f8600ee958a04a775af
	EAP-Message = 0x0201000d0167696c626572746f
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "264"
	NAS-Port = 264
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 5
  rlm_eap: EAP packet type response id 1 length 13
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 5
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 3
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 3
  modcall[authorize]: module "sql" returns ok for request 5
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 5
modcall: leaving group authorize (returns updated) for request 5
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 5
  rlm_eap: EAP Identity
  rlm_eap: processing type tls
  rlm_eap_tls: Initiate
  rlm_eap_tls: Start returned 1
  modcall[authenticate]: module "eap" returns handled for request 5
modcall: leaving group authenticate (returns handled) for request 5
Sending Access-Challenge of id 6 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x010200061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x4bd6c130f499a2ec58518339a504f83b
Finished request 5
Going to the next request
Thread 1 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=7, length=159
Waking up in 2 seconds...
Thread 2 got semaphore
Threads: total/active/spare threads = 5/0/5
Thread 2 handling request 6, (2 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0xfef325d99adbe35fcf1d6f8bd19a0d83
	EAP-Message = 0x0203000d0167696c626572746f
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "264"
	NAS-Port = 264
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 6
  rlm_eap: EAP packet type response id 3 length 13
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 6
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 2
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 2
  modcall[authorize]: module "sql" returns ok for request 6
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 6
modcall: leaving group authorize (returns updated) for request 6
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 6
  rlm_eap: EAP Identity
  rlm_eap: processing type tls
  rlm_eap_tls: Initiate
  rlm_eap_tls: Start returned 1
  modcall[authenticate]: module "eap" returns handled for request 6
modcall: leaving group authenticate (returns handled) for request 6
Sending Access-Challenge of id 7 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x010400061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x4bb993a5275308488ff94c8951fc9df4
Finished request 6
Going to the next request
Thread 2 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=8, length=256
Waking up in 2 seconds...
Thread 3 got semaphore
Thread 3 handling request 7, (2 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0xaa3e0458cb2da93f8bd91508b49fe0c3
	EAP-Message = 0x0204005c158000000052160301004d010000490301e34d2bcb74e9edfb84341a547b2b05cdb2373ce8685c193c86bfd3a92f9dfbe4201861b6bb2f420668d6fbcc2783558fb6810050aabab55338abd03a37c56af65d0002000a0100
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "264"
	NAS-Port = 264
	State = 0x4bb993a5275308488ff94c8951fc9df4
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 7
  rlm_eap: EAP packet type response id 4 length 92
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 7
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 1
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 1
  modcall[authorize]: module "sql" returns ok for request 7
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 7
modcall: leaving group authorize (returns updated) for request 7
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 7
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/ttls
  rlm_eap: processing type ttls
  rlm_eap_ttls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11 
    (other): before/accept initialization 
    TLS_accept: before/accept initialization 
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 004d], ClientHello  
    TLS_accept: SSLv3 read client hello A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello  
    TLS_accept: SSLv3 write server hello A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0694], Certificate  
    TLS_accept: SSLv3 write certificate A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
    TLS_accept: SSLv3 write server done A 
    TLS_accept: SSLv3 flush data 
    TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase 
In SSL Accept mode  
  eaptls_process returned 13 
  modcall[authenticate]: module "eap" returns handled for request 7
modcall: leaving group authenticate (returns handled) for request 7
Sending Access-Challenge of id 8 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x0105040a15c0000006f1160301004a020000460301467ade155df2954abcd56ab43900c60fa001301a26aade31b2726e76ad8663bf20956154aff114e89e9d0260f441587dfcf414b543e50a2bf7a9c78919968f58e7000a0016030106940b00069000068d0002cd308202c930820232a003020102020102300d06092a864886f70d010104050030819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e74206365
	EAP-Message = 0x7274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d301e170d3034303132353133323631305a170d3035303132343133323631305a30819b310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f73743119301706035504031310526f6f74206365727469666963617465311f301d06092a864886f70d0109011610726f6f74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003
	EAP-Message = 0x818d0030818902818100dac525422bfedb082629a2cba44b3449c90d0ab462fb72c8434a782098863d7eb7d7e70028c2b7ad555a51cc756cf4fa1d7091615ab450d5289553ae6616aff014a55085d6b8fb4aee98638e426175cdd36c665c63cda177d34920eb30585edc8773999c2980f81ad4638bbbea1c82d054023db7ef24a3ec1c3f6241a903d7f30203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d0101040500038181007a2d921b1cf13bf2982a9178ec9ede6d88edc178a2e8bd40a0a06fb6f0769957884cd7084537083496fd184165293f583c8e8240eb68e042c94b15752e4c07e80d09
	EAP-Message = 0x779afa3dd55c24fa54ac292d77205d1c2477ed30d59f57caf9bd21ff2a8d16cc0911c50e4f295763fcb60efa3c3d2d0e43850f6e6fbe284902f6e83503650003ba308203b63082031fa003020102020100300d06092a864886f70d010104050030819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c
	EAP-Message = 0x652e636f6d301e170d3034303132353133323630375a
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x2de00f68998dc8400511676ab890399d
Finished request 7
Going to the next request
Thread 3 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=9, length=170
Waking up in 2 seconds...
Thread 4 got semaphore
Thread 4 handling request 8, (2 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0x121c75cb1ee9a78e79299f3213a6b6b8
	EAP-Message = 0x020500061500
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "264"
	NAS-Port = 264
	State = 0x2de00f68998dc8400511676ab890399d
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 8
  rlm_eap: EAP packet type response id 5 length 6
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 8
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 0
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 0
  modcall[authorize]: module "sql" returns ok for request 8
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 8
modcall: leaving group authorize (returns updated) for request 8
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 8
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/ttls
  rlm_eap: processing type ttls
  rlm_eap_ttls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
  rlm_eap_tls: ack handshake fragment handler
  eaptls_verify returned 1 
  eaptls_process returned 13 
  modcall[authenticate]: module "eap" returns handled for request 8
modcall: leaving group authenticate (returns handled) for request 8
Sending Access-Challenge of id 9 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x010602fb1580000006f1170d3036303132343133323630375a30819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100d4c5b19724f164acf1ffb189db1c8fbff4f14396ea7cb1e90f78d69451725377895dfe52cc
	EAP-Message = 0xb99b41e80ddeb58b127a943f4f58cbc562878192fbdc6fece9f871e7c130d35cf5188817e9b133249edd2a1c75d31043ae87553cec7a77ef26aa7d74281db9b77e17c6446c5dd9b188b43250ca0229963722a123a726b00b4027fd0203010001a381ff3081fc301d0603551d0e0416041468d36d3e1ee7bc9d5a057021c363da1365d1ade33081cc0603551d230481c43081c1801468d36d3e1ee7bc9d5a057021c363da1365d1ade3a181a5a481a230819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e
	EAP-Message = 0x31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d820100300c0603551d13040530030101ff300d06092a864886f70d01010405000381810033c00b66b1e579ef73a06798252dab8d5e5511fc00fd276d80d12f834777c6743fdc2743fca1507704e4bc0979e4f60ac3ad9ee83e6f347369229d1f77229ba2e982359da563024a00163dba6d6c986c0bad28af85132ff8f0d76501bf1b7c2dff658ce1e62c01997b6e64e3e8d4373354ce9912847651539063b85bbc5485c51603010004
	EAP-Message = 0x0e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x2aefa9a82e6178895e706ab7410007fe
Finished request 8
Going to the next request
Thread 4 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=10, length=364
Waking up in 2 seconds...
Thread 5 got semaphore
Thread 5 handling request 9, (2 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0xa9b65f85fee568e6ec3a7873c79e28e7
	EAP-Message = 0x020600c81580000000be160301008610000082008001b69b3fa2001e372dd469320eda21f39bb055f5b7fc093b4685400a2dc248ac4c8b7039453100dab968d2e62c1f92d905800299b2287239d200c52ab5063262821a99ad41fc0b140a01de7835d7a913d3447cd745905ac2a447a19e7d66e086c50186cebe8df11ef59c4fd17adfc443fd656bb8e5acb699497c0c8a90b7cee41403010001011603010028dd5730628ccc1738a713376718cd65a41de9d8c5a627fbd0363756a87d3e29c076384f1cceefbd91
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "264"
	NAS-Port = 264
	State = 0x2aefa9a82e6178895e706ab7410007fe
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 9
  rlm_eap: EAP packet type response id 6 length 200
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 9
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 4
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 4
  modcall[authorize]: module "sql" returns ok for request 9
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 9
modcall: leaving group authorize (returns updated) for request 9
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 9
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/ttls
  rlm_eap: processing type ttls
  rlm_eap_ttls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11 
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange  
    TLS_accept: SSLv3 read client key exchange A 
  rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]  
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished  
    TLS_accept: SSLv3 read finished A 
  rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]  
    TLS_accept: SSLv3 write change cipher spec A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished  
    TLS_accept: SSLv3 write finished A 
    TLS_accept: SSLv3 flush data 
    (other): SSL negotiation finished successfully 
SSL Connection Established 
  eaptls_process returned 13 
  modcall[authenticate]: module "eap" returns handled for request 9
modcall: leaving group authenticate (returns handled) for request 9
Sending Access-Challenge of id 10 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x0107003d1580000000331403010001011603010028d09a0d15b9f17a54edb4e07a811ae3ee573dc37bea7d6020ef40e193285ccde39f81c34e77512361
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x55dc6df6783d5f2580d0d5a0ca2b002c
Finished request 9
Going to the next request
Thread 5 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=11, length=235
Waking up in 2 seconds...
Thread 1 got semaphore
Thread 1 handling request 10, (3 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0x0f23d28e21d0ae5d05c1ef8623e474e5
	EAP-Message = 0x0207004715800000003d1703010038736c639ffc49cf8fe16d239e25fba0624211a06879f2c90bb26db208064b476b3d48319aea982d1a6b66df5fd80abd6f3d5b06440a2bc956
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "264"
	NAS-Port = 264
	State = 0x55dc6df6783d5f2580d0d5a0ca2b002c
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 10
  rlm_eap: EAP packet type response id 7 length 71
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 10
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 3
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 3
  modcall[authorize]: module "sql" returns ok for request 10
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 10
modcall: leaving group authorize (returns updated) for request 10
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 10
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/ttls
  rlm_eap: processing type ttls
  rlm_eap_ttls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11 
  eaptls_process returned 7 
  rlm_eap_ttls: Session established.  Proceeding to decode tunneled attributes.
  TTLS: Got tunneled request
	User-Name = "gilberto"
	User-Password = "teste"
	FreeRADIUS-Proxied-To = 127.0.0.1
  TTLS: Sending tunneled request
	User-Name = "gilberto"
	User-Password = "teste"
	FreeRADIUS-Proxied-To = 127.0.0.1
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 10
  rlm_eap: No EAP-Message, not doing EAP
  modcall[authorize]: module "eap" returns noop for request 10
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 2
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 2
  modcall[authorize]: module "sql" returns ok for request 10
  modcall[authorize]: module "pap" returns updated for request 10
modcall: leaving group authorize (returns updated) for request 10
  rad_check_password:  Found Auth-Type pap
auth: type "PAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group PAP for request 10
rlm_pap: login attempt with password teste
rlm_pap: Using CRYPT encryption.
rlm_pap: User authenticated successfully
  modcall[authenticate]: module "pap" returns ok for request 10
modcall: leaving group PAP (returns ok) for request 10
Trying to look up name of unknown client 127.0.0.1. 
Login OK: [gilberto/teste] (from client UNKNOWN-CLIENT port 0)
  TTLS: Got tunneled reply RADIUS code 2
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
  TTLS: Got tunneled Access-Accept
  rlm_eap: Freeing handler
  modcall[authenticate]: module "eap" returns ok for request 10
modcall: leaving group authenticate (returns ok) for request 10
Login OK: [gilberto/<no User-Password attribute>] (from client ap2 port 264 cli 0040.96a2.24f3)
Sending Access-Accept of id 11 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	MS-MPPE-Recv-Key = 0x2ccf173bda6a1c3f7ca61a68e11a4ced2f8250da966128d13ddcd8b15c117d47
	MS-MPPE-Send-Key = 0x5db9cbefd51f579d8e13b9b7a985cd326502a08d4f83b0aab2b977b79c9e3b0c
	EAP-Message = 0x03070004
	Message-Authenticator = 0x00000000000000000000000000000000
	User-Name = "gilberto"
Finished request 10
Going to the next request
Thread 1 waiting to be assigned a request
--- Walking the entire request list ---
Cleaning up request 0 ID 1 with timestamp 467ade11
Cleaning up request 1 ID 2 with timestamp 467ade11
Cleaning up request 2 ID 3 with timestamp 467ade11
Cleaning up request 3 ID 4 with timestamp 467ade11
Cleaning up request 4 ID 5 with timestamp 467ade11
Waking up in 4 seconds...
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=12, length=159
--- Walking the entire request list ---
Thread 2 got semaphore
Waking up in 2 seconds...
Thread 2 handling request 11, (3 handled so far)
Threads: total/active/spare threads = 5/1/4
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0x67f4e443d3f867d495d1539eb169b5df
	EAP-Message = 0x0201000d0167696c626572746f
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "265"
	NAS-Port = 265
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 11
  rlm_eap: EAP packet type response id 1 length 13
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 11
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 1
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 1
  modcall[authorize]: module "sql" returns ok for request 11
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 11
modcall: leaving group authorize (returns updated) for request 11
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 11
  rlm_eap: EAP Identity
  rlm_eap: processing type tls
  rlm_eap_tls: Initiate
  rlm_eap_tls: Start returned 1
  modcall[authenticate]: module "eap" returns handled for request 11
modcall: leaving group authenticate (returns handled) for request 11
Sending Access-Challenge of id 12 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x010200061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x495e97fbd83c8c8abea0ebd247bbbdf7
Finished request 11
Going to the next request
Thread 2 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=13, length=159
Waking up in 2 seconds...
Thread 3 got semaphore
Threads: total/active/spare threads = 5/0/5
Thread 3 handling request 12, (3 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0xf3dba6252ba148fabca275161c321a4f
	EAP-Message = 0x0203000d0167696c626572746f
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "265"
	NAS-Port = 265
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 12
  rlm_eap: EAP packet type response id 3 length 13
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 12
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 0
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 0
  modcall[authorize]: module "sql" returns ok for request 12
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 12
modcall: leaving group authorize (returns updated) for request 12
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 12
  rlm_eap: EAP Identity
  rlm_eap: processing type tls
  rlm_eap_tls: Initiate
  rlm_eap_tls: Start returned 1
  modcall[authenticate]: module "eap" returns handled for request 12
modcall: leaving group authenticate (returns handled) for request 12
Sending Access-Challenge of id 13 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x010400061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x71edece91825e4ace2ab65b7ed192fe7
Finished request 12
Going to the next request
Thread 3 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=14, length=256
Waking up in 2 seconds...
Thread 4 got semaphore
Thread 4 handling request 13, (3 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0x55078379ded64b891aa47a9895e95d69
	EAP-Message = 0x0204005c158000000052160301004d01000049030194f3c3f268be36088799671156803b4c2e771caf5730d084c6fffc9c5dc14bfc20956154aff114e89e9d0260f441587dfcf414b543e50a2bf7a9c78919968f58e70002000a0100
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "265"
	NAS-Port = 265
	State = 0x71edece91825e4ace2ab65b7ed192fe7
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 13
  rlm_eap: EAP packet type response id 4 length 92
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 13
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 4
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 4
  modcall[authorize]: module "sql" returns ok for request 13
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 13
modcall: leaving group authorize (returns updated) for request 13
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 13
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/ttls
  rlm_eap: processing type ttls
  rlm_eap_ttls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11 
    (other): before/accept initialization 
    TLS_accept: before/accept initialization 
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 004d], ClientHello  
    TLS_accept: SSLv3 read client hello A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello  
    TLS_accept: SSLv3 write server hello A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0694], Certificate  
    TLS_accept: SSLv3 write certificate A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
    TLS_accept: SSLv3 write server done A 
    TLS_accept: SSLv3 flush data 
    TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase 
In SSL Accept mode  
  eaptls_process returned 13 
  modcall[authenticate]: module "eap" returns handled for request 13
modcall: leaving group authenticate (returns handled) for request 13
Sending Access-Challenge of id 14 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x0105040a15c0000006f1160301004a020000460301467ade1973f1c30a6d7c87770297168766a7bbecdac34879ac3538b1735320e3202e6ca6bb3cfbb973be7ab33fe8a36f2299e781ccbe9352b53781a8f9c3db294e000a0016030106940b00069000068d0002cd308202c930820232a003020102020102300d06092a864886f70d010104050030819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e74206365
	EAP-Message = 0x7274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d301e170d3034303132353133323631305a170d3035303132343133323631305a30819b310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f73743119301706035504031310526f6f74206365727469666963617465311f301d06092a864886f70d0109011610726f6f74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003
	EAP-Message = 0x818d0030818902818100dac525422bfedb082629a2cba44b3449c90d0ab462fb72c8434a782098863d7eb7d7e70028c2b7ad555a51cc756cf4fa1d7091615ab450d5289553ae6616aff014a55085d6b8fb4aee98638e426175cdd36c665c63cda177d34920eb30585edc8773999c2980f81ad4638bbbea1c82d054023db7ef24a3ec1c3f6241a903d7f30203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d0101040500038181007a2d921b1cf13bf2982a9178ec9ede6d88edc178a2e8bd40a0a06fb6f0769957884cd7084537083496fd184165293f583c8e8240eb68e042c94b15752e4c07e80d09
	EAP-Message = 0x779afa3dd55c24fa54ac292d77205d1c2477ed30d59f57caf9bd21ff2a8d16cc0911c50e4f295763fcb60efa3c3d2d0e43850f6e6fbe284902f6e83503650003ba308203b63082031fa003020102020100300d06092a864886f70d010104050030819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c
	EAP-Message = 0x652e636f6d301e170d3034303132353133323630375a
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x371209c8b0393addfc9574a8deb19ea3
Finished request 13
Going to the next request
Thread 4 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=15, length=170
Waking up in 2 seconds...
Thread 5 got semaphore
Thread 5 handling request 14, (3 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0x94118edafb7ca6af2b7513c76a207457
	EAP-Message = 0x020500061500
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "265"
	NAS-Port = 265
	State = 0x371209c8b0393addfc9574a8deb19ea3
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 14
  rlm_eap: EAP packet type response id 5 length 6
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 14
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 3
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 3
  modcall[authorize]: module "sql" returns ok for request 14
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 14
modcall: leaving group authorize (returns updated) for request 14
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 14
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/ttls
  rlm_eap: processing type ttls
  rlm_eap_ttls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
  rlm_eap_tls: ack handshake fragment handler
  eaptls_verify returned 1 
  eaptls_process returned 13 
  modcall[authenticate]: module "eap" returns handled for request 14
modcall: leaving group authenticate (returns handled) for request 14
Sending Access-Challenge of id 15 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x010602fb1580000006f1170d3036303132343133323630375a30819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100d4c5b19724f164acf1ffb189db1c8fbff4f14396ea7cb1e90f78d69451725377895dfe52cc
	EAP-Message = 0xb99b41e80ddeb58b127a943f4f58cbc562878192fbdc6fece9f871e7c130d35cf5188817e9b133249edd2a1c75d31043ae87553cec7a77ef26aa7d74281db9b77e17c6446c5dd9b188b43250ca0229963722a123a726b00b4027fd0203010001a381ff3081fc301d0603551d0e0416041468d36d3e1ee7bc9d5a057021c363da1365d1ade33081cc0603551d230481c43081c1801468d36d3e1ee7bc9d5a057021c363da1365d1ade3a181a5a481a230819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e
	EAP-Message = 0x31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d820100300c0603551d13040530030101ff300d06092a864886f70d01010405000381810033c00b66b1e579ef73a06798252dab8d5e5511fc00fd276d80d12f834777c6743fdc2743fca1507704e4bc0979e4f60ac3ad9ee83e6f347369229d1f77229ba2e982359da563024a00163dba6d6c986c0bad28af85132ff8f0d76501bf1b7c2dff658ce1e62c01997b6e64e3e8d4373354ce9912847651539063b85bbc5485c51603010004
	EAP-Message = 0x0e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x006e3c1c72446aff2654cd8cecfa7fa1
Finished request 14
Going to the next request
Thread 5 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=16, length=364
Waking up in 2 seconds...
Thread 1 got semaphore
Thread 1 handling request 15, (4 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0x524fa587cf207d7c9b8c1ba136cbecfa
	EAP-Message = 0x020600c81580000000be160301008610000082008046ad1556ba03b82ab2373f27b54cb33821bb18f34e7037716be2652d0d64029023596463895159a1d23ed245674a37baf8ced3c2998635d2b386442b5c5fed432b7772fbbae32634f6e717ffff8e5d547024f29f72cdb28c7592e620a3466e03fa495f379a83a6aa6565ab4ae84bc799789eb2a409bf6ecde32ca410084eeba614030100010116030100285cb5ff5277464035712b49844bc7dc44e5f33e1a63dd4542d509b4eb6f1daa94f2e4e1651e83baca
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "265"
	NAS-Port = 265
	State = 0x006e3c1c72446aff2654cd8cecfa7fa1
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 15
  rlm_eap: EAP packet type response id 6 length 200
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 15
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 2
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 2
  modcall[authorize]: module "sql" returns ok for request 15
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 15
modcall: leaving group authorize (returns updated) for request 15
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 15
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/ttls
  rlm_eap: processing type ttls
  rlm_eap_ttls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11 
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange  
    TLS_accept: SSLv3 read client key exchange A 
  rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]  
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished  
    TLS_accept: SSLv3 read finished A 
  rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]  
    TLS_accept: SSLv3 write change cipher spec A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished  
    TLS_accept: SSLv3 write finished A 
    TLS_accept: SSLv3 flush data 
    (other): SSL negotiation finished successfully 
SSL Connection Established 
  eaptls_process returned 13 
  modcall[authenticate]: module "eap" returns handled for request 15
modcall: leaving group authenticate (returns handled) for request 15
Sending Access-Challenge of id 16 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x0107003d15800000003314030100010116030100282200a62e549cd997393e3628406e71f4b4e49761532bbd3d8da404ee17e92d354733755b2688ef97
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x601dd2da0012ca6354a7c04d5b91a21d
Finished request 15
Going to the next request
Thread 1 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=17, length=235
Waking up in 2 seconds...
Thread 2 got semaphore
Thread 2 handling request 16, (4 handled so far)
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0x2092b71d0b47bb3ae7bbf807a348d2db
	EAP-Message = 0x0207004715800000003d1703010038aece30d0891a4be87d6452677e3db6f8f2eb02954b52550ddd1cb23f507c0ff3284cf92ede34eda182e55b6236ed31a7385a88d76f3a5791
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "265"
	NAS-Port = 265
	State = 0x601dd2da0012ca6354a7c04d5b91a21d
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 16
  rlm_eap: EAP packet type response id 7 length 71
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 16
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 1
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 1
  modcall[authorize]: module "sql" returns ok for request 16
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 16
modcall: leaving group authorize (returns updated) for request 16
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 16
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/ttls
  rlm_eap: processing type ttls
  rlm_eap_ttls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11 
  eaptls_process returned 7 
  rlm_eap_ttls: Session established.  Proceeding to decode tunneled attributes.
  TTLS: Got tunneled request
	User-Name = "gilberto"
	User-Password = "teste"
	FreeRADIUS-Proxied-To = 127.0.0.1
  TTLS: Sending tunneled request
	User-Name = "gilberto"
	User-Password = "teste"
	FreeRADIUS-Proxied-To = 127.0.0.1
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 16
  rlm_eap: No EAP-Message, not doing EAP
  modcall[authorize]: module "eap" returns noop for request 16
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 0
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 0
  modcall[authorize]: module "sql" returns ok for request 16
  modcall[authorize]: module "pap" returns updated for request 16
modcall: leaving group authorize (returns updated) for request 16
  rad_check_password:  Found Auth-Type pap
auth: type "PAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group PAP for request 16
rlm_pap: login attempt with password teste
rlm_pap: Using CRYPT encryption.
rlm_pap: User authenticated successfully
  modcall[authenticate]: module "pap" returns ok for request 16
modcall: leaving group PAP (returns ok) for request 16
Trying to look up name of unknown client 127.0.0.1. 
Login OK: [gilberto/teste] (from client UNKNOWN-CLIENT port 0)
  TTLS: Got tunneled reply RADIUS code 2
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
  TTLS: Got tunneled Access-Accept
  rlm_eap: Freeing handler
  modcall[authenticate]: module "eap" returns ok for request 16
modcall: leaving group authenticate (returns ok) for request 16
Login OK: [gilberto/<no User-Password attribute>] (from client ap2 port 265 cli 0040.96a2.24f3)
Sending Access-Accept of id 17 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	MS-MPPE-Recv-Key = 0x3a2094f4e129d1f9884e3c37b4810d4808872c6e8fd566e8b6c8900f52b4b554
	MS-MPPE-Send-Key = 0x54d7106f542b65ca06bc4c190f0e9af2549baa3c73a781eb36bd129d036e02da
	EAP-Message = 0x03070004
	Message-Authenticator = 0x00000000000000000000000000000000
	User-Name = "gilberto"
Finished request 16
Going to the next request
Thread 2 waiting to be assigned a request
--- Walking the entire request list ---
Cleaning up request 5 ID 6 with timestamp 467ade15
Cleaning up request 6 ID 7 with timestamp 467ade15
Cleaning up request 7 ID 8 with timestamp 467ade15
Cleaning up request 8 ID 9 with timestamp 467ade15
Cleaning up request 9 ID 10 with timestamp 467ade15
Cleaning up request 10 ID 11 with timestamp 467ade15
Waking up in 4 seconds...
rad_recv: Access-Request packet from host 10.10.10.5:1645, id=18, length=159
--- Walking the entire request list ---
Thread 3 got semaphore
Waking up in 2 seconds...
Thread 3 handling request 17, (4 handled so far)
Threads: total/active/spare threads = 5/1/4
	User-Name = "gilberto"
	Framed-MTU = 1400
	Called-Station-Id = "001b.5303.b550"
	Calling-Station-Id = "0040.96a2.24f3"
	Cisco-AVPair = "ssid=FONTELONGA"
	Service-Type = Login-User
	Message-Authenticator = 0xf0b730c04cfa71a99363741eedebc8b6
	EAP-Message = 0x0202000d0167696c626572746f
	NAS-Port-Type = Wireless-802.11
	Cisco-NAS-Port = "266"
	NAS-Port = 266
	NAS-IP-Address = 10.10.10.5
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 17
  rlm_eap: EAP packet type response id 2 length 13
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 17
radius_xlat:  'gilberto'
rlm_sql (sql): sql_set_user escaped user --> 'gilberto'
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radcheck           WHERE Username = 'gilberto'          ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 4
radius_xlat:  ''
radius_xlat:  'SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'gilberto'           ORDER BY id'
radius_xlat:  ''
rlm_sql (sql): Released sql socket id: 4
  modcall[authorize]: module "sql" returns ok for request 17
rlm_pap: Found existing Auth-Type, not changing it.
  modcall[authorize]: module "pap" returns noop for request 17
modcall: leaving group authorize (returns updated) for request 17
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 17
  rlm_eap: EAP Identity
  rlm_eap: processing type tls
  rlm_eap_tls: Initiate
  rlm_eap_tls: Start returned 1
  modcall[authenticate]: module "eap" returns handled for request 17
modcall: leaving group authenticate (returns handled) for request 17
Sending Access-Challenge of id 18 to 10.10.10.5 port 1645
	Tunnel-Type:0 := VLAN
	Tunnel-Medium-Type:0 := IEEE-802
	Tunnel-Private-Group-Id:0 := "2"
	EAP-Message = 0x010300061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xed36682d4ca76bf242a5306504c869d2
Finished request 17