Acct-Interim-Interval not being sent to NAS with Accept-Accept

23 Sep 2010

      I am a newbie on freeradius, so please forgive what may be a simple question 
to all you power users out there!!

I am trying to work out why an Acct-Interim-Interval is not being sent to 
NAS with the Accept-Accept. I don't receive back any accounting messages 
from my WRT54GL with DD-WRT v24 on it. I have seen other posts where this 
comes out with the Accept-Accept and I presume it is needed by the NAS to 
know if to send Acct records back. I have attached the debug output.

The question I have is: Should I see the Acct-Interim-Interval on the 
Accept-Accept. If so, can anyone suggest why it is missing.

Thanks in advance.

Charles

===================================
/etc/freeradius# freeradius -X
FreeRADIUS Version 2.1.9, for host i486-pc-linux-gnu, built on Jun 18 2010 
at 03:34:08
Copyright (C) 1999-2009 The FreeRADIUS server project and contributors.
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE.
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License v2.
Starting - reading configuration files ...
including configuration file /etc/freeradius/radiusd.conf
including configuration file /etc/freeradius/proxy.conf
including configuration file /etc/freeradius/clients.conf
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/inner-tunnel
including configuration file /etc/freeradius/sites-enabled/default
main {
user = "freerad"
group = "freerad"
allow_core_dumps = no
}
including dictionary file /etc/freeradius/dictionary
main {
prefix = "/usr"
localstatedir = "/var"
logdir = "/var/log/freeradius"
libdir = "/usr/lib/freeradius"
radacctdir = "/var/log/freeradius/radacct"
hostname_lookups = no
max_request_time = 30
cleanup_delay = 5
max_requests = 1024
pidfile = "/var/run/freeradius/freeradius.pid"
checkrad = "/usr/sbin/checkrad"
debug_level = 0
proxy_requests = yes
log {
stripped_names = no
auth = no
auth_badpass = no
auth_goodpass = no
}
security {
max_attributes = 200
reject_delay = 1
status_server = yes
}
}
radiusd: #### Loading Realms and Home Servers ####
proxy server {
retry_delay = 5
retry_count = 3
default_fallback = no
dead_time = 120
wake_all_if_all_dead = no
}
home_server localhost {
ipaddr = 127.0.0.1
port = 1812
type = "auth"
secret = "testing123"
response_window = 20
max_outstanding = 65536
require_message_authenticator = no
zombie_period = 40
status_check = "status-server"
ping_interval = 30
check_interval = 30
num_answers_to_alive = 3
num_pings_to_alive = 3
revive_interval = 120
status_check_timeout = 4
irt = 2
mrt = 16
mrc = 5
mrd = 30
}
home_server_pool my_auth_failover {
type = fail-over
home_server = localhost
}
realm example.com {
auth_pool = my_auth_failover
}
realm LOCAL {
}
radiusd: #### Loading Clients ####
client localhost {
ipaddr = 127.0.0.1
require_message_authenticator = no
secret = "aaaaa"
nastype = "other"
}
radiusd: #### Instantiating modules ####
instantiate {
Module: Linked to module rlm_exec
Module: Instantiating exec
exec {
wait = yes
input_pairs = "request"
shell_escape = yes
}
Module: Linked to module rlm_expr
Module: Instantiating expr
Module: Linked to module rlm_counter
Module: Instantiating daily
counter daily {
filename = "/etc/freeradius/db.daily"
key = "User-Name"
reset = "daily"
count-attribute = "Acct-Session-Time"
counter-name = "Daily-Session-Time"
check-name = "Max-Daily-Session"
reply-name = "Session-Timeout"
allowed-servicetype = "Framed-User"
cache-size = 5000
}
rlm_counter: Counter attribute Daily-Session-Time is number 11273
rlm_counter: Current Time: 1285232199 [2010-09-23 09:56:39], Next reset 
1285282800 [2010-09-24 00:00:00]
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 = "md5"
timer_expire = 60
ignore_unknown_eap_types = no
cisco_accounting_username_bug = no
max_sessions = 4096
}
Module: Linked to sub-module rlm_eap_md5
Module: Instantiating eap-md5
Module: Linked to sub-module rlm_eap_leap
Module: Instantiating eap-leap
Module: Linked to sub-module rlm_eap_gtc
Module: Instantiating eap-gtc
gtc {
challenge = "Password: "
auth_type = "PAP"
}
Module: Linked to sub-module rlm_eap_tls
Module: Instantiating eap-tls
tls {
rsa_key_exchange = no
dh_key_exchange = yes
rsa_key_length = 512
dh_key_length = 512
verify_depth = 0
pem_file_type = yes
private_key_file = "/etc/freeradius/certs/server.key"
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 = "md5"
copy_request_to_tunnel = no
use_tunneled_reply = no
virtual_server = "inner-tunnel"
include_length = yes
}
Module: Linked to sub-module rlm_eap_peap
Module: Instantiating eap-peap
peap {
default_eap_type = "mschapv2"
copy_request_to_tunnel = no
use_tunneled_reply = no
proxy_tunneled_request_as_eap = yes
virtual_server = "inner-tunnel"
}
Module: Linked to sub-module rlm_eap_mschapv2
Module: Instantiating eap-mschapv2
mschapv2 {
with_ntdomain_hack = no
}
Module: Checking authorize {...} for more modules to load
Module: Linked to module rlm_realm
Module: Instantiating suffix
realm suffix {
format = "suffix"
delimiter = "@"
ignore_default = no
ignore_null = no
}
Module: Instantiating ntdomain
realm ntdomain {
format = "prefix"
delimiter = "\"
ignore_default = no
ignore_null = no
}
Module: Linked to module rlm_files
Module: Instantiating files
files {
usersfile = "/etc/freeradius/users"
acctusersfile = "/etc/freeradius/acct_users"
preproxy_usersfile = "/etc/freeradius/preproxy_users"
compat = "no"
}
Module: Linked to module rlm_sql
Module: Instantiating sql
sql {
driver = "rlm_sql_mysql"
server = "localhost"
port = ""
login = "xxx"
password = "XXX"
radius_db = "xxxx"
read_groups = yes
sqltrace = no
sqltracefile = "/var/log/freeradius/sqltrace.sql"
readclients = yes
deletestalesessions = yes
num_sql_socks = 5
lifetime = 0
max_queries = 0
sql_user_name = "%{User-Name}"
default_user_profile = ""
nas_query = "SELECT id, nasname, shortname, type, secret, server 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 
freeradius_user@localhost:/freeradius
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 4ting 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, server FROM nas
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Read entry nasname=192.168.0.7,shortname=dd-wrt,secret=aaaaa
rlm_sql (sql): Adding client 192.168.0.7 (dd-wrt, server=<none>) to clients 
list
rlm_sql (sql): Read entry nasname=192.168.0.1,shortname=netgear,secret=aaaaa
rlm_sql (sql): Adding client 192.168.0.1 (netgear, 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
} # server
server {
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: 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: Linked to module rlm_detail
Module: Instantiating detail
detail {
detailfile = 
"/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
header = "%t"
detailperm = 384
dirperm = 493
locking = no
log_packet_header = no
}
Module: Checking session {...} for more modules to load
Module: Checking post-proxy {...} for more modules to load
Module: Checking post-auth {...} for more modules to load
} # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
type = "auth"
ipaddr = *
port = 0
}
listen {
type = "acct"
ipaddr = *
port = 0
}
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on proxy address * port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=127
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x0200000c01636861726c6573
Message-Authenticator = 0x40d74e6360091f5b471db2a38b23d4ec
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 0 length 12
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns updated
++[files] returns noop
[sql] expand: %{User-Name} -> charles
[sql] sql_set_user escaped user --> 'charles'
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 = 'charles' 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 = 'charles' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup WHERE username = 
'%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup 
WHERE username = 'charles' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck 
WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, 
attribute, Value, op FROM radgroupcheck WHERE groupname = 'HomeUsers' ORDER 
BY id
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
rlm_counter: Entering module authorize code
rlm_counter: Searching the database for key 'charles'
rlm_counter: Could not find the requested key in the database.
rlm_counter: Check item = 900, Count = 0
rlm_counter: res is greater than zero
rlm_counter: (Check item - counter) is greater than zero
rlm_counter: Authorized user charles, check_item=900, counter=0
rlm_counter: Sent Reply-Item for user charles, Type=Session-Timeout, 
value=900
++[daily] 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 md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 2 to 192.168.0.7 port 2051
Acct-Interim-Interval := 60
Acct-Status-Type := Interim-Update
Session-Timeout = 900
EAP-Message = 0x010100160410733020935ccee6ccf66f72c7941f4d30
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0703300a070234454676e124127a065d
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=139
Cleaning up request 0 ID 2 with timestamp +19
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x0703300a070234454676e124127a065d
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020100060319
Message-Authenticator = 0xe8ab3dd891fa8ccc2f53c603f6cc78e9
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 1 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns updated
++[files] returns noop
[sql] expand: %{User-Name} -> charles
[sql] sql_set_user escaped user --> 'charles'
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 = 'charles' 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 = 'charles' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup WHERE username = 
'%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup 
WHERE username = 'charles' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck 
WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, 
attribute, Value, op FROM radgroupcheck WHERE groupname = 'HomeUsers' ORDER 
BY id
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
rlm_counter: Entering module authorize code
rlm_counter: Searching the database for key 'charles'
rlm_counter: Could not find the requested key in the database.
rlm_counter: Check item = 900, Count = 0
rlm_counter: res is greater than zero
rlm_counter: (Check item - counter) is greater than zero
rlm_counter: Authorized user charles, check_item=900, counter=0
rlm_counter: Sent Reply-Item for user charles, Type=Session-Timeout, 
value=900
++[daily] 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 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 2 to 192.168.0.7 port 2051
Acct-Interim-Interval := 60
Acct-Status-Type := Interim-Update
Session-Timeout = 900
EAP-Message = 0x010200061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0703300a060129454676e124127a065d
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=220
Cleaning up request 1 ID 2 with timestamp +19
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x0703300a060129454676e124127a065d
NAS-Port-Type = Wireless-802.11
EAP-Message = 
0x0202005719800000004d16030100480100004403014c9b16dfa6a28ff98136bca9192d52181a0a8a3d16265d36f4c48b946276482000001600040005000a0009006400620003000600130012006301000005ff01000100
Message-Authenticator = 0x3834adacb827b5a5ca203f2287816182
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 2 length 87
[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 77
[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 0048], ClientHello
[peap] TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 0031], ServerHello
[peap] TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 085e], 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 2 to 192.168.0.7 port 2051
EAP-Message = 
0x0103040019c0000008a216030100310200002d03014c9b165aabc2515e7288e27bd332d3578cca6c17e9498220e0b3efc4d49ae013000004000005ff01000100160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c65204365727469666963617465204175
EAP-Message = 
0x74686f72697479301e170d3130303932313134343433355a170d3131303932313134343433355a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100a947d77fc244222c3051278ec56424766c79192080269eb9d83d2401a5885f5a888f83ff02a7dd89ae4b58344dab2d7004b91013ec933e
EAP-Message = 
0x5bb741d28f9a0579282ebcacdce170fca1389963e37d0deeb5462575ba778b152eb7251addbbaddaf2578377e0f5fc1defa76352ad46148497a444928bf2c4b720d44d40114661be35771f4cc7e83706fca30b973206a6c05b18478f4db31a40edc9722fc5d9fcb2ed659132edb2f7c9da7a07ddfee485c6213ab7f477acbaf6ce6c05d33df64ac4e48a2142b92b2f628d3f2f1ffad51486ed2252f1368fda8dd22aebf58b2ead29b09894eba26ef4e3e846f9ef579e7cf852e6289bbe7285eacee0ec78fbb70159850203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003820101004589
EAP-Message = 
0x32925695831bbe9332cbb4d3c9c0f2b1564a7ff7e8734c3c3ee8e423526938c6c3a69d1f7cae87a5c21d4dca20b878bb4f9b9697f12484f5ca89d5a0afb4da7fe0dfeace419c1bcfb3687ec5bf09f23e3e0186c99db744ce2a72a64cabacbacb25817d9b37e0a40d0f4135c3a2f34af25d19df558184d725384197ad291a42e162f7fdaf17ee3fc452f5257a73d2129fc2d1a7191cc58ce61d124239c2132cd74c26ceb1d7fc494e745fb44e51a2c222f2890f3329a1dc9e47eb8623f1265861f373ea95b5aa584a5e46c2821eee0450cd67010ca9d5024e23d0e470afe979b28da6cf95b0ec99d9ddd1db3fd4760dd9ef528ae659e778ccb3cf5966b6
EAP-Message = 0x1f0004ab308204a73082038f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0703300a050029454676e124127a065d
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=139
Cleaning up request 2 ID 2 with timestamp +19
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x0703300a050029454676e124127a065d
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020300061900
Message-Authenticator = 0x1770d92b253b1c5cffae5684c014475d
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 3 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 2 to 192.168.0.7 port 2051
EAP-Message = 
0x010403fc1940a003020102020900aca526def0727594300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3130303932313134343433355a170d3131303932313134343433355a308193310b3009060355040613024652310f300d0603550408130652616469757331
EAP-Message = 
0x12301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100c27c8bce4f03439dc7c0ca77e5f6224fb9e3684cedc183ac136d9d1d98930a11aae2b960832af6803258fa4d35fd5452170d791414d32b244ad53121f21c35c5a812e56c92a9002cffacffaa7398c5406e7371dae840252b572ad05ea0254bc1e4fb0022c215ff89
EAP-Message = 
0xed93d46f998c6ec3e7d486ae648ac5182b1dd16631536fa436bf616f9d884d1523c97182c61a06fa8cff6a46777a33e38b3abf854de4987e811b86401eeb95fb211af010dae404ef86b9f0639402f5d72c524579d5705fcab77226234174a9f55fe3232f93f76c572b4ee46de5b7ef3063ea028e0dcc7cfaa11d4f837510232d9a12a289fbdf2867ee31ee7af44d38f35480b58e3127ad050203010001a381fb3081f8301d0603551d0e041604148e237dd4b65b0dc510e8e923b82e71241312d4cc3081c80603551d230481c03081bd80148e237dd4b65b0dc510e8e923b82e71241312d4cca18199a48196308193310b300906035504061302465231
EAP-Message = 
0x0f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479820900aca526def0727594300c0603551d13040530030101ff300d06092a864886f70d010105050003820101008d2d620d5c8af22df228bd953558f0158c77a6532ce9a89226a778f928de90dd1a8f1891f857affc72c1e73c3e8fc69382dfb26230430798b770ac49f3eab077c1865c1a53ee6adcffc371
EAP-Message = 0xdac0aeeeb96cb3ab
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0703300a040729454676e124127a065d
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 3 ID 2 with timestamp +19
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=127
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x0201000c01636861726c6573
Message-Authenticator = 0xfd87d4320dfb5c01f3a3f76fc032f666
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 1 length 12
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns updated
++[files] returns noop
[sql] expand: %{User-Name} -> charles
[sql] sql_set_user escaped user --> 'charles'
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 = 'charles' 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 = 'charles' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup WHERE username = 
'%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup 
WHERE username = 'charles' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck 
WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, 
attribute, Value, op FROM radgroupcheck WHERE groupname = 'HomeUsers' ORDER 
BY id
rlm_sql (sql): Released sql socket id: 1
++[sql] returns ok
rlm_counter: Entering module authorize code
rlm_counter: Searching the database for key 'charles'
rlm_counter: Could not find the requested key in the database.
rlm_counter: Check item = 900, Count = 0
rlm_counter: res is greater than zero
rlm_counter: (Check item - counter) is greater than zero
rlm_counter: Authorized user charles, check_item=900, counter=0
rlm_counter: Sent Reply-Item for user charles, Type=Session-Timeout, 
value=900
++[daily] 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 md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 2 to 192.168.0.7 port 2051
Acct-Interim-Interval := 60
Acct-Status-Type := Interim-Update
Session-Timeout = 900
EAP-Message = 0x0102001604109ebc076e4695d7f1c24e6b298e7b0d3b
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x184ac8341848cc58a97571663b9b84a6
Finished request 4.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=139
Cleaning up request 4 ID 2 with timestamp +49
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x184ac8341848cc58a97571663b9b84a6
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020200060319
Message-Authenticator = 0x78b5df5d10f1b6656da32d7411d9a498
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", 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
++[files] returns noop
[sql] expand: %{User-Name} -> charles
[sql] sql_set_user escaped user --> 'charles'
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 = 'charles' 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 = 'charles' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup WHERE username = 
'%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup 
WHERE username = 'charles' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck 
WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, 
attribute, Value, op FROM radgroupcheck WHERE groupname = 'HomeUsers' ORDER 
BY id
rlm_sql (sql): Released sql socket id: 0
++[sql] returns ok
rlm_counter: Entering module authorize code
rlm_counter: Searching the database for key 'charles'
rlm_counter: Could not find the requested key in the database.
rlm_counter: Check item = 900, Count = 0
rlm_counter: res is greater than zero
rlm_counter: (Check item - counter) is greater than zero
rlm_counter: Authorized user charles, check_item=900, counter=0
rlm_counter: Sent Reply-Item for user charles, Type=Session-Timeout, 
value=900
++[daily] 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 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 2 to 192.168.0.7 port 2051
Acct-Interim-Interval := 60
Acct-Status-Type := Interim-Update
Session-Timeout = 900
EAP-Message = 0x010300061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x184ac8341949d158a97571663b9b84a6
Finished request 5.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=220
Cleaning up request 5 ID 2 with timestamp +49
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x184ac8341949d158a97571663b9b84a6
NAS-Port-Type = Wireless-802.11
EAP-Message = 
0x0203005719800000004d16030100480100004403014c9b16fe79620ad4e9e00ba8c0f3e6e0b88987e44b89fa8d0680a7c0e3874dc300001600040005000a0009006400620003000600130012006301000005ff01000100
Message-Authenticator = 0x95b83f99d6a5e9a5e634cb692f69e242
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 3 length 87
[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 77
[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 0048], ClientHello
[peap] TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 0031], ServerHello
[peap] TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 085e], 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 2 to 192.168.0.7 port 2051
EAP-Message = 
0x0104040019c0000008a216030100310200002d03014c9b16789f92d063ad63f1e7e285caadb3c2ecca12822881a3e862b852dadf39000004000005ff01000100160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c65204365727469666963617465204175
EAP-Message = 
0x74686f72697479301e170d3130303932313134343433355a170d3131303932313134343433355a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100a947d77fc244222c3051278ec56424766c79192080269eb9d83d2401a5885f5a888f83ff02a7dd89ae4b58344dab2d7004b91013ec933e
EAP-Message = 
0x5bb741d28f9a0579282ebcacdce170fca1389963e37d0deeb5462575ba778b152eb7251addbbaddaf2578377e0f5fc1defa76352ad46148497a444928bf2c4b720d44d40114661be35771f4cc7e83706fca30b973206a6c05b18478f4db31a40edc9722fc5d9fcb2ed659132edb2f7c9da7a07ddfee485c6213ab7f477acbaf6ce6c05d33df64ac4e48a2142b92b2f628d3f2f1ffad51486ed2252f1368fda8dd22aebf58b2ead29b09894eba26ef4e3e846f9ef579e7cf852e6289bbe7285eacee0ec78fbb70159850203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003820101004589
EAP-Message = 
0x32925695831bbe9332cbb4d3c9c0f2b1564a7ff7e8734c3c3ee8e423526938c6c3a69d1f7cae87a5c21d4dca20b878bb4f9b9697f12484f5ca89d5a0afb4da7fe0dfeace419c1bcfb3687ec5bf09f23e3e0186c99db744ce2a72a64cabacbacb25817d9b37e0a40d0f4135c3a2f34af25d19df558184d725384197ad291a42e162f7fdaf17ee3fc452f5257a73d2129fc2d1a7191cc58ce61d124239c2132cd74c26ceb1d7fc494e745fb44e51a2c222f2890f3329a1dc9e47eb8623f1265861f373ea95b5aa584a5e46c2821eee0450cd67010ca9d5024e23d0e470afe979b28da6cf95b0ec99d9ddd1db3fd4760dd9ef528ae659e778ccb3cf5966b6
EAP-Message = 0x1f0004ab308204a73082038f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x184ac8341a4ed158a97571663b9b84a6
Finished request 6.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=139
Cleaning up request 6 ID 2 with timestamp +49
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x184ac8341a4ed158a97571663b9b84a6
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020400061900
Message-Authenticator = 0x74c8d02b2b9401ef0bff14d047ab70fc
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", 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 2 to 192.168.0.7 port 2051
EAP-Message = 
0x010503fc1940a003020102020900aca526def0727594300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3130303932313134343433355a170d3131303932313134343433355a308193310b3009060355040613024652310f300d0603550408130652616469757331
EAP-Message = 
0x12301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100c27c8bce4f03439dc7c0ca77e5f6224fb9e3684cedc183ac136d9d1d98930a11aae2b960832af6803258fa4d35fd5452170d791414d32b244ad53121f21c35c5a812e56c92a9002cffacffaa7398c5406e7371dae840252b572ad05ea0254bc1e4fb0022c215ff89
EAP-Message = 
0xed93d46f998c6ec3e7d486ae648ac5182b1dd16631536fa436bf616f9d884d1523c97182c61a06fa8cff6a46777a33e38b3abf854de4987e811b86401eeb95fb211af010dae404ef86b9f0639402f5d72c524579d5705fcab77226234174a9f55fe3232f93f76c572b4ee46de5b7ef3063ea028e0dcc7cfaa11d4f837510232d9a12a289fbdf2867ee31ee7af44d38f35480b58e3127ad050203010001a381fb3081f8301d0603551d0e041604148e237dd4b65b0dc510e8e923b82e71241312d4cc3081c80603551d230481c03081bd80148e237dd4b65b0dc510e8e923b82e71241312d4cca18199a48196308193310b300906035504061302465231
EAP-Message = 
0x0f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479820900aca526def0727594300c0603551d13040530030101ff300d06092a864886f70d010105050003820101008d2d620d5c8af22df228bd953558f0158c77a6532ce9a89226a778f928de90dd1a8f1891f857affc72c1e73c3e8fc69382dfb26230430798b770ac49f3eab077c1865c1a53ee6adcffc371
EAP-Message = 0xdac0aeeeb96cb3ab
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x184ac8341b4fd158a97571663b9b84a6
Finished request 7.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=139
Cleaning up request 7 ID 2 with timestamp +49
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x184ac8341b4fd158a97571663b9b84a6
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020500061900
Message-Authenticator = 0x16d6a25797e6cca47e966fffe57df788
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", 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 2 to 192.168.0.7 port 2051
EAP-Message = 
0x010600bc19000fd45c44735cbe28f65c3847f862f0b9b3d67f0491938856104891e679457a5f2e5dfa741579c0c147e1f48fb7db12e297e45c3e4f816e9d77063b885d65d39ef9766244d84b17080226e9e1d8b07bef86cb6efa7d879dd7075a148f3bc0d2cdd571d9e93633480ef141e0f29d872b0f8208cfae2d27c3cdcaf02a30fb8d4d80b802706d1163d45c68edb64e573793395266c02e703dfe1bf641e24831fbd72e02244fb7a862c072fcbf0ff19016030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x184ac8341c4cd158a97571663b9b84a6
Finished request 8.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=455
Cleaning up request 8 ID 2 with timestamp +49
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x184ac8341c4cd158a97571663b9b84a6
NAS-Port-Type = Wireless-802.11
EAP-Message = 
0x02060140198000000136160301010610000102010039b73a495bea01d1883e42bfed3b40dd660a5f640dab0c0cd6d15d9b85faaf6fb3da78919eab9cac3e4dd2b73dabff742fc977fac9c31a489434167fa6fba0364a5953f05a89e711f0f5b0eb74979bfbb69e0e3592d64f7bca856bdfe63718c59eb57e5b477f963d85eb550ef2d95901a6c38aa248b86663e23926d2fff7e0ce035871a95365fff14066c54b7842c5dd8cadb8e4c3a6bcfbc7fffc46e1f7ddde6fd4262d27f7c13cf323c7c7034d408e3105e611d1c7c995d020420b2a5821db0264ff8caf7d152ae3ee254aca34486f5f2ba11cc20a460013926c94e1c3b87aea4634209e3763fe
EAP-Message = 
0xdce0658172de5720eff09d14cd99110a0b116d7f2c9ef81e140301000101160301002034c2af04667e5167cb80d745efa84732bd7242eb77e95d945eedbdd581d526bc
Message-Authenticator = 0x0ddc2cee443e1fefdc7e08ef6b8489b1
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", 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 310
[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 2 to 192.168.0.7 port 2051
EAP-Message = 
0x0107003119001403010001011603010020e11d8d3be0918705ecd1b79059270028bcd911d7f3e365fa133ed2a14883a946
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x184ac8341d4dd158a97571663b9b84a6
Finished request 9.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=139
Cleaning up request 9 ID 2 with timestamp +49
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x184ac8341d4dd158a97571663b9b84a6
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020700061900
Message-Authenticator = 0x3d6f891983ebf23d0a87f53e04cc23b2
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", 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 2 to 192.168.0.7 port 2051
EAP-Message = 
0x01080020190017030100152902748450b6821b0372acfacd8c16eea6e5cbfcbb
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x184ac8341e42d158a97571663b9b84a6
Finished request 10.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=168
Cleaning up request 10 ID 2 with timestamp +49
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x184ac8341e42d158a97571663b9b84a6
NAS-Port-Type = Wireless-802.11
EAP-Message = 
0x0208002319001703010018bc944056537b4694f40fb6fb4135fc254a1a1697b4a09ab0
Message-Authenticator = 0xe7c011633a8c2d5a927476b6d86effc6
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 8 length 35
[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 - charles
[peap] Got tunneled request
EAP-Message = 0x0208000c01636861726c6573
server {
PEAP: Got tunneled identity of charles
PEAP: Setting default EAP type for tunneled EAP session.
PEAP: Setting User-Name to charles
Sending tunneled request
EAP-Message = 0x0208000c01636861726c6573
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "charles"
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
++[mschap] returns noop
++[unix] returns updated
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "charles", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++[control] returns noop
[eap] EAP packet type response id 8 length 12
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql] expand: %{User-Name} -> charles
[sql] sql_set_user escaped user --> 'charles'
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 = 'charles' 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 = 'charles' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup WHERE username = 
'%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup 
WHERE username = 'charles' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck 
WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, 
attribute, Value, op FROM radgroupcheck WHERE groupname = 'HomeUsers' ORDER 
BY id
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
rlm_counter: Entering module authorize code
rlm_counter: Searching the database for key 'charles'
rlm_counter: Could not find the requested key in the database.
rlm_counter: Check item = 900, Count = 0
rlm_counter: res is greater than zero
rlm_counter: (Check item - counter) is greater than zero
rlm_counter: Authorized user charles, check_item=900, counter=0
rlm_counter: Sent Reply-Item for user charles, Type=Session-Timeout, 
value=900
++[daily] 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
Acct-Interim-Interval := 60
Acct-Status-Type := Interim-Update
Session-Timeout = 900
EAP-Message = 
0x010900211a0109001c10a3113b279e9d81b599af49127844d3ff636861726c6573
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xa37a2ef7a373341ab9c8a866b4c7e470
[peap] Got tunneled reply RADIUS code 11
Acct-Interim-Interval := 60
Acct-Status-Type := Interim-Update
Session-Timeout = 900
EAP-Message = 
0x010900211a0109001c10a3113b279e9d81b599af49127844d3ff636861726c6573
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xa37a2ef7a373341ab9c8a866b4c7e470
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 2 to 192.168.0.7 port 2051
EAP-Message = 
0x010900381900170301002d041c657b6df17df361a88aa6e58c055d3645f7461628503d600cebf3b6a31f34ce956e9bdda8e267529ddcb958
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x184ac8341f43d158a97571663b9b84a6
Finished request 11.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=222
Cleaning up request 11 ID 2 with timestamp +49
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x184ac8341f43d158a97571663b9b84a6
NAS-Port-Type = Wireless-802.11
EAP-Message = 
0x020900591900170301004e9c54278aff817c5dd4077ecf14b849fc5990a82578a3d0f10cfffc4711d10216b599d9ba3c062d01c774e40c88821064f127b2228c67a8b6fe69e21b32a0a80f8ba966d2d6ad281cc2024ed01ef5
Message-Authenticator = 0xefaeb01a5024086b395728f317563c28
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 9 length 89
[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 tunneled request
EAP-Message = 
0x020900421a0209003d3113a3b279ffaff88ba1065fa433140f220000000000000000008ada86d50e3e3f6e3f915bb52267b355874c14fc2a07ab00636861726c6573
server {
PEAP: Setting User-Name to charles
Sending tunneled request
EAP-Message = 
0x020900421a0209003d3113a3b279ffaff88ba1065fa433140f220000000000000000008ada86d50e3e3f6e3f915bb52267b355874c14fc2a07ab00636861726c6573
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "charles"
State = 0xa37a2ef7a373341ab9c8a866b4c7e470
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
++[mschap] returns noop
++[unix] returns updated
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "charles", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++[control] returns noop
[eap] EAP packet type response id 9 length 66
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql] expand: %{User-Name} -> charles
[sql] sql_set_user escaped user --> 'charles'
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 = 'charles' 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 = 'charles' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup WHERE username = 
'%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup 
WHERE username = 'charles' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck 
WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, 
attribute, Value, op FROM radgroupcheck WHERE groupname = 'HomeUsers' ORDER 
BY id
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
rlm_counter: Entering module authorize code
rlm_counter: Searching the database for key 'charles'
rlm_counter: Could not find the requested key in the database.
rlm_counter: Check item = 900, Count = 0
rlm_counter: res is greater than zero
rlm_counter: (Check item - counter) is greater than zero
rlm_counter: Authorized user charles, check_item=900, counter=0
rlm_counter: Sent Reply-Item for user charles, Type=Session-Timeout, 
value=900
++[daily] 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 charles 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
Acct-Interim-Interval := 60
Acct-Status-Type := Interim-Update
Session-Timeout = 900
EAP-Message = 
0x010a00331a0309002e533d45364245353031414531453633353738363535374131303236343933303044463643364130303243
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xa37a2ef7a270341ab9c8a866b4c7e470
[peap] Got tunneled reply RADIUS code 11
Acct-Interim-Interval := 60
Acct-Status-Type := Interim-Update
Session-Timeout = 900
EAP-Message = 
0x010a00331a0309002e533d45364245353031414531453633353738363535374131303236343933303044463643364130303243
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xa37a2ef7a270341ab9c8a866b4c7e470
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 2 to 192.168.0.7 port 2051
EAP-Message = 
0x010a004a1900170301003fb38ca328975287b34abd72f832a70dbf3f15f98a806eb73d666b4d74cf127ad4be011657d7c5cc592babc80facd53ec18d7fac0cd3af6cb33b722ebaca6f77
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x184ac8341040d158a97571663b9b84a6
Finished request 12.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=162
Cleaning up request 12 ID 2 with timestamp +49
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x184ac8341040d158a97571663b9b84a6
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020a001d1900170301001221ea7d1c5bdd49d4cacc9f2a0814a124ebdc
Message-Authenticator = 0xe8a0051f0cf3cc730a01582388a2fce0
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 10 length 29
[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 tunneled request
EAP-Message = 0x020a00061a03
server {
PEAP: Setting User-Name to charles
Sending tunneled request
EAP-Message = 0x020a00061a03
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "charles"
State = 0xa37a2ef7a270341ab9c8a866b4c7e470
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
++[mschap] returns noop
++[unix] returns updated
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "charles", looking up realm NULL
[ntdomain] No such realm "NULL"
++[ntdomain] returns noop
++[control] 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
++[files] returns noop
[sql] expand: %{User-Name} -> charles
[sql] sql_set_user escaped user --> 'charles'
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 = 'charles' 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 = 'charles' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup WHERE username = 
'%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup 
WHERE username = 'charles' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck 
WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, 
attribute, Value, op FROM radgroupcheck WHERE groupname = 'HomeUsers' ORDER 
BY id
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
rlm_counter: Entering module authorize code
rlm_counter: Searching the database for key 'charles'
rlm_counter: Could not find the requested key in the database.
rlm_counter: Check item = 900, Count = 0
rlm_counter: res is greater than zero
rlm_counter: (Check item - counter) is greater than zero
rlm_counter: Authorized user charles, check_item=900, counter=0
rlm_counter: Sent Reply-Item for user charles, Type=Session-Timeout, 
value=900
++[daily] 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
+- entering group post-auth {...}
[sql] expand: %{User-Name} -> charles
[sql] sql_set_user escaped user --> 'charles'
[sql] expand: %{User-Password} ->
[sql] ... expanding second conditional
[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 ( 'charles', '', 'Access-Accept', '2010-09-23 
09:57:28')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, 
pass, reply, authdate) VALUES ( 'charles', '', 'Access-Accept', '2010-09-23 
09:57:28')
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql (sql): Released sql socket id: 1
++[sql] returns ok
} # server inner-tunnel
[peap] Got tunneled reply code 2
Acct-Interim-Interval := 60
Acct-Status-Type := Interim-Update
Session-Timeout = 900
EAP-Message = 0x030a0004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "charles"
[peap] Got tunneled reply RADIUS code 2
Acct-Interim-Interval := 60
Acct-Status-Type := Interim-Update
Session-Timeout = 900
EAP-Message = 0x030a0004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "charles"
[peap] Tunneled authentication was successful.
[peap] SUCCESS
++[eap] returns handled
Sending Access-Challenge of id 2 to 192.168.0.7 port 2051
EAP-Message = 
0x010b00261900170301001bcf9e3e1a01aa0f1d4a68214e0d27ccd9ef636e0f962377ef61197b
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x184ac8341141d158a97571663b9b84a6
Finished request 13.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.7 port 2051, id=2, 
length=171
Cleaning up request 13 ID 2 with timestamp +49
User-Name = "charles"
NAS-IP-Address = 192.168.0.7
Called-Station-Id = "687f744c8918"
Calling-Station-Id = "00210085663c"
NAS-Identifier = "687f744c8918"
NAS-Port = 31
Framed-MTU = 1400
State = 0x184ac8341141d158a97571663b9b84a6
NAS-Port-Type = Wireless-802.11
EAP-Message = 
0x020b00261900170301001b6c23276c711434b52cb657b958c09a8905fdfa237c098ced8f6a50
Message-Authenticator = 0xf83cefea0a541faa08c15e0177a596f3
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "charles", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 11 length 38
[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
rlm_eap_tls: add_reply failed to create attribute EAP-MSK: Invalid octet 
string "" for attribute name "EAP-MSK"
rlm_eap_tls: add_reply failed to create attribute EAP-EMSK: Invalid octet 
string "" for attribute name "EAP-EMSK"
[eap] Freeing handler
++[eap] returns ok
+- entering group post-auth {...}
[sql] expand: %{User-Name} -> charles
[sql] sql_set_user escaped user --> 'charles'
[sql] expand: %{User-Password} ->
[sql] ... expanding second conditional
[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 ( 'charles', '', 'Access-Accept', '2010-09-23 
09:57:28')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, 
pass, reply, authdate) VALUES ( 'charles', '', 'Access-Accept', '2010-09-23 
09:57:28')
rlm_sql (sql): Reserving sql socket id: 0
rlm_sql (sql): Released sql socket id: 0
++[sql] returns ok
++[exec] returns noop
Sending Access-Accept of id 2 to 192.168.0.7 port 2051
MS-MPPE-Recv-Key = 
0xd5abef2ceb586cd3522078905bcb4359df84cf514cec2602fac0f3be09ab3560
MS-MPPE-Send-Key = 
0x6a8ae9377fa76e5019fa7ba4414ff22ed24ccf721885fd46117f81cb2d7c35ae
EAP-Message = 0x030b0004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "charles"
Finished request 14.
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 14 ID 2 with timestamp +49
Ready to process requests.

Acct-Interim-Interval not being sent to NAS with Accept-Accept

Charles Hooper