hostapd + freeradius + windows users problem

Dajul Goa goa at dajul.com
Wed Nov 12 17:30:47 CET 2008


Hello,
I've setup hostapd 0.5.10-1(with bridge) + freeradius 2.1.1(with mysql) and it works pretty good except one thing:
Windows(vista sp1) users when turn their machines off, radacct mess up (this doesn't happened when user request disconnect manually)

User "goa" connects and when he turns machine off, new user "host/filteria"(his machine name) appears.
Maybe the problems is inside hostapd(which I can't find), but I don't understand why "host/filteria" is updated with "goa" info.

Radacct looks like this (hostapd radius_acct_interim_interval=300):
Client IP Address 	Download 	Login Time 	Logout Time 	NAS IP Address 	NAS Port 	Session Time 	Upload 	User Name
- 	 0.78 MBs 	2008-11-12 15:45:06 	- 	                   127.0.0.1 	0 	20 minutes 	233.77 KBs 	goa
- 	0.81 MBs 	2008-11-12 15:45:06 	2008-11-12 16:07:06 	127.0.0.1 	0 	22 minutes 	244.33 KBs 	host/filteria


Thanks.


Debug log for "goa" connect and "host/filteria" disconnect:

Starting - reading configuration files ...
including configuration file /etc/freeradius/radiusd.conf
including configuration file /etc/freeradius/clients.conf
including files in directory /etc/freeradius/modules/
including configuration file /etc/freeradius/modules/policy
including configuration file /etc/freeradius/modules/detail.example.com
including configuration file /etc/freeradius/modules/sradutmp
including configuration file /etc/freeradius/modules/ippool
including configuration file /etc/freeradius/modules/mac2ip
including configuration file /etc/freeradius/modules/linelog
including configuration file /etc/freeradius/modules/krb5
including configuration file /etc/freeradius/modules/detail
including configuration file /etc/freeradius/modules/sql_log
including configuration file /etc/freeradius/modules/checkval
including configuration file /etc/freeradius/modules/inner-eap
including configuration file /etc/freeradius/modules/counter
including configuration file /etc/freeradius/modules/always
including configuration file /etc/freeradius/modules/smbpasswd
including configuration file /etc/freeradius/modules/mac2vlan
including configuration file /etc/freeradius/modules/exec
including configuration file /etc/freeradius/modules/expiration
including configuration file /etc/freeradius/modules/ldap
including configuration file /etc/freeradius/modules/detail.log
including configuration file /etc/freeradius/modules/pam
including configuration file /etc/freeradius/modules/attr_rewrite
including configuration file /etc/freeradius/modules/preprocess
including configuration file /etc/freeradius/modules/unix
including configuration file /etc/freeradius/modules/files
including configuration file /etc/freeradius/modules/radutmp
including configuration file /etc/freeradius/modules/echo
including configuration file /etc/freeradius/modules/acct_unique
including configuration file /etc/freeradius/modules/expr
including configuration file /etc/freeradius/modules/passwd
including configuration file /etc/freeradius/modules/etc_group
including configuration file /etc/freeradius/modules/realm
including configuration file /etc/freeradius/modules/chap
including configuration file /etc/freeradius/modules/attr_filter
including configuration file /etc/freeradius/modules/logintime
including configuration file /etc/freeradius/modules/pap
including configuration file /etc/freeradius/modules/digest
including configuration file /etc/freeradius/modules/wimax
including configuration file /etc/freeradius/modules/mschap
including configuration file /etc/freeradius/eap.conf
including configuration file /etc/freeradius/sql.conf
including configuration file /etc/freeradius/sql/mysql/dialup.conf
including configuration file /etc/freeradius/sql/mysql/counter.conf
including configuration file /etc/freeradius/policy.conf
including files in directory /etc/freeradius/sites-enabled/
including configuration file /etc/freeradius/sites-enabled/default
including configuration file /etc/freeradius/sites-enabled/inner-tunnel
group = freerad
user = freerad
including dictionary file /etc/freeradius/dictionary
main {
	prefix = "/usr/local"
	localstatedir = "/usr/local/var"
	logdir = "/var/log/freeradius"
	libdir = "/usr/lib"
	radacctdir = "/var/log/freeradius/radacct"
	hostname_lookups = no
	max_request_time = 30
	cleanup_delay = 5
	max_requests = 1024
	allow_core_dumps = no
	pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
	checkrad = "/usr/sbin/checkrad"
	debug_level = 0
	proxy_requests = no
 log {
	stripped_names = no
	auth = yes
	auth_badpass = yes
	auth_goodpass = no
 }
 security {
	max_attributes = 200
	reject_delay = 1
	status_server = yes
 }
}
 client localhost {
	ipaddr = 127.0.0.2
	require_message_authenticator = no
	secret = "secret"
	nastype = "other"
 }
radiusd: #### Loading Realms and Home Servers ####
radiusd: #### Instantiating modules ####
 instantiate {
 Module: Linked to module rlm_exec
 Module: Instantiating exec
  exec {
	wait = no
	input_pairs = "request"
	shell_escape = yes
  }
 Module: Linked to module rlm_expr
 Module: Instantiating expr
 Module: Linked to module rlm_expiration
 Module: Instantiating expiration
  expiration {
	reply-message = "Password Has Expired  "
  }
 Module: Linked to module rlm_logintime
 Module: Instantiating logintime
  logintime {
	reply-message = "You are calling outside your allowed timespan  "
	minimum-timeout = 60
  }
 }
radiusd: #### Loading Virtual Servers ####
server inner-tunnel {
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_pap
 Module: Instantiating pap
  pap {
	encryption_scheme = "auto"
	auto_header = no
  }
 Module: Linked to module rlm_chap
 Module: Instantiating chap
 Module: Linked to module rlm_mschap
 Module: Instantiating mschap
  mschap {
	use_mppe = yes
	require_encryption = no
	require_strong = no
	with_ntdomain_hack = no
  }
 Module: Linked to module rlm_unix
 Module: Instantiating unix
  unix {
	radwtmp = "/var/log/freeradius/radwtmp"
  }
 Module: Linked to module rlm_eap
 Module: Instantiating eap
  eap {
	default_eap_type = "ttls"
	timer_expire = 60
	ignore_unknown_eap_types = no
	cisco_accounting_username_bug = no
	max_sessions = 2048
  }
 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
	pem_file_type = yes
	private_key_file = "/etc/freeradius/certs/server.pem"
	certificate_file = "/etc/freeradius/certs/server.pem"
	CA_file = "/etc/freeradius/certs/ca.pem"
	private_key_password = "whatever"
	dh_file = "/etc/freeradius/certs/dh"
	random_file = "/etc/freeradius/certs/random"
	fragment_size = 1024
	include_length = yes
	check_crl = no
	cipher_list = "DEFAULT"
	make_cert_command = "/etc/freeradius/certs/bootstrap"
    cache {
	enable = no
	lifetime = 24
	max_entries = 255
    }
   }
 Module: Linked to sub-module rlm_eap_ttls
 Module: Instantiating eap-ttls
   ttls {
	default_eap_type = "mschapv2"
	copy_request_to_tunnel = no
	use_tunneled_reply = no
	virtual_server = "inner-tunnel"
   }
 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 suffix
  realm suffix {
	format = "suffix"
	delimiter = "@"
	ignore_default = no
	ignore_null = no
  }
 Module: Linked to module rlm_sql
 Module: Instantiating sql
  sql {
	driver = "rlm_sql_mysql"
	server = "localhost"
	port = ""
	login = "freerad"
	password = "mysqlpass"
	radius_db = "freerad"
	read_groups = yes
	sqltrace = no
	sqltracefile = "/var/log/freeradius/sqltrace.sql"
	readclients = yes
	deletestalesessions = yes
	num_sql_socks = 5
	sql_user_name = "%{User-Name}"
	default_user_profile = ""
	nas_query = "SELECT id, nasname, shortname, type, secret FROM nas"
	authorize_check_query = "SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id"
	authorize_reply_query = "SELECT id, username, attribute, value, op           FROM radreply           WHERE username = '%{SQL-User-Name}'           ORDER BY id"
	authorize_group_check_query = "SELECT id, groupname, attribute,           Value, op           FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'           ORDER BY id"
	authorize_group_reply_query = "SELECT id, groupname, attribute,           value, op           FROM radgroupreply           WHERE groupname = '%{Sql-Group}'           ORDER BY id"
	accounting_onoff_query = "          UPDATE radacct           SET              acctstoptime       =  '%S',              acctsessiontime    =  unix_timestamp('%S') -                                    unix_timestamp(acctstarttime),              acctterminatecause =  '%{Acct-Terminate-Cause}',              acctstopdelay      =  %{%{Acct-Delay-Time}:-0}           WHERE acctstoptime IS NULL           AND nasipaddress      =  '%{NAS-IP-Address}'           AND acctstarttime     <= '%S'"
	accounting_update_query = "           UPDATE radacct           SET              framedipaddress = '%{Framed-IP-Address}',              acctsessiontime     = '%{Acct-Session-Time}',              acctinputoctets     = '%{%{Acct-Input-Gigawords}:-0}'  << 32 |                                    '%{%{Acct-Input-Octets}:-0}',              acctoutputoctets    = '%{%{Acct-Output-Gigawords}:-0}' << 32 |                                    '%{%{Acct-Output-Octets}:-0}'           WHERE acctsessionid = '%{Acct-Session-Id}'           AND username        = '%{SQL-User-Name}'           AND nasipaddress    = '%{NAS-IP-Address}'"
	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,   xascendsessionsvrkey)           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-Gigawords}:-0}' << 32 |              '%{%{Acct-Input-Octets}:-0}',              '%{%{Acct-Output-Gigawords}:-0}' << 32 |              '%{%{Acct-Output-Octets}:-0}',              '%{Called-Station-Id}', '%{Calling-Station-Id}',              '%{Service-Type}', '%{Framed-Protocol}',              '%{Framed-IP-Address}',              '0', '%{X-Ascend-Session-Svr-Key}')"
	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,    xascendsessionsvrkey)           VALUES             ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',              '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',              '%{NAS-Port-Type}', '%S', NULL,              '0', '%{Acct-Authentic}', '%{Connect-Info}',              '', '0', '0',              '%{Called-Station-Id}', '%{Calling-Station-Id}', '',              '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',              '%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')"
	accounting_start_query_alt = "           UPDATE radacct SET              acctstarttime     = '%S',              acctstartdelay    = '%{%{Acct-Delay-Time}:-0}',              connectinfo_start = '%{Connect-Info}'           WHERE acctsessionid  = '%{Acct-Session-Id}'           AND username         = '%{SQL-User-Name}'           AND nasipaddress     = '%{NAS-IP-Address}'"
	accounting_stop_query = "           UPDATE radacct SET              acctstoptime       = '%S',              acctsessiontime    = '%{Acct-Session-Time}',              acctinputoctets    = '%{%{Acct-Input-Gigawords}:-0}' << 32 |                                   '%{%{Acct-Input-Octets}:-0}',              acctoutputoctets   = '%{%{Acct-Output-Gigawords}:-0}' << 32 |                                   '%{%{Acct-Output-Octets}:-0}',              acctterminatecause = '%{Acct-Terminate-Cause}',              acctstopdelay      = '%{%{Acct-Delay-Time}:-0}',              connectinfo_stop   = '%{Connect-Info}'           WHERE acctsessionid   = '%{Acct-Session-Id}'           AND username          = '%{SQL-User-Name}'           AND nasipaddress      = '%{NAS-IP-Address}'"
	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-Gigawords}:-0}' << 32 |              '%{%{Acct-Input-Octets}:-0}',              '%{%{Acct-Output-Gigawords}:-0}' << 32 |              '%{%{Acct-Output-Octets}:-0}',              '%{Called-Station-Id}', '%{Calling-Station-Id}',              '%{Acct-Terminate-Cause}',              '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',              '0', '%{%{Acct-Delay-Time}:-0}')"
	group_membership_query = "SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority"
	connect_failure_retry_delay = 60
	simul_count_query = ""
	simul_verify_query = "SELECT radacctid, acctsessionid, username,                                nasipaddress, nasportid, framedipaddress,                                callingstationid, framedprotocol                                FROM radacct                                WHERE username = '%{SQL-User-Name}'                                AND acctstoptime IS NULL"
	postauth_query = "INSERT INTO radpostauth                           (username, pass, reply, authdate)                           VALUES (                           '%{User-Name}',                           '%{%{User-Password}:-%{Chap-Password}}',                           '%{reply:Packet-Type}', '%S')"
	safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
  }
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (sql): Attempting to connect to freerad at localhost:/freerad
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
rlm_sql (sql): Processing generate_sql_clients
rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret FROM nas
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Read entry nasname=localhost,shortname=localhost,secret=secret
rlm_sql (sql): Adding client 127.0.0.1 (localhost, server=<none>) to clients list
rlm_sql (sql): Released sql socket id: 4
 Module: Checking session {...} for more modules to load
 Module: Linked to module rlm_radutmp
 Module: Instantiating radutmp
  radutmp {
	filename = "/var/log/freeradius/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 attr_filter.access_reject
  attr_filter attr_filter.access_reject {
	attrsfile = "/etc/freeradius/attrs.access_reject"
	key = "%{User-Name}"
  }
 }
}
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating preprocess
  preprocess {
	huntgroups = "/etc/freeradius/huntgroups"
	hints = "/etc/freeradius/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: Linked to module rlm_sqlcounter
 Module: Instantiating noresetcounter
  sqlcounter noresetcounter {
	counter-name = "Max-All-Session-Time"
	check-name = "Max-All-Session"
	key = "User-Name"
	sqlmod-inst = "sql"
	query = "SELECT SUM(AcctSessionTime) FROM radacct WHERE UserName='%{%k}'"
	reset = "never"
	safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
  }
rlm_sqlcounter: Reply attribute set to Session-Timeout.
rlm_sqlcounter: Counter attribute Max-All-Session-Time is number 11273
rlm_sqlcounter: Check attribute Max-All-Session is number 11274
rlm_sqlcounter: Current Time: 1226501089 [2008-11-12 15:44:49], Next reset 0 [2008-11-12 15:00:00]
rlm_sqlcounter: Current Time: 1226501089 [2008-11-12 15:44:49], Prev reset 0 [2008-11-12 15:00:00]
 Module: Instantiating dailycounter
  sqlcounter dailycounter {
	counter-name = "Daily-Session-Time"
	check-name = "Max-Daily-Session"
	reply-name = "Session-Timeout"
	key = "User-Name"
	sqlmod-inst = "sql"
	query = "SELECT SUM(acctsessiontime -                  GREATEST((%b - UNIX_TIMESTAMP(acctstarttime)), 0))                  FROM radacct WHERE username = '%{%k}' AND                  UNIX_TIMESTAMP(acctstarttime) + acctsessiontime > '%b'"
	reset = "daily"
	safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
  }
rlm_sqlcounter: Reply attribute Session-Timeout is number 27
rlm_sqlcounter: Counter attribute Daily-Session-Time is number 11275
rlm_sqlcounter: Check attribute Max-Daily-Session is number 11276
rlm_sqlcounter: Current Time: 1226501089 [2008-11-12 15:44:49], Next reset 1226530800 [2008-11-13 00:00:00]
rlm_sqlcounter: Current Time: 1226501089 [2008-11-12 15:44:49], Prev reset 1226444400 [2008-11-12 00:00:00]
 Module: Instantiating monthlycounter
  sqlcounter monthlycounter {
	counter-name = "Monthly-Session-Time"
	check-name = "Max-Monthly-Session"
	reply-name = "Session-Timeout"
	key = "User-Name"
	sqlmod-inst = "sql"
	query = "SELECT SUM(acctsessiontime -                  GREATEST((%b - UNIX_TIMESTAMP(acctstarttime)), 0))                  FROM radacct WHERE username='%{%k}' AND                  UNIX_TIMESTAMP(acctstarttime) + acctsessiontime > '%b'"
	reset = "monthly"
	safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
  }
rlm_sqlcounter: Reply attribute Session-Timeout is number 27
rlm_sqlcounter: Counter attribute Monthly-Session-Time is number 11277
rlm_sqlcounter: Check attribute Max-Monthly-Session is number 11278
rlm_sqlcounter: Current Time: 1226501089 [2008-11-12 15:44:49], Next reset 1228086000 [2008-12-01 00:00:00]
rlm_sqlcounter: Current Time: 1226501089 [2008-11-12 15:44:49], Prev reset 1225494000 [2008-11-01 00:00:00]
 Module: Checking preacct {...} for more modules to load
 Module: Linked to module rlm_acct_unique
 Module: Instantiating 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: Instantiating attr_filter.accounting_response
  attr_filter attr_filter.accounting_response {
	attrsfile = "/etc/freeradius/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
 }
radiusd: #### Opening IP addresses and Ports ####
listen {
	type = "auth"
	ipaddr = *
	port = 1812
}
listen {
	type = "acct"
	ipaddr = *
	port = 1813
}
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Ready to process requests.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=108, length=150
	User-Name = "goa"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x0201000801676f61
	Message-Authenticator = 0x4c0eb88ca3928e1068231df5c10666d8
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "goa", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 1 length 8
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns updated
[sql] 	expand: %{User-Name} -> goa
[sql] sql_set_user escaped user --> 'goa'
rlm_sql (sql): Reserving sql socket id: 3
[sql] 	expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'goa'           ORDER BY id
[sql] User found in radcheck table
[sql] 	expand: SELECT id, username, attribute, value, op           FROM radreply           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radreply           WHERE username = 'goa'           ORDER BY id
[sql] 	expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'goa'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] Found existing Auth-Type, not changing it.
++[pap] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[noresetcounter] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[dailycounter] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[monthlycounter] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 108 to 127.0.0.1 port 48290
	EAP-Message = 0x010200061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x4b99d30d4b9bc6906e64b3cd075565f3
Finished request 88.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=109, length=166
	User-Name = "goa"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x020200060319
	State = 0x4b99d30d4b9bc6906e64b3cd075565f3
	Message-Authenticator = 0xbe0ecf56d874c7e7c7468b346602f4c3
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "goa", 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
++[unix] returns updated
[sql] 	expand: %{User-Name} -> goa
[sql] sql_set_user escaped user --> 'goa'
rlm_sql (sql): Reserving sql socket id: 2
[sql] 	expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'goa'           ORDER BY id
[sql] User found in radcheck table
[sql] 	expand: SELECT id, username, attribute, value, op           FROM radreply           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radreply           WHERE username = 'goa'           ORDER BY id
[sql] 	expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'goa'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] Found existing Auth-Type, not changing it.
++[pap] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[noresetcounter] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[dailycounter] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[monthlycounter] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/peap
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 109 to 127.0.0.1 port 48290
	EAP-Message = 0x010300061920
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x4b99d30d4a9aca906e64b3cd075565f3
Finished request 89.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=110, length=274
	User-Name = "goa"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x0203007219800000006816030100630100005f0301491b015f888a66bd71ea6c49b2ece384af9572bde192ccda1309da7212f5bf69000018002f00350005000ac009c00ac013c01400320038001300040100001e000000080006000003676f61000a00080006001700180019000b00020100
	State = 0x4b99d30d4a9aca906e64b3cd075565f3
	Message-Authenticator = 0x20c3d87287fb00cf7af795ce6ff9c280
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "goa", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 3 length 114
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 104
[peap] Length Included
[peap] eaptls_verify returned 11 
[peap]     (other): before/accept initialization 
[peap]     TLS_accept: before/accept initialization 
[peap] <<< TLS 1.0 Handshake [length 0063], ClientHello  
[peap]     TLS_accept: SSLv3 read client hello A 
[peap] >>> TLS 1.0 Handshake [length 002a], ServerHello  
[peap]     TLS_accept: SSLv3 write server hello A 
[peap] >>> TLS 1.0 Handshake [length 0874], Certificate  
[peap]     TLS_accept: SSLv3 write certificate A 
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
[peap]     TLS_accept: SSLv3 write server done A 
[peap]     TLS_accept: SSLv3 flush data 
[peap]     TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase 
In SSL Accept mode  
[peap] eaptls_process returned 13 
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 110 to 127.0.0.1 port 48290
	EAP-Message = 0x0104040019c0000008b1160301002a020000260301491b01672b4a939dceb642dd8c2811cbe1f06a5e3e762ac4f12020a5dd37e31d00002f0016030108740b00087000086d0003b3308203af30820297a003020102020101300d06092a864886f70d0101040500308196310b3009060355040613024553310f300d06035504081306526164697573310f300d0603550407130652616469757331133011060355040a130a44616a756c20496e632e3123302106092a864886f70d0109011614686f73746d61737465724064616a756c2e636f6d312b30290603550403132244616a756c2052616469757320436572746966696361746520417574686f72
	EAP-Message = 0x697479301e170d3038313130383233343733375a170d3138313130363233343733375a308185310b3009060355040613024553310f300d0603550408130652616469757331133011060355040a130a44616a756c20496e632e312b30290603550403132244616a756c2052616469757320436572746966696361746520417574686f726974793123302106092a864886f70d0109011614686f73746d61737465724064616a756c2e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100c953091b7003769d774816aeee6b74d2fec7daf3acdfba5f0a734eb816ca61219ac489aeb8a92fb1b83672e4cbb6fba4c6
	EAP-Message = 0x61dcdc00b1eee1f5c56bd514351da6a2100bae5bec431ae99da78eec0cc46dad92ed06b294d0d04673ca2ac7193278946194100b168d471e917e80aa80523222542927b8beeb284a9516a60e32e64e46c730cbea9f54e7cb48576082319faab2e667ba8135ccc277e4bdabe67cd0e1048f55b034345ed55c0494b106f70d436f50a37e4512252ffe039216ec007dc8ce9ca1f06b9491f6a76caca3ab184e9f83f47116dea65eb6b7c97d61f820f394f1da8995543eec3fa22efd394dbf564b676cbba01f275b25f15fe6bee970a0ff0203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003
	EAP-Message = 0x82010100bc5063282808324084017644002f1320a2ca7147d87a07339ab16fe585a7adeda46c166e4d70dad225e3c033d2db732ddabc7afcb6a7f353948a5398ee06092a1e28ee8077c89113010f1e835bc5bbecdadb52906e8253b186007b6d8cf6aa34a9feb7546785f6c1acbf9bbc8488c28d850025fb714c15d209ac6d7659cfc2158e6a5873d2da1367181b64d2205afe749c7bd1617c647eef50341ac85ded1f9b7a92d4d520ac7e095dbf59b8979bc1bcb07ff7885fcff66aabf9db921ebd507c27d6190e2f447870cddea02c15be593a97701c6f6147b0d98e29b6db0013bd7fd1f5448bf35013a27bde2b83180652f12e09cfeda89faf59d8
	EAP-Message = 0xd214a0a4c2b8ed0004b43082
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x4b99d30d499dca906e64b3cd075565f3
Finished request 90.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=111, length=166
	User-Name = "goa"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x020400061900
	State = 0x4b99d30d499dca906e64b3cd075565f3
	Message-Authenticator = 0x8b5194c26941cfe5b2446f0fddf56d17
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "goa", 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
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1 
[peap] eaptls_process returned 13 
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 111 to 127.0.0.1 port 48290
	EAP-Message = 0x010503fc194004b030820398a003020102020900a9a512d433693877300d06092a864886f70d0101050500308196310b3009060355040613024553310f300d06035504081306526164697573310f300d0603550407130652616469757331133011060355040a130a44616a756c20496e632e3123302106092a864886f70d0109011614686f73746d61737465724064616a756c2e636f6d312b30290603550403132244616a756c2052616469757320436572746966696361746520417574686f72697479301e170d3038313130383233343733375a170d3138313130363233343733375a308196310b3009060355040613024553310f300d0603550408
	EAP-Message = 0x1306526164697573310f300d0603550407130652616469757331133011060355040a130a44616a756c20496e632e3123302106092a864886f70d0109011614686f73746d61737465724064616a756c2e636f6d312b30290603550403132244616a756c2052616469757320436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100ca79376ffeca2a1947dfcee50c95ec7adc98795903b679ab3af5f89054880a533ab524b9d270d723ca0ed787d71342be87366a4b7da0e7e1cbf1c8d6919dac4a3e6c9111f33e708c170f968502690220a78587f41f43eba3b904ec84
	EAP-Message = 0x8428b434fd666889edf9a198747b222d594481a16cadfb747be4590f168d5bcd2e16fa6c5bf967f239c6748724528f0fd994d8d81f78cc7baf9795cf18b82db4efedd9afb12b4e6d10bd81d8f198849f71090d8498b7f122b72159a552dbec70a2ebb215b3b88a0519ae2602f3d3ec99c658f26a908077feede744d205902253feeb357390a23edaaf6bcfa1a0f6a5917010a56ca97ed1d048ec4e06fa84cbcb9926ed070203010001a381fe3081fb301d0603551d0e041604140072fc96f53ec1183a10709ab2c7fb94fb63c7c83081cb0603551d230481c33081c080140072fc96f53ec1183a10709ab2c7fb94fb63c7c8a1819ca48199308196310b
	EAP-Message = 0x3009060355040613024553310f300d06035504081306526164697573310f300d0603550407130652616469757331133011060355040a130a44616a756c20496e632e3123302106092a864886f70d0109011614686f73746d61737465724064616a756c2e636f6d312b30290603550403132244616a756c2052616469757320436572746966696361746520417574686f72697479820900a9a512d433693877300c0603551d13040530030101ff300d06092a864886f70d0101050500038201010046db86797f5dad5c0c90d7413e63408906ca16ee412da530db5cae9154d23fb73eed2bdc2268e499ced937b2e315232da97a2417c888e9d5099bb74c
	EAP-Message = 0xf057eeca59eba2f4
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x4b99d30d489cca906e64b3cd075565f3
Finished request 91.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=112, length=166
	User-Name = "goa"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x020500061900
	State = 0x4b99d30d489cca906e64b3cd075565f3
	Message-Authenticator = 0xb6419eb7a2496da19c943f473a2aca2f
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "goa", 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
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1 
[peap] eaptls_process returned 13 
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 112 to 127.0.0.1 port 48290
	EAP-Message = 0x010600cb190067e9d87d8ab1845fe86ca7eb76074bbee06d08efaa166634273cd09614a41449a1664518226423bd66cbac960e2c384aab995b490eb5bc65495f4dc57c318a7204ba8e56b92ddb6efdbf9e3132b7d842f3acc2071f9b4a535c35f5387191a0228b8a0684b637ccb2bece245d05371bebee160f88c011797a594178d5fb81bc9bf23addb740f3f075c20128ab0b093a40119ac34791997773203d830a82a7a5b713a0a339ec55efa00f77cc3d5a618dc4a2f7123fa6c6b5bba3959a9a16030100040e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x4b99d30d4f9fca906e64b3cd075565f3
Finished request 92.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=113, length=498
	User-Name = "goa"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x020601501980000001461603010106100001020100419006468f761b4f6a235351cd4ed9ad0b9dc1d01b16de407abdc340d13ea4ae49cf4ee1686cbfca6668d804dfbe99287d4bba824bddfa509e6b866ae6ea8d989621aa9b690e5d031acfac7d74761d381b380783ba051c0b75a0e9eb8a7bc717b7154e19fced83e098ff902a78027972846e73411c5bc4107421390831246cb86c314b2e37459bb610cf210ebc46e3cc795c094e7e11f7b4421d61687dbbb7b6b749474da7f373057693459b8b552d2e537326a946746a225bfb4d7878958bad05b9c6e0cc83cf2fefa73697c0f42fe7631a86168332674e6326080334f8c203796fe386cde1e257
	EAP-Message = 0x26d873cc67a33de41063b0db4cfa6132d888f4f914547ff414030100010116030100309325e82e3e311badbfb9ccd2f03a3cb43f6bc7b1d9ca64c3367156a8d177f3afaef558669e9e936a31bd3cf351460884
	State = 0x4b99d30d4f9fca906e64b3cd075565f3
	Message-Authenticator = 0x787ab3a0f510f1f76e5da0aed3e89288
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "goa", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 6 length 253
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 326
[peap] Length Included
[peap] eaptls_verify returned 11 
[peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange  
[peap]     TLS_accept: SSLv3 read client key exchange A 
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]  
[peap] <<< TLS 1.0 Handshake [length 0010], Finished  
[peap]     TLS_accept: SSLv3 read finished A 
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]  
[peap]     TLS_accept: SSLv3 write change cipher spec A 
[peap] >>> TLS 1.0 Handshake [length 0010], Finished  
[peap]     TLS_accept: SSLv3 write finished A 
[peap]     TLS_accept: SSLv3 flush data 
[peap]     (other): SSL negotiation finished successfully 
SSL Connection Established 
[peap] eaptls_process returned 13 
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 113 to 127.0.0.1 port 48290
	EAP-Message = 0x0107004119001403010001011603010030cf1d7acbe5013d38b99800782c599385d8b5d42c039adf684135e503c1c2c044d5f825223a9898d30ad0c5100d0f658b
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x4b99d30d4e9eca906e64b3cd075565f3
Finished request 93.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=114, length=166
	User-Name = "goa"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x020700061900
	State = 0x4b99d30d4e9eca906e64b3cd075565f3
	Message-Authenticator = 0x3c23c41b7444b39a7a32138268b82324
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "goa", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 7 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake is finished
[peap] eaptls_verify returned 3 
[peap] eaptls_process returned 3 
[peap] EAPTLS_SUCCESS
++[eap] returns handled
Sending Access-Challenge of id 114 to 127.0.0.1 port 48290
	EAP-Message = 0x0108002b1900170301002025a24ea766072abdd134ba7d281ede6c6fb9ff823de347830359356f048c77ad
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x4b99d30d4d91ca906e64b3cd075565f3
Finished request 94.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=115, length=203
	User-Name = "goa"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x0208002b190017030100200405ba708c9c0f78c03a5ef5a8eb839953b8d90f51ec88d50f0150394c009a67
	State = 0x4b99d30d4d91ca906e64b3cd075565f3
	Message-Authenticator = 0xc8c8fd1654ccd9584cffccdaa1e941f6
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "goa", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 8 length 43
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7 
[peap] Done initial handshake
[peap] eaptls_process returned 7 
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Identity - goa
[peap] Got tunnled request
	EAP-Message = 0x0208000801676f61
server (null) {
  PEAP: Got tunneled identity of goa
  PEAP: Setting default EAP type for tunneled EAP session.
  PEAP: Setting User-Name to goa
Sending tunneled request
	EAP-Message = 0x0208000801676f61
	FreeRADIUS-Proxied-To = 127.0.0.1
	User-Name = "goa"
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
++[mschap] returns noop
++[unix] returns updated
[suffix] No '@' in User-Name = "goa", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 8 length 8
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[sql] 	expand: %{User-Name} -> goa
[sql] sql_set_user escaped user --> 'goa'
rlm_sql (sql): Reserving sql socket id: 1
[sql] 	expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'goa'           ORDER BY id
[sql] User found in radcheck table
[sql] 	expand: SELECT id, username, attribute, value, op           FROM radreply           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radreply           WHERE username = 'goa'           ORDER BY id
[sql] 	expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'goa'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 1
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] Found existing Auth-Type, not changing it.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
++[eap] returns handled
} # server inner-tunnel
[peap] Got tunneled reply code 11
	EAP-Message = 0x0109001d1a01090018105de803fdedfed73165bb3558532f3a66676f61
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x9f97f2289f9ee8e87c9460d74b6eb272
[peap] Got tunneled reply RADIUS code 11
	EAP-Message = 0x0109001d1a01090018105de803fdedfed73165bb3558532f3a66676f61
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x9f97f2289f9ee8e87c9460d74b6eb272
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 115 to 127.0.0.1 port 48290
	EAP-Message = 0x0109003b1900170301003024eefe1cd498c25520f7809d9828616262290187eaf4ae03babd72427c4302fc327858b70e1052e1d224257fb98e9f27
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x4b99d30d4c90ca906e64b3cd075565f3
Finished request 95.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=116, length=251
	User-Name = "goa"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x0209005b190017030100506d3e13b8540005c9c6ef7e20faf4e42524ee39e9a44b53d9c788900799b5d1ec9bf6057cd9323e6048833ae5e230630f7fd728c4ca53c4d07a739fa843486507f6bd44336d98c83c549b36b561c38c32
	State = 0x4b99d30d4c90ca906e64b3cd075565f3
	Message-Authenticator = 0x9bd316eea408ac5b0de657e498a5a53d
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "goa", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 9 length 91
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7 
[peap] Done initial handshake
[peap] eaptls_process returned 7 
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] EAP type mschapv2
[peap] Got tunnled request
	EAP-Message = 0x0209003e1a0209003931709030ad20b0b3eb42cb7d6e17c51aa80000000000000000140b10b852f4fd9c9cf8fc39913ddd3d1f08cf5795d607e500676f61
server (null) {
  PEAP: Setting User-Name to goa
Sending tunneled request
	EAP-Message = 0x0209003e1a0209003931709030ad20b0b3eb42cb7d6e17c51aa80000000000000000140b10b852f4fd9c9cf8fc39913ddd3d1f08cf5795d607e500676f61
	FreeRADIUS-Proxied-To = 127.0.0.1
	User-Name = "goa"
	State = 0x9f97f2289f9ee8e87c9460d74b6eb272
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
++[mschap] returns noop
++[unix] returns updated
[suffix] No '@' in User-Name = "goa", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 9 length 62
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[sql] 	expand: %{User-Name} -> goa
[sql] sql_set_user escaped user --> 'goa'
rlm_sql (sql): Reserving sql socket id: 0
[sql] 	expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'goa'           ORDER BY id
[sql] User found in radcheck table
[sql] 	expand: SELECT id, username, attribute, value, op           FROM radreply           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radreply           WHERE username = 'goa'           ORDER BY id
[sql] 	expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'goa'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 0
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] Found existing Auth-Type, not changing it.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[mschapv2] +- entering group MS-CHAP {...}
[mschap] Told to do MS-CHAPv2 for goa with NT-Password
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
MSCHAP Success 
++[eap] returns handled
} # server inner-tunnel
[peap] Got tunneled reply code 11
	EAP-Message = 0x010a00331a0309002e533d30343843463441444337434241393532393142303043444332394544424234303646383730443933
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x9f97f2289e9de8e87c9460d74b6eb272
[peap] Got tunneled reply RADIUS code 11
	EAP-Message = 0x010a00331a0309002e533d30343843463441444337434241393532393142303043444332394544424234303646383730443933
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x9f97f2289e9de8e87c9460d74b6eb272
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 116 to 127.0.0.1 port 48290
	EAP-Message = 0x010a005b19001703010050255f8238122fa05ddc0d3817587da401d00faad7956cd93c1526324d08fc2d7584e8db57472102e78553f9ddbd8832a094f6e95e73bdf1f7f6ed48451dc94b2cc38a4a4f0b689e5004fd402142eb8dfd
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x4b99d30d4393ca906e64b3cd075565f3
Finished request 96.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=117, length=203
	User-Name = "goa"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x020a002b190017030100204735c1a490cf40c01270af0846512c40b7aebee97bc1c0765a30c39d869fd529
	State = 0x4b99d30d4393ca906e64b3cd075565f3
	Message-Authenticator = 0x7813a24cc33a1dcc3f257e9cb9a1e027
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "goa", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 10 length 43
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7 
[peap] Done initial handshake
[peap] eaptls_process returned 7 
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] EAP type mschapv2
[peap] Got tunnled request
	EAP-Message = 0x020a00061a03
server (null) {
  PEAP: Setting User-Name to goa
Sending tunneled request
	EAP-Message = 0x020a00061a03
	FreeRADIUS-Proxied-To = 127.0.0.1
	User-Name = "goa"
	State = 0x9f97f2289e9de8e87c9460d74b6eb272
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
++[mschap] returns noop
++[unix] returns updated
[suffix] No '@' in User-Name = "goa", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 10 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[sql] 	expand: %{User-Name} -> goa
[sql] sql_set_user escaped user --> 'goa'
rlm_sql (sql): Reserving sql socket id: 4
[sql] 	expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'goa'           ORDER BY id
[sql] User found in radcheck table
[sql] 	expand: SELECT id, username, attribute, value, op           FROM radreply           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radreply           WHERE username = 'goa'           ORDER BY id
[sql] 	expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'goa'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] Found existing Auth-Type, not changing it.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[eap] Freeing handler
++[eap] returns ok
Login OK: [goa] (from client localhost port 0 via TLS tunnel)
} # server inner-tunnel
[peap] Got tunneled reply code 2
	EAP-Message = 0x030a0004
	Message-Authenticator = 0x00000000000000000000000000000000
	User-Name = "goa"
[peap] Got tunneled reply RADIUS code 2
	EAP-Message = 0x030a0004
	Message-Authenticator = 0x00000000000000000000000000000000
	User-Name = "goa"
[peap] Tunneled authentication was successful.
[peap] SUCCESS
++[eap] returns handled
Sending Access-Challenge of id 117 to 127.0.0.1 port 48290
	EAP-Message = 0x010b002b190017030100202a9483874a219f046d6e6c787f476a4d3cfa7225f495b39abdb1178a34c6129e
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x4b99d30d4292ca906e64b3cd075565f3
Finished request 97.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=118, length=203
	User-Name = "goa"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x020b002b190017030100206d08dd866d33934b1081d00d1fca1aec1d077d601f4f81dc1844b63eee41c189
	State = 0x4b99d30d4292ca906e64b3cd075565f3
	Message-Authenticator = 0xc02bcc0d9ae87af86070f84534d8439d
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "goa", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 11 length 43
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7 
[peap] Done initial handshake
[peap] eaptls_process returned 7 
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Received EAP-TLV response.
[peap] Success
[eap] Freeing handler
++[eap] returns ok
Login OK: [goa] (from client localhost port 0 cli 00-60-B3-FE-3E-57)
+- entering group post-auth {...}
[sql] 	expand: %{User-Name} -> goa
[sql] sql_set_user escaped user --> 'goa'
[sql] 	expand: %{User-Password} -> 
[sql] 	expand: %{Chap-Password} -> 
[sql] 	expand: INSERT INTO radpostauth                           (username, pass, reply, authdate)                           VALUES (                           '%{User-Name}',                           '%{%{User-Password}:-%{Chap-Password}}',                           '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth                           (username, pass, reply, authdate)                           VALUES (                           'goa',                           '',                           'Access-Accept', '2008-11-12 17:16:39')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth                           (username, pass, reply, authdate)                           VALUES (                           'goa',                           '',                           'Access-Accept', '2008-11-12 17:16:39')
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
++[exec] returns noop
Sending Access-Accept of id 118 to 127.0.0.1 port 48290
	MS-MPPE-Recv-Key = 0x2fb199cd608728bd36632ecd4c5127e09652af4f10a9470ec2f3c7ed36216ff5
	MS-MPPE-Send-Key = 0x7cc8961a7623da969486d294530cb4f92180bfa429b8043a5b2c5f242d50b5e4
	EAP-Message = 0x030b0004
	Message-Authenticator = 0x00000000000000000000000000000000
	User-Name = "goa"
Finished request 98.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Accounting-Request packet from host 127.0.0.1 port 48750, id=119, length=147
	Acct-Session-Id = "491AE8D8-00000005"
	Acct-Status-Type = Start
	Acct-Authentic = RADIUS
	User-Name = "goa"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address = 127.0.0.1,NAS-IP-Address = 127.0.0.1,Acct-Session-Id = "491AE8D8-00000005",User-Name = "goa"'
[acct_unique] Acct-Unique-Session-ID = "fdadf057d3e7bf59".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "goa", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
+- entering group accounting {...}
++[unix] returns ok
[radutmp] 	expand: /var/log/freeradius/radutmp -> /var/log/freeradius/radutmp
[radutmp] 	expand: %{User-Name} -> goa
++[radutmp] returns ok
[sql] 	expand: %{User-Name} -> goa
[sql] sql_set_user escaped user --> 'goa'
[sql] 	expand: %{Acct-Delay-Time} -> 
[sql] 	expand:            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,    xascendsessionsvrkey)           VALUES             ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',              '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',              '%{NAS-Port-Type}', '%S', NULL,              '0', '%{Acct-Authentic}', '%{Connect-Info}',              '', '0', '0',              '%{Called-Station-Id}', '%{Calling-Station-Id}', '',              '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',      
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
[attr_filter.accounting_response] 	expand: %{User-Name} -> goa
 attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 119 to 127.0.0.1 port 48750
Finished request 99.
Cleaning up request 99 ID 119 with timestamp +5510
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 88 ID 108 with timestamp +5509
Cleaning up request 89 ID 109 with timestamp +5509
Cleaning up request 90 ID 110 with timestamp +5510
Cleaning up request 91 ID 111 with timestamp +5510
Cleaning up request 92 ID 112 with timestamp +5510
Cleaning up request 93 ID 113 with timestamp +5510
Cleaning up request 94 ID 114 with timestamp +5510
Cleaning up request 95 ID 115 with timestamp +5510
Cleaning up request 96 ID 116 with timestamp +5510
Cleaning up request 97 ID 117 with timestamp +5510
Cleaning up request 98 ID 118 with timestamp +5510
Ready to process requests.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=120, length=170
	User-Name = "host/filteria"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x020c001201686f73742f66696c7465726961
	Message-Authenticator = 0xd1b21268ceb7ac27768204f1e67600ca
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "host/filteria", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 12 length 18
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[sql] 	expand: %{User-Name} -> host/filteria
[sql] sql_set_user escaped user --> 'host/filteria'
rlm_sql (sql): Reserving sql socket id: 1
[sql] 	expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'host/filteria'           ORDER BY id
[sql] 	expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'host/filteria'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 1
[sql] User host/filteria not found
++[sql] returns notfound
++[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
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[noresetcounter] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[dailycounter] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[monthlycounter] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 120 to 127.0.0.1 port 48290
	EAP-Message = 0x010d00061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf8f4575ff8f942716e1298eab8e3a233
Finished request 100.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=121, length=176
	User-Name = "host/filteria"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x020d00060319
	State = 0xf8f4575ff8f942716e1298eab8e3a233
	Message-Authenticator = 0x404527658f155043ada1b3ddaf9e226e
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "host/filteria", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 13 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[sql] 	expand: %{User-Name} -> host/filteria
[sql] sql_set_user escaped user --> 'host/filteria'
rlm_sql (sql): Reserving sql socket id: 0
[sql] 	expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'host/filteria'           ORDER BY id
[sql] 	expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'host/filteria'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 0
[sql] User host/filteria not found
++[sql] returns notfound
++[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
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[noresetcounter] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[dailycounter] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[monthlycounter] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/peap
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 121 to 127.0.0.1 port 48290
	EAP-Message = 0x010e00061920
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf8f4575ff9fa4e716e1298eab8e3a233
Finished request 101.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=122, length=289
	User-Name = "host/filteria"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x020e007719800000006d1603010068010000640301491b017fff9c81449db04ff624ad25c38998bfc079eb4f3637f8feb0423fad0f000018002f00350005000ac009c00ac013c0140032003800130004010000230000000d000b00000866696c7465726961000a00080006001700180019000b00020100
	State = 0xf8f4575ff9fa4e716e1298eab8e3a233
	Message-Authenticator = 0x315eafc4de1a9c304ba4a4b2d9d26fb0
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "host/filteria", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 14 length 119
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 109
[peap] Length Included
[peap] eaptls_verify returned 11 
[peap]     (other): before/accept initialization 
[peap]     TLS_accept: before/accept initialization 
[peap] <<< TLS 1.0 Handshake [length 0068], ClientHello  
[peap]     TLS_accept: SSLv3 read client hello A 
[peap] >>> TLS 1.0 Handshake [length 002a], ServerHello  
[peap]     TLS_accept: SSLv3 write server hello A 
[peap] >>> TLS 1.0 Handshake [length 0874], Certificate  
[peap]     TLS_accept: SSLv3 write certificate A 
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
[peap]     TLS_accept: SSLv3 write server done A 
[peap]     TLS_accept: SSLv3 flush data 
[peap]     TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase 
In SSL Accept mode  
[peap] eaptls_process returned 13 
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 122 to 127.0.0.1 port 48290
	EAP-Message = 0x010f040019c0000008b1160301002a020000260301491b0187c1b4b935a665848f1bad8d2e0241ffbf1a7fc9489ca35a5671c93c0500002f0016030108740b00087000086d0003b3308203af30820297a003020102020101300d06092a864886f70d0101040500308196310b3009060355040613024553310f300d06035504081306526164697573310f300d0603550407130652616469757331133011060355040a130a44616a756c20496e632e3123302106092a864886f70d0109011614686f73746d61737465724064616a756c2e636f6d312b30290603550403132244616a756c2052616469757320436572746966696361746520417574686f72
	EAP-Message = 0x697479301e170d3038313130383233343733375a170d3138313130363233343733375a308185310b3009060355040613024553310f300d0603550408130652616469757331133011060355040a130a44616a756c20496e632e312b30290603550403132244616a756c2052616469757320436572746966696361746520417574686f726974793123302106092a864886f70d0109011614686f73746d61737465724064616a756c2e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100c953091b7003769d774816aeee6b74d2fec7daf3acdfba5f0a734eb816ca61219ac489aeb8a92fb1b83672e4cbb6fba4c6
	EAP-Message = 0x61dcdc00b1eee1f5c56bd514351da6a2100bae5bec431ae99da78eec0cc46dad92ed06b294d0d04673ca2ac7193278946194100b168d471e917e80aa80523222542927b8beeb284a9516a60e32e64e46c730cbea9f54e7cb48576082319faab2e667ba8135ccc277e4bdabe67cd0e1048f55b034345ed55c0494b106f70d436f50a37e4512252ffe039216ec007dc8ce9ca1f06b9491f6a76caca3ab184e9f83f47116dea65eb6b7c97d61f820f394f1da8995543eec3fa22efd394dbf564b676cbba01f275b25f15fe6bee970a0ff0203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003
	EAP-Message = 0x82010100bc5063282808324084017644002f1320a2ca7147d87a07339ab16fe585a7adeda46c166e4d70dad225e3c033d2db732ddabc7afcb6a7f353948a5398ee06092a1e28ee8077c89113010f1e835bc5bbecdadb52906e8253b186007b6d8cf6aa34a9feb7546785f6c1acbf9bbc8488c28d850025fb714c15d209ac6d7659cfc2158e6a5873d2da1367181b64d2205afe749c7bd1617c647eef50341ac85ded1f9b7a92d4d520ac7e095dbf59b8979bc1bcb07ff7885fcff66aabf9db921ebd507c27d6190e2f447870cddea02c15be593a97701c6f6147b0d98e29b6db0013bd7fd1f5448bf35013a27bde2b83180652f12e09cfeda89faf59d8
	EAP-Message = 0xd214a0a4c2b8ed0004b43082
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf8f4575ffafb4e716e1298eab8e3a233
Finished request 102.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=123, length=176
	User-Name = "host/filteria"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x020f00061900
	State = 0xf8f4575ffafb4e716e1298eab8e3a233
	Message-Authenticator = 0x7d8e76c82407efe9a4c2da7af3bccf41
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "host/filteria", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 15 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1 
[peap] eaptls_process returned 13 
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 123 to 127.0.0.1 port 48290
	EAP-Message = 0x011003fc194004b030820398a003020102020900a9a512d433693877300d06092a864886f70d0101050500308196310b3009060355040613024553310f300d06035504081306526164697573310f300d0603550407130652616469757331133011060355040a130a44616a756c20496e632e3123302106092a864886f70d0109011614686f73746d61737465724064616a756c2e636f6d312b30290603550403132244616a756c2052616469757320436572746966696361746520417574686f72697479301e170d3038313130383233343733375a170d3138313130363233343733375a308196310b3009060355040613024553310f300d0603550408
	EAP-Message = 0x1306526164697573310f300d0603550407130652616469757331133011060355040a130a44616a756c20496e632e3123302106092a864886f70d0109011614686f73746d61737465724064616a756c2e636f6d312b30290603550403132244616a756c2052616469757320436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100ca79376ffeca2a1947dfcee50c95ec7adc98795903b679ab3af5f89054880a533ab524b9d270d723ca0ed787d71342be87366a4b7da0e7e1cbf1c8d6919dac4a3e6c9111f33e708c170f968502690220a78587f41f43eba3b904ec84
	EAP-Message = 0x8428b434fd666889edf9a198747b222d594481a16cadfb747be4590f168d5bcd2e16fa6c5bf967f239c6748724528f0fd994d8d81f78cc7baf9795cf18b82db4efedd9afb12b4e6d10bd81d8f198849f71090d8498b7f122b72159a552dbec70a2ebb215b3b88a0519ae2602f3d3ec99c658f26a908077feede744d205902253feeb357390a23edaaf6bcfa1a0f6a5917010a56ca97ed1d048ec4e06fa84cbcb9926ed070203010001a381fe3081fb301d0603551d0e041604140072fc96f53ec1183a10709ab2c7fb94fb63c7c83081cb0603551d230481c33081c080140072fc96f53ec1183a10709ab2c7fb94fb63c7c8a1819ca48199308196310b
	EAP-Message = 0x3009060355040613024553310f300d06035504081306526164697573310f300d0603550407130652616469757331133011060355040a130a44616a756c20496e632e3123302106092a864886f70d0109011614686f73746d61737465724064616a756c2e636f6d312b30290603550403132244616a756c2052616469757320436572746966696361746520417574686f72697479820900a9a512d433693877300c0603551d13040530030101ff300d06092a864886f70d0101050500038201010046db86797f5dad5c0c90d7413e63408906ca16ee412da530db5cae9154d23fb73eed2bdc2268e499ced937b2e315232da97a2417c888e9d5099bb74c
	EAP-Message = 0xf057eeca59eba2f4
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf8f4575ffbe44e716e1298eab8e3a233
Finished request 103.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=124, length=176
	User-Name = "host/filteria"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x021000061900
	State = 0xf8f4575ffbe44e716e1298eab8e3a233
	Message-Authenticator = 0xc0a0aa3b5e27956b05ab0be22a8faf90
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "host/filteria", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 16 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1 
[peap] eaptls_process returned 13 
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 124 to 127.0.0.1 port 48290
	EAP-Message = 0x011100cb190067e9d87d8ab1845fe86ca7eb76074bbee06d08efaa166634273cd09614a41449a1664518226423bd66cbac960e2c384aab995b490eb5bc65495f4dc57c318a7204ba8e56b92ddb6efdbf9e3132b7d842f3acc2071f9b4a535c35f5387191a0228b8a0684b637ccb2bece245d05371bebee160f88c011797a594178d5fb81bc9bf23addb740f3f075c20128ab0b093a40119ac34791997773203d830a82a7a5b713a0a339ec55efa00f77cc3d5a618dc4a2f7123fa6c6b5bba3959a9a16030100040e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf8f4575ffce54e716e1298eab8e3a233
Finished request 104.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 48290, id=125, length=176
	User-Name = "host/filteria"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	EAP-Message = 0x021100061900
	State = 0xf8f4575ffce54e716e1298eab8e3a233
	Message-Authenticator = 0x4ad12dfa1a0338fc14f8c4d528a93e75
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "host/filteria", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 17 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1 
[peap] eaptls_process returned 13 
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 125 to 127.0.0.1 port 48290
	EAP-Message = 0x011200061900
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf8f4575ffde64e716e1298eab8e3a233
Finished request 105.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Accounting-Request packet from host 127.0.0.1 port 48750, id=126, length=199
	Acct-Session-Id = "491AE8D8-00000005"
	Acct-Status-Type = Stop
	Acct-Authentic = RADIUS
	User-Name = "host/filteria"
	NAS-IP-Address = 127.0.0.1
	NAS-Port = 0
	Called-Station-Id = "00-13-F7-27-52-EE:Debian Lenny"
	Calling-Station-Id = "00-60-B3-FE-3E-57"
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 0Mbps 802.11"
	Acct-Session-Time = 32
	Acct-Input-Packets = 153
	Acct-Output-Packets = 18
	Acct-Input-Octets = 17918
	Acct-Output-Octets = 3659
	Event-Timestamp = "Nov 12 2008 17:17:11 CET"
	Acct-Terminate-Cause = User-Request
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address = 127.0.0.1,NAS-IP-Address = 127.0.0.1,Acct-Session-Id = "491AE8D8-00000005",User-Name = "host/filteria"'
[acct_unique] Acct-Unique-Session-ID = "26b8b12308938e2c".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "host/filteria", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
+- entering group accounting {...}
++[unix] returns ok
[radutmp] 	expand: /var/log/freeradius/radutmp -> /var/log/freeradius/radutmp
[radutmp] 	expand: %{User-Name} -> host/filteria
++[radutmp] returns ok
[sql] 	expand: %{User-Name} -> host/filteria
[sql] sql_set_user escaped user --> 'host/filteria'
[sql] 	expand: %{Acct-Input-Gigawords} -> 
[sql] 	expand: %{Acct-Input-Octets} -> 17918
[sql] 	expand: %{Acct-Output-Gigawords} -> 
[sql] 	expand: %{Acct-Output-Octets} -> 3659
[sql] 	expand: %{Acct-Delay-Time} -> 
[sql] 	expand:            UPDATE radacct SET              acctstoptime       = '%S',              acctsessiontime    = '%{Acct-Session-Time}',              acctinputoctets    = '%{%{Acct-Input-Gigawords}:-0}' << 32 |                                   '%{%{Acct-Input-Octets}:-0}',              acctoutputoctets   = '%{%{Acct-Output-Gigawords}:-0}' << 32 |                                   '%{%{Acct-Output-Octets}:-0}',              acctterminatecause = '%{Acct-Terminate-Cause}',              acctstopdelay      = '%{%{Acct-Delay-Time}:-0}',              connectinfo_stop   = '%{Connect-Info}'           WHERE acctsessionid   = '%{Acct-Session-Id}'           AND username          = '%{SQL-User-Name}'           AND nasipaddress      = '%{NAS-IP-Address}' ->            UPDATE radacct SET              acctstoptime       = '2008-11-12 17:17:11',              acctsessiontime    = '32',              acctinputoctets    = '0' << 32 |                                   '17918',              acctoutputoctets   = '0' << 32 | 
rlm_sql (sql): Reserving sql socket id: 4
[sql] 	expand: %{Acct-Session-Time} -> 32
[sql] 	expand: %{Acct-Delay-Time} -> 
[sql] 	expand: %{Acct-Input-Gigawords} -> 
[sql] 	expand: %{Acct-Input-Octets} -> 17918
[sql] 	expand: %{Acct-Output-Gigawords} -> 
[sql] 	expand: %{Acct-Output-Octets} -> 3659
[sql] 	expand: %{Acct-Delay-Time} -> 
[sql] 	expand:            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-Gigawords}:-0}' << 32 |              '%{%{Acct-Inpu
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
[attr_filter.accounting_response] 	expand: %{User-Name} -> host/filteria
 attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 126 to 127.0.0.1 port 48750
Finished request 106.
Cleaning up request 106 ID 126 with timestamp +5542
Going to the next request
Waking up in 4.7 seconds.
Cleaning up request 100 ID 120 with timestamp +5542
Cleaning up request 101 ID 121 with timestamp +5542
Cleaning up request 102 ID 122 with timestamp +5542
Cleaning up request 103 ID 123 with timestamp +5542
Cleaning up request 104 ID 124 with timestamp +5542
Waking up in 0.1 seconds.
Cleaning up request 105 ID 125 with timestamp +5542
Ready to process requests.





More information about the Freeradius-Users mailing list