Class Attribute Missing in Accounting Request Packets from Windows 8.1
Selahattin Cilek
selahattin_cilek at hotmail.com
Sun Aug 6 21:10:22 CEST 2017
I have encountered a strange issue with Accounting Request when I connected a fresh-installed Windows 8.1 Pro machine to the Wi-Fi network.
When I connect using an iPhone 5SE, I see the all important Class attribute in the Accounting Request packets, but it is missing when I connect the Windows 8.1 Pro machine. That did not happen with FreeRADIUS 2.2.9. Why does that happen? How can I solve this problem?
# radiusd -X
FreeRADIUS Version 3.0.15
Copyright (C) 1999-2017 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
For more information about these matters, see the file named COPYRIGHT
Starting - reading configuration files ...
including dictionary file /usr/local/share/freeradius/dictionary
including dictionary file /usr/local/share/freeradius/dictionary.dhcp
including dictionary file /usr/local/share/freeradius/dictionary.vqp
including dictionary file /usr/local/etc/raddb/dictionary
including configuration file /usr/local/etc/raddb/radiusd.conf
including configuration file /usr/local/etc/raddb/clients.conf
including files in directory /usr/local/etc/raddb/mods-enabled/
including configuration file /usr/local/etc/raddb/mods-enabled/attr_filter
including configuration file /usr/local/etc/raddb/mods-enabled/cache_eap
including configuration file /usr/local/etc/raddb/mods-enabled/chap
including configuration file /usr/local/etc/raddb/mods-enabled/date
including configuration file /usr/local/etc/raddb/mods-enabled/detail
including configuration file /usr/local/etc/raddb/mods-enabled/detail.log
including configuration file /usr/local/etc/raddb/mods-enabled/dhcp
including configuration file /usr/local/etc/raddb/mods-enabled/digest
including configuration file /usr/local/etc/raddb/mods-enabled/dynamic_clients
including configuration file /usr/local/etc/raddb/mods-enabled/eap
including configuration file /usr/local/etc/raddb/mods-enabled/echo
including configuration file /usr/local/etc/raddb/mods-enabled/exec
including configuration file /usr/local/etc/raddb/mods-enabled/expiration
including configuration file /usr/local/etc/raddb/mods-enabled/expr
including configuration file /usr/local/etc/raddb/mods-enabled/files
including configuration file /usr/local/etc/raddb/mods-enabled/linelog
including configuration file /usr/local/etc/raddb/mods-enabled/logintime
including configuration file /usr/local/etc/raddb/mods-enabled/mschap
including configuration file /usr/local/etc/raddb/mods-enabled/ntlm_auth
including configuration file /usr/local/etc/raddb/mods-enabled/pap
including configuration file /usr/local/etc/raddb/mods-enabled/passwd
including configuration file /usr/local/etc/raddb/mods-enabled/preprocess
including configuration file /usr/local/etc/raddb/mods-enabled/radutmp
including configuration file /usr/local/etc/raddb/mods-enabled/realm
including configuration file /usr/local/etc/raddb/mods-enabled/replicate
including configuration file /usr/local/etc/raddb/mods-enabled/soh
including configuration file /usr/local/etc/raddb/mods-enabled/sradutmp
including configuration file /usr/local/etc/raddb/mods-enabled/always
including configuration file /usr/local/etc/raddb/mods-enabled/unix
including configuration file /usr/local/etc/raddb/mods-enabled/unpack
including configuration file /usr/local/etc/raddb/mods-enabled/utf8
including configuration file /usr/local/etc/raddb/mods-enabled/motp
including configuration file /usr/local/etc/raddb/mods-enabled/googleauth
including configuration file /usr/local/etc/raddb/mods-enabled/datacounter_acct
including configuration file /usr/local/etc/raddb/mods-enabled/sql
including configuration file /usr/local/etc/raddb/mods-config/sql/main/mysql/queries.conf
including configuration file /usr/local/etc/raddb/mods-enabled/sqlcounter
including configuration file /usr/local/etc/raddb/mods-config/sql/counter/mysql/dailycounter.conf
including configuration file /usr/local/etc/raddb/mods-config/sql/counter/mysql/monthlycounter.conf
including configuration file /usr/local/etc/raddb/mods-config/sql/counter/mysql/noresetcounter.conf
including configuration file /usr/local/etc/raddb/mods-config/sql/counter/mysql/expire_on_login.conf
including files in directory /usr/local/etc/raddb/policy.d/
including configuration file /usr/local/etc/raddb/policy.d/accounting
including configuration file /usr/local/etc/raddb/policy.d/canonicalization
including configuration file /usr/local/etc/raddb/policy.d/control
including configuration file /usr/local/etc/raddb/policy.d/cui
including configuration file /usr/local/etc/raddb/policy.d/debug
including configuration file /usr/local/etc/raddb/policy.d/dhcp
including configuration file /usr/local/etc/raddb/policy.d/eap
including configuration file /usr/local/etc/raddb/policy.d/filter
including configuration file /usr/local/etc/raddb/policy.d/moonshot-targeted-ids
including configuration file /usr/local/etc/raddb/policy.d/operator-name
including configuration file /usr/local/etc/raddb/policy.d/abfab-tr
including configuration file /usr/local/etc/raddb/policy.d/pfs_custom_policies
including files in directory /usr/local/etc/raddb/sites-enabled/
including configuration file /usr/local/etc/raddb/sites-enabled/default
including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel-peap
including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
main {
security {
allow_core_dumps = no
}
name = "radiusd"
prefix = "/usr/local"
localstatedir = "/var"
logdir = "/var/log"
run_dir = "/var/run"
}
main {
name = "radiusd"
prefix = "/usr/local"
localstatedir = "/var"
sbindir = "/usr/local/sbin"
logdir = "/var/log"
run_dir = "/var/run"
libdir = "/usr/local/lib/freeradius-3.0.15"
radacctdir = "/var/log/radacct"
hostname_lookups = no
max_request_time = 30
cleanup_delay = 5
max_requests = 36864
pidfile = "/var/run/radiusd.pid"
checkrad = "/usr/local/sbin/checkrad"
debug_level = 0
proxy_requests = yes
log {
stripped_names = no
auth = yes
auth_badpass = no
auth_goodpass = no
msg_badpass = ""
msg_goodpass = ""
colourise = yes
msg_denied = "You are already logged in - access denied"
}
resources {
}
security {
max_attributes = 200
reject_delay = 3.000000
status_server = no
allow_vulnerable_openssl = "yes"
}
}
radiusd: #### Loading Realms and Home Servers ####
radiusd: #### Loading Clients ####
client pfsense {
ipaddr = 127.0.0.1
require_message_authenticator = no
secret = <<< secret >>>
shortname = "pfsense"
limit {
max_connections = 16
lifetime = 0
idle_timeout = 30
}
}
Debugger not attached
# Creating Auth-Type = pap
# Creating Auth-Type = eap
# Creating Auth-Type = mschap
# Creating Auth-Type = MS-CHAP
# Creating Auth-Type = CHAP
radiusd: #### Instantiating modules ####
modules {
# Loaded module rlm_attr_filter
# Loading module "attr_filter.post-proxy" from file /usr/local/etc/raddb/mods-enabled/attr_filter
attr_filter attr_filter.post-proxy {
filename = "/usr/local/etc/raddb/mods-config/attr_filter/post-proxy"
key = "%{Realm}"
relaxed = no
}
# Loading module "attr_filter.pre-proxy" from file /usr/local/etc/raddb/mods-enabled/attr_filter
attr_filter attr_filter.pre-proxy {
filename = "/usr/local/etc/raddb/mods-config/attr_filter/pre-proxy"
key = "%{Realm}"
relaxed = no
}
# Loading module "attr_filter.access_reject" from file /usr/local/etc/raddb/mods-enabled/attr_filter
attr_filter attr_filter.access_reject {
filename = "/usr/local/etc/raddb/mods-config/attr_filter/access_reject"
key = "%{User-Name}"
relaxed = no
}
# Loading module "attr_filter.access_challenge" from file /usr/local/etc/raddb/mods-enabled/attr_filter
attr_filter attr_filter.access_challenge {
filename = "/usr/local/etc/raddb/mods-config/attr_filter/access_challenge"
key = "%{User-Name}"
relaxed = no
}
# Loading module "attr_filter.accounting_response" from file /usr/local/etc/raddb/mods-enabled/attr_filter
attr_filter attr_filter.accounting_response {
filename = "/usr/local/etc/raddb/mods-config/attr_filter/accounting_response"
key = "%{User-Name}"
relaxed = no
}
# Loaded module rlm_cache
# Loading module "cache_eap" from file /usr/local/etc/raddb/mods-enabled/cache_eap
cache cache_eap {
driver = "rlm_cache_rbtree"
key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}"
ttl = 15
max_entries = 0
epoch = 0
add_stats = no
}
# Loaded module rlm_chap
# Loading module "chap" from file /usr/local/etc/raddb/mods-enabled/chap
# Loaded module rlm_date
# Loading module "date" from file /usr/local/etc/raddb/mods-enabled/date
date {
format = "%b %e %Y %H:%M:%S %Z"
utc = no
}
# Loaded module rlm_detail
# Loading module "detail" from file /usr/local/etc/raddb/mods-enabled/detail
detail {
filename = "/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d"
header = "%t"
permissions = 384
locking = no
escape_filenames = no
log_packet_header = no
}
# Loading module "auth_log" from file /usr/local/etc/raddb/mods-enabled/detail.log
detail auth_log {
filename = "/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d"
header = "%t"
permissions = 384
locking = no
escape_filenames = no
log_packet_header = no
}
# Loading module "reply_log" from file /usr/local/etc/raddb/mods-enabled/detail.log
detail reply_log {
filename = "/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d"
header = "%t"
permissions = 384
locking = no
escape_filenames = no
log_packet_header = no
}
# Loading module "pre_proxy_log" from file /usr/local/etc/raddb/mods-enabled/detail.log
detail pre_proxy_log {
filename = "/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d"
header = "%t"
permissions = 384
locking = no
escape_filenames = no
log_packet_header = no
}
# Loading module "post_proxy_log" from file /usr/local/etc/raddb/mods-enabled/detail.log
detail post_proxy_log {
filename = "/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d"
header = "%t"
permissions = 384
locking = no
escape_filenames = no
log_packet_header = no
}
# Loaded module rlm_dhcp
# Loading module "dhcp" from file /usr/local/etc/raddb/mods-enabled/dhcp
# Loaded module rlm_digest
# Loading module "digest" from file /usr/local/etc/raddb/mods-enabled/digest
# Loaded module rlm_dynamic_clients
# Loading module "dynamic_clients" from file /usr/local/etc/raddb/mods-enabled/dynamic_clients
# Loaded module rlm_eap
# Loading module "eap" from file /usr/local/etc/raddb/mods-enabled/eap
eap {
default_eap_type = "ttls"
timer_expire = 60
ignore_unknown_eap_types = no
cisco_accounting_username_bug = no
max_sessions = 4096
}
# Loaded module rlm_exec
# Loading module "echo" from file /usr/local/etc/raddb/mods-enabled/echo
exec echo {
wait = yes
program = "/bin/echo %{User-Name}"
input_pairs = "request"
output_pairs = "reply"
shell_escape = yes
}
# Loading module "exec" from file /usr/local/etc/raddb/mods-enabled/exec
exec {
wait = no
input_pairs = "request"
shell_escape = yes
timeout = 10
}
# Loaded module rlm_expiration
# Loading module "expiration" from file /usr/local/etc/raddb/mods-enabled/expiration
# Loaded module rlm_expr
# Loading module "expr" from file /usr/local/etc/raddb/mods-enabled/expr
expr {
safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôSùûüa ÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔRÙÛÜx"
}
# Loaded module rlm_files
# Loading module "files" from file /usr/local/etc/raddb/mods-enabled/files
files {
filename = "/usr/local/etc/raddb/mods-config/files/authorize"
acctusersfile = "/usr/local/etc/raddb/mods-config/files/accounting"
preproxy_usersfile = "/usr/local/etc/raddb/mods-config/files/pre-proxy"
}
# Loaded module rlm_linelog
# Loading module "linelog" from file /usr/local/etc/raddb/mods-enabled/linelog
linelog {
filename = "/var/log/linelog"
escape_filenames = no
syslog_severity = "info"
permissions = 384
format = "This is a log message for %{User-Name}"
reference = "messages.%{%{reply:Packet-Type}:-default}"
}
# Loading module "log_accounting" from file /usr/local/etc/raddb/mods-enabled/linelog
linelog log_accounting {
filename = "/var/log/linelog-accounting"
escape_filenames = no
syslog_severity = "info"
permissions = 384
format = ""
reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}"
}
# Loaded module rlm_logintime
# Loading module "logintime" from file /usr/local/etc/raddb/mods-enabled/logintime
logintime {
minimum_timeout = 60
}
# Loaded module rlm_mschap
# Loading module "mschap" from file /usr/local/etc/raddb/mods-enabled/mschap
mschap {
use_mppe = yes
require_encryption = no
require_strong = no
with_ntdomain_hack = yes
passchange {
}
allow_retry = yes
winbind_retry_with_normalised_username = no
}
# Loading module "ntlm_auth" from file /usr/local/etc/raddb/mods-enabled/ntlm_auth
exec ntlm_auth {
wait = yes
program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}"
shell_escape = yes
}
# Loaded module rlm_pap
# Loading module "pap" from file /usr/local/etc/raddb/mods-enabled/pap
pap {
normalise = yes
}
# Loaded module rlm_passwd
# Loading module "etc_passwd" from file /usr/local/etc/raddb/mods-enabled/passwd
passwd etc_passwd {
filename = "/etc/passwd"
format = "*User-Name:Crypt-Password:"
delimiter = ":"
ignore_nislike = no
ignore_empty = yes
allow_multiple_keys = no
hash_size = 100
}
# Loaded module rlm_preprocess
# Loading module "preprocess" from file /usr/local/etc/raddb/mods-enabled/preprocess
preprocess {
huntgroups = "/usr/local/etc/raddb/mods-config/preprocess/huntgroups"
hints = "/usr/local/etc/raddb/mods-config/preprocess/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
}
# Loaded module rlm_radutmp
# Loading module "radutmp" from file /usr/local/etc/raddb/mods-enabled/radutmp
radutmp {
filename = "/var/log/radutmp"
username = "%{User-Name}"
case_sensitive = yes
check_with_nas = yes
permissions = 384
caller_id = yes
}
# Loaded module rlm_realm
# Loading module "IPASS" from file /usr/local/etc/raddb/mods-enabled/realm
realm IPASS {
format = "prefix"
delimiter = "/"
ignore_default = no
ignore_null = yes
}
# Loading module "suffix" from file /usr/local/etc/raddb/mods-enabled/realm
realm suffix {
format = "suffix"
delimiter = "@"
ignore_default = no
ignore_null = yes
}
# Loading module "realmpercent" from file /usr/local/etc/raddb/mods-enabled/realm
realm realmpercent {
format = "suffix"
delimiter = "%"
ignore_default = no
ignore_null = yes
}
# Loading module "ntdomain" from file /usr/local/etc/raddb/mods-enabled/realm
realm ntdomain {
format = "prefix"
delimiter = "\"
ignore_default = no
ignore_null = yes
}
# Loaded module rlm_replicate
# Loading module "replicate" from file /usr/local/etc/raddb/mods-enabled/replicate
# Loaded module rlm_soh
# Loading module "soh" from file /usr/local/etc/raddb/mods-enabled/soh
soh {
dhcp = yes
}
# Loading module "sradutmp" from file /usr/local/etc/raddb/mods-enabled/sradutmp
radutmp sradutmp {
filename = "/var/log/sradutmp"
username = "%{User-Name}"
case_sensitive = yes
check_with_nas = yes
permissions = 420
caller_id = no
}
# Loaded module rlm_always
# Loading module "reject" from file /usr/local/etc/raddb/mods-enabled/always
always reject {
rcode = "reject"
simulcount = 0
mpp = no
}
# Loading module "fail" from file /usr/local/etc/raddb/mods-enabled/always
always fail {
rcode = "fail"
simulcount = 0
mpp = no
}
# Loading module "ok" from file /usr/local/etc/raddb/mods-enabled/always
always ok {
rcode = "ok"
simulcount = 0
mpp = no
}
# Loading module "handled" from file /usr/local/etc/raddb/mods-enabled/always
always handled {
rcode = "handled"
simulcount = 0
mpp = no
}
# Loading module "invalid" from file /usr/local/etc/raddb/mods-enabled/always
always invalid {
rcode = "invalid"
simulcount = 0
mpp = no
}
# Loading module "userlock" from file /usr/local/etc/raddb/mods-enabled/always
always userlock {
rcode = "userlock"
simulcount = 0
mpp = no
}
# Loading module "notfound" from file /usr/local/etc/raddb/mods-enabled/always
always notfound {
rcode = "notfound"
simulcount = 0
mpp = no
}
# Loading module "noop" from file /usr/local/etc/raddb/mods-enabled/always
always noop {
rcode = "noop"
simulcount = 0
mpp = no
}
# Loading module "updated" from file /usr/local/etc/raddb/mods-enabled/always
always updated {
rcode = "updated"
simulcount = 0
mpp = no
}
# Loaded module rlm_unix
# Loading module "unix" from file /usr/local/etc/raddb/mods-enabled/unix
unix {
radwtmp = "/var/log/radwtmp"
}
Creating attribute Unix-Group
# Loaded module rlm_unpack
# Loading module "unpack" from file /usr/local/etc/raddb/mods-enabled/unpack
# Loaded module rlm_utf8
# Loading module "utf8" from file /usr/local/etc/raddb/mods-enabled/utf8
# Loading module "motp" from file /usr/local/etc/raddb/mods-enabled/motp
exec motp {
wait = yes
program = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/otpverify.sh %{request:User-Name} %{request:User-Password} %{reply:MOTP-Init-Secret} %{reply:MOTP-PIN} %{
reply:MOTP-Offset}"
shell_escape = yes
}
# Loading module "googleauth" from file /usr/local/etc/raddb/mods-enabled/googleauth
exec googleauth {
wait = yes
program = "/usr/local/etc/raddb/scripts/googleauth.py %{request:User-Name} %{reply:MOTP-Init-Secret} %{reply:MOTP-PIN} %{request:User-Password}"
shell_escape = yes
}
# Loading module "check_quota" from file /usr/local/etc/raddb/mods-enabled/datacounter_acct
exec check_quota {
wait = no
program = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} %{request:Calling-Station-Id} %{request:NAS-IP-Address} %{reques
t:Class} %{request:Acct-Status-Type}"
shell_escape = yes
}
# Loaded module rlm_sql
# Loading module "sql1" from file /usr/local/etc/raddb/mods-enabled/sql
sql sql1 {
driver = "rlm_sql_mysql"
server = "localhost"
port = 33316
login = "raduser"
password = <<< secret >>>
radius_db = "raddb3"
read_groups = yes
read_profiles = yes
read_clients = yes
delete_stale_sessions = yes
sql_user_name = "%{User-Name}"
logfile = "/var/log/sqltrace.sql"
default_user_profile = ""
client_query = "CALL load_clients()"
authorize_check_query = "CALL authorize_check('%{SQL-User-Name}')"
authorize_reply_query = "CALL authorize_reply('%{SQL-User-Name}')"
authorize_group_check_query = "CALL authorize_group_check('%{sql1-SQL-Group}')"
authorize_group_reply_query = "CALL authorize_group_reply('%{sql1-SQL-Group}')"
group_membership_query = "CALL group_membership('%{SQL-User-Name}')"
simul_count_query = "CALL simul_count('%{SQL-User-Name}')"
safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_"
accounting {
reference = "%{tolower:type.%{Acct-Status-Type}.query}"
type {
accounting-on {
query = "CALL accounting_on('%{Called-Station-Id}')"
}
accounting-off {
query = "CALL accounting_off('%{Called-Station-Id}')"
}
start {
query = "CALL accounting_start('%{Acct-Session-Id}','%{SQL-User-Name}','%{Class}','%{NAS-IP-Address}','%{Called-Station-Id}','%{Calling-Station-Id}')"
}
interim-update {
query = "CALL accounting_update ('%{Acct-Session-Id}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-Input-Octets}','%{Acct-Input-Giga
words}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}')"
}
stop {
query = "CALL accounting_stop ('%{Acct-Session-Id}','%{SQL-User-Name}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-Input-Octets}','
%{Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}','%{Acct-Terminate-Cause}')"
}
}
}
post-auth {
reference = ".query"
}
}
rlm_sql (sql1): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Creating attribute sql1-SQL-Group
# Loaded module rlm_sqlcounter
# Loading module "dailycounter" from file /usr/local/etc/raddb/mods-enabled/sqlcounter
sqlcounter dailycounter {
sql_module_instance = "sql"
key = "User-Name"
query = "SELECT SUM(acctsessiontime - GREATEST((%%b - UNIX_TIMESTAMP(acctstarttime)), 0)) FROM radacct WHERE username = '%{User-Name}' AND UNIX_TIMESTAMP(acctstartti
me) + acctsessiontime > '%%b'"
reset = "daily"
counter_name = "Daily-Session-Time"
check_name = "Max-Daily-Session"
reply_name = "Session-Timeout"
}
# Loading module "monthlycounter" from file /usr/local/etc/raddb/mods-enabled/sqlcounter
sqlcounter monthlycounter {
sql_module_instance = "sql"
key = "User-Name"
query = "SELECT SUM(acctsessiontime - GREATEST((%%b - UNIX_TIMESTAMP(acctstarttime)), 0)) FROM radacct WHERE username='%{User-Name}' AND UNIX_TIMESTAMP(acctstarttime
) + acctsessiontime > '%%b'"
reset = "monthly"
counter_name = "Monthly-Session-Time"
check_name = "Max-Monthly-Session"
reply_name = "Session-Timeout"
}
# Loading module "noresetcounter" from file /usr/local/etc/raddb/mods-enabled/sqlcounter
sqlcounter noresetcounter {
sql_module_instance = "sql"
key = "User-Name"
query = "SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='%{User-Name}'"
reset = "never"
counter_name = "Max-All-Session-Time"
check_name = "Max-All-Session"
reply_name = "Session-Timeout"
}
# Loading module "expire_on_login" from file /usr/local/etc/raddb/mods-enabled/sqlcounter
sqlcounter expire_on_login {
sql_module_instance = "sql"
key = "User-Name"
query = "SELECT IFNULL( MAX(TIME_TO_SEC(TIMEDIFF(NOW(), acctstarttime))),0) FROM radacct WHERE UserName='%{User-Name}' ORDER BY acctstarttime LIMIT 1;"
reset = "never"
counter_name = "Expire-After-Initial-Login"
check_name = "Expire-After"
reply_name = "Session-Timeout"
}
instantiate {
# Instantiating module "expiration" from file /usr/local/etc/raddb/mods-enabled/expiration
# Instantiating module "logintime" from file /usr/local/etc/raddb/mods-enabled/logintime
# Instantiating module "sql1" from file /usr/local/etc/raddb/mods-enabled/sql
rlm_sql_mysql: libmysql version: 5.6.35
mysql {
tls {
}
warnings = "auto"
}
rlm_sql (sql1): Attempting to connect to database "raddb3"
rlm_sql (sql1): Initialising connection pool
pool {
start = 32
min = 16
max = 16
spare = 32
uses = 0
lifetime = 0
cleanup_interval = 30
idle_timeout = 60
retry_delay = 60
spread = no
}
WARNING: Ignoring "start = 32", forcing to "start = 16"
WARNING: Ignoring "spare = 32", forcing to "spare = 0"
rlm_sql (sql1): Opening additional connection (0), 1 of 16 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (1), 1 of 15 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (2), 1 of 14 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (3), 1 of 13 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (4), 1 of 12 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (5), 1 of 11 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (6), 1 of 10 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (7), 1 of 9 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (8), 1 of 8 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (9), 1 of 7 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (10), 1 of 6 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (11), 1 of 5 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (12), 1 of 4 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (13), 1 of 3 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (14), 1 of 2 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Opening additional connection (15), 1 of 1 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
rlm_sql (sql1): Processing generate_sql_clients
rlm_sql (sql1) in generate_sql_clients: query is CALL load_clients()
rlm_sql (sql1): Reserved connection (0)
rlm_sql (sql1): Executing select query: CALL load_clients()
rlm_sql (sql1): Adding client 192.168.0.4 (HOME_AP) to global clients list
rlm_sql (192.168.0.4): Client "HOME_AP" (sql1) added
rlm_sql (sql1): Released connection (0)
}
# Instantiating module "attr_filter.post-proxy" from file /usr/local/etc/raddb/mods-enabled/attr_filter
reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/post-proxy
# Instantiating module "attr_filter.pre-proxy" from file /usr/local/etc/raddb/mods-enabled/attr_filter
reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/pre-proxy
# Instantiating module "attr_filter.access_reject" from file /usr/local/etc/raddb/mods-enabled/attr_filter
reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/access_reject
[/usr/local/etc/raddb/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT".
[/usr/local/etc/raddb/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec" found in filter list for realm "DEFAULT".
# Instantiating module "attr_filter.access_challenge" from file /usr/local/etc/raddb/mods-enabled/attr_filter
reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/access_challenge
# Instantiating module "attr_filter.accounting_response" from file /usr/local/etc/raddb/mods-enabled/attr_filter
reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/accounting_response
# Instantiating module "cache_eap" from file /usr/local/etc/raddb/mods-enabled/cache_eap
rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked
# Instantiating module "detail" from file /usr/local/etc/raddb/mods-enabled/detail
# Instantiating module "auth_log" from file /usr/local/etc/raddb/mods-enabled/detail.log
rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output
# Instantiating module "reply_log" from file /usr/local/etc/raddb/mods-enabled/detail.log
# Instantiating module "pre_proxy_log" from file /usr/local/etc/raddb/mods-enabled/detail.log
# Instantiating module "post_proxy_log" from file /usr/local/etc/raddb/mods-enabled/detail.log
# Instantiating module "eap" from file /usr/local/etc/raddb/mods-enabled/eap
# Linked to sub-module rlm_eap_tls
tls {
tls = "tls-common"
}
tls-config tls-common {
verify_depth = 0
ca_path = "/usr/local/etc/raddb/certs"
pem_file_type = yes
private_key_file = "/usr/local/etc/raddb/certs/server_key.pem"
certificate_file = "/usr/local/etc/raddb/certs/server_cert.pem"
ca_file = "/usr/local/etc/raddb/certs/ca_cert.pem"
dh_file = "/usr/local/etc/raddb/certs/dh"
random_file = "/dev/urandom"
fragment_size = 1024
include_length = yes
auto_chain = yes
check_crl = no
check_all_crl = no
cipher_list = "DEFAULT"
cipher_server_preference = no
ecdh_curve = "prime256v1"
cache {
enable = no
lifetime = 24
max_entries = 255
}
verify {
skip_if_ocsp_ok = no
}
ocsp {
enable = no
override_cert_url = no
url = "http://127.0.0.1/ocsp/"<http://127.0.0.1/ocsp/>
use_nonce = yes
timeout = 0
softfail = no
}
}
# Linked to sub-module rlm_eap_ttls
ttls {
tls = "tls-common"
default_eap_type = "tls"
copy_request_to_tunnel = yes
use_tunneled_reply = no
virtual_server = "inner-tunnel-ttls"
include_length = yes
require_client_cert = no
}
tls: Using cached TLS configuration from previous invocation
# Linked to sub-module rlm_eap_peap
peap {
tls = "tls-common"
default_eap_type = "tls"
copy_request_to_tunnel = yes
use_tunneled_reply = no
proxy_tunneled_request_as_eap = yes
virtual_server = "inner-tunnel-peap"
soh = no
require_client_cert = no
}
tls: Using cached TLS configuration from previous invocation
# Linked to sub-module rlm_eap_mschapv2
mschapv2 {
with_ntdomain_hack = no
send_error = no
}
# Instantiating module "files" from file /usr/local/etc/raddb/mods-enabled/files
reading pairlist file /usr/local/etc/raddb/mods-config/files/authorize
reading pairlist file /usr/local/etc/raddb/mods-config/files/accounting
reading pairlist file /usr/local/etc/raddb/mods-config/files/pre-proxy
# Instantiating module "linelog" from file /usr/local/etc/raddb/mods-enabled/linelog
# Instantiating module "log_accounting" from file /usr/local/etc/raddb/mods-enabled/linelog
# Instantiating module "mschap" from file /usr/local/etc/raddb/mods-enabled/mschap
rlm_mschap (mschap): using internal authentication
# Instantiating module "pap" from file /usr/local/etc/raddb/mods-enabled/pap
# Instantiating module "etc_passwd" from file /usr/local/etc/raddb/mods-enabled/passwd
rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no
# Instantiating module "preprocess" from file /usr/local/etc/raddb/mods-enabled/preprocess
reading pairlist file /usr/local/etc/raddb/mods-config/preprocess/huntgroups
reading pairlist file /usr/local/etc/raddb/mods-config/preprocess/hints
# Instantiating module "IPASS" from file /usr/local/etc/raddb/mods-enabled/realm
# Instantiating module "suffix" from file /usr/local/etc/raddb/mods-enabled/realm
# Instantiating module "realmpercent" from file /usr/local/etc/raddb/mods-enabled/realm
# Instantiating module "ntdomain" from file /usr/local/etc/raddb/mods-enabled/realm
# Instantiating module "reject" from file /usr/local/etc/raddb/mods-enabled/always
# Instantiating module "fail" from file /usr/local/etc/raddb/mods-enabled/always
# Instantiating module "ok" from file /usr/local/etc/raddb/mods-enabled/always
# Instantiating module "handled" from file /usr/local/etc/raddb/mods-enabled/always
# Instantiating module "invalid" from file /usr/local/etc/raddb/mods-enabled/always
# Instantiating module "userlock" from file /usr/local/etc/raddb/mods-enabled/always
# Instantiating module "notfound" from file /usr/local/etc/raddb/mods-enabled/always
# Instantiating module "noop" from file /usr/local/etc/raddb/mods-enabled/always
# Instantiating module "updated" from file /usr/local/etc/raddb/mods-enabled/always
# Instantiating module "dailycounter" from file /usr/local/etc/raddb/mods-enabled/sqlcounter
rlm_sqlcounter: Current Time: 1502046043 [2017-08-06 22:00:43], Prev reset 1501966800 [2017-08-06 00:00:00]
# Instantiating module "monthlycounter" from file /usr/local/etc/raddb/mods-enabled/sqlcounter
rlm_sqlcounter: Current Time: 1502046043 [2017-08-06 22:00:43], Prev reset 1501534800 [2017-08-01 00:00:00]
# Instantiating module "noresetcounter" from file /usr/local/etc/raddb/mods-enabled/sqlcounter
rlm_sqlcounter: Current Time: 1502046043 [2017-08-06 22:00:43], Prev reset 0 [2017-08-06 22:00:00]
# Instantiating module "expire_on_login" from file /usr/local/etc/raddb/mods-enabled/sqlcounter
rlm_sqlcounter: Current Time: 1502046043 [2017-08-06 22:00:43], Prev reset 0 [2017-08-06 22:00:00]
} # modules
radiusd: #### Loading Virtual Servers ####
server { # from file /usr/local/etc/raddb/radiusd.conf
} # server
server default { # from file /usr/local/etc/raddb/sites-enabled/default
# Loading authenticate {...}
# Loading authorize {...}
# Loading preacct {...}
# Loading accounting {...}
# Loading session {...}
# Loading post-proxy {...}
# Loading post-auth {...}
} # server default
server inner-tunnel-peap { # from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-peap
# Loading authenticate {...}
# Loading authorize {...}
# Loading session {...}
# Loading post-proxy {...}
# Loading post-auth {...}
} # server inner-tunnel-peap
server inner-tunnel-ttls { # from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
# Loading authenticate {...}
# Loading authorize {...}
# Loading session {...}
# Loading post-proxy {...}
# Loading post-auth {...}
} # server inner-tunnel-ttls
radiusd: #### Opening IP addresses and Ports ####
listen {
type = "auth"
ipaddr = 192.168.0.1
port = 1812
}
listen {
type = "acct"
ipaddr = 192.168.0.1
port = 1813
}
listen {
type = "auth"
ipaddr = 127.0.0.1
port = 18128
}
listen {
type = "auth"
ipaddr = 127.0.0.1
port = 18127
}
Listening on auth address 192.168.0.1 port 1812 bound to server default
Listening on acct address 192.168.0.1 port 1813 bound to server default
Listening on auth address 127.0.0.1 port 18128 bound to server inner-tunnel-peap
Listening on auth address 127.0.0.1 port 18127 bound to server inner-tunnel-ttls
Ready to process requests
(0) Received Accounting-Request Id 147 from 192.168.0.4:44463 to 192.168.0.1:1813 length 208
(0) Acct-Session-Id = "59873E49-00000019"
(0) Acct-Status-Type = Stop
(0) Acct-Authentic = RADIUS
(0) User-Name = "anonymous"
(0) Framed-IP-Address = 192.168.0.104
(0) NAS-Identifier = "802aa8ac1ef9"
(0) NAS-Port = 0
(0) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(0) Calling-Station-Id = "00-22-FA-F5-B9-0A"
(0) NAS-Port-Type = Wireless-802.11
(0) Connect-Info = "CONNECT 0Mbps 802.11b"
(0) Acct-Session-Time = 51
(0) Acct-Input-Packets = 176
(0) Acct-Output-Packets = 22
(0) Acct-Input-Octets = 16127
(0) Acct-Output-Octets = 4777
(0) Event-Timestamp = "Aug 6 2017 22:00:04 +03"
(0) Acct-Terminate-Cause = User-Request
(0) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
(0) preacct {
(0) [preprocess] = ok
(0) } # preacct = ok
(0) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
(0) accounting {
(0) detail: EXPAND /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
(0) detail: --> /var/log/radacct/192.168.0.4/detail_2017_08_06
(0) detail: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d expands to /var/log/radacct/192.168.0.4/detail_2017_08_06
(0) detail: EXPAND %t
(0) detail: --> Sun Aug 6 22:00:54 2017
(0) [detail] = ok
(0) redundant sql {
(0) sql1: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(0) sql1: --> type.stop.query
(0) sql1: Using query template 'query'
rlm_sql (sql1): Reserved connection (1)
(0) sql1: EXPAND %{User-Name}
(0) sql1: --> anonymous
(0) sql1: SQL-User-Name set to 'anonymous'
(0) sql1: EXPAND CALL accounting_stop ('%{Acct-Session-Id}','%{SQL-User-Name}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-Input-Octets}','
%{Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}','%{Acct-Terminate-Cause}')
(0) sql1: --> CALL accounting_stop ('59873E49-00000019','anonymous','80-2A-A8-AD-1E-F9=3ASCILEK.NET','00-22-FA-F5-B9-0A','51','16127','','4777','','User-Request')
(0) sql1: EXPAND /var/log/sqltrace.sql
(0) sql1: --> /var/log/sqltrace.sql
(0) sql1: Executing query: CALL accounting_stop ('59873E49-00000019','anonymous','80-2A-A8-AD-1E-F9=3ASCILEK.NET','00-22-FA-F5-B9-0A','51','16127','','4777','','User-Request
')
(0) sql1: SQL query returned: success
(0) sql1: 1 record(s) updated
rlm_sql (sql1): Released connection (1)
(0) [sql1] = ok
(0) } # redundant sql = ok
(0) [exec] = noop
(0) if (request:Acct-Status-Type == Interim-Update) {
(0) if (request:Acct-Status-Type == Interim-Update) -> FALSE
(0) } # accounting = ok
(0) Sent Accounting-Response Id 147 from 192.168.0.1:1813 to 192.168.0.4:44463 length 0
(0) Finished request
(0) Cleaning up request packet ID 147 with timestamp +11
Ready to process requests
(1) Received Access-Request Id 148 from 192.168.0.4:37009 to 192.168.0.1:1812 length 163
(1) User-Name = "scilek"
(1) NAS-Identifier = "802aa8ac1ef9"
(1) NAS-Port = 0
(1) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(1) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(1) Framed-MTU = 1400
(1) NAS-Port-Type = Wireless-802.11
(1) Connect-Info = "CONNECT 0Mbps 802.11b"
(1) EAP-Message = 0x02b6000b017363696c656b
(1) Message-Authenticator = 0xecd086e7eb7d720848f759fbea3e68dd
(1) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(1) authorize {
(1) [preprocess] = ok
(1) redundant sql {
(1) sql1: EXPAND %{User-Name}
(1) sql1: --> scilek
(1) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (2)
(1) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(1) sql1: --> CALL authorize_check('scilek')
(1) sql1: Executing select query: CALL authorize_check('scilek')
(1) sql1: User found in radcheck table
(1) sql1: Conditional check items matched, merging assignment check items
(1) sql1: Cleartext-Password := "0000"
(1) sql1: Simultaneous-Use := 1
(1) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(1) sql1: --> CALL authorize_reply('scilek')
(1) sql1: Executing select query: CALL authorize_reply('scilek')
(1) sql1: User found in radreply table, merging reply items
(1) sql1: Class := 0x7363696c656b
(1) sql1: Idle-Timeout := 120
(1) sql1: Acct-Interim-Interval := 600
(1) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(1) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(1) sql1: --> CALL group_membership('scilek')
(1) sql1: Executing select query: CALL group_membership('scilek')
(1) sql1: User not found in any groups
rlm_sql (sql1): Released connection (2)
(1) [sql1] = ok
(1) } # redundant sql = ok
(1) pap: No User-Password attribute in the request. Cannot do PAP
(1) [pap] = noop
(1) eap: Peer sent EAP Response (code 2) ID 182 length 11
(1) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize
(1) [eap] = ok
(1) } # authorize = ok
(1) Found Auth-Type = eap
(1) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(1) authenticate {
(1) eap: Peer sent packet with method EAP Identity (1)
(1) eap: Calling submodule eap_ttls to process data
(1) eap_ttls: Initiating new EAP-TLS session
(1) eap_ttls: [eaptls start] = request
(1) eap: Sending EAP Request (code 1) ID 183 length 6
(1) eap: EAP session adding &reply:State = 0x04505bcc04e74ea0
(1) [eap] = handled
(1) } # authenticate = handled
(1) Using Post-Auth-Type Challenge
(1) Post-Auth-Type sub-section not found. Ignoring.
(1) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(1) Sent Access-Challenge Id 148 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(1) Class = 0x7363696c656b
(1) Idle-Timeout = 120
(1) Acct-Interim-Interval = 600
(1) EAP-Message = 0x01b700061520
(1) Message-Authenticator = 0x00000000000000000000000000000000
(1) State = 0x04505bcc04e74ea0e22d93a65254c60e
(1) Finished request
Waking up in 4.9 seconds.
(2) Received Access-Request Id 149 from 192.168.0.4:37009 to 192.168.0.1:1812 length 297
(2) User-Name = "scilek"
(2) NAS-Identifier = "802aa8ac1ef9"
(2) NAS-Port = 0
(2) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(2) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(2) Framed-MTU = 1400
(2) NAS-Port-Type = Wireless-802.11
(2) Connect-Info = "CONNECT 0Mbps 802.11b"
(2) EAP-Message = 0x02b7007f15800000007516030100700100006c030159876769a174d1b43f51e91a68364f8fe5c039642809fc74205540b4eaa79c9600002000ffc024c023c00ac009c008c028c027c014c01
3c012003d003c0035002f000a01000023000a00080006001700180019000b00020100000500050100000000
(2) State = 0x04505bcc04e74ea0e22d93a65254c60e
(2) Message-Authenticator = 0x4a0a55f0a010a073bf4399b9bf683ec3
(2) session-state: No cached attributes
(2) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(2) authorize {
(2) [preprocess] = ok
(2) redundant sql {
(2) sql1: EXPAND %{User-Name}
(2) sql1: --> scilek
(2) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (3)
(2) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(2) sql1: --> CALL authorize_check('scilek')
(2) sql1: Executing select query: CALL authorize_check('scilek')
(2) sql1: User found in radcheck table
(2) sql1: Conditional check items matched, merging assignment check items
(2) sql1: Cleartext-Password := "0000"
(2) sql1: Simultaneous-Use := 1
(2) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(2) sql1: --> CALL authorize_reply('scilek')
(2) sql1: Executing select query: CALL authorize_reply('scilek')
(2) sql1: User found in radreply table, merging reply items
(2) sql1: Class := 0x7363696c656b
(2) sql1: Idle-Timeout := 120
(2) sql1: Acct-Interim-Interval := 600
(2) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(2) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(2) sql1: --> CALL group_membership('scilek')
(2) sql1: Executing select query: CALL group_membership('scilek')
(2) sql1: User not found in any groups
rlm_sql (sql1): Released connection (3)
(2) [sql1] = ok
(2) } # redundant sql = ok
(2) pap: No User-Password attribute in the request. Cannot do PAP
(2) [pap] = noop
(2) eap: Peer sent EAP Response (code 2) ID 183 length 127
(2) eap: Continuing tunnel setup
(2) [eap] = ok
(2) } # authorize = ok
(2) Found Auth-Type = eap
(2) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(2) authenticate {
(2) eap: Expiring EAP session with state 0x04505bcc04e74ea0
(2) eap: Finished EAP session with state 0x04505bcc04e74ea0
(2) eap: Previous EAP request found for state 0x04505bcc04e74ea0, released from the list
(2) eap: Peer sent packet with method EAP TTLS (21)
(2) eap: Calling submodule eap_ttls to process data
(2) eap_ttls: Authenticate
(2) eap_ttls: Continuing EAP-TLS
(2) eap_ttls: Peer indicated complete TLS record size will be 117 bytes
(2) eap_ttls: Got complete TLS record (117 bytes)
(2) eap_ttls: [eaptls verify] = length included
(2) eap_ttls: (other): before/accept initialization
(2) eap_ttls: TLS_accept: before/accept initialization
(2) eap_ttls: <<< recv TLS 1.0 Handshake [length 0070], ClientHello
(2) eap_ttls: TLS_accept: SSLv3 read client hello A
(2) eap_ttls: >>> send TLS 1.0 Handshake [length 0039], ServerHello
(2) eap_ttls: TLS_accept: SSLv3 write server hello A
(2) eap_ttls: >>> send TLS 1.0 Handshake [length 09de], Certificate
(2) eap_ttls: TLS_accept: SSLv3 write certificate A
(2) eap_ttls: >>> send TLS 1.0 Handshake [length 014b], ServerKeyExchange
(2) eap_ttls: TLS_accept: SSLv3 write key exchange A
(2) eap_ttls: >>> send TLS 1.0 Handshake [length 0004], ServerHelloDone
(2) eap_ttls: TLS_accept: SSLv3 write server done A
(2) eap_ttls: TLS_accept: SSLv3 flush data
(2) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client certificate A
(2) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client certificate A
(2) eap_ttls: In SSL Handshake Phase
(2) eap_ttls: In SSL Accept mode
(2) eap_ttls: [eaptls process] = handled
(2) eap: Sending EAP Request (code 1) ID 184 length 1004
(2) eap: EAP session adding &reply:State = 0x04505bcc05e84ea0
(2) [eap] = handled
(2) } # authenticate = handled
(2) Using Post-Auth-Type Challenge
(2) Post-Auth-Type sub-section not found. Ignoring.
(2) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(2) Sent Access-Challenge Id 149 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(2) Class = 0x7363696c656b
(2) Idle-Timeout = 120
(2) Acct-Interim-Interval = 600
(2) EAP-Message = 0x01b803ec15c000000b7a160301003902000035030155db105da8ad066200feca07bf619b9573fcfb7388515a37695fd8d75b5675c400c01400000dff01000100000b0004030001021603010
9de0b0009da0009d70005333082052f30820417a003020102020103300d06092a864886f70d01010b050030
(2) Message-Authenticator = 0x00000000000000000000000000000000
(2) State = 0x04505bcc05e84ea0e22d93a65254c60e
(2) Finished request
Waking up in 4.9 seconds.
(3) Received Access-Request Id 150 from 192.168.0.4:37009 to 192.168.0.1:1812 length 176
(3) User-Name = "scilek"
(3) NAS-Identifier = "802aa8ac1ef9"
(3) NAS-Port = 0
(3) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(3) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(3) Framed-MTU = 1400
(3) NAS-Port-Type = Wireless-802.11
(3) Connect-Info = "CONNECT 0Mbps 802.11b"
(3) EAP-Message = 0x02b800061500
(3) State = 0x04505bcc05e84ea0e22d93a65254c60e
(3) Message-Authenticator = 0x45a91ad09cc1e4c9a5f76538b1a75bdf
(3) session-state: No cached attributes
(3) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(3) authorize {
(3) [preprocess] = ok
(3) redundant sql {
(3) sql1: EXPAND %{User-Name}
(3) sql1: --> scilek
(3) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (4)
(3) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(3) sql1: --> CALL authorize_check('scilek')
(3) sql1: Executing select query: CALL authorize_check('scilek')
(3) sql1: User found in radcheck table
(3) sql1: Conditional check items matched, merging assignment check items
(3) sql1: Cleartext-Password := "0000"
(3) sql1: Simultaneous-Use := 1
(3) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(3) sql1: --> CALL authorize_reply('scilek')
(3) sql1: Executing select query: CALL authorize_reply('scilek')
(3) sql1: User found in radreply table, merging reply items
(3) sql1: Class := 0x7363696c656b
(3) sql1: Idle-Timeout := 120
(3) sql1: Acct-Interim-Interval := 600
(3) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(3) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(3) sql1: --> CALL group_membership('scilek')
(3) sql1: Executing select query: CALL group_membership('scilek')
(3) sql1: User not found in any groups
rlm_sql (sql1): Released connection (4)
(3) [sql1] = ok
(3) } # redundant sql = ok
(3) pap: No User-Password attribute in the request. Cannot do PAP
(3) [pap] = noop
(3) eap: Peer sent EAP Response (code 2) ID 184 length 6
(3) eap: Continuing tunnel setup
(3) [eap] = ok
(3) } # authorize = ok
(3) Found Auth-Type = eap
(3) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(3) authenticate {
(3) eap: Expiring EAP session with state 0x04505bcc05e84ea0
(3) eap: Finished EAP session with state 0x04505bcc05e84ea0
(3) eap: Previous EAP request found for state 0x04505bcc05e84ea0, released from the list
(3) eap: Peer sent packet with method EAP TTLS (21)
(3) eap: Calling submodule eap_ttls to process data
(3) eap_ttls: Authenticate
(3) eap_ttls: Continuing EAP-TLS
(3) eap_ttls: Peer ACKed our handshake fragment
(3) eap_ttls: [eaptls verify] = request
(3) eap_ttls: [eaptls process] = handled
(3) eap: Sending EAP Request (code 1) ID 185 length 1004
(3) eap: EAP session adding &reply:State = 0x04505bcc06e94ea0
(3) [eap] = handled
(3) } # authenticate = handled
(3) Using Post-Auth-Type Challenge
(3) Post-Auth-Type sub-section not found. Ignoring.
(3) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(3) Sent Access-Challenge Id 150 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(3) Class = 0x7363696c656b
(3) Idle-Timeout = 120
(3) Acct-Interim-Interval = 600
(3) EAP-Message = 0x01b903ec15c000000b7a864886f70d010901161c73656c6168617474696e5f63696c656b40686f746d61696c2e636f6d3111300f0603550403130864616d6c612d6361820100301d0603551
d250416301406082b0601050507030106082b06010505080202300b0603551d0f0404030205a03020060355
(3) Message-Authenticator = 0x00000000000000000000000000000000
(3) State = 0x04505bcc06e94ea0e22d93a65254c60e
(3) Finished request
Waking up in 4.9 seconds.
(4) Received Access-Request Id 151 from 192.168.0.4:37009 to 192.168.0.1:1812 length 176
(4) User-Name = "scilek"
(4) NAS-Identifier = "802aa8ac1ef9"
(4) NAS-Port = 0
(4) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(4) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(4) Framed-MTU = 1400
(4) NAS-Port-Type = Wireless-802.11
(4) Connect-Info = "CONNECT 0Mbps 802.11b"
(4) EAP-Message = 0x02b900061500
(4) State = 0x04505bcc06e94ea0e22d93a65254c60e
(4) Message-Authenticator = 0xb7b7deb80f22c03b7b67284e31aedfe7
(4) session-state: No cached attributes
(4) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(4) authorize {
(4) [preprocess] = ok
(4) redundant sql {
(4) sql1: EXPAND %{User-Name}
(4) sql1: --> scilek
(4) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (5)
(4) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(4) sql1: --> CALL authorize_check('scilek')
(4) sql1: Executing select query: CALL authorize_check('scilek')
(4) sql1: User found in radcheck table
(4) sql1: Conditional check items matched, merging assignment check items
(4) sql1: Cleartext-Password := "0000"
(4) sql1: Simultaneous-Use := 1
(4) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(4) sql1: --> CALL authorize_reply('scilek')
(4) sql1: Executing select query: CALL authorize_reply('scilek')
(4) sql1: User found in radreply table, merging reply items
(4) sql1: Class := 0x7363696c656b
(4) sql1: Idle-Timeout := 120
(4) sql1: Acct-Interim-Interval := 600
(4) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(4) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(4) sql1: --> CALL group_membership('scilek')
(4) sql1: Executing select query: CALL group_membership('scilek')
(4) sql1: User not found in any groups
rlm_sql (sql1): Released connection (5)
(4) [sql1] = ok
(4) } # redundant sql = ok
(4) pap: No User-Password attribute in the request. Cannot do PAP
(4) [pap] = noop
(4) eap: Peer sent EAP Response (code 2) ID 185 length 6
(4) eap: Continuing tunnel setup
(4) [eap] = ok
(4) } # authorize = ok
(4) Found Auth-Type = eap
(4) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(4) authenticate {
(4) eap: Expiring EAP session with state 0x04505bcc06e94ea0
(4) eap: Finished EAP session with state 0x04505bcc06e94ea0
(4) eap: Previous EAP request found for state 0x04505bcc06e94ea0, released from the list
(4) eap: Peer sent packet with method EAP TTLS (21)
(4) eap: Calling submodule eap_ttls to process data
(4) eap_ttls: Authenticate
(4) eap_ttls: Continuing EAP-TLS
(4) eap_ttls: Peer ACKed our handshake fragment
(4) eap_ttls: [eaptls verify] = request
(4) eap_ttls: [eaptls process] = handled
(4) eap: Sending EAP Request (code 1) ID 186 length 960
(4) eap: EAP session adding &reply:State = 0x04505bcc07ea4ea0
(4) [eap] = handled
(4) } # authenticate = handled
(4) Using Post-Auth-Type Challenge
(4) Post-Auth-Type sub-section not found. Ignoring.
(4) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(4) Sent Access-Challenge Id 151 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(4) Class = 0x7363696c656b
(4) Idle-Timeout = 120
(4) Acct-Interim-Interval = 600
(4) EAP-Message = 0x01ba03c0158000000b7ad35ed94c294c4915363eead91eb754997cc9e358432fc92ea951cc3bf0ca257b331a7cb6a269a2a68568a263e95de9f53ec3793bc049b13f139ae3b681106134abf
5b4d08b0203010001a381fc3081f9301d0603551d0e04160414af297b64d5335e54578a00c1231a91e0b971
(4) Message-Authenticator = 0x00000000000000000000000000000000
(4) State = 0x04505bcc07ea4ea0e22d93a65254c60e
(4) Finished request
Waking up in 4.9 seconds.
(5) Received Access-Request Id 152 from 192.168.0.4:37009 to 192.168.0.1:1812 length 314
(5) User-Name = "scilek"
(5) NAS-Identifier = "802aa8ac1ef9"
(5) NAS-Port = 0
(5) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(5) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(5) Framed-MTU = 1400
(5) NAS-Port-Type = Wireless-802.11
(5) Connect-Info = "CONNECT 0Mbps 802.11b"
(5) EAP-Message = 0x02ba00901580000000861603010046100000424104930a9b3c73dac921851d8ab0f682712f717dcabd9168c5198e90ee4e8f42c0df4222a064549fa68d3c58f0ece3bfa78dff21ff2053f6e
f8442299d87f05682481403010001011603010030f9dccf05d275407d8a94d01743bbca728333116b00a1e7
(5) State = 0x04505bcc07ea4ea0e22d93a65254c60e
(5) Message-Authenticator = 0x9a619954e29219b191d011153f6c40b0
(5) session-state: No cached attributes
(5) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(5) authorize {
(5) [preprocess] = ok
(5) redundant sql {
(5) sql1: EXPAND %{User-Name}
(5) sql1: --> scilek
(5) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (6)
(5) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(5) sql1: --> CALL authorize_check('scilek')
(5) sql1: Executing select query: CALL authorize_check('scilek')
(5) sql1: User found in radcheck table
(5) sql1: Conditional check items matched, merging assignment check items
(5) sql1: Cleartext-Password := "0000"
(5) sql1: Simultaneous-Use := 1
(5) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(5) sql1: --> CALL authorize_reply('scilek')
(5) sql1: Executing select query: CALL authorize_reply('scilek')
(5) sql1: User found in radreply table, merging reply items
(5) sql1: Class := 0x7363696c656b
(5) sql1: Idle-Timeout := 120
(5) sql1: Acct-Interim-Interval := 600
(5) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(5) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(5) sql1: --> CALL group_membership('scilek')
(5) sql1: Executing select query: CALL group_membership('scilek')
(5) sql1: User not found in any groups
rlm_sql (sql1): Released connection (6)
(5) [sql1] = ok
(5) } # redundant sql = ok
(5) pap: No User-Password attribute in the request. Cannot do PAP
(5) [pap] = noop
(5) eap: Peer sent EAP Response (code 2) ID 186 length 144
(5) eap: Continuing tunnel setup
(5) [eap] = ok
(5) } # authorize = ok
(5) Found Auth-Type = eap
(5) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(5) authenticate {
(5) eap: Expiring EAP session with state 0x04505bcc07ea4ea0
(5) eap: Finished EAP session with state 0x04505bcc07ea4ea0
(5) eap: Previous EAP request found for state 0x04505bcc07ea4ea0, released from the list
(5) eap: Peer sent packet with method EAP TTLS (21)
(5) eap: Calling submodule eap_ttls to process data
(5) eap_ttls: Authenticate
(5) eap_ttls: Continuing EAP-TLS
(5) eap_ttls: Peer indicated complete TLS record size will be 134 bytes
(5) eap_ttls: Got complete TLS record (134 bytes)
(5) eap_ttls: [eaptls verify] = length included
(5) eap_ttls: <<< recv TLS 1.0 Handshake [length 0046], ClientKeyExchange
(5) eap_ttls: TLS_accept: SSLv3 read client key exchange A
(5) eap_ttls: TLS_accept: SSLv3 read certificate verify A
(5) eap_ttls: <<< recv TLS 1.0 ChangeCipherSpec [length 0001]
(5) eap_ttls: <<< recv TLS 1.0 Handshake [length 0010], Finished
(5) eap_ttls: TLS_accept: SSLv3 read finished A
(5) eap_ttls: >>> send TLS 1.0 ChangeCipherSpec [length 0001]
(5) eap_ttls: TLS_accept: SSLv3 write change cipher spec A
(5) eap_ttls: >>> send TLS 1.0 Handshake [length 0010], Finished
(5) eap_ttls: TLS_accept: SSLv3 write finished A
(5) eap_ttls: TLS_accept: SSLv3 flush data
(5) eap_ttls: (other): SSL negotiation finished successfully
(5) eap_ttls: SSL Connection Established
(5) eap_ttls: [eaptls process] = handled
(5) eap: Sending EAP Request (code 1) ID 187 length 69
(5) eap: EAP session adding &reply:State = 0x04505bcc00eb4ea0
(5) [eap] = handled
(5) } # authenticate = handled
(5) Using Post-Auth-Type Challenge
(5) Post-Auth-Type sub-section not found. Ignoring.
(5) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(5) Sent Access-Challenge Id 152 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(5) Class = 0x7363696c656b
(5) Idle-Timeout = 120
(5) Acct-Interim-Interval = 600
(5) EAP-Message = 0x01bb004515800000003b1403010001011603010030634c922d6bc2683c316c571d9c853fac87c9e27f07fa69d43607157d30546461b057cbe08149b128d53f3056e46ef21e
(5) Message-Authenticator = 0x00000000000000000000000000000000
(5) State = 0x04505bcc00eb4ea0e22d93a65254c60e
(5) Finished request
Waking up in 3.1 seconds.
(6) Received Access-Request Id 153 from 192.168.0.4:37009 to 192.168.0.1:1812 length 233
(6) User-Name = "scilek"
(6) NAS-Identifier = "802aa8ac1ef9"
(6) NAS-Port = 0
(6) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(6) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(6) Framed-MTU = 1400
(6) NAS-Port-Type = Wireless-802.11
(6) Connect-Info = "CONNECT 0Mbps 802.11b"
(6) EAP-Message = 0x02bb003f158000000035170301003032c62cae5225ad1cc1be64730c15889bf074af354c931c15c9470ded18a4b61bad881d0e401a037f6d522797d226d5f3
(6) State = 0x04505bcc00eb4ea0e22d93a65254c60e
(6) Message-Authenticator = 0x5523305c39995cf5e531221ccc3a6912
(6) session-state: No cached attributes
(6) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(6) authorize {
(6) [preprocess] = ok
(6) redundant sql {
(6) sql1: EXPAND %{User-Name}
(6) sql1: --> scilek
(6) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (7)
(6) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(6) sql1: --> CALL authorize_check('scilek')
(6) sql1: Executing select query: CALL authorize_check('scilek')
(6) sql1: User found in radcheck table
(6) sql1: Conditional check items matched, merging assignment check items
(6) sql1: Cleartext-Password := "0000"
(6) sql1: Simultaneous-Use := 1
(6) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(6) sql1: --> CALL authorize_reply('scilek')
(6) sql1: Executing select query: CALL authorize_reply('scilek')
(6) sql1: User found in radreply table, merging reply items
(6) sql1: Class := 0x7363696c656b
(6) sql1: Idle-Timeout := 120
(6) sql1: Acct-Interim-Interval := 600
(6) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(6) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(6) sql1: --> CALL group_membership('scilek')
(6) sql1: Executing select query: CALL group_membership('scilek')
(6) sql1: User not found in any groups
rlm_sql (sql1): Released connection (7)
(6) [sql1] = ok
(6) } # redundant sql = ok
(6) pap: No User-Password attribute in the request. Cannot do PAP
(6) [pap] = noop
(6) eap: Peer sent EAP Response (code 2) ID 187 length 63
(6) eap: Continuing tunnel setup
(6) [eap] = ok
(6) } # authorize = ok
(6) Found Auth-Type = eap
(6) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(6) authenticate {
(6) eap: Expiring EAP session with state 0x04505bcc00eb4ea0
(6) eap: Finished EAP session with state 0x04505bcc00eb4ea0
(6) eap: Previous EAP request found for state 0x04505bcc00eb4ea0, released from the list
(6) eap: Peer sent packet with method EAP TTLS (21)
(6) eap: Calling submodule eap_ttls to process data
(6) eap_ttls: Authenticate
(6) eap_ttls: Continuing EAP-TLS
(6) eap_ttls: Peer indicated complete TLS record size will be 53 bytes
(6) eap_ttls: Got complete TLS record (53 bytes)
(6) eap_ttls: [eaptls verify] = length included
(6) eap_ttls: [eaptls process] = ok
(6) eap_ttls: Session established. Proceeding to decode tunneled attributes
(6) eap_ttls: Got tunneled request
(6) eap_ttls: EAP-Message = 0x0200000b017363696c656b
(6) eap_ttls: FreeRADIUS-Proxied-To = 127.0.0.1
(6) eap_ttls: Got tunneled identity of scilek
(6) eap_ttls: Setting default EAP type for tunneled EAP session
(6) eap_ttls: Sending tunneled request
(6) Virtual server inner-tunnel-ttls received request
(6) EAP-Message = 0x0200000b017363696c656b
(6) FreeRADIUS-Proxied-To = 127.0.0.1
(6) User-Name = "scilek"
(6) NAS-Identifier = "802aa8ac1ef9"
(6) NAS-Port = 0
(6) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(6) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(6) Framed-MTU = 1400
(6) NAS-Port-Type = Wireless-802.11
(6) Connect-Info = "CONNECT 0Mbps 802.11b"
(6) Event-Timestamp = "Aug 6 2017 22:01:04 +03"
(6) NAS-IP-Address = 192.168.0.4
(6) WARNING: Outer and inner identities are the same. User privacy is compromised.
(6) server inner-tunnel-ttls {
(6) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(6) authorize {
(6) update control {
(6) &Proxy-To-Realm := LOCAL
(6) } # update control = noop
(6) eap: Peer sent EAP Response (code 2) ID 0 length 11
(6) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize
(6) [eap] = ok
(6) } # authorize = ok
(6) WARNING: You set Proxy-To-Realm = LOCAL, but the realm does not exist! Cancelling invalid proxy request.
(6) Found Auth-Type = eap
(6) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(6) authenticate {
(6) eap: Peer sent packet with method EAP Identity (1)
(6) eap: Calling submodule eap_tls to process data
(6) eap_tls: Initiating new EAP-TLS session
(6) eap_tls: Setting verify mode to require certificate from client
(6) eap_tls: [eaptls start] = request
(6) eap: Sending EAP Request (code 1) ID 1 length 6
(6) eap: EAP session adding &reply:State = 0xb261b712b260baef
(6) [eap] = handled
(6) } # authenticate = handled
(6) } # server inner-tunnel-ttls
(6) Virtual server sending reply
(6) EAP-Message = 0x010100060d20
(6) Message-Authenticator = 0x00000000000000000000000000000000
(6) State = 0xb261b712b260baef1bb99e7a9d2d07d1
(6) eap_ttls: Got tunneled Access-Challenge
(6) eap: Sending EAP Request (code 1) ID 188 length 63
(6) eap: EAP session adding &reply:State = 0x04505bcc01ec4ea0
(6) [eap] = handled
(6) } # authenticate = handled
(6) Using Post-Auth-Type Challenge
(6) Post-Auth-Type sub-section not found. Ignoring.
(6) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(6) Sent Access-Challenge Id 153 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(6) Class = 0x7363696c656b
(6) Idle-Timeout = 120
(6) Acct-Interim-Interval = 600
(6) EAP-Message = 0x01bc003f158000000035170301003071469a10b0f1b3b1435b53b91ff9222f139ad1069d07f31fd9be750df2d0318c204da31cacfccfdf07670980b8c7d825
(6) Message-Authenticator = 0x00000000000000000000000000000000
(6) State = 0x04505bcc01ec4ea0e22d93a65254c60e
(6) Finished request
Waking up in 3.1 seconds.
(7) Received Access-Request Id 154 from 192.168.0.4:37009 to 192.168.0.1:1812 length 233
(7) User-Name = "scilek"
(7) NAS-Identifier = "802aa8ac1ef9"
(7) NAS-Port = 0
(7) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(7) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(7) Framed-MTU = 1400
(7) NAS-Port-Type = Wireless-802.11
(7) Connect-Info = "CONNECT 0Mbps 802.11b"
(7) EAP-Message = 0x02bc003f15800000003517030100308b11e5a28fd93731564ae120793d5d4c1d1b1ebbdf8f8631529412cb8c943e87e3a255fa25307aedc28e2ce0fa6374d4
(7) State = 0x04505bcc01ec4ea0e22d93a65254c60e
(7) Message-Authenticator = 0xd2091d38934748e580def21e79c2dcba
(7) session-state: No cached attributes
(7) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(7) authorize {
(7) [preprocess] = ok
(7) redundant sql {
(7) sql1: EXPAND %{User-Name}
(7) sql1: --> scilek
(7) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (8)
(7) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(7) sql1: --> CALL authorize_check('scilek')
(7) sql1: Executing select query: CALL authorize_check('scilek')
(7) sql1: User found in radcheck table
(7) sql1: Conditional check items matched, merging assignment check items
(7) sql1: Cleartext-Password := "0000"
(7) sql1: Simultaneous-Use := 1
(7) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(7) sql1: --> CALL authorize_reply('scilek')
(7) sql1: Executing select query: CALL authorize_reply('scilek')
(7) sql1: User found in radreply table, merging reply items
(7) sql1: Class := 0x7363696c656b
(7) sql1: Idle-Timeout := 120
(7) sql1: Acct-Interim-Interval := 600
(7) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(7) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(7) sql1: --> CALL group_membership('scilek')
(7) sql1: Executing select query: CALL group_membership('scilek')
(7) sql1: User not found in any groups
rlm_sql (sql1): Released connection (8)
(7) [sql1] = ok
(7) } # redundant sql = ok
(7) pap: No User-Password attribute in the request. Cannot do PAP
(7) [pap] = noop
(7) eap: Peer sent EAP Response (code 2) ID 188 length 63
(7) eap: Continuing tunnel setup
(7) [eap] = ok
(7) } # authorize = ok
(7) Found Auth-Type = eap
(7) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(7) authenticate {
(7) eap: Expiring EAP session with state 0xb261b712b260baef
(7) eap: Finished EAP session with state 0x04505bcc01ec4ea0
(7) eap: Previous EAP request found for state 0x04505bcc01ec4ea0, released from the list
(7) eap: Peer sent packet with method EAP TTLS (21)
(7) eap: Calling submodule eap_ttls to process data
(7) eap_ttls: Authenticate
(7) eap_ttls: Continuing EAP-TLS
(7) eap_ttls: Peer indicated complete TLS record size will be 53 bytes
(7) eap_ttls: Got complete TLS record (53 bytes)
(7) eap_ttls: [eaptls verify] = length included
(7) eap_ttls: [eaptls process] = ok
(7) eap_ttls: Session established. Proceeding to decode tunneled attributes
(7) eap_ttls: Got tunneled request
(7) eap_ttls: EAP-Message = 0x02010006031a
(7) eap_ttls: FreeRADIUS-Proxied-To = 127.0.0.1
(7) eap_ttls: Sending tunneled request
(7) Virtual server inner-tunnel-ttls received request
(7) EAP-Message = 0x02010006031a
(7) FreeRADIUS-Proxied-To = 127.0.0.1
(7) User-Name = "scilek"
(7) State = 0xb261b712b260baef1bb99e7a9d2d07d1
(7) NAS-Identifier = "802aa8ac1ef9"
(7) NAS-Port = 0
(7) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(7) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(7) Framed-MTU = 1400
(7) NAS-Port-Type = Wireless-802.11
(7) Connect-Info = "CONNECT 0Mbps 802.11b"
(7) Event-Timestamp = "Aug 6 2017 22:01:04 +03"
(7) NAS-IP-Address = 192.168.0.4
(7) WARNING: Outer and inner identities are the same. User privacy is compromised.
(7) server inner-tunnel-ttls {
(7) session-state: No cached attributes
(7) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(7) authorize {
(7) update control {
(7) &Proxy-To-Realm := LOCAL
(7) } # update control = noop
(7) eap: Peer sent EAP Response (code 2) ID 1 length 6
(7) eap: No EAP Start, assuming it's an on-going EAP conversation
(7) [eap] = updated
(7) redundant sql {
(7) sql1: EXPAND %{User-Name}
(7) sql1: --> scilek
(7) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (9)
(7) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(7) sql1: --> CALL authorize_check('scilek')
(7) sql1: Executing select query: CALL authorize_check('scilek')
(7) sql1: User found in radcheck table
(7) sql1: Conditional check items matched, merging assignment check items
(7) sql1: Cleartext-Password := "0000"
(7) sql1: Simultaneous-Use := 1
(7) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(7) sql1: --> CALL authorize_reply('scilek')
(7) sql1: Executing select query: CALL authorize_reply('scilek')
(7) sql1: User found in radreply table, merging reply items
(7) sql1: Class := 0x7363696c656b
(7) sql1: Idle-Timeout := 120
(7) sql1: Acct-Interim-Interval := 600
(7) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(7) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(7) sql1: --> CALL group_membership('scilek')
(7) sql1: Executing select query: CALL group_membership('scilek')
(7) sql1: User not found in any groups
rlm_sql (sql1): Released connection (9)
(7) [sql1] = ok
(7) } # redundant sql = ok
(7) [expiration] = noop
(7) [logintime] = noop
(7) pap: WARNING: Auth-Type already set. Not setting to PAP
(7) [pap] = noop
(7) } # authorize = updated
(7) WARNING: You set Proxy-To-Realm = LOCAL, but the realm does not exist! Cancelling invalid proxy request.
(7) Found Auth-Type = eap
(7) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(7) authenticate {
(7) eap: Expiring EAP session with state 0xb261b712b260baef
(7) eap: Finished EAP session with state 0xb261b712b260baef
(7) eap: Previous EAP request found for state 0xb261b712b260baef, released from the list
(7) eap: Peer sent packet with method EAP NAK (3)
(7) eap: Found mutually acceptable type MSCHAPv2 (26)
(7) eap: Calling submodule eap_mschapv2 to process data
(7) eap_mschapv2: Issuing Challenge
(7) eap: Sending EAP Request (code 1) ID 2 length 43
(7) eap: EAP session adding &reply:State = 0xb261b712b363adef
(7) [eap] = handled
(7) } # authenticate = handled
(7) } # server inner-tunnel-ttls
(7) Virtual server sending reply
(7) Class = 0x7363696c656b
(7) Idle-Timeout = 120
(7) Acct-Interim-Interval = 600
(7) Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(7) EAP-Message = 0x0102002b1a010200261076275b44d652a45dd691ef8c9f594154667265657261646975732d332e302e3135
(7) Message-Authenticator = 0x00000000000000000000000000000000
(7) State = 0xb261b712b363adef1bb99e7a9d2d07d1
(7) eap_ttls: Got tunneled Access-Challenge
(7) eap: Sending EAP Request (code 1) ID 189 length 95
(7) eap: EAP session adding &reply:State = 0x04505bcc02ed4ea0
(7) [eap] = handled
(7) } # authenticate = handled
(7) Using Post-Auth-Type Challenge
(7) Post-Auth-Type sub-section not found. Ignoring.
(7) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(7) Sent Access-Challenge Id 154 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(7) Class = 0x7363696c656b
(7) Idle-Timeout = 120
(7) Acct-Interim-Interval = 600
(7) EAP-Message = 0x01bd005f15800000005517030100506d9b920856058f51d9d63731a1ba2cca6089b76a27e0dddbca0c273dbc8c806f5f5467b1b69776fe35cd70c68d9b3bd05b771011e352ff26e0deee630
7f527c97cf9159e92723688dbf3061a419c08f7
(7) Message-Authenticator = 0x00000000000000000000000000000000
(7) State = 0x04505bcc02ed4ea0e22d93a65254c60e
(7) Finished request
Waking up in 3.0 seconds.
(8) Received Access-Request Id 155 from 192.168.0.4:37009 to 192.168.0.1:1812 length 297
(8) User-Name = "scilek"
(8) NAS-Identifier = "802aa8ac1ef9"
(8) NAS-Port = 0
(8) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(8) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(8) Framed-MTU = 1400
(8) NAS-Port-Type = Wireless-802.11
(8) Connect-Info = "CONNECT 0Mbps 802.11b"
(8) EAP-Message = 0x02bd007f1580000000751703010070f2c2216c991f799561341c814c3163c6d7aef3ee5c288293c03d51683bdcb15fd1c034000acd7fca07a3c9aabea8e9c3a28b98238da442ea319076deb
6b0db7c02fe625f4166210c16388beed43b5f746b9ca8fdcc76f9534b5465685f312694803f1dcca7b3f741
(8) State = 0x04505bcc02ed4ea0e22d93a65254c60e
(8) Message-Authenticator = 0x44a5776045dff1d0cd24cf4a8a73d84f
(8) session-state: No cached attributes
(8) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(8) authorize {
(8) [preprocess] = ok
(8) redundant sql {
(8) sql1: EXPAND %{User-Name}
(8) sql1: --> scilek
(8) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (10)
(8) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(8) sql1: --> CALL authorize_check('scilek')
(8) sql1: Executing select query: CALL authorize_check('scilek')
(8) sql1: User found in radcheck table
(8) sql1: Conditional check items matched, merging assignment check items
(8) sql1: Cleartext-Password := "0000"
(8) sql1: Simultaneous-Use := 1
(8) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(8) sql1: --> CALL authorize_reply('scilek')
(8) sql1: Executing select query: CALL authorize_reply('scilek')
(8) sql1: User found in radreply table, merging reply items
(8) sql1: Class := 0x7363696c656b
(8) sql1: Idle-Timeout := 120
(8) sql1: Acct-Interim-Interval := 600
(8) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(8) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(8) sql1: --> CALL group_membership('scilek')
(8) sql1: Executing select query: CALL group_membership('scilek')
(8) sql1: User not found in any groups
rlm_sql (sql1): Released connection (10)
(8) [sql1] = ok
(8) } # redundant sql = ok
(8) pap: No User-Password attribute in the request. Cannot do PAP
(8) [pap] = noop
(8) eap: Peer sent EAP Response (code 2) ID 189 length 127
(8) eap: Continuing tunnel setup
(8) [eap] = ok
(8) } # authorize = ok
(8) Found Auth-Type = eap
(8) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(8) authenticate {
(8) eap: Expiring EAP session with state 0xb261b712b363adef
(8) eap: Finished EAP session with state 0x04505bcc02ed4ea0
(8) eap: Previous EAP request found for state 0x04505bcc02ed4ea0, released from the list
(8) eap: Peer sent packet with method EAP TTLS (21)
(8) eap: Calling submodule eap_ttls to process data
(8) eap_ttls: Authenticate
(8) eap_ttls: Continuing EAP-TLS
(8) eap_ttls: Peer indicated complete TLS record size will be 117 bytes
(8) eap_ttls: Got complete TLS record (117 bytes)
(8) eap_ttls: [eaptls verify] = length included
(8) eap_ttls: [eaptls process] = ok
(8) eap_ttls: Session established. Proceeding to decode tunneled attributes
(8) eap_ttls: Got tunneled request
(8) eap_ttls: EAP-Message = 0x020200411a0202003c3123b9165317bd2d22a434e4ac00b57acc000000000000000095496f7e45ddbc1dd890243a7947e68d2749164433e3a15e007363696c656b
(8) eap_ttls: FreeRADIUS-Proxied-To = 127.0.0.1
(8) eap_ttls: Sending tunneled request
(8) Virtual server inner-tunnel-ttls received request
(8) EAP-Message = 0x020200411a0202003c3123b9165317bd2d22a434e4ac00b57acc000000000000000095496f7e45ddbc1dd890243a7947e68d2749164433e3a15e007363696c656b
(8) FreeRADIUS-Proxied-To = 127.0.0.1
(8) User-Name = "scilek"
(8) State = 0xb261b712b363adef1bb99e7a9d2d07d1
(8) NAS-Identifier = "802aa8ac1ef9"
(8) NAS-Port = 0
(8) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(8) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(8) Framed-MTU = 1400
(8) NAS-Port-Type = Wireless-802.11
(8) Connect-Info = "CONNECT 0Mbps 802.11b"
(8) Event-Timestamp = "Aug 6 2017 22:01:05 +03"
(8) NAS-IP-Address = 192.168.0.4
(8) WARNING: Outer and inner identities are the same. User privacy is compromised.
(8) server inner-tunnel-ttls {
(8) session-state: No cached attributes
(8) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(8) authorize {
(8) update control {
(8) &Proxy-To-Realm := LOCAL
(8) } # update control = noop
(8) eap: Peer sent EAP Response (code 2) ID 2 length 65
(8) eap: No EAP Start, assuming it's an on-going EAP conversation
(8) [eap] = updated
(8) redundant sql {
(8) sql1: EXPAND %{User-Name}
(8) sql1: --> scilek
(8) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (11)
(8) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(8) sql1: --> CALL authorize_check('scilek')
(8) sql1: Executing select query: CALL authorize_check('scilek')
(8) sql1: User found in radcheck table
(8) sql1: Conditional check items matched, merging assignment check items
(8) sql1: Cleartext-Password := "0000"
(8) sql1: Simultaneous-Use := 1
(8) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(8) sql1: --> CALL authorize_reply('scilek')
(8) sql1: Executing select query: CALL authorize_reply('scilek')
(8) sql1: User found in radreply table, merging reply items
(8) sql1: Class := 0x7363696c656b
(8) sql1: Idle-Timeout := 120
(8) sql1: Acct-Interim-Interval := 600
(8) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(8) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(8) sql1: --> CALL group_membership('scilek')
(8) sql1: Executing select query: CALL group_membership('scilek')
(8) sql1: User not found in any groups
rlm_sql (sql1): Released connection (11)
(8) [sql1] = ok
(8) } # redundant sql = ok
(8) [expiration] = noop
(8) [logintime] = noop
(8) pap: WARNING: Auth-Type already set. Not setting to PAP
(8) [pap] = noop
(8) } # authorize = updated
(8) WARNING: You set Proxy-To-Realm = LOCAL, but the realm does not exist! Cancelling invalid proxy request.
(8) Found Auth-Type = eap
(8) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(8) authenticate {
(8) eap: Expiring EAP session with state 0xb261b712b363adef
(8) eap: Finished EAP session with state 0xb261b712b363adef
(8) eap: Previous EAP request found for state 0xb261b712b363adef, released from the list
(8) eap: Peer sent packet with method EAP MSCHAPv2 (26)
(8) eap: Calling submodule eap_mschapv2 to process data
(8) eap_mschapv2: # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(8) eap_mschapv2: authenticate {
(8) mschap: Found Cleartext-Password, hashing to create NT-Password
(8) mschap: Found Cleartext-Password, hashing to create LM-Password
(8) mschap: Creating challenge hash with username: scilek
(8) mschap: Client is using MS-CHAPv2
(8) mschap: Adding MS-CHAPv2 MPPE keys
(8) [mschap] = ok
(8) } # authenticate = ok
(8) MSCHAP Success
(8) eap: Sending EAP Request (code 1) ID 3 length 51
(8) eap: EAP session adding &reply:State = 0xb261b712b062adef
(8) [eap] = handled
(8) } # authenticate = handled
(8) } # server inner-tunnel-ttls
(8) Virtual server sending reply
(8) Class = 0x7363696c656b
(8) Idle-Timeout = 120
(8) Acct-Interim-Interval = 600
(8) Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(8) EAP-Message = 0x010300331a0302002e533d35374338384535394446343042374534464530344235393938433245343036413942414330313735
(8) Message-Authenticator = 0x00000000000000000000000000000000
(8) State = 0xb261b712b062adef1bb99e7a9d2d07d1
(8) eap_ttls: Got tunneled Access-Challenge
(8) eap: Sending EAP Request (code 1) ID 190 length 111
(8) eap: EAP session adding &reply:State = 0x04505bcc03ee4ea0
(8) [eap] = handled
(8) } # authenticate = handled
(8) Using Post-Auth-Type Challenge
(8) Post-Auth-Type sub-section not found. Ignoring.
(8) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(8) Sent Access-Challenge Id 155 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(8) Class = 0x7363696c656b
(8) Idle-Timeout = 120
(8) Acct-Interim-Interval = 600
(8) EAP-Message = 0x01be006f15800000006517030100607fa1a1325acdddb66d4edf3e8ca2e1ce4efbab2332a0db5f9b9fd88f89d4740dc90babafc823bf48e0eef8baf16b27939ef7b632d37b7c2c0b26a7ae0
86fb09e5059665a5c0ab2642e517da8daa1f5d410bd49833b5b06ddc3ba709fc00c6397
(8) Message-Authenticator = 0x00000000000000000000000000000000
(8) State = 0x04505bcc03ee4ea0e22d93a65254c60e
(8) Finished request
Waking up in 3.0 seconds.
(9) Received Access-Request Id 156 from 192.168.0.4:37009 to 192.168.0.1:1812 length 233
(9) User-Name = "scilek"
(9) NAS-Identifier = "802aa8ac1ef9"
(9) NAS-Port = 0
(9) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(9) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(9) Framed-MTU = 1400
(9) NAS-Port-Type = Wireless-802.11
(9) Connect-Info = "CONNECT 0Mbps 802.11b"
(9) EAP-Message = 0x02be003f15800000003517030100307b461ab4e2d39fbcdc7e73d4ad3e69bd4a10b459077867f0d1caa1e8f7be1e0b977e098f3f5c753ff00974b1d596ada8
(9) State = 0x04505bcc03ee4ea0e22d93a65254c60e
(9) Message-Authenticator = 0x75a8ef09c04fddc52861bdbd1959b9af
(9) session-state: No cached attributes
(9) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(9) authorize {
(9) [preprocess] = ok
(9) redundant sql {
(9) sql1: EXPAND %{User-Name}
(9) sql1: --> scilek
(9) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (12)
(9) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(9) sql1: --> CALL authorize_check('scilek')
(9) sql1: Executing select query: CALL authorize_check('scilek')
(9) sql1: User found in radcheck table
(9) sql1: Conditional check items matched, merging assignment check items
(9) sql1: Cleartext-Password := "0000"
(9) sql1: Simultaneous-Use := 1
(9) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(9) sql1: --> CALL authorize_reply('scilek')
(9) sql1: Executing select query: CALL authorize_reply('scilek')
(9) sql1: User found in radreply table, merging reply items
(9) sql1: Class := 0x7363696c656b
(9) sql1: Idle-Timeout := 120
(9) sql1: Acct-Interim-Interval := 600
(9) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(9) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(9) sql1: --> CALL group_membership('scilek')
(9) sql1: Executing select query: CALL group_membership('scilek')
(9) sql1: User not found in any groups
rlm_sql (sql1): Released connection (12)
(9) [sql1] = ok
(9) } # redundant sql = ok
(9) pap: No User-Password attribute in the request. Cannot do PAP
(9) [pap] = noop
(9) eap: Peer sent EAP Response (code 2) ID 190 length 63
(9) eap: Continuing tunnel setup
(9) [eap] = ok
(9) } # authorize = ok
(9) Found Auth-Type = eap
(9) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(9) authenticate {
(9) eap: Expiring EAP session with state 0xb261b712b062adef
(9) eap: Finished EAP session with state 0x04505bcc03ee4ea0
(9) eap: Previous EAP request found for state 0x04505bcc03ee4ea0, released from the list
(9) eap: Peer sent packet with method EAP TTLS (21)
(9) eap: Calling submodule eap_ttls to process data
(9) eap_ttls: Authenticate
(9) eap_ttls: Continuing EAP-TLS
(9) eap_ttls: Peer indicated complete TLS record size will be 53 bytes
(9) eap_ttls: Got complete TLS record (53 bytes)
(9) eap_ttls: [eaptls verify] = length included
(9) eap_ttls: [eaptls process] = ok
(9) eap_ttls: Session established. Proceeding to decode tunneled attributes
(9) eap_ttls: Got tunneled request
(9) eap_ttls: EAP-Message = 0x020300061a03
(9) eap_ttls: FreeRADIUS-Proxied-To = 127.0.0.1
(9) eap_ttls: Sending tunneled request
(9) Virtual server inner-tunnel-ttls received request
(9) EAP-Message = 0x020300061a03
(9) FreeRADIUS-Proxied-To = 127.0.0.1
(9) User-Name = "scilek"
(9) State = 0xb261b712b062adef1bb99e7a9d2d07d1
(9) NAS-Identifier = "802aa8ac1ef9"
(9) NAS-Port = 0
(9) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(9) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(9) Framed-MTU = 1400
(9) NAS-Port-Type = Wireless-802.11
(9) Connect-Info = "CONNECT 0Mbps 802.11b"
(9) Event-Timestamp = "Aug 6 2017 22:01:05 +03"
(9) NAS-IP-Address = 192.168.0.4
(9) WARNING: Outer and inner identities are the same. User privacy is compromised.
(9) server inner-tunnel-ttls {
(9) session-state: No cached attributes
(9) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(9) authorize {
(9) update control {
(9) &Proxy-To-Realm := LOCAL
(9) } # update control = noop
(9) eap: Peer sent EAP Response (code 2) ID 3 length 6
(9) eap: No EAP Start, assuming it's an on-going EAP conversation
(9) [eap] = updated
(9) redundant sql {
(9) sql1: EXPAND %{User-Name}
(9) sql1: --> scilek
(9) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (13)
(9) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(9) sql1: --> CALL authorize_check('scilek')
(9) sql1: Executing select query: CALL authorize_check('scilek')
(9) sql1: User found in radcheck table
(9) sql1: Conditional check items matched, merging assignment check items
(9) sql1: Cleartext-Password := "0000"
(9) sql1: Simultaneous-Use := 1
(9) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(9) sql1: --> CALL authorize_reply('scilek')
(9) sql1: Executing select query: CALL authorize_reply('scilek')
(9) sql1: User found in radreply table, merging reply items
(9) sql1: Class := 0x7363696c656b
(9) sql1: Idle-Timeout := 120
(9) sql1: Acct-Interim-Interval := 600
(9) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(9) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(9) sql1: --> CALL group_membership('scilek')
(9) sql1: Executing select query: CALL group_membership('scilek')
(9) sql1: User not found in any groups
rlm_sql (sql1): Released connection (13)
(9) [sql1] = ok
(9) } # redundant sql = ok
(9) [expiration] = noop
(9) [logintime] = noop
(9) pap: WARNING: Auth-Type already set. Not setting to PAP
(9) [pap] = noop
(9) } # authorize = updated
(9) WARNING: You set Proxy-To-Realm = LOCAL, but the realm does not exist! Cancelling invalid proxy request.
(9) Found Auth-Type = eap
(9) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(9) authenticate {
(9) eap: Expiring EAP session with state 0xb261b712b062adef
(9) eap: Finished EAP session with state 0xb261b712b062adef
(9) eap: Previous EAP request found for state 0xb261b712b062adef, released from the list
(9) eap: Peer sent packet with method EAP MSCHAPv2 (26)
(9) eap: Calling submodule eap_mschapv2 to process data
(9) eap: Sending EAP Success (code 3) ID 3 length 4
(9) eap: Freeing handler
(9) [eap] = ok
(9) } # authenticate = ok
(9) # Executing section session from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(9) session {
(9) redundant sql {
(9) sql1: EXPAND %{User-Name}
(9) sql1: --> scilek
(9) sql1: SQL-User-Name set to 'scilek'
(9) sql1: EXPAND CALL simul_count('%{SQL-User-Name}')
(9) sql1: --> CALL simul_count('scilek')
rlm_sql (sql1): Reserved connection (14)
(9) sql1: Executing select query: CALL simul_count('scilek')
rlm_sql (sql1): Released connection (14)
(9) [sql1] = ok
(9) } # redundant sql = ok
(9) } # session = ok
(9) # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(9) post-auth {
(9) if (1) {
(9) if (1) -> TRUE
(9) if (1) {
(9) update reply {
(9) User-Name !* ANY
(9) Message-Authenticator !* ANY
(9) EAP-Message !* ANY
(9) Proxy-State !* ANY
(9) MS-MPPE-Encryption-Types !* ANY
(9) MS-MPPE-Encryption-Policy !* ANY
(9) MS-MPPE-Send-Key !* ANY
(9) MS-MPPE-Recv-Key !* ANY
(9) } # update reply = noop
(9) update {
(9) &outer.session-state::Class += &reply:Class[*] -> 0x7363696c656b
(9) &outer.session-state::Idle-Timeout += &reply:Idle-Timeout[*] -> 120
(9) &outer.session-state::Acct-Interim-Interval += &reply:Acct-Interim-Interval[*] -> 600
(9) &outer.session-state::Exec-Program-Wait += &reply:Exec-Program-Wait[*] -> '/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek'
(9) } # update = noop
(9) } # if (1) = noop
(9) } # post-auth = noop
(9) Login OK: [scilek] (from client HOME_AP port 0 cli 2C-F0-A2-87-C1-CA via TLS tunnel)
(9) } # server inner-tunnel-ttls
(9) Virtual server sending reply
(9) Class = 0x7363696c656b
(9) Idle-Timeout = 120
(9) Acct-Interim-Interval = 600
(9) Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(9) eap_ttls: Got tunneled Access-Accept
(9) eap: Sending EAP Success (code 3) ID 190 length 4
(9) eap: Freeing handler
(9) [eap] = ok
(9) } # authenticate = ok
(9) # Executing section session from file /usr/local/etc/raddb/sites-enabled/default
(9) session {
(9) redundant sql {
(9) sql1: EXPAND %{User-Name}
(9) sql1: --> scilek
(9) sql1: SQL-User-Name set to 'scilek'
(9) sql1: EXPAND CALL simul_count('%{SQL-User-Name}')
(9) sql1: --> CALL simul_count('scilek')
rlm_sql (sql1): Reserved connection (15)
(9) sql1: Executing select query: CALL simul_count('scilek')
rlm_sql (sql1): Released connection (15)
(9) [sql1] = ok
(9) } # redundant sql = ok
(9) } # session = ok
(9) # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default
(9) post-auth {
(9) exec: Executing: /usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek:
Warning: Using a password on the command line interface can be insecure.
(9) exec: Program returned code (0) and output ''
(9) exec: Program executed successfully
(9) [exec] = ok
(9) policy remove_reply_message_if_eap {
(9) if (&reply:EAP-Message && &reply:Reply-Message) {
(9) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
(9) else {
(9) [noop] = noop
(9) } # else = noop
(9) } # policy remove_reply_message_if_eap = noop
(9) } # post-auth = ok
(9) Login OK: [scilek] (from client HOME_AP port 0 cli 2C-F0-A2-87-C1-CA)
(9) Sent Access-Accept Id 156 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(9) Class = 0x7363696c656b
(9) Idle-Timeout = 120
(9) Acct-Interim-Interval = 600
(9) MS-MPPE-Recv-Key = 0xc2f8ed83b9161ee9e763fc08a1cbb53359246d980a1c477f8390a3766098302e
(9) MS-MPPE-Send-Key = 0xbff1510aac7ed023d300ed023f9bffe2a1b76f585158b62a72e2cf196bd1c780
(9) EAP-Message = 0x03be0004
(9) Message-Authenticator = 0x00000000000000000000000000000000
(9) User-Name = "scilek"
(9) Finished request
Waking up in 2.9 seconds.
(10) Received Accounting-Request Id 157 from 192.168.0.4:44463 to 192.168.0.1:1813 length 171
(10) Acct-Session-Id = "59873E49-0000001A"
(10) Acct-Status-Type = Start
(10) Acct-Authentic = RADIUS
(10) User-Name = "scilek"
(10) Framed-IP-Address = 0.0.0.0
(10) NAS-Identifier = "802aa8ac1ef9"
(10) NAS-Port = 0
(10) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(10) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(10) NAS-Port-Type = Wireless-802.11
(10) Connect-Info = "CONNECT 0Mbps 802.11b"
(10) Class = 0x7363696c656b
(10) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
(10) preacct {
(10) [preprocess] = ok
(10) } # preacct = ok
(10) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
(10) accounting {
(10) detail: EXPAND /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
(10) detail: --> /var/log/radacct/192.168.0.4/detail_2017_08_06
(10) detail: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d expands to /var/log/radacct/192.168.0.4/detail_2017_08_06
(10) detail: EXPAND %t
(10) detail: --> Sun Aug 6 22:01:05 2017
(10) [detail] = ok
(10) redundant sql {
(10) sql1: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(10) sql1: --> type.start.query
(10) sql1: Using query template 'query'
rlm_sql (sql1): Reserved connection (0)
(10) sql1: EXPAND %{User-Name}
(10) sql1: --> scilek
(10) sql1: SQL-User-Name set to 'scilek'
(10) sql1: EXPAND CALL accounting_start('%{Acct-Session-Id}','%{SQL-User-Name}','%{Class}','%{NAS-IP-Address}','%{Called-Station-Id}','%{Calling-Station-Id}')
(10) sql1: --> CALL accounting_start('59873E49-0000001A','scilek','0x7363696c656b','192.168.0.4','80-2A-A8-AD-1E-F9=3ASCILEK.NET','2C-F0-A2-87-C1-CA')
(10) sql1: EXPAND /var/log/sqltrace.sql
(10) sql1: --> /var/log/sqltrace.sql
(10) sql1: Executing query: CALL accounting_start('59873E49-0000001A','scilek','0x7363696c656b','192.168.0.4','80-2A-A8-AD-1E-F9=3ASCILEK.NET','2C-F0-A2-87-C1-CA')
(10) sql1: SQL query returned: success
(10) sql1: 1 record(s) updated
rlm_sql (sql1): Released connection (0)
(10) [sql1] = ok
(10) } # redundant sql = ok
(10) [exec] = noop
(10) if (request:Acct-Status-Type == Interim-Update) {
(10) if (request:Acct-Status-Type == Interim-Update) -> FALSE
(10) } # accounting = ok
(10) Sent Accounting-Response Id 157 from 192.168.0.1:1813 to 192.168.0.4:44463 length 0
(10) Finished request
(10) Cleaning up request packet ID 157 with timestamp +22
Waking up in 2.9 seconds.
(11) Received Accounting-Request Id 158 from 192.168.0.4:44463 to 192.168.0.1:1813 length 207
(11) Acct-Session-Id = "59873E49-0000001A"
(11) Acct-Status-Type = Interim-Update
(11) Acct-Authentic = RADIUS
(11) User-Name = "scilek"
(11) Framed-IP-Address = 192.168.0.103
(11) NAS-Identifier = "802aa8ac1ef9"
(11) NAS-Port = 0
(11) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(11) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(11) NAS-Port-Type = Wireless-802.11
(11) Connect-Info = "CONNECT 0Mbps 802.11b"
(11) Class = 0x7363696c656b
(11) Acct-Session-Time = 0
(11) Acct-Input-Packets = 14
(11) Acct-Output-Packets = 14
(11) Acct-Input-Octets = 1858
(11) Acct-Output-Octets = 4091
(11) Event-Timestamp = "Aug 6 2017 22:00:59 +03"
(11) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
(11) preacct {
(11) [preprocess] = ok
(11) } # preacct = ok
(11) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
(11) accounting {
(11) detail: EXPAND /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
(11) detail: --> /var/log/radacct/192.168.0.4/detail_2017_08_06
(11) detail: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d expands to /var/log/radacct/192.168.0.4/detail_2017_08_06
(11) detail: EXPAND %t
(11) detail: --> Sun Aug 6 22:01:05 2017
(11) [detail] = ok
(11) redundant sql {
(11) sql1: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(11) sql1: --> type.interim-update.query
(11) sql1: Using query template 'query'
rlm_sql (sql1): Reserved connection (1)
(11) sql1: EXPAND %{User-Name}
(11) sql1: --> scilek
(11) sql1: SQL-User-Name set to 'scilek'
(11) sql1: EXPAND CALL accounting_update ('%{Acct-Session-Id}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-Input-Octets}','%{Acct-Input-Gig
awords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}')
(11) sql1: --> CALL accounting_update ('59873E49-0000001A','80-2A-A8-AD-1E-F9=3ASCILEK.NET','2C-F0-A2-87-C1-CA','0','1858','','4091','')
(11) sql1: EXPAND /var/log/sqltrace.sql
(11) sql1: --> /var/log/sqltrace.sql
(11) sql1: Executing query: CALL accounting_update ('59873E49-0000001A','80-2A-A8-AD-1E-F9=3ASCILEK.NET','2C-F0-A2-87-C1-CA','0','1858','','4091','')
(11) sql1: SQL query returned: success
(11) sql1: 1 record(s) updated
rlm_sql (sql1): Released connection (1)
(11) [sql1] = ok
(11) } # redundant sql = ok
(11) [exec] = noop
(11) if (request:Acct-Status-Type == Interim-Update) {
(11) if (request:Acct-Status-Type == Interim-Update) -> TRUE
(11) if (request:Acct-Status-Type == Interim-Update) {
(11) check_quota: Executing: /usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} %{request:Calling-Station-Id} %{request:NAS-IP-Address
} %{request:Class} %{request:Acct-Status-Type}:
(11) check_quota: EXPAND %{request:User-Name}
(11) check_quota: --> scilek
(11) check_quota: EXPAND %{request:Calling-Station-Id}
(11) check_quota: --> 2C-F0-A2-87-C1-CA
(11) check_quota: EXPAND %{request:NAS-IP-Address}
(11) check_quota: --> 192.168.0.4
(11) check_quota: EXPAND %{request:Class}
(11) check_quota: --> 0x7363696c656b
(11) check_quota: EXPAND %{request:Acct-Status-Type}
(11) check_quota: --> Interim-Update
(11) check_quota: Program executed successfully
(11) [check_quota] = ok
(11) } # if (request:Acct-Status-Type == Interim-Update) = ok
(11) } # accounting = ok
(11) Sent Accounting-Response Id 158 from 192.168.0.1:1813 to 192.168.0.4:44463 length 0
(11) Finished request
(11) Cleaning up request packet ID 158 with timestamp +22
Waking up in 2.9 seconds.
Warning: Using a password on the command line interface can be insecure.
Warning: Using a password on the command line interface can be insecure.
(1) Cleaning up request packet ID 148 with timestamp +20
(2) Cleaning up request packet ID 149 with timestamp +20
(3) Cleaning up request packet ID 150 with timestamp +20
(4) Cleaning up request packet ID 151 with timestamp +20
Waking up in 1.7 seconds.
(5) Cleaning up request packet ID 152 with timestamp +21
(6) Cleaning up request packet ID 153 with timestamp +21
(7) Cleaning up request packet ID 154 with timestamp +21
(8) Cleaning up request packet ID 155 with timestamp +22
(9) Cleaning up request packet ID 156 with timestamp +22
Ready to process requests
(12) Received Accounting-Request Id 159 from 192.168.0.4:44463 to 192.168.0.1:1813 length 213
(12) Acct-Session-Id = "59873E49-0000001A"
(12) Acct-Status-Type = Stop
(12) Acct-Authentic = RADIUS
(12) User-Name = "scilek"
(12) Framed-IP-Address = 192.168.0.103
(12) NAS-Identifier = "802aa8ac1ef9"
(12) NAS-Port = 0
(12) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(12) Calling-Station-Id = "2C-F0-A2-87-C1-CA"
(12) NAS-Port-Type = Wireless-802.11
(12) Connect-Info = "CONNECT 0Mbps 802.11b"
(12) Class = 0x7363696c656b
(12) Acct-Session-Time = 10
(12) Acct-Input-Packets = 178
(12) Acct-Output-Packets = 55
(12) Acct-Input-Octets = 19062
(12) Acct-Output-Octets = 17357
(12) Event-Timestamp = "Aug 6 2017 22:01:09 +03"
(12) Acct-Terminate-Cause = User-Request
(12) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
(12) preacct {
(12) [preprocess] = ok
(12) } # preacct = ok
(12) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
(12) accounting {
(12) detail: EXPAND /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
(12) detail: --> /var/log/radacct/192.168.0.4/detail_2017_08_06
(12) detail: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d expands to /var/log/radacct/192.168.0.4/detail_2017_08_06
(12) detail: EXPAND %t
(12) detail: --> Sun Aug 6 22:01:15 2017
(12) [detail] = ok
(12) redundant sql {
(12) sql1: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(12) sql1: --> type.stop.query
(12) sql1: Using query template 'query'
rlm_sql (sql1): Reserved connection (2)
(12) sql1: EXPAND %{User-Name}
(12) sql1: --> scilek
(12) sql1: SQL-User-Name set to 'scilek'
(12) sql1: EXPAND CALL accounting_stop ('%{Acct-Session-Id}','%{SQL-User-Name}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-Input-Octets}',
'%{Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}','%{Acct-Terminate-Cause}')
(12) sql1: --> CALL accounting_stop ('59873E49-0000001A','scilek','80-2A-A8-AD-1E-F9=3ASCILEK.NET','2C-F0-A2-87-C1-CA','10','19062','','17357','','User-Request')
(12) sql1: EXPAND /var/log/sqltrace.sql
(12) sql1: --> /var/log/sqltrace.sql
(12) sql1: Executing query: CALL accounting_stop ('59873E49-0000001A','scilek','80-2A-A8-AD-1E-F9=3ASCILEK.NET','2C-F0-A2-87-C1-CA','10','19062','','17357','','User-Request'
)
(12) sql1: SQL query returned: success
(12) sql1: 1 record(s) updated
rlm_sql (sql1): Released connection (2)
rlm_sql (sql1): Closing connection (3), from 16 unused connections
rlm_sql_mysql: Socket destructor called, closing socket
(12) [sql1] = ok
(12) } # redundant sql = ok
(12) [exec] = noop
(12) if (request:Acct-Status-Type == Interim-Update) {
(12) if (request:Acct-Status-Type == Interim-Update) -> FALSE
(12) } # accounting = ok
(12) Sent Accounting-Response Id 159 from 192.168.0.1:1813 to 192.168.0.4:44463 length 0
(12) Finished request
(12) Cleaning up request packet ID 159 with timestamp +32
Ready to process requests
(13) Received Access-Request Id 160 from 192.168.0.4:37009 to 192.168.0.1:1812 length 169
(13) User-Name = "anonymous"
(13) NAS-Identifier = "802aa8ac1ef9"
(13) NAS-Port = 0
(13) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(13) Calling-Station-Id = "00-22-FA-F5-B9-0A"
(13) Framed-MTU = 1400
(13) NAS-Port-Type = Wireless-802.11
(13) Connect-Info = "CONNECT 0Mbps 802.11b"
(13) EAP-Message = 0x0245000e01616e6f6e796d6f7573
(13) Message-Authenticator = 0x42438b836ce8307cd2ec1cf6757f171e
(13) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(13) authorize {
(13) [preprocess] = ok
(13) redundant sql {
(13) sql1: EXPAND %{User-Name}
(13) sql1: --> anonymous
(13) sql1: SQL-User-Name set to 'anonymous'
rlm_sql (sql1): Reserved connection (4)
(13) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(13) sql1: --> CALL authorize_check('anonymous')
(13) sql1: Executing select query: CALL authorize_check('anonymous')
(13) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(13) sql1: --> CALL group_membership('anonymous')
(13) sql1: Executing select query: CALL group_membership('anonymous')
(13) sql1: User not found in any groups
rlm_sql (sql1): Released connection (4)
Need 1 more connections to reach min connections (16)
rlm_sql (sql1): Opening additional connection (16), 1 of 1 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
(13) [sql1] = notfound
(13) } # redundant sql = notfound
(13) pap: WARNING: No "known good" password found for the user. Not setting Auth-Type
(13) pap: WARNING: Authentication will fail unless a "known good" password is available
(13) [pap] = noop
(13) eap: Peer sent EAP Response (code 2) ID 69 length 14
(13) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize
(13) [eap] = ok
(13) } # authorize = ok
(13) Found Auth-Type = eap
(13) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(13) authenticate {
(13) eap: Peer sent packet with method EAP Identity (1)
(13) eap: Calling submodule eap_ttls to process data
(13) eap_ttls: Initiating new EAP-TLS session
(13) eap_ttls: [eaptls start] = request
(13) eap: Sending EAP Request (code 1) ID 70 length 6
(13) eap: EAP session adding &reply:State = 0xdc673415dc2121b4
(13) [eap] = handled
(13) } # authenticate = handled
(13) Using Post-Auth-Type Challenge
(13) Post-Auth-Type sub-section not found. Ignoring.
(13) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(13) Sent Access-Challenge Id 160 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(13) EAP-Message = 0x014600061520
(13) Message-Authenticator = 0x00000000000000000000000000000000
(13) State = 0xdc673415dc2121b4141f6b25def0c2b8
(13) Finished request
Waking up in 4.9 seconds.
(14) Received Access-Request Id 161 from 192.168.0.4:37009 to 192.168.0.1:1812 length 282
(14) User-Name = "anonymous"
(14) NAS-Identifier = "802aa8ac1ef9"
(14) NAS-Port = 0
(14) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(14) Calling-Station-Id = "00-22-FA-F5-B9-0A"
(14) Framed-MTU = 1400
(14) NAS-Port-Type = Wireless-802.11
(14) Connect-Info = "CONNECT 0Mbps 802.11b"
(14) EAP-Message = 0x0246006d158000000063160301005e0100005a0301598767992897f75b0513f6af9eda58e324d0eb66100a43cbaefd1e29b80338c6000018002f00350005000ac013c014c009c00a003200
380013000401000019ff01000100000a0006000400170018000b0002010000230000
(14) State = 0xdc673415dc2121b4141f6b25def0c2b8
(14) Message-Authenticator = 0x45abb8d7b842bd7204baa251c0096dbb
(14) session-state: No cached attributes
(14) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(14) authorize {
(14) [preprocess] = ok
(14) redundant sql {
(14) sql1: EXPAND %{User-Name}
(14) sql1: --> anonymous
(14) sql1: SQL-User-Name set to 'anonymous'
rlm_sql (sql1): Reserved connection (5)
(14) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(14) sql1: --> CALL authorize_check('anonymous')
(14) sql1: Executing select query: CALL authorize_check('anonymous')
(14) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(14) sql1: --> CALL group_membership('anonymous')
(14) sql1: Executing select query: CALL group_membership('anonymous')
(14) sql1: User not found in any groups
rlm_sql (sql1): Released connection (5)
(14) [sql1] = notfound
(14) } # redundant sql = notfound
(14) pap: WARNING: No "known good" password found for the user. Not setting Auth-Type
(14) pap: WARNING: Authentication will fail unless a "known good" password is available
(14) [pap] = noop
(14) eap: Peer sent EAP Response (code 2) ID 70 length 109
(14) eap: Continuing tunnel setup
(14) [eap] = ok
(14) } # authorize = ok
(14) Found Auth-Type = eap
(14) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(14) authenticate {
(14) eap: Expiring EAP session with state 0xdc673415dc2121b4
(14) eap: Finished EAP session with state 0xdc673415dc2121b4
(14) eap: Previous EAP request found for state 0xdc673415dc2121b4, released from the list
(14) eap: Peer sent packet with method EAP TTLS (21)
(14) eap: Calling submodule eap_ttls to process data
(14) eap_ttls: Authenticate
(14) eap_ttls: Continuing EAP-TLS
(14) eap_ttls: Peer indicated complete TLS record size will be 99 bytes
(14) eap_ttls: Got complete TLS record (99 bytes)
(14) eap_ttls: [eaptls verify] = length included
(14) eap_ttls: (other): before/accept initialization
(14) eap_ttls: TLS_accept: before/accept initialization
(14) eap_ttls: <<< recv TLS 1.0 Handshake [length 005e], ClientHello
(14) eap_ttls: TLS_accept: SSLv3 read client hello A
(14) eap_ttls: >>> send TLS 1.0 Handshake [length 0031], ServerHello
(14) eap_ttls: TLS_accept: SSLv3 write server hello A
(14) eap_ttls: >>> send TLS 1.0 Handshake [length 09de], Certificate
(14) eap_ttls: TLS_accept: SSLv3 write certificate A
(14) eap_ttls: >>> send TLS 1.0 Handshake [length 0004], ServerHelloDone
(14) eap_ttls: TLS_accept: SSLv3 write server done A
(14) eap_ttls: TLS_accept: SSLv3 flush data
(14) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client certificate A
(14) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client certificate A
(14) eap_ttls: In SSL Handshake Phase
(14) eap_ttls: In SSL Accept mode
(14) eap_ttls: [eaptls process] = handled
(14) eap: Sending EAP Request (code 1) ID 71 length 1004
(14) eap: EAP session adding &reply:State = 0xdc673415dd2021b4
(14) [eap] = handled
(14) } # authenticate = handled
(14) Using Post-Auth-Type Challenge
(14) Post-Auth-Type sub-section not found. Ignoring.
(14) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(14) Sent Access-Challenge Id 161 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(14) EAP-Message = 0x014703ec15c000000a2216030100310200002d03011ae4c8a4a3884e49362c42edc1320f9e0b83ee4ad152061ddee7acc2d9e0438200002f000005ff0100010016030109de0b0009da0009
d70005333082052f30820417a003020102020103300d06092a864886f70d01010b050030818f310b30090603
(14) Message-Authenticator = 0x00000000000000000000000000000000
(14) State = 0xdc673415dd2021b4141f6b25def0c2b8
(14) Finished request
Waking up in 4.9 seconds.
(15) Received Access-Request Id 162 from 192.168.0.4:37009 to 192.168.0.1:1812 length 179
(15) User-Name = "anonymous"
(15) NAS-Identifier = "802aa8ac1ef9"
(15) NAS-Port = 0
(15) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(15) Calling-Station-Id = "00-22-FA-F5-B9-0A"
(15) Framed-MTU = 1400
(15) NAS-Port-Type = Wireless-802.11
(15) Connect-Info = "CONNECT 0Mbps 802.11b"
(15) EAP-Message = 0x024700061500
(15) State = 0xdc673415dd2021b4141f6b25def0c2b8
(15) Message-Authenticator = 0x6161f01c2d94dbc44b6786ff344d1311
(15) session-state: No cached attributes
(15) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(15) authorize {
(15) [preprocess] = ok
(15) redundant sql {
(15) sql1: EXPAND %{User-Name}
(15) sql1: --> anonymous
(15) sql1: SQL-User-Name set to 'anonymous'
rlm_sql (sql1): Reserved connection (6)
(15) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(15) sql1: --> CALL authorize_check('anonymous')
(15) sql1: Executing select query: CALL authorize_check('anonymous')
(15) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(15) sql1: --> CALL group_membership('anonymous')
(15) sql1: Executing select query: CALL group_membership('anonymous')
(15) sql1: User not found in any groups
rlm_sql (sql1): Released connection (6)
(15) [sql1] = notfound
(15) } # redundant sql = notfound
(15) pap: WARNING: No "known good" password found for the user. Not setting Auth-Type
(15) pap: WARNING: Authentication will fail unless a "known good" password is available
(15) [pap] = noop
(15) eap: Peer sent EAP Response (code 2) ID 71 length 6
(15) eap: Continuing tunnel setup
(15) [eap] = ok
(15) } # authorize = ok
(15) Found Auth-Type = eap
(15) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(15) authenticate {
(15) eap: Expiring EAP session with state 0xdc673415dd2021b4
(15) eap: Finished EAP session with state 0xdc673415dd2021b4
(15) eap: Previous EAP request found for state 0xdc673415dd2021b4, released from the list
(15) eap: Peer sent packet with method EAP TTLS (21)
(15) eap: Calling submodule eap_ttls to process data
(15) eap_ttls: Authenticate
(15) eap_ttls: Continuing EAP-TLS
(15) eap_ttls: Peer ACKed our handshake fragment
(15) eap_ttls: [eaptls verify] = request
(15) eap_ttls: [eaptls process] = handled
(15) eap: Sending EAP Request (code 1) ID 72 length 1004
(15) eap: EAP session adding &reply:State = 0xdc673415de2f21b4
(15) [eap] = handled
(15) } # authenticate = handled
(15) Using Post-Auth-Type Challenge
(15) Post-Auth-Type sub-section not found. Ignoring.
(15) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(15) Sent Access-Challenge Id 162 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(15) EAP-Message = 0x014803ec15c000000a22161c73656c6168617474696e5f63696c656b40686f746d61696c2e636f6d3111300f0603550403130864616d6c612d6361820100301d0603551d25041630140608
2b0601050507030106082b06010505080202300b0603551d0f0404030205a030200603551d11041930178215
(15) Message-Authenticator = 0x00000000000000000000000000000000
(15) State = 0xdc673415de2f21b4141f6b25def0c2b8
(15) Finished request
Waking up in 4.9 seconds.
(16) Received Access-Request Id 163 from 192.168.0.4:37009 to 192.168.0.1:1812 length 179
(16) User-Name = "anonymous"
(16) NAS-Identifier = "802aa8ac1ef9"
(16) NAS-Port = 0
(16) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(16) Calling-Station-Id = "00-22-FA-F5-B9-0A"
(16) Framed-MTU = 1400
(16) NAS-Port-Type = Wireless-802.11
(16) Connect-Info = "CONNECT 0Mbps 802.11b"
(16) EAP-Message = 0x024800061500
(16) State = 0xdc673415de2f21b4141f6b25def0c2b8
(16) Message-Authenticator = 0x8fea16e427c8b3137cf55f16827cd2fa
(16) session-state: No cached attributes
(16) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(16) authorize {
(16) [preprocess] = ok
(16) redundant sql {
(16) sql1: EXPAND %{User-Name}
(16) sql1: --> anonymous
(16) sql1: SQL-User-Name set to 'anonymous'
rlm_sql (sql1): Reserved connection (7)
(16) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(16) sql1: --> CALL authorize_check('anonymous')
(16) sql1: Executing select query: CALL authorize_check('anonymous')
(16) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(16) sql1: --> CALL group_membership('anonymous')
(16) sql1: Executing select query: CALL group_membership('anonymous')
(16) sql1: User not found in any groups
rlm_sql (sql1): Released connection (7)
(16) [sql1] = notfound
(16) } # redundant sql = notfound
(16) pap: WARNING: No "known good" password found for the user. Not setting Auth-Type
(16) pap: WARNING: Authentication will fail unless a "known good" password is available
(16) [pap] = noop
(16) eap: Peer sent EAP Response (code 2) ID 72 length 6
(16) eap: Continuing tunnel setup
(16) [eap] = ok
(16) } # authorize = ok
(16) Found Auth-Type = eap
(16) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(16) authenticate {
(16) eap: Expiring EAP session with state 0xdc673415de2f21b4
(16) eap: Finished EAP session with state 0xdc673415de2f21b4
(16) eap: Previous EAP request found for state 0xdc673415de2f21b4, released from the list
(16) eap: Peer sent packet with method EAP TTLS (21)
(16) eap: Calling submodule eap_ttls to process data
(16) eap_ttls: Authenticate
(16) eap_ttls: Continuing EAP-TLS
(16) eap_ttls: Peer ACKed our handshake fragment
(16) eap_ttls: [eaptls verify] = request
(16) eap_ttls: [eaptls process] = handled
(16) eap: Sending EAP Request (code 1) ID 73 length 616
(16) eap: EAP session adding &reply:State = 0xdc673415df2e21b4
(16) [eap] = handled
(16) } # authenticate = handled
(16) Using Post-Auth-Type Challenge
(16) Post-Auth-Type sub-section not found. Ignoring.
(16) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(16) Sent Access-Challenge Id 163 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(16) EAP-Message = 0x01490268158000000a22363eead91eb754997cc9e358432fc92ea951cc3bf0ca257b331a7cb6a269a2a68568a263e95de9f53ec3793bc049b13f139ae3b681106134abf5b4d08b02030100
01a381fc3081f9301d0603551d0e04160414af297b64d5335e54578a00c1231a91e0b971ea743081bc060355
(16) Message-Authenticator = 0x00000000000000000000000000000000
(16) State = 0xdc673415df2e21b4141f6b25def0c2b8
(16) Finished request
Waking up in 4.9 seconds.
(17) Received Access-Request Id 164 from 192.168.0.4:37009 to 192.168.0.1:1812 length 511
(17) User-Name = "anonymous"
(17) NAS-Identifier = "802aa8ac1ef9"
(17) NAS-Port = 0
(17) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(17) Calling-Station-Id = "00-22-FA-F5-B9-0A"
(17) Framed-MTU = 1400
(17) NAS-Port-Type = Wireless-802.11
(17) Connect-Info = "CONNECT 0Mbps 802.11b"
(17) EAP-Message = 0x024901501580000001461603010106100001020100a65b4d5c49a2215bba9dc64326661261903eac3adc93ec20ced1a1ef5626ef2c91c948960f7bfb8a82b9c8fe5d831666781bbd3dd80c
98153e7603b42851ab94ac188fd6df6c7b7f79f5678662403e7126fa270fb5c5420fde081949376a29f7f629
(17) State = 0xdc673415df2e21b4141f6b25def0c2b8
(17) Message-Authenticator = 0x0912742ea0e17ef435aefa6a2b785ba8
(17) session-state: No cached attributes
(17) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(17) authorize {
(17) [preprocess] = ok
(17) redundant sql {
(17) sql1: EXPAND %{User-Name}
(17) sql1: --> anonymous
(17) sql1: SQL-User-Name set to 'anonymous'
rlm_sql (sql1): Reserved connection (8)
(17) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(17) sql1: --> CALL authorize_check('anonymous')
(17) sql1: Executing select query: CALL authorize_check('anonymous')
(17) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(17) sql1: --> CALL group_membership('anonymous')
(17) sql1: Executing select query: CALL group_membership('anonymous')
(17) sql1: User not found in any groups
rlm_sql (sql1): Released connection (8)
(17) [sql1] = notfound
(17) } # redundant sql = notfound
(17) pap: WARNING: No "known good" password found for the user. Not setting Auth-Type
(17) pap: WARNING: Authentication will fail unless a "known good" password is available
(17) [pap] = noop
(17) eap: Peer sent EAP Response (code 2) ID 73 length 336
(17) eap: Continuing tunnel setup
(17) [eap] = ok
(17) } # authorize = ok
(17) Found Auth-Type = eap
(17) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(17) authenticate {
(17) eap: Expiring EAP session with state 0xdc673415df2e21b4
(17) eap: Finished EAP session with state 0xdc673415df2e21b4
(17) eap: Previous EAP request found for state 0xdc673415df2e21b4, released from the list
(17) eap: Peer sent packet with method EAP TTLS (21)
(17) eap: Calling submodule eap_ttls to process data
(17) eap_ttls: Authenticate
(17) eap_ttls: Continuing EAP-TLS
(17) eap_ttls: Peer indicated complete TLS record size will be 326 bytes
(17) eap_ttls: Got complete TLS record (326 bytes)
(17) eap_ttls: [eaptls verify] = length included
(17) eap_ttls: <<< recv TLS 1.0 Handshake [length 0106], ClientKeyExchange
(17) eap_ttls: TLS_accept: SSLv3 read client key exchange A
(17) eap_ttls: TLS_accept: SSLv3 read certificate verify A
(17) eap_ttls: <<< recv TLS 1.0 ChangeCipherSpec [length 0001]
(17) eap_ttls: <<< recv TLS 1.0 Handshake [length 0010], Finished
(17) eap_ttls: TLS_accept: SSLv3 read finished A
(17) eap_ttls: >>> send TLS 1.0 ChangeCipherSpec [length 0001]
(17) eap_ttls: TLS_accept: SSLv3 write change cipher spec A
(17) eap_ttls: >>> send TLS 1.0 Handshake [length 0010], Finished
(17) eap_ttls: TLS_accept: SSLv3 write finished A
(17) eap_ttls: TLS_accept: SSLv3 flush data
(17) eap_ttls: (other): SSL negotiation finished successfully
(17) eap_ttls: SSL Connection Established
(17) eap_ttls: [eaptls process] = handled
(17) eap: Sending EAP Request (code 1) ID 74 length 69
(17) eap: EAP session adding &reply:State = 0xdc673415d82d21b4
(17) [eap] = handled
(17) } # authenticate = handled
(17) Using Post-Auth-Type Challenge
(17) Post-Auth-Type sub-section not found. Ignoring.
(17) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(17) Sent Access-Challenge Id 164 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(17) EAP-Message = 0x014a004515800000003b1403010001011603010030b38544bf21cba71d1f37439457db5c83cb9eb80c6d852f51007a0f9fffd3c9b451989f1149d8105e84c05d7a678c7580
(17) Message-Authenticator = 0x00000000000000000000000000000000
(17) State = 0xdc673415d82d21b4141f6b25def0c2b8
(17) Finished request
Waking up in 4.9 seconds.
(18) Received Access-Request Id 165 from 192.168.0.4:37009 to 192.168.0.1:1812 length 252
(18) User-Name = "anonymous"
(18) NAS-Identifier = "802aa8ac1ef9"
(18) NAS-Port = 0
(18) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(18) Calling-Station-Id = "00-22-FA-F5-B9-0A"
(18) Framed-MTU = 1400
(18) NAS-Port-Type = Wireless-802.11
(18) Connect-Info = "CONNECT 0Mbps 802.11b"
(18) EAP-Message = 0x024a004f15800000004517030100401161d9d8f7802510cd5a830be41e537f91f95b6714a56475f21167d83f0dfd2451fa2b34f871f434bffda2190257c023fad8bbf0f673ef9690611a25
a4072032
(18) State = 0xdc673415d82d21b4141f6b25def0c2b8
(18) Message-Authenticator = 0xfb5c045dc54c3a1c5a23567d87d0ae99
(18) session-state: No cached attributes
(18) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(18) authorize {
(18) [preprocess] = ok
(18) redundant sql {
(18) sql1: EXPAND %{User-Name}
(18) sql1: --> anonymous
(18) sql1: SQL-User-Name set to 'anonymous'
rlm_sql (sql1): Reserved connection (9)
(18) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(18) sql1: --> CALL authorize_check('anonymous')
(18) sql1: Executing select query: CALL authorize_check('anonymous')
(18) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(18) sql1: --> CALL group_membership('anonymous')
(18) sql1: Executing select query: CALL group_membership('anonymous')
(18) sql1: User not found in any groups
rlm_sql (sql1): Released connection (9)
(18) [sql1] = notfound
(18) } # redundant sql = notfound
(18) pap: WARNING: No "known good" password found for the user. Not setting Auth-Type
(18) pap: WARNING: Authentication will fail unless a "known good" password is available
(18) [pap] = noop
(18) eap: Peer sent EAP Response (code 2) ID 74 length 79
(18) eap: Continuing tunnel setup
(18) [eap] = ok
(18) } # authorize = ok
(18) Found Auth-Type = eap
(18) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(18) authenticate {
(18) eap: Expiring EAP session with state 0xdc673415d82d21b4
(18) eap: Finished EAP session with state 0xdc673415d82d21b4
(18) eap: Previous EAP request found for state 0xdc673415d82d21b4, released from the list
(18) eap: Peer sent packet with method EAP TTLS (21)
(18) eap: Calling submodule eap_ttls to process data
(18) eap_ttls: Authenticate
(18) eap_ttls: Continuing EAP-TLS
(18) eap_ttls: Peer indicated complete TLS record size will be 69 bytes
(18) eap_ttls: Got complete TLS record (69 bytes)
(18) eap_ttls: [eaptls verify] = length included
(18) eap_ttls: [eaptls process] = ok
(18) eap_ttls: Session established. Proceeding to decode tunneled attributes
(18) eap_ttls: Got tunneled request
(18) eap_ttls: User-Name = "scilek"
(18) eap_ttls: User-Password = "0000"
(18) eap_ttls: FreeRADIUS-Proxied-To = 127.0.0.1
(18) eap_ttls: Sending tunneled request
(18) Virtual server inner-tunnel-ttls received request
(18) User-Name = "scilek"
(18) User-Password = "0000"
(18) FreeRADIUS-Proxied-To = 127.0.0.1
(18) NAS-Identifier = "802aa8ac1ef9"
(18) NAS-Port = 0
(18) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(18) Calling-Station-Id = "00-22-FA-F5-B9-0A"
(18) Framed-MTU = 1400
(18) NAS-Port-Type = Wireless-802.11
(18) Connect-Info = "CONNECT 0Mbps 802.11b"
(18) Event-Timestamp = "Aug 6 2017 22:01:45 +03"
(18) NAS-IP-Address = 192.168.0.4
(18) server inner-tunnel-ttls {
(18) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(18) authorize {
(18) update control {
(18) &Proxy-To-Realm := LOCAL
(18) } # update control = noop
(18) eap: No EAP-Message, not doing EAP
(18) [eap] = noop
(18) redundant sql {
(18) sql1: EXPAND %{User-Name}
(18) sql1: --> scilek
(18) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (10)
(18) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(18) sql1: --> CALL authorize_check('scilek')
(18) sql1: Executing select query: CALL authorize_check('scilek')
(18) sql1: User found in radcheck table
(18) sql1: Conditional check items matched, merging assignment check items
(18) sql1: Cleartext-Password := "0000"
(18) sql1: Simultaneous-Use := 1
(18) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(18) sql1: --> CALL authorize_reply('scilek')
(18) sql1: Executing select query: CALL authorize_reply('scilek')
(18) sql1: User found in radreply table, merging reply items
(18) sql1: Class := 0x7363696c656b
(18) sql1: Idle-Timeout := 120
(18) sql1: Acct-Interim-Interval := 600
(18) sql1: Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(18) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(18) sql1: --> CALL group_membership('scilek')
(18) sql1: Executing select query: CALL group_membership('scilek')
(18) sql1: User not found in any groups
rlm_sql (sql1): Released connection (10)
(18) [sql1] = ok
(18) } # redundant sql = ok
(18) [expiration] = noop
(18) [logintime] = noop
(18) [pap] = updated
(18) } # authorize = updated
(18) WARNING: You set Proxy-To-Realm = LOCAL, but the realm does not exist! Cancelling invalid proxy request.
(18) Found Auth-Type = pap
(18) # Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(18) Auth-Type PAP {
(18) pap: Login attempt with password
(18) pap: Comparing with "known good" Cleartext-Password
(18) pap: User authenticated successfully
(18) [pap] = ok
(18) } # Auth-Type PAP = ok
(18) # Executing section session from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(18) session {
(18) redundant sql {
(18) sql1: EXPAND %{User-Name}
(18) sql1: --> scilek
(18) sql1: SQL-User-Name set to 'scilek'
(18) sql1: EXPAND CALL simul_count('%{SQL-User-Name}')
(18) sql1: --> CALL simul_count('scilek')
rlm_sql (sql1): Reserved connection (11)
(18) sql1: Executing select query: CALL simul_count('scilek')
rlm_sql (sql1): Released connection (11)
(18) [sql1] = ok
(18) } # redundant sql = ok
(18) } # session = ok
(18) # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(18) post-auth {
(18) if (1) {
(18) if (1) -> TRUE
(18) if (1) {
(18) update reply {
(18) User-Name !* ANY
(18) Message-Authenticator !* ANY
(18) EAP-Message !* ANY
(18) Proxy-State !* ANY
(18) MS-MPPE-Encryption-Types !* ANY
(18) MS-MPPE-Encryption-Policy !* ANY
(18) MS-MPPE-Send-Key !* ANY
(18) MS-MPPE-Recv-Key !* ANY
(18) } # update reply = noop
(18) update {
(18) &outer.session-state::Class += &reply:Class[*] -> 0x7363696c656b
(18) &outer.session-state::Idle-Timeout += &reply:Idle-Timeout[*] -> 120
(18) &outer.session-state::Acct-Interim-Interval += &reply:Acct-Interim-Interval[*] -> 600
(18) &outer.session-state::Exec-Program-Wait += &reply:Exec-Program-Wait[*] -> '/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek'
(18) } # update = noop
(18) } # if (1) = noop
(18) } # post-auth = noop
(18) Login OK: [scilek] (from client HOME_AP port 0 cli 00-22-FA-F5-B9-0A via TLS tunnel)
(18) } # server inner-tunnel-ttls
(18) Virtual server sending reply
(18) Class = 0x7363696c656b
(18) Idle-Timeout = 120
(18) Acct-Interim-Interval = 600
(18) Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(18) eap_ttls: Got tunneled Access-Accept
(18) eap: Sending EAP Success (code 3) ID 74 length 4
(18) eap: Freeing handler
(18) [eap] = ok
(18) } # authenticate = ok
(18) # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default
(18) post-auth {
(18) [exec] = noop
(18) policy remove_reply_message_if_eap {
(18) if (&reply:EAP-Message && &reply:Reply-Message) {
(18) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
(18) else {
(18) [noop] = noop
(18) } # else = noop
(18) } # policy remove_reply_message_if_eap = noop
(18) } # post-auth = noop
(18) Login OK: [anonymous] (from client HOME_AP port 0 cli 00-22-FA-F5-B9-0A)
(18) Sent Access-Accept Id 165 from 192.168.0.1:1812 to 192.168.0.4:37009 length 0
(18) MS-MPPE-Recv-Key = 0x151579da0bae738f62b1b12c1150cc56bfa288ec7e69fb8401407407e1756b60
(18) MS-MPPE-Send-Key = 0x67877d1a658cf4f19874c1fe8d9cfa05d7bc7ceb33d6e8d25af8cf5befac456f
(18) EAP-Message = 0x034a0004
(18) Message-Authenticator = 0x00000000000000000000000000000000
(18) User-Name = "anonymous"
(18) Finished request
Waking up in 4.9 seconds.
(19) Received Accounting-Request Id 166 from 192.168.0.4:44463 to 192.168.0.1:1813 length 166
(19) Acct-Session-Id = "59873E49-0000001B"
(19) Acct-Status-Type = Start
(19) Acct-Authentic = RADIUS
(19) User-Name = "anonymous"
(19) Framed-IP-Address = 0.0.0.0
(19) NAS-Identifier = "802aa8ac1ef9"
(19) NAS-Port = 0
(19) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(19) Calling-Station-Id = "00-22-FA-F5-B9-0A"
(19) NAS-Port-Type = Wireless-802.11
(19) Connect-Info = "CONNECT 0Mbps 802.11b"
(19) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
(19) preacct {
(19) [preprocess] = ok
(19) } # preacct = ok
(19) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
(19) accounting {
(19) detail: EXPAND /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
(19) detail: --> /var/log/radacct/192.168.0.4/detail_2017_08_06
(19) detail: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d expands to /var/log/radacct/192.168.0.4/detail_2017_08_06
(19) detail: EXPAND %t
(19) detail: --> Sun Aug 6 22:01:45 2017
(19) [detail] = ok
(19) redundant sql {
(19) sql1: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(19) sql1: --> type.start.query
(19) sql1: Using query template 'query'
rlm_sql (sql1): Reserved connection (12)
(19) sql1: EXPAND %{User-Name}
(19) sql1: --> anonymous
(19) sql1: SQL-User-Name set to 'anonymous'
(19) sql1: EXPAND CALL accounting_start('%{Acct-Session-Id}','%{SQL-User-Name}','%{Class}','%{NAS-IP-Address}','%{Called-Station-Id}','%{Calling-Station-Id}')
(19) sql1: --> CALL accounting_start('59873E49-0000001B','anonymous','','192.168.0.4','80-2A-A8-AD-1E-F9=3ASCILEK.NET','00-22-FA-F5-B9-0A')
(19) sql1: EXPAND /var/log/sqltrace.sql
(19) sql1: --> /var/log/sqltrace.sql
(19) sql1: Executing query: CALL accounting_start('59873E49-0000001B','anonymous','','192.168.0.4','80-2A-A8-AD-1E-F9=3ASCILEK.NET','00-22-FA-F5-B9-0A')
(19) sql1: SQL query returned: success
(19) sql1: 1 record(s) updated
rlm_sql (sql1): Released connection (12)
(19) [sql1] = ok
(19) } # redundant sql = ok
(19) [exec] = noop
(19) if (request:Acct-Status-Type == Interim-Update) {
(19) if (request:Acct-Status-Type == Interim-Update) -> FALSE
(19) } # accounting = ok
(19) Sent Accounting-Response Id 166 from 192.168.0.1:1813 to 192.168.0.4:44463 length 0
(19) Finished request
(19) Cleaning up request packet ID 166 with timestamp +62
Waking up in 4.9 seconds.
(20) Received Accounting-Request Id 167 from 192.168.0.4:44463 to 192.168.0.1:1813 length 202
(20) Acct-Session-Id = "59873E49-0000001B"
(20) Acct-Status-Type = Interim-Update
(20) Acct-Authentic = RADIUS
(20) User-Name = "anonymous"
(20) Framed-IP-Address = 192.168.0.104
(20) NAS-Identifier = "802aa8ac1ef9"
(20) NAS-Port = 0
(20) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(20) Calling-Station-Id = "00-22-FA-F5-B9-0A"
(20) NAS-Port-Type = Wireless-802.11
(20) Connect-Info = "CONNECT 0Mbps 802.11b"
(20) Acct-Session-Time = 0
(20) Acct-Input-Packets = 11
(20) Acct-Output-Packets = 11
(20) Acct-Input-Octets = 1586
(20) Acct-Output-Octets = 3417
(20) Event-Timestamp = "Aug 6 2017 22:01:39 +03"
(20) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
(20) preacct {
(20) [preprocess] = ok
(20) } # preacct = ok
(20) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
(20) accounting {
(20) detail: EXPAND /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
(20) detail: --> /var/log/radacct/192.168.0.4/detail_2017_08_06
(20) detail: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d expands to /var/log/radacct/192.168.0.4/detail_2017_08_06
(20) detail: EXPAND %t
(20) detail: --> Sun Aug 6 22:01:45 2017
(20) [detail] = ok
(20) redundant sql {
(20) sql1: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(20) sql1: --> type.interim-update.query
(20) sql1: Using query template 'query'
rlm_sql (sql1): Reserved connection (13)
(20) sql1: EXPAND %{User-Name}
(20) sql1: --> anonymous
(20) sql1: SQL-User-Name set to 'anonymous'
(20) sql1: EXPAND CALL accounting_update ('%{Acct-Session-Id}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-Input-Octets}','%{Acct-Input-Gig
awords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}')
(20) sql1: --> CALL accounting_update ('59873E49-0000001B','80-2A-A8-AD-1E-F9=3ASCILEK.NET','00-22-FA-F5-B9-0A','0','1586','','3417','')
(20) sql1: EXPAND /var/log/sqltrace.sql
(20) sql1: --> /var/log/sqltrace.sql
(20) sql1: Executing query: CALL accounting_update ('59873E49-0000001B','80-2A-A8-AD-1E-F9=3ASCILEK.NET','00-22-FA-F5-B9-0A','0','1586','','3417','')
(20) sql1: SQL query returned: success
(20) sql1: 1 record(s) updated
rlm_sql (sql1): Released connection (13)
(20) [sql1] = ok
(20) } # redundant sql = ok
(20) [exec] = noop
(20) if (request:Acct-Status-Type == Interim-Update) {
(20) if (request:Acct-Status-Type == Interim-Update) -> TRUE
(20) if (request:Acct-Status-Type == Interim-Update) {
(20) check_quota: Executing: /usr/local/bin/bash /usr/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} %{request:Calling-Station-Id} %{request:NAS-IP-Address
} %{request:Class} %{request:Acct-Status-Type}:
(20) check_quota: EXPAND %{request:User-Name}
(20) check_quota: --> anonymous
(20) check_quota: EXPAND %{request:Calling-Station-Id}
(20) check_quota: --> 00-22-FA-F5-B9-0A
(20) check_quota: EXPAND %{request:NAS-IP-Address}
(20) check_quota: --> 192.168.0.4
(20) check_quota: EXPAND %{request:Class}
(20) check_quota: -->
(20) check_quota: EXPAND %{request:Acct-Status-Type}
(20) check_quota: --> Interim-Update
(20) check_quota: Program executed successfully
(20) [check_quota] = ok
(20) } # if (request:Acct-Status-Type == Interim-Update) = ok
(20) } # accounting = ok
(20) Sent Accounting-Response Id 167 from 192.168.0.1:1813 to 192.168.0.4:44463 length 0
(20) Finished request
(20) Cleaning up request packet ID 167 with timestamp +62
Waking up in 4.9 seconds.
Warning: Using a password on the command line interface can be insecure.
Warning: Using a password on the command line interface can be insecure.
/usr/local/etc/raddb/scripts/datacounter_acct.sh: line 58: ((: < : syntax error: operand expected (error token is "< ")
scilek at 192.168.0.4<mailto:scilek at 192.168.0.4>'s password: (13) Cleaning up request packet ID 160 with timestamp +62
(14) Cleaning up request packet ID 161 with timestamp +62
(15) Cleaning up request packet ID 162 with timestamp +62
(16) Cleaning up request packet ID 163 with timestamp +62
(17) Cleaning up request packet ID 164 with timestamp +62
(18) Cleaning up request packet ID 165 with timestamp +62
Ready to process requests
(21) Received Accounting-Request Id 168 from 192.168.0.4:44463 to 192.168.0.1:1813 length 208
(21) Acct-Session-Id = "59873E49-0000001B"
(21) Acct-Status-Type = Stop
(21) Acct-Authentic = RADIUS
(21) User-Name = "anonymous"
(21) Framed-IP-Address = 192.168.0.104
(21) NAS-Identifier = "802aa8ac1ef9"
(21) NAS-Port = 0
(21) Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
(21) Calling-Station-Id = "00-22-FA-F5-B9-0A"
(21) NAS-Port-Type = Wireless-802.11
(21) Connect-Info = "CONNECT 0Mbps 802.11b"
(21) Acct-Session-Time = 25
(21) Acct-Input-Packets = 156
(21) Acct-Output-Packets = 17
(21) Acct-Input-Octets = 13971
(21) Acct-Output-Octets = 4095
(21) Event-Timestamp = "Aug 6 2017 22:02:04 +03"
(21) Acct-Terminate-Cause = User-Request
(21) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
(21) preacct {
(21) [preprocess] = ok
(21) } # preacct = ok
(21) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
(21) accounting {
(21) detail: EXPAND /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
(21) detail: --> /var/log/radacct/192.168.0.4/detail_2017_08_06
(21) detail: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d expands to /var/log/radacct/192.168.0.4/detail_2017_08_06
(21) detail: EXPAND %t
(21) detail: --> Sun Aug 6 22:02:10 2017
(21) [detail] = ok
(21) redundant sql {
(21) sql1: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(21) sql1: --> type.stop.query
(21) sql1: Using query template 'query'
rlm_sql (sql1): Closing connection (14): Hit idle_timeout, was idle for 65 seconds
rlm_sql (sql1): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql1): Closing connection (15): Hit idle_timeout, was idle for 65 seconds
rlm_sql (sql1): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql1): Closing connection (0): Hit idle_timeout, was idle for 65 seconds
rlm_sql (sql1): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql1): Closing connection (1): Hit idle_timeout, was idle for 65 seconds
rlm_sql (sql1): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql1): Reserved connection (2)
(21) sql1: EXPAND %{User-Name}
(21) sql1: --> anonymous
(21) sql1: SQL-User-Name set to 'anonymous'
(21) sql1: EXPAND CALL accounting_stop ('%{Acct-Session-Id}','%{SQL-User-Name}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-Input-Octets}',
'%{Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}','%{Acct-Terminate-Cause}')
(21) sql1: --> CALL accounting_stop ('59873E49-0000001B','anonymous','80-2A-A8-AD-1E-F9=3ASCILEK.NET','00-22-FA-F5-B9-0A','25','13971','','4095','','User-Request')
(21) sql1: EXPAND /var/log/sqltrace.sql
(21) sql1: --> /var/log/sqltrace.sql
(21) sql1: Executing query: CALL accounting_stop ('59873E49-0000001B','anonymous','80-2A-A8-AD-1E-F9=3ASCILEK.NET','00-22-FA-F5-B9-0A','25','13971','','4095','','User-Reques
t')
(21) sql1: SQL query returned: success
(21) sql1: 1 record(s) updated
rlm_sql (sql1): Released connection (2)
Need 4 more connections to reach min connections (16)
rlm_sql (sql1): Opening additional connection (17), 1 of 4 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb3' on Localhost via UNIX socket, server version 5.6.34, protocol version 10
(21) [sql1] = ok
(21) } # redundant sql = ok
(21) [exec] = noop
(21) if (request:Acct-Status-Type == Interim-Update) {
(21) if (request:Acct-Status-Type == Interim-Update) -> FALSE
(21) } # accounting = ok
(21) Sent Accounting-Response Id 168 from 192.168.0.1:1813 to 192.168.0.4:44463 length 0
(21) Finished request
(21) Cleaning up request packet ID 168 with timestamp +87
Ready to process requests
[https://ipmcdn.avast.com/images/icons/icon-envelope-tick-round-orange-animated-no-repeat-v1.gif]<https://www.avast.com/sig-email?utm_medium=email&utm_source=link&utm_campaign=sig-email&utm_content=emailclient> Virus-free. www.avast.com<https://www.avast.com/sig-email?utm_medium=email&utm_source=link&utm_campaign=sig-email&utm_content=emailclient>
More information about the Freeradius-Users
mailing list