Freeradius Proxy
Fernando Pizarro
feanpg at gmail.com
Fri Nov 22 13:22:03 CET 2013
Hi all!
I'm trying to configure radius proxy for EAP authentication but I don't
know what is wrong in my config. I have a Radius server on a Ubuntu
server with version 2.1.10 and my Radius proxy is a Pfsense with version
2.2.0.
Authentication works fine on both servers but Pfsense doesn't proxied
anything packet to the server. There is debug output of Pfsense.
FreeRADIUS Version 2.2.0, for host i386-portbld-freebsd8.3, built on Dec
20 2012 at 23:43:04
Copyright (C) 1999-2012 The FreeRADIUS server project and contributors.
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE.
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License v2.
Starting - reading configuration files ...
including configuration file /usr/pbi/freeradius-i386/etc/raddb/radiusd.conf
including configuration file /usr/pbi/freeradius-i386/etc/raddb/proxy.conf
including configuration file /usr/pbi/freeradius-i386/etc/raddb/clients.conf
including files in directory /usr/pbi/freeradius-i386/etc/raddb/modules/
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/wimax
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/always
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/attr_filter
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/attr_rewrite
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/cache
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/chap
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/checkval
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/counter
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/cui
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/detail
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/detail.example.com
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/detail.log
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/dhcp_sqlippool
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/sql/mysql/ippool-dhcp.conf
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/digest
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/dynamic_clients
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/echo
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/etc_group
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/exec
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/expiration
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/expr
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/files
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/inner-eap
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/ippool
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/krb5
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/ldap
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/linelog
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/otp
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/logintime
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/mac2ip
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/mac2vlan
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/mschap
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/ntlm_auth
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/opendirectory
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/pam
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/pap
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/passwd
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/perl
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/policy
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/preprocess
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/radrelay
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/radutmp
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/realm
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/redis
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/rediswho
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/replicate
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/smbpasswd
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/smsotp
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/soh
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/sql_log
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/sqlcounter_expire_on_login
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/sradutmp
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/unix
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/acct_unique
including configuration file /usr/pbi/freeradius-i386/etc/raddb/modules/motp
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/modules/datacounter_acct
including configuration file /usr/pbi/freeradius-i386/etc/raddb/eap.conf
including configuration file /usr/pbi/freeradius-i386/etc/raddb/sql.conf
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/sql/mysql/dialup.conf
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/sql/mysql/dialup.conf
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/sql/mysql/counter.conf
including configuration file /usr/pbi/freeradius-i386/etc/raddb/policy.conf
including files in directory
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/
including configuration file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
main {
allow_core_dumps = no
}
including dictionary file /usr/pbi/freeradius-i386/etc/raddb/dictionary
main {
name = "radiusd"
prefix = "/usr/pbi/freeradius-i386"
localstatedir = "/var"
sbindir = "/usr/pbi/freeradius-i386/sbin"
logdir = "/var/log"
run_dir = "/var/run"
radacctdir = "/var/log/radacct"
hostname_lookups = no
max_request_time = 30
cleanup_delay = 5
max_requests = 1024
pidfile = "/var/run/radiusd.pid"
checkrad = "/usr/pbi/freeradius-i386/sbin/checkrad"
debug_level = 0
proxy_requests = yes
log {
stripped_names = no
auth = yes
auth_badpass = no
auth_goodpass = no
msg_badpass = ""
msg_goodpass = ""
}
security {
max_attributes = 200
reject_delay = 1
status_server = no
}
}
radiusd: #### Loading Realms and Home Servers ####
proxy server {
retry_delay = 5
retry_count = 3
default_fallback = no
dead_time = 120
wake_all_if_all_dead = no
}
realm NULL {
authhost = 192.168.1.223:1812
accthost = 192.168.1.223:1813
secret = testing123
}
realm DEFAULT {
authhost = 192.168.1.223:1812
accthost = 192.168.1.223:1813
secret = testing123
}
radiusd: #### Loading Clients ####
client hostapd {
ipaddr = 172.16.0.2
require_message_authenticator = no
secret = "testing123"
shortname = "hostapd"
nastype = "other"
}
radiusd: #### Instantiating modules ####
instantiate {
Module: Linked to module rlm_exec
Module: Instantiating module "exec" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/exec
exec {
wait = no
input_pairs = "request"
shell_escape = yes
}
Module: Linked to module rlm_expr
Module: Instantiating module "expr" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/expr
Module: Linked to module rlm_counter
Module: Instantiating module "daily" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/counter
counter daily {
filename = "/var/log/radacct/timecounter/db.daily"
key = "User-Name"
reset = "daily"
count-attribute = "Acct-Session-Time"
counter-name = "Daily-Session-Time"
check-name = "Max-Daily-Session"
reply-name = "Session-Timeout"
cache-size = 5000
}
rlm_counter: Counter attribute Daily-Session-Time is number 11273
rlm_counter: Current Time: 1385116609 [2013-11-22 11:36:49], Next reset
1385161200 [2013-11-23 00:00:00]
Module: Instantiating module "weekly" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/counter
counter weekly {
filename = "/var/log/radacct/timecounter/db.weekly"
key = "User-Name"
reset = "weekly"
count-attribute = "Acct-Session-Time"
counter-name = "Weekly-Session-Time"
check-name = "Max-Weekly-Session"
reply-name = "Session-Timeout"
cache-size = 5000
}
rlm_counter: Counter attribute Weekly-Session-Time is number 11275
rlm_counter: Current Time: 1385116609 [2013-11-22 11:36:49], Next reset
1385247600 [2013-11-24 00:00:00]
Module: Instantiating module "monthly" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/counter
counter monthly {
filename = "/var/log/radacct/timecounter/db.monthly"
key = "User-Name"
reset = "monthly"
count-attribute = "Acct-Session-Time"
counter-name = "Monthly-Session-Time"
check-name = "Max-Monthly-Session"
reply-name = "Session-Timeout"
cache-size = 5000
}
rlm_counter: Counter attribute Monthly-Session-Time is number 11277
rlm_counter: Current Time: 1385116609 [2013-11-22 11:36:49], Next reset
1385852400 [2013-12-01 00:00:00]
Module: Instantiating module "forever" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/counter
counter forever {
filename = "/var/log/radacct/timecounter/db.forever"
key = "User-Name"
reset = "never"
count-attribute = "Acct-Session-Time"
counter-name = "Forever-Session-Time"
check-name = "Max-Forever-Session"
reply-name = "Session-Timeout"
cache-size = 5000
}
rlm_counter: Counter attribute Forever-Session-Time is number 11279
rlm_counter: Current Time: 1385116609 [2013-11-22 11:36:49], Next reset
0 [2013-11-22 11:00:00]
Module: Linked to module rlm_expiration
Module: Instantiating module "expiration" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/expiration
expiration {
reply-message = "Password Has Expired "
}
Module: Linked to module rlm_logintime
Module: Instantiating module "logintime" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/logintime
logintime {
reply-message = "You are calling outside your allowed timespan "
minimum-timeout = 60
}
}
radiusd: #### Loading Virtual Servers ####
server { # from file /usr/pbi/freeradius-i386/etc/raddb/radiusd.conf
modules {
Module: Creating Auth-Type = MOTP
Module: Creating Auth-Type = digest
Module: Creating Autz-Type = Status-Server
Module: Creating Acct-Type = Status-Server
Module: Creating Post-Auth-Type = REJECT
Module: Checking authenticate {...} for more modules to load
Module: Linked to module rlm_pap
Module: Instantiating module "pap" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/pap
pap {
encryption_scheme = "auto"
auto_header = no
}
Module: Linked to module rlm_chap
Module: Instantiating module "chap" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/chap
Module: Linked to module rlm_mschap
Module: Instantiating module "mschap" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/mschap
mschap {
use_mppe = yes
require_encryption = no
require_strong = no
with_ntdomain_hack = yes
allow_retry = yes
}
Module: Instantiating module "motp" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/motp
exec motp {
wait = yes
program = "/usr/local/bin/bash
/usr/pbi/freeradius-i386/etc/raddb/scripts/otpverify.sh
%{request:User-Name} %{request:User-Password} %{reply:MOTP-Init-Secret}
%{reply:MOTP-PIN} %{reply:MOTP-Offset}"
input_pairs = "request"
shell_escape = yes
}
Module: Linked to module rlm_digest
Module: Instantiating module "digest" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/digest
Module: Linked to module rlm_unix
Module: Instantiating module "unix" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/unix
unix {
radwtmp = "/var/log/radwtmp"
}
Module: Linked to module rlm_eap
Module: Instantiating module "eap" from file
/usr/pbi/freeradius-i386/etc/raddb/eap.conf
eap {
default_eap_type = "peap"
timer_expire = 60
ignore_unknown_eap_types = no
cisco_accounting_username_bug = no
max_sessions = 4096
}
Module: Linked to sub-module rlm_eap_md5
Module: Instantiating eap-md5
Module: Linked to sub-module rlm_eap_leap
Module: Instantiating eap-leap
Module: Linked to sub-module rlm_eap_gtc
Module: Instantiating eap-gtc
gtc {
challenge = "Password: "
auth_type = "PAP"
}
Module: Linked to sub-module rlm_eap_tls
Module: Instantiating eap-tls
tls {
rsa_key_exchange = no
dh_key_exchange = yes
rsa_key_length = 512
dh_key_length = 512
verify_depth = 0
CA_path = "/usr/pbi/freeradius-i386/etc/raddb/certs"
pem_file_type = yes
private_key_file =
"/usr/pbi/freeradius-i386/etc/raddb/certs/server.pem"
certificate_file =
"/usr/pbi/freeradius-i386/etc/raddb/certs/server.pem"
CA_file = "/usr/pbi/freeradius-i386/etc/raddb/certs/ca.pem"
private_key_password = "whatever"
dh_file = "/usr/pbi/freeradius-i386/etc/raddb/certs/dh"
random_file = "/usr/pbi/freeradius-i386/etc/raddb/certs/random"
fragment_size = 1024
include_length = yes
check_crl = no
cipher_list = "DEFAULT"
ecdh_curve = "prime256v1"
cache {
enable = no
lifetime = 24
max_entries = 255
}
verify {
}
ocsp {
enable = no
override_cert_url = no
url = "http://127.0.0.1/ocsp/"
use_nonce = yes
timeout = 0
softfail = no
}
}
Module: Linked to sub-module rlm_eap_ttls
Module: Instantiating eap-ttls
ttls {
default_eap_type = "md5"
copy_request_to_tunnel = no
use_tunneled_reply = yes
include_length = yes
}
Module: Linked to sub-module rlm_eap_peap
Module: Instantiating eap-peap
peap {
default_eap_type = "mschapv2"
copy_request_to_tunnel = yes
use_tunneled_reply = yes
proxy_tunneled_request_as_eap = yes
soh = no
}
Module: Linked to sub-module rlm_eap_mschapv2
Module: Instantiating eap-mschapv2
mschapv2 {
with_ntdomain_hack = no
send_error = no
}
Module: Checking authorize {...} for more modules to load
Module: Linked to module rlm_preprocess
Module: Instantiating module "preprocess" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/preprocess
preprocess {
huntgroups = "/usr/pbi/freeradius-i386/etc/raddb/huntgroups"
hints = "/usr/pbi/freeradius-i386/etc/raddb/hints"
with_ascend_hack = no
ascend_channels_per_line = 23
with_ntdomain_hack = no
with_specialix_jetstream_hack = no
with_cisco_vsa_hack = no
with_alvarion_vsa_hack = no
}
reading pairlist file /usr/pbi/freeradius-i386/etc/raddb/huntgroups
reading pairlist file /usr/pbi/freeradius-i386/etc/raddb/hints
Module: Linked to module rlm_files
Module: Instantiating module "files" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/files
files {
usersfile = "/usr/pbi/freeradius-i386/etc/raddb/users"
acctusersfile = "/usr/pbi/freeradius-i386/etc/raddb/acct_users"
preproxy_usersfile =
"/usr/pbi/freeradius-i386/etc/raddb/preproxy_users"
compat = "no"
}
reading pairlist file /usr/pbi/freeradius-i386/etc/raddb/users
reading pairlist file /usr/pbi/freeradius-i386/etc/raddb/acct_users
reading pairlist file /usr/pbi/freeradius-i386/etc/raddb/preproxy_users
Module: Linked to module rlm_sql
Module: Instantiating module "sql" from file
/usr/pbi/freeradius-i386/etc/raddb/sql.conf
sql {
driver = "rlm_sql_mysql"
server = "192.168.1.223"
port = "3306"
login = "radius"
password = "radpass"
radius_db = "radiusdb"
read_groups = yes
sqltrace = no
sqltracefile = "/var/log/sqltrace.sql"
readclients = no
deletestalesessions = yes
num_sql_socks = 5
lifetime = 0
max_queries = 0
sql_user_name = "%{User-Name}"
default_user_profile = ""
nas_query = "SELECT id, nasname, shortname, type, secret, server
FROM nas"
authorize_check_query = "SELECT id, username, attribute, value,
op FROM radcheck WHERE username =
'%{SQL-User-Name}' ORDER BY id"
authorize_reply_query = "SELECT id, username, attribute, value,
op FROM radreply WHERE username =
'%{SQL-User-Name}' ORDER BY id"
authorize_group_check_query = "SELECT id, groupname,
attribute, Value, op FROM radgroupcheck
WHERE groupname = '%{Sql-Group}' ORDER BY id"
authorize_group_reply_query = "SELECT id, groupname,
attribute, value, op FROM radgroupreply
WHERE groupname = '%{Sql-Group}' ORDER BY id"
accounting_onoff_query = " UPDATE radacct SET
acctstoptime = '%S', acctsessiontime = unix_timestamp('%S') -
unix_timestamp(acctstarttime), acctterminatecause =
'%{Acct-Terminate-Cause}', acctstopdelay =
%{%{Acct-Delay-Time}:-0} WHERE acctstoptime IS NULL
AND nasipaddress = '%{NAS-IP-Address}' AND
acctstarttime <= '%S'"
accounting_update_query = " UPDATE radacct
SET framedipaddress = '%{Framed-IP-Address}',
acctsessiontime = '%{Acct-Session-Time}',
acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}', acctoutputoctets =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid =
'%{Acct-Session-Id}' AND username =
'%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'"
accounting_update_query_alt = " INSERT INTO
radacct (acctsessionid, acctuniqueid,
username, realm, nasipaddress,
nasportid, nasporttype, acctstarttime,
acctsessiontime, acctauthentic, connectinfo_start,
acctinputoctets, acctoutputoctets, calledstationid,
callingstationid, servicetype, framedprotocol,
framedipaddress, acctstartdelay,
xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}',
'%{Acct-Unique-Session-Id}', '%{SQL-User-Name}',
'%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',
'%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL
(%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND),
'%{Acct-Session-Time}', '%{Acct-Authentic}',
'', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%
{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}',
'%{Calling-Station-Id}', '%{Service-Type}',
'%{Framed-Protocol}', '%{Framed-IP-Address}', '0',
'%{X-Ascend-Session-Svr-Key}')"
accounting_start_query = " INSERT INTO
radacct (acctsessionid, acctuniqueid,
username, realm, nasipaddress,
nasportid, nasporttype, acctstarttime,
acctstoptime, acctsessiontime, acctauthentic,
connectinfo_start, connectinfo_stop, acctinputoctets,
acctoutputoctets, calledstationid, callingstationid,
acctterminatecause, servicetype, framedprotocol,
framedipaddress, acctstartdelay, acctstopdelay,
xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}',
'%{Acct-Unique-Session-Id}', '%{SQL-User-Name}',
'%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',
'%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}',
'%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}',
'%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}',
'%{Framed-IP-
Address}', '%{%{Acct-Delay-Time}:-0}', '0',
'%{X-Ascend-Session-Svr-Key}')"
accounting_start_query_alt = " UPDATE radacct
SET acctstarttime = '%S', acctstartdelay =
'%{%{Acct-Delay-Time}:-0}', connectinfo_start =
'%{Connect-Info}' WHERE acctsessionid =
'%{Acct-Session-Id}' AND username =
'%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'"
accounting_stop_query = " UPDATE radacct SET
acctstoptime = '%S', acctsessiontime = '%{Acct-Session-Time}',
acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}', acctoutputoctets =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}', acctterminatecause =
'%{Acct-Terminate-Cause}', acctstopdelay =
'%{%{Acct-Delay-Time}:-0}', connectinfo_stop =
'%{Connect-Info}' WHERE acctsessionid =
'%{Acct-Session-Id}' AND username =
'%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'"
accounting_stop_query_alt = " INSERT INTO
radacct (acctsessionid, acctuniqueid, username,
realm, nasipaddress, nasportid, nasporttype, acctstarttime,
acctstoptime, acctsessiontime, acctauthentic, connectinfo_start,
connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid,
callingstationid, acctterminatecause, servicetype, framedprotocol,
framedipaddress, acctstartdelay, acctstopdelay) VALUES
('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
'%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}',
'%{NAS-Port}', '%{NAS-Port-Type}',
DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0}
+ %{%{Acct-Delay-Time}:-0}) SECOND), '%S',
'%{Acct-Session-Time}', '%{Acct-Authentic}', '',
'%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}',
'%{Calling-Station-Id}', '%{Acct-Terminate-Cause}',
'%{Service-Type}', '%{Framed-Protocol}',
'%{Framed-IP-Address}', '0', '%{%{Acct-Delay-Time}:-0}')"
group_membership_query = "SELECT groupname FROM
radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY
priority"
connect_failure_retry_delay = 60
simul_count_query = ""
simul_verify_query = "SELECT radacctid, acctsessionid,
username, nasipaddress, nasportid,
framedipaddress, callingstationid,
framedprotocol FROM
radacct WHERE username =
'%{SQL-User-Name}' AND acctstoptime IS NULL"
postauth_query = "INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES (
'%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S')"
safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
}
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (sql): Attempting to connect to radius at 192.168.1.223:3306/radiusdb
rlm_sql (sql): starting 0
rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
rlm_sql_mysql: Starting connect to MySQL server for #0
rlm_sql (sql): Connected new DB handle, #0
rlm_sql (sql): starting 1
rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
rlm_sql_mysql: Starting connect to MySQL server for #1
rlm_sql (sql): Connected new DB handle, #1
rlm_sql (sql): starting 2
rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
rlm_sql_mysql: Starting connect to MySQL server for #2
rlm_sql (sql): Connected new DB handle, #2
rlm_sql (sql): starting 3
rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
rlm_sql_mysql: Starting connect to MySQL server for #3
rlm_sql (sql): Connected new DB handle, #3
rlm_sql (sql): starting 4
rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
rlm_sql_mysql: Starting connect to MySQL server for #4
rlm_sql (sql): Connected new DB handle, #4
Module: Linked to module rlm_checkval
Module: Instantiating module "checkval" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/checkval
checkval {
item-name = "Calling-Station-Id"
check-name = "Calling-Station-Id"
data-type = "string"
notfound-reject = no
}
rlm_checkval: Registered name Calling-Station-Id for attribute 31
Module: Checking preacct {...} for more modules to load
Module: Linked to module rlm_acct_unique
Module: Instantiating module "acct_unique" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/acct_unique
acct_unique {
key = "User-Name, Acct-Session-Id, NAS-IP-Address, NAS-Identifier,
NAS-Port"
}
Module: Linked to module rlm_realm
Module: Instantiating module "suffix" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/realm
realm suffix {
format = "suffix"
delimiter = "@"
ignore_default = no
ignore_null = yes
}
Module: Instantiating module "ntdomain" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/realm
realm ntdomain {
format = "prefix"
delimiter = "\"
ignore_default = no
ignore_null = yes
}
Module: Checking accounting {...} for more modules to load
Module: Linked to module rlm_detail
Module: Instantiating module "detail" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/detail
detail {
detailfile =
"/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
header = "%t"
detailperm = 384
dirperm = 493
locking = no
log_packet_header = no
}
Module: Instantiating module "datacounterdaily" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/datacounter_acct
exec datacounterdaily {
wait = yes
program = "/bin/sh
/usr/pbi/freeradius-i386/etc/raddb/scripts/datacounter_acct.sh
%{request:User-Name} daily %{request:Acct-Input-Octets}
%{request:Acct-Output-Octets}"
input_pairs = "request"
shell_escape = yes
}
Module: Instantiating module "datacounterweekly" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/datacounter_acct
exec datacounterweekly {
wait = yes
program = "/bin/sh
/usr/pbi/freeradius-i386/etc/raddb/scripts/datacounter_acct.sh
%{request:User-Name} weekly %{request:Acct-Input-Octets}
%{request:Acct-Output-Octets}"
input_pairs = "request"
shell_escape = yes
}
Module: Instantiating module "datacountermonthly" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/datacounter_acct
exec datacountermonthly {
wait = yes
program = "/bin/sh
/usr/pbi/freeradius-i386/etc/raddb/scripts/datacounter_acct.sh
%{request:User-Name} monthly %{request:Acct-Input-Octets}
%{request:Acct-Output-Octets}"
input_pairs = "request"
shell_escape = yes
}
Module: Instantiating module "datacounterforever" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/datacounter_acct
exec datacounterforever {
wait = yes
program = "/bin/sh
/usr/pbi/freeradius-i386/etc/raddb/scripts/datacounter_acct.sh
%{request:User-Name} forever %{request:Acct-Input-Octets}
%{request:Acct-Output-Octets}"
input_pairs = "request"
shell_escape = yes
}
Module: Linked to module rlm_radutmp
Module: Instantiating module "radutmp" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/radutmp
radutmp {
filename = "/var/log/radutmp"
username = "%{User-Name}"
case_sensitive = yes
check_with_nas = yes
perm = 384
callerid = yes
}
Module: Linked to module rlm_attr_filter
Module: Instantiating module "attr_filter.accounting_response" from
file /usr/pbi/freeradius-i386/etc/raddb/modules/attr_filter
attr_filter attr_filter.accounting_response {
attrsfile =
"/usr/pbi/freeradius-i386/etc/raddb/attrs.accounting_response"
key = "%{User-Name}"
relaxed = no
}
reading pairlist file
/usr/pbi/freeradius-i386/etc/raddb/attrs.accounting_response
Module: Checking session {...} for more modules to load
Module: Checking pre-proxy {...} for more modules to load
Module: Instantiating module "attr_filter.pre-proxy" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/attr_filter
attr_filter attr_filter.pre-proxy {
attrsfile = "/usr/pbi/freeradius-i386/etc/raddb/attrs.pre-proxy"
key = "%{Realm}"
relaxed = no
}
reading pairlist file /usr/pbi/freeradius-i386/etc/raddb/attrs.pre-proxy
Module: Checking post-proxy {...} for more modules to load
Module: Instantiating module "attr_filter.post-proxy" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/attr_filter
attr_filter attr_filter.post-proxy {
attrsfile = "/usr/pbi/freeradius-i386/etc/raddb/attrs"
key = "%{Realm}"
relaxed = no
}
reading pairlist file /usr/pbi/freeradius-i386/etc/raddb/attrs
Module: Checking post-auth {...} for more modules to load
Module: Instantiating module "attr_filter.access_reject" from file
/usr/pbi/freeradius-i386/etc/raddb/modules/attr_filter
attr_filter attr_filter.access_reject {
attrsfile = "/usr/pbi/freeradius-i386/etc/raddb/attrs.access_reject"
key = "%{User-Name}"
relaxed = no
}
reading pairlist file /usr/pbi/freeradius-i386/etc/raddb/attrs.access_reject
} # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
type = "auth"
ipaddr = 172.16.0.1
port = 1645
}
listen {
type = "acct"
ipaddr = 172.16.0.1
port = 1646
}
Listening on authentication address 172.16.0.1 port 1645
Listening on accounting address 172.16.0.1 port 1646
Listening on proxy address 172.16.0.1 port 1647
Ready to process requests.
rad_recv: Accounting-Request packet from host 172.16.0.2 port 54960,
id=0, length=89
Acct-Status-Type = Accounting-On
Acct-Authentic = RADIUS
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
Acct-Terminate-Cause = NAS-Reboot
# Executing section preacct from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
expand: %{Acct-Session-Time} ->
... expanding second conditional
expand: %{Acct-Delay-Time} ->
... expanding second conditional
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}
-> 1385116612 - 0 - 0
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} -
%{%{Acct-Delay-Time}:-0}} -> 1385116612
++[request] returns ok
[acct_unique] WARNING: Attribute NAS-Port was not found in request,
unique ID MAY be inconsistent
[acct_unique] WARNING: Attribute Acct-Session-Id was not found in
request, unique ID MAY be inconsistent
[acct_unique] WARNING: Attribute User-Name was not found in request,
unique ID MAY be inconsistent
[acct_unique] Hashing ',NAS-Identifier = "myAP",NAS-IP-Address =
172.16.0.2,,'
[acct_unique] Acct-Unique-Session-ID = "96c937b8b7290e37".
++[acct_unique] returns ok
[suffix] Proxy reply, or no User-Name. Ignoring.
++[suffix] returns ok
[ntdomain] Proxy reply, or no User-Name. Ignoring.
++[ntdomain] returns ok
++[files] returns noop
# Executing section accounting from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.0.2
[detail] expand:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radacct/172.16.0.2/detail-20131122
[detail]
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radacct/172.16.0.2/detail-20131122
[detail] expand: %t -> Fri Nov 22 11:36:52 2013
++[detail] returns ok
rlm_counter: We only run on Accounting-Stop packets.
++[daily] returns noop
rlm_counter: We only run on Accounting-Stop packets.
++[weekly] returns noop
rlm_counter: We only run on Accounting-Stop packets.
++[monthly] returns noop
rlm_counter: We only run on Accounting-Stop packets.
++[forever] returns noop
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type
== Interim-Update))
?? Evaluating (request:Acct-Status-Type == Stop) -> FALSE
?? Evaluating (request:Acct-Status-Type == Interim-Update) -> FALSE
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type
== Interim-Update)) -> FALSE
++[unix] returns noop
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
rlm_radutmp: NAS hostapd restarted (Accounting-On packet seen)
++[radutmp] returns ok
++- entering policy redundant {...}
[sql] Received Acct On/Off packet
[sql] expand: %{Acct-Delay-Time} ->
[sql] ... expanding second conditional
[sql] expand: UPDATE radacct SET
acctstoptime = '%S', acctsessiontime = unix_timestamp('%S') -
unix_timestamp(acctstarttime), acctterminatecause =
'%{Acct-Terminate-Cause}', acctstopdelay =
%{%{Acct-Delay-Time}:-0} WHERE acctstoptime IS NULL
AND nasipaddress = '%{NAS-IP-Address}' AND
acctstarttime <= '%S' -> UPDATE radacct SET
acctstoptime = '2013-11-22 11:36:52', acctsessiontime =
unix_timestamp('2013-11-22 11:36:52') -
unix_timestamp(acctstarttime), acctterminatecause =
'NAS-Reboot', acctstopdelay = 0 WHERE
acctstoptime IS NULL AND nasipaddress =
'172.16.0.2' AND acctstarttime <= '2013-11-22 11:36:52'
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Released sql socket id: 4
+++[sql] returns ok
++- policy redundant returns ok
++[exec] returns noop
[attr_filter.accounting_response] expand: %{User-Name} ->
++[attr_filter.accounting_response] returns noop
Sending Accounting-Response of id 0 to 172.16.0.2 port 54960
Finished request 0.
Cleaning up request 0 ID 0 with timestamp +3
Going to the next request
Ready to process requests.
rad_recv: Access-Request packet from host 172.16.0.2 port 46731, id=1,
length=184
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
EAP-Message = 0x0269000b01616c67756e6f
Message-Authenticator = 0x9e1deffbe8b07933f8cb516a197a9bda
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 105 length 11
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
++- entering policy redundant {...}
[sql] expand: %{User-Name} -> myUser
[sql] sql_set_user escaped user --> 'myUser'
rlm_sql (sql): Reserving sql socket id: 3
[sql] expand: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radcheck WHERE username = 'myUser' ORDER BY id
[sql] User found in radcheck table
[sql] expand: SELECT id, username, attribute, value, op
FROM radreply WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radreply WHERE username = 'myUser' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup
WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT
groupname FROM radusergroup WHERE username =
'myUser' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value,
op FROM radgroupcheck WHERE groupname =
'%{Sql-Group}' ORDER BY id -> SELECT id, groupname,
attribute, Value, op FROM radgroupcheck
WHERE groupname = 'VLAN_2' ORDER BY id
[sql] User found in group VLAN_2
[sql] expand: SELECT id, groupname, attribute, value,
op FROM radgroupreply WHERE groupname =
'%{Sql-Group}' ORDER BY id -> SELECT id, groupname,
attribute, value, op FROM radgroupreply
WHERE groupname = 'VLAN_2' ORDER BY id
rlm_sql (sql): Released sql socket id: 3
+++[sql] returns ok
++- policy redundant returns ok
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[daily] returns noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[weekly] returns noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[monthly] returns noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[forever] returns noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 38-EC-E4-7B-2A-85
rlm_checkval: Could not find attribute named Calling-Station-Id in check
pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] Normalizing NT-Password from hex encoding
[pap] WARNING: Auth-Type already set. Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 1 to 172.16.0.2 port 46731
Tunnel-Type:0 := VLAN
Tunnel-Medium-Type:0 := IEEE-802
Tunnel-Private-Group-Id:0 := "2"
Acct-Interim-Interval := 600
EAP-Message = 0x016a00061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb7b377c8b7d96eb26d0ebbe451557537
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.0.2 port 46731, id=2,
length=391
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
EAP-Message =
0x026a00c81980000000be16030100b9010000b50301528f347f21688b21d87841d56e723544bc2e3733aa01f372c845e577e5089a36000048c014c00a00390038c00fc0050035c012c00800160013c00dc003000ac013c00900330032c00ec004002fc011c007c00cc002000500040015001200090014001100080006000300ff01000044000b000403000102000a00340032000100020003000400050006000700080009000a000b000c000d000e000f001000110012001300140015001600170018001900230000
State = 0xb7b377c8b7d96eb26d0ebbe451557537
Message-Authenticator = 0x241bfa850843303b3f25396cb3690b69
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 106 length 200
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
TLS Length 190
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] (other): before/accept initialization
[peap] TLS_accept: before/accept initialization
[peap] <<< TLS 1.0 Handshake [length 00b9], ClientHello
[peap] TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 0031], ServerHello
[peap] TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 085e], Certificate
[peap] TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange
[peap] TLS_accept: SSLv3 write key exchange A
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[peap] TLS_accept: SSLv3 write server done A
[peap] TLS_accept: SSLv3 flush data
[peap] TLS_accept: Need to read more data: SSLv3 read client
certificate A
In SSL Handshake Phase
In SSL Accept mode
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 2 to 172.16.0.2 port 46731
EAP-Message =
0x016b040019c000000ab416030100310200002d0301528f33cfff5e57459fca395f16fe9c2480452c5c1d6d7ef0ab2f7828961f9046000039000005ff01000100160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c65204365727469666963617465204175
EAP-Message =
0x74686f72697479301e170d3132313232303233343333355a170d3133313232303233343333355a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100d2610b1ca45e16d0ec30629f9c08d97d3a9eb084e007ad307c31ce99ac0a657ac68a34d2af29391dae89d2011a70dcd600a560fc43dc85
EAP-Message =
0xa0056e772b73f9bf04b7790d3196d4f89a0a53cb92369adff66e9d6bba28ce42c06761aea13fdd3b7b8307838a16b8eaa892be1f0e433054caa55c8952a3d3e0c29d8034207373801068c3af09d06b968ece4f529b571e6b42eabba2144102a81fc891419a3052611e4459ee73dd726d5ff4f4a1a70bc06bd06530cd850143c32b8b4df82b2a6b2224b32a88c8dc94f9bbc940f45ec2ed9d1f004b0d2c7d6b6f501f5e2fceead03631690bd644e404e811f633788509e8667dc506747eed55214006c6f6f236f4f3410203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010505000382010100523e
EAP-Message =
0xa319f376376fd4397159a2544e85089f33c5130ba97a331f31091431140439c248b5f89fa7b4e6ea288cc2da70fd10939e8d3367cce66289aba956fd35224aa94c4e2d69f8b4ffbda96063e564ac31eb680872548028feaeb7e32db57b21e9472b5cadfe56ef68ba2d485c10fff3bfb481f2e09d45a192349fba6778037b3dad59aac8c324e5f06179a26db59912ac600f679496fc2890339d2aeb731facb97d6410478ceacc327beb37201e811aa38595416508f2b9681658e6bf379bba00814d8d2783e1cad9f3b5a8e82baed7acd0053b5647ed1cdaac3d77f6faa9e30a4398346d12fcb0681eb8f3d517c15570df60b2f56649b312b90772da9f4b
EAP-Message = 0x720004ab308204a73082038f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb7b377c8b6d86eb26d0ebbe451557537
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.0.2 port 46731, id=3,
length=197
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
EAP-Message = 0x026b00061900
State = 0xb7b377c8b6d86eb26d0ebbe451557537
Message-Authenticator = 0xaa36673698fb723042f2bda359589131
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 107 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 3 to 172.16.0.2 port 46731
EAP-Message =
0x016c03fc1940a003020102020900da6ca063e714a5eb300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3132313232303233343333355a170d3133313232303233343333355a308193310b3009060355040613024652310f300d0603550408130652616469757331
EAP-Message =
0x12301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a02820101009377ea646f5ceefa70cae9d77064deee5fd7af4de18cc755ea507757bfebe35a2664ad9dc67735b3ad3719722b95b250fdc524716658a7ca17f21040d3f5e4dd412061dc9d5e6677f54515cae68534ead380182a4fe2fd98f1bcc15bae48b1c25f3bc099f3ca8bb4
EAP-Message =
0x52093375295cd601982dfaab1d0814e755c19fcd969abfc232214b5c1aaa2e06ba7f331690a667938852e4ea1585cbdd9648964116ee6bad7781cf029572252c2ed88d74eef0b5ccd1395d14e9f426732d2fbe55e81679c1b1d77755696597c8797ebf3bc88062c5ae861dacac346c350f79361c2670b4203b916a59fda93d93e614477f141c0d5119f152a0714947a5c72087985590b90d0203010001a381fb3081f8301d0603551d0e04160414f748cc032af05d7417d7d07b1c6156113c2fa4e33081c80603551d230481c03081bd8014f748cc032af05d7417d7d07b1c6156113c2fa4e3a18199a48196308193310b300906035504061302465231
EAP-Message =
0x0f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479820900da6ca063e714a5eb300c0603551d13040530030101ff300d06092a864886f70d010105050003820101002141ed49abf513b4eb259428fd866ba0d7d3a14a088cc85b3ea74ea786834ce75b460471562ab775f3eef62a1fca82da5a070d6409a206f7c7d26ed2dd754f72f39d8a4694e93ff72005b6
EAP-Message = 0xcb22f856226674f1
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb7b377c8b5df6eb26d0ebbe451557537
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.0.2 port 46731, id=4,
length=197
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
EAP-Message = 0x026c00061900
State = 0xb7b377c8b5df6eb26d0ebbe451557537
Message-Authenticator = 0x9c70584c1dc06f5e1a61b499f2f41a03
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 108 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 4 to 172.16.0.2 port 46731
EAP-Message =
0x016d02ce1900a1e967254d4185a1f8efb0da44685d53c15f69147b58b88b27ac7885316e927b94d35c40d4d28907d237e751834e5c35aaf340e2172ab006fe4f70a31fc02044192510961b8d371f987febde6fb68ced841a1015669bd307318c7b897774c8395c6b034f1af9e6fd08f6917c1c5e261773cba1ab547420ecab6788b91b03c780f14a2b8d7c68e061ffc9990bfd341b721ed7d2e2c98dd8c3fef0e4a1313cf8cc00790befb632000600d4d88229160301020d0c0002090080e6d9244e55f42955571582ad273c461ef82c1f15c6d174c5e1fe64b6d7b652b3272e1827adfd8bf153d89d669366b9a9574b061c847d0072356af464594c2b
EAP-Message =
0x6a79c9d6665d0f9e91c6b633489bf07dd0b7d42d0d072c7beeef9a462c6e8fa83de60f55ec7383f3d7b1edb8005002eadb8414cc67005bf3d055aceb27d9251dcb0001020080559f405372465388c11eac577ad9d165541ba70a0d83b2aee00f02a126ddc1e0578b4375601e4e8bbc5138eec3ed6e860624664fce5ae527179a286ab0ac6e7a2e1bc9fee85da9dc6d15ad45ecf45741f6fcb87f77ed0bd58c4a627472ab4d5ebcc09e967a5fa8c5dee2d550346637bc6777f8cb7fa0b22f263d6628b9cbec7e0100cdaa37358603a26ca901e3977d5d0a97fb0ea92b9021dbe2128eee89e4c4d4241d1edfd241e0bee114841be347b93ac45fac06a5a8
EAP-Message =
0xf4f77671c83a68d2d76564893d5ca04ac159721939f3953e182d01b2e69692bc43b52fa346bb88589b9c031d6f73a7f8fabe141fb4afb3c1767c756711bbb3ea88992d5ba7d5bb7f809d8dde84d774a25e2cfb5241cc5d713e6a109e072955c857a1979f50a6a3aee4159bfc6a82dcfb7b854aa88809bebdae2208451cf66d7f5db33a33e2998690b109990a9443476fe22e817fc7547cd477369bf6cfef242981e2ceeca3d22636726161dd6a6bd3b409d9aa18a0ad1208d86df19d8bea5d9e24344c691f20d98b30851a16030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb7b377c8b4de6eb26d0ebbe451557537
Finished request 4.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 172.16.0.2 port 46731, id=5,
length=399
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
EAP-Message =
0x026d00d01980000000c61603010086100000820080601372e2f7754b43e384e606e9282c37d7e3ccff37736f84ed75a49a4feceb44eabf516c351751147a250ca15fc5b671608eb2ab2d7f4e99ac0687556d6e03889c368fd9858e6be212dbd159ac668abe52dc06d5bb8c32486ad36c97233ac9f09f1e602def8d6d8b882585cd4f5d709e96d99b2b9c8a87ccc58352680a3fed191403010001011603010030fb49dc7ff5b0a283f62b7765cc39d7fb425e374a320b4e42208c6b2fac701ddbc35d258f963076f57be43116d99c641f
State = 0xb7b377c8b4de6eb26d0ebbe451557537
Message-Authenticator = 0x8d78ab857f37e829e266f5672d76090a
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 109 length 208
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
TLS Length 198
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
[peap] TLS_accept: SSLv3 read client key exchange A
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[peap] <<< TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 read finished A
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[peap] TLS_accept: SSLv3 write change cipher spec A
[peap] >>> TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 write finished A
[peap] TLS_accept: SSLv3 flush data
[peap] (other): SSL negotiation finished successfully
SSL Connection Established
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 5 to 172.16.0.2 port 46731
EAP-Message =
0x016e0041190014030100010116030100306b08ce5dea860974f60b36ffd69d22df3affec08d45f809b9d3d5da8750444432458501fe4077fc88db8fa2456b549ef
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb7b377c8b3dd6eb26d0ebbe451557537
Finished request 5.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 172.16.0.2 port 46731, id=6,
length=197
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
EAP-Message = 0x026e00061900
State = 0xb7b377c8b3dd6eb26d0ebbe451557537
Message-Authenticator = 0xb9f5278d298cf52522d904fecde1bb85
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 110 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake is finished
[peap] eaptls_verify returned 3
[peap] eaptls_process returned 3
[peap] EAPTLS_SUCCESS
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state TUNNEL ESTABLISHED
++[eap] returns handled
Sending Access-Challenge of id 6 to 172.16.0.2 port 46731
EAP-Message =
0x016f002b190017030100201042c8ac3a893d457f078fd228c41ccf6e1c6f5a4968af99900248053a4060b8
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb7b377c8b2dc6eb26d0ebbe451557537
Finished request 6.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 172.16.0.2 port 46731, id=7,
length=271
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
EAP-Message =
0x026f0050190017030100200ee7c4c7c2e71ea7a7ca614dc306ad5b0e820e86bb0dc0f6ba10b4b9aca6f5601703010020f94c3a0475b7373d1eca463aff36317bf4437ce46860afaf399a9c84f8aec9b9
State = 0xb7b377c8b2dc6eb26d0ebbe451557537
Message-Authenticator = 0xe2437b8a99ba7bb46e53964f2530173d
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 111 length 80
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state WAITING FOR INNER IDENTITY
[peap] Identity - myUser
[peap] Got inner identity 'myUser'
[peap] Setting default EAP type for tunneled EAP session.
[peap] Got tunneled request
EAP-Message = 0x026f000b01616c67756e6f
server {
[peap] Setting User-Name to myUser
Sending tunneled request
EAP-Message = 0x026f000b01616c67756e6f
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
NAS-IP-Address = 172.16.0.2
server {
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 111 length 11
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
++- entering policy redundant {...}
[sql] expand: %{User-Name} -> myUser
[sql] sql_set_user escaped user --> 'myUser'
rlm_sql (sql): Reserving sql socket id: 2
[sql] expand: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radcheck WHERE username = 'myUser' ORDER BY id
[sql] User found in radcheck table
[sql] expand: SELECT id, username, attribute, value, op
FROM radreply WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radreply WHERE username = 'myUser' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup
WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT
groupname FROM radusergroup WHERE username =
'myUser' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value,
op FROM radgroupcheck WHERE groupname =
'%{Sql-Group}' ORDER BY id -> SELECT id, groupname,
attribute, Value, op FROM radgroupcheck
WHERE groupname = 'VLAN_2' ORDER BY id
[sql] User found in group VLAN_2
[sql] expand: SELECT id, groupname, attribute, value,
op FROM radgroupreply WHERE groupname =
'%{Sql-Group}' ORDER BY id -> SELECT id, groupname,
attribute, value, op FROM radgroupreply
WHERE groupname = 'VLAN_2' ORDER BY id
rlm_sql (sql): Released sql socket id: 2
+++[sql] returns ok
++- policy redundant returns ok
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[daily] returns noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[weekly] returns noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[monthly] returns noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[forever] returns noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 38-EC-E4-7B-2A-85
rlm_checkval: Could not find attribute named Calling-Station-Id in check
pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] Normalizing NT-Password from hex encoding
[pap] WARNING: Auth-Type already set. Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
++[eap] returns handled
} # server
[peap] Got tunneled reply code 11
Tunnel-Type:0 := VLAN
Tunnel-Medium-Type:0 := IEEE-802
Tunnel-Private-Group-Id:0 := "2"
Acct-Interim-Interval := 600
EAP-Message =
0x017000201a0170001b1066b4cd1cfa1925628bf21ac16870c069616c67756e6f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x466def3e461df5a9b4742da332335fbe
[peap] Got tunneled reply RADIUS code 11
Tunnel-Type:0 := VLAN
Tunnel-Medium-Type:0 := IEEE-802
Tunnel-Private-Group-Id:0 := "2"
Acct-Interim-Interval := 600
EAP-Message =
0x017000201a0170001b1066b4cd1cfa1925628bf21ac16870c069616c67756e6f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x466def3e461df5a9b4742da332335fbe
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 7 to 172.16.0.2 port 46731
EAP-Message =
0x0170004b1900170301004029cda7f66f24f85647b1ea26e5c0e558827d45961f7ed34a711b1b5329eaf52f1dd2acc49b3fafa51ad2a52f56eb31dea90eec9abaccf56d1f866fc04d14c288
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb7b377c8b1c36eb26d0ebbe451557537
Finished request 7.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 172.16.0.2 port 46731, id=8,
length=335
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
EAP-Message =
0x027000901900170301002082b6317d7e5ae9285add203487ec94890ddb3766844cf7b109b06dfea6e6ff1c17030100603f68beb9784fde085ec580fa03c08b3e94f893c2fa97b8ff9829a1d4b62ae42a69cbada105ca555de76f5e6e56cbce6a9fc175b727fb777e52f3561b1f7df47bfe834fd71665b9c822affb98dcb55d91d44f4846665085dc5823964bae9a3802
State = 0xb7b377c8b1c36eb26d0ebbe451557537
Message-Authenticator = 0xd1710eb1156662186da3e1c6946a8d69
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 112 length 144
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state phase2
[peap] EAP type mschapv2
[peap] Got tunneled request
EAP-Message =
0x027000411a0270003c3135e9e440a48f598b6d215a2f87a2abfa00000000000000003534e3ad1124cc76385cc591b15df4a4773c5af247bbf77700616c67756e6f
server {
[peap] Setting User-Name to myUser
Sending tunneled request
EAP-Message =
0x027000411a0270003c3135e9e440a48f598b6d215a2f87a2abfa00000000000000003534e3ad1124cc76385cc591b15df4a4773c5af247bbf77700616c67756e6f
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "myUser"
State = 0x466def3e461df5a9b4742da332335fbe
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
NAS-IP-Address = 172.16.0.2
server {
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 112 length 65
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
++- entering policy redundant {...}
[sql] expand: %{User-Name} -> myUser
[sql] sql_set_user escaped user --> 'myUser'
rlm_sql (sql): Reserving sql socket id: 1
[sql] expand: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radcheck WHERE username = 'myUser' ORDER BY id
[sql] User found in radcheck table
[sql] expand: SELECT id, username, attribute, value, op
FROM radreply WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radreply WHERE username = 'myUser' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup
WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT
groupname FROM radusergroup WHERE username =
'myUser' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value,
op FROM radgroupcheck WHERE groupname =
'%{Sql-Group}' ORDER BY id -> SELECT id, groupname,
attribute, Value, op FROM radgroupcheck
WHERE groupname = 'VLAN_2' ORDER BY id
[sql] User found in group VLAN_2
[sql] expand: SELECT id, groupname, attribute, value,
op FROM radgroupreply WHERE groupname =
'%{Sql-Group}' ORDER BY id -> SELECT id, groupname,
attribute, value, op FROM radgroupreply
WHERE groupname = 'VLAN_2' ORDER BY id
rlm_sql (sql): Released sql socket id: 1
+++[sql] returns ok
++- policy redundant returns ok
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[daily] returns noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[weekly] returns noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[monthly] returns noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[forever] returns noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 38-EC-E4-7B-2A-85
rlm_checkval: Could not find attribute named Calling-Station-Id in check
pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] Normalizing NT-Password from hex encoding
[pap] WARNING: Auth-Type already set. Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[mschapv2] # Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
[mschapv2] +- entering group MS-CHAP {...}
[mschap] No Cleartext-Password configured. Cannot create LM-Password.
[mschap] Found NT-Password
[mschap] Creating challenge hash with username: myUser
[mschap] Client is using MS-CHAPv2 for myUser, we need NT-Password
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
MSCHAP Success
++[eap] returns handled
} # server
[peap] Got tunneled reply code 11
Tunnel-Type:0 := VLAN
Tunnel-Medium-Type:0 := IEEE-802
Tunnel-Private-Group-Id:0 := "2"
Acct-Interim-Interval := 600
EAP-Message =
0x017100331a0370002e533d31434634354137313446454244323043443438424135443131364337314533434341424333394546
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x466def3e471cf5a9b4742da332335fbe
[peap] Got tunneled reply RADIUS code 11
Tunnel-Type:0 := VLAN
Tunnel-Medium-Type:0 := IEEE-802
Tunnel-Private-Group-Id:0 := "2"
Acct-Interim-Interval := 600
EAP-Message =
0x017100331a0370002e533d31434634354137313446454244323043443438424135443131364337314533434341424333394546
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x466def3e471cf5a9b4742da332335fbe
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 8 to 172.16.0.2 port 46731
EAP-Message =
0x0171005b1900170301005049ac12c1d149ddda90666c752b828051e4e4ae4d5b67edcccc515a0b44967023d9c28fc6cef89571015a09e5d937845658cd9356287badac62fb6cbc2d4e50e1d65f101bd314ce7c1204e8b3789490bf
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb7b377c8b0c26eb26d0ebbe451557537
Finished request 8.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 172.16.0.2 port 46731, id=9,
length=271
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
EAP-Message =
0x0271005019001703010020b13180ca373aa4a63c92e74c1146946af33dce40d84c9e04dc1cc95a10ea786d1703010020ae3482af4132073c5b03f42a8fedebd6ce35e55cf15c673070c340e08f669539
State = 0xb7b377c8b0c26eb26d0ebbe451557537
Message-Authenticator = 0x1e3afd69afd6b7aaadc2c840b34e75ff
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 113 length 80
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state phase2
[peap] EAP type mschapv2
[peap] Got tunneled request
EAP-Message = 0x027100061a03
server {
[peap] Setting User-Name to myUser
Sending tunneled request
EAP-Message = 0x027100061a03
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "myUser"
State = 0x466def3e471cf5a9b4742da332335fbe
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
NAS-IP-Address = 172.16.0.2
server {
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 113 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
++- entering policy redundant {...}
[sql] expand: %{User-Name} -> myUser
[sql] sql_set_user escaped user --> 'myUser'
rlm_sql (sql): Reserving sql socket id: 0
[sql] expand: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radcheck WHERE username = 'myUser' ORDER BY id
[sql] User found in radcheck table
[sql] expand: SELECT id, username, attribute, value, op
FROM radreply WHERE username = '%{SQL-User-Name}'
ORDER BY id -> SELECT id, username, attribute, value, op FROM
radreply WHERE username = 'myUser' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup
WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT
groupname FROM radusergroup WHERE username =
'myUser' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value,
op FROM radgroupcheck WHERE groupname =
'%{Sql-Group}' ORDER BY id -> SELECT id, groupname,
attribute, Value, op FROM radgroupcheck
WHERE groupname = 'VLAN_2' ORDER BY id
[sql] User found in group VLAN_2
[sql] expand: SELECT id, groupname, attribute, value,
op FROM radgroupreply WHERE groupname =
'%{Sql-Group}' ORDER BY id -> SELECT id, groupname,
attribute, value, op FROM radgroupreply
WHERE groupname = 'VLAN_2' ORDER BY id
rlm_sql (sql): Released sql socket id: 0
+++[sql] returns ok
++- policy redundant returns ok
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[daily] returns noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[weekly] returns noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[monthly] returns noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[forever] returns noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 38-EC-E4-7B-2A-85
rlm_checkval: Could not find attribute named Calling-Station-Id in check
pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] Normalizing NT-Password from hex encoding
[pap] WARNING: Auth-Type already set. Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[eap] Freeing handler
++[eap] returns ok
expand: ->
Login OK: [myUser] (from client hostapd port 1 cli 38-EC-E4-7B-2A-85 via
TLS tunnel)
# Executing section post-auth from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group post-auth {...}
++[exec] returns noop
} # server
[peap] Got tunneled reply code 2
Tunnel-Type:0 := VLAN
Tunnel-Medium-Type:0 := IEEE-802
Tunnel-Private-Group-Id:0 := "2"
Acct-Interim-Interval := 600
MS-MPPE-Encryption-Policy = 0x00000001
MS-MPPE-Encryption-Types = 0x00000006
MS-MPPE-Send-Key = 0x32ef5908d99eda655abda54e9bf7f77b
MS-MPPE-Recv-Key = 0xefb998f7c565cfbeeb73094aff999a41
EAP-Message = 0x03710004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "myUser"
[peap] Got tunneled reply RADIUS code 2
Tunnel-Type:0 := VLAN
Tunnel-Medium-Type:0 := IEEE-802
Tunnel-Private-Group-Id:0 := "2"
Acct-Interim-Interval := 600
MS-MPPE-Encryption-Policy = 0x00000001
MS-MPPE-Encryption-Types = 0x00000006
MS-MPPE-Send-Key = 0x32ef5908d99eda655abda54e9bf7f77b
MS-MPPE-Recv-Key = 0xefb998f7c565cfbeeb73094aff999a41
EAP-Message = 0x03710004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "myUser"
[peap] Tunneled authentication was successful.
[peap] SUCCESS
[peap] Saving tunneled attributes for later
++[eap] returns handled
Sending Access-Challenge of id 9 to 172.16.0.2 port 46731
EAP-Message =
0x0172002b190017030100208ba698cacf0345d16f24dee242f6485aff94302d17ac9606e9c13b7c79e9ee61
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb7b377c8bfc16eb26d0ebbe451557537
Finished request 9.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 172.16.0.2 port 46731, id=10,
length=271
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Framed-MTU = 1400
EAP-Message =
0x027200501900170301002081edd9ce2846a96f61e004aebc1c5b0a5d2a3dd0cad530f4711a6901030b9af41703010020ded847ebff59e1a46b180780b80f214126a2eff3cff961b77fb40996b44a0852
State = 0xb7b377c8bfc16eb26d0ebbe451557537
Message-Authenticator = 0x5037a5c7a61e5b9ee4849c6cd9c4ab93
# Executing section authorize from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[eap] EAP packet type response id 114 length 80
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state send tlv success
[peap] Received EAP-TLV response.
[peap] Success
[peap] Using saved attributes from the original Access-Accept
Tunnel-Type:0 := VLAN
Tunnel-Medium-Type:0 := IEEE-802
Tunnel-Private-Group-Id:0 := "2"
Acct-Interim-Interval := 600
User-Name = "myUser"
[eap] Freeing handler
++[eap] returns ok
expand: ->
Login OK: [myUser] (from client hostapd port 1 cli 38-EC-E4-7B-2A-85)
# Executing section post-auth from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group post-auth {...}
++[exec] returns noop
Sending Access-Accept of id 10 to 172.16.0.2 port 46731
Tunnel-Type:0 := VLAN
Tunnel-Medium-Type:0 := IEEE-802
Tunnel-Private-Group-Id:0 := "2"
Acct-Interim-Interval := 600
User-Name = "myUser"
MS-MPPE-Recv-Key =
0x28788d4e84b809cf23fe1fcdc17f6379e52a10d5175ee8405c3caff2c6f9e30c
MS-MPPE-Send-Key =
0xabb187fd1eff53ab37e76c316a81aba98d65b7c83309e29b42cb57b4f5e514b7
EAP-Message = 0x03720004
Message-Authenticator = 0x00000000000000000000000000000000
Finished request 10.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Accounting-Request packet from host 172.16.0.2 port 54960,
id=11, length=178
Acct-Session-Id = "528F33C3-00000000"
Acct-Status-Type = Start
Acct-Authentic = RADIUS
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
# Executing section preacct from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
expand: %{Acct-Session-Time} ->
... expanding second conditional
expand: %{Acct-Delay-Time} ->
... expanding second conditional
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}
-> 1385116623 - 0 - 0
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} -
%{%{Acct-Delay-Time}:-0}} -> 1385116623
++[request] returns ok
[acct_unique] Hashing 'NAS-Port = 1,NAS-Identifier =
"myAP",NAS-IP-Address = 172.16.0.2,Acct-Session-Id =
"528F33C3-00000000",User-Name = "myUser"'
[acct_unique] Acct-Unique-Session-ID = "c3ecb1c16ce63600".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "myUser", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "myUser", skipping NULL due to config.
++[ntdomain] returns noop
++[files] returns noop
# Executing section accounting from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.0.2
[detail] expand:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radacct/172.16.0.2/detail-20131122
[detail]
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radacct/172.16.0.2/detail-20131122
[detail] expand: %t -> Fri Nov 22 11:37:03 2013
++[detail] returns ok
rlm_counter: We only run on Accounting-Stop packets.
++[daily] returns noop
rlm_counter: We only run on Accounting-Stop packets.
++[weekly] returns noop
rlm_counter: We only run on Accounting-Stop packets.
++[monthly] returns noop
rlm_counter: We only run on Accounting-Stop packets.
++[forever] returns noop
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type
== Interim-Update))
?? Evaluating (request:Acct-Status-Type == Stop) -> FALSE
?? Evaluating (request:Acct-Status-Type == Interim-Update) -> FALSE
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type
== Interim-Update)) -> FALSE
++[unix] returns ok
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
[radutmp] expand: %{User-Name} -> myUser
++[radutmp] returns ok
++- entering policy redundant {...}
[sql] expand: %{User-Name} -> myUser
[sql] sql_set_user escaped user --> 'myUser'
[sql] expand: %{Acct-Delay-Time} ->
[sql] ... expanding second conditional
[sql] expand: INSERT INTO radacct (acctsessionid,
acctuniqueid, username, realm, nasipaddress,
nasportid, nasporttype, acctstarttime, acctstoptime,
acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop,
acctinputoctets, acctoutputoctets, calledstationid, callingstationid,
acctterminatecause, servicetype, framedprotocol, framedipaddress,
acctstartdelay, acctstopdelay, xascendsessionsvrkey)
VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
'%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}',
'%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL,
'0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0',
'%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}',
'%{Framed-Protocol}', '%{Framed-IP-Address}',
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Released sql socket id: 4
+++[sql] returns ok
++- policy redundant returns ok
++[exec] returns noop
[attr_filter.accounting_response] expand: %{User-Name} -> myUser
attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 11 to 172.16.0.2 port 54960
Finished request 11.
Cleaning up request 11 ID 11 with timestamp +14
Going to the next request
Waking up in 4.6 seconds.
rad_recv: Accounting-Request packet from host 172.16.0.2 port 54960,
id=12, length=220
Acct-Session-Id = "528F33C3-00000000"
Acct-Status-Type = Stop
Acct-Authentic = RADIUS
User-Name = "myUser"
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
NAS-Port = 1
Calling-Station-Id = "38-EC-E4-7B-2A-85"
Connect-Info = "CONNECT 54Mbps 802.11g"
Acct-Session-Id = "528F33C3-00000000"
Acct-Session-Time = 4
Acct-Input-Packets = 56
Acct-Output-Packets = 28
Acct-Input-Octets = 4425
Acct-Output-Octets = 6386
Event-Timestamp = "Nov 22 2013 11:37:07 CET"
Acct-Terminate-Cause = User-Request
# Executing section preacct from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
expand: %{Acct-Session-Time} -> 4
expand: %{Acct-Delay-Time} ->
... expanding second conditional
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}
-> 1385116627 - 4 - 0
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} -
%{%{Acct-Delay-Time}:-0}} -> 1385116623
++[request] returns ok
[acct_unique] Hashing 'NAS-Port = 1,NAS-Identifier =
"myAP",NAS-IP-Address = 172.16.0.2,Acct-Session-Id =
"528F33C3-00000000",User-Name = "myUser"'
[acct_unique] Acct-Unique-Session-ID = "c3ecb1c16ce63600".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "myUser", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] No '\' in User-Name = "myUser", skipping NULL due to config.
++[ntdomain] returns noop
++[files] returns noop
# Executing section accounting from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.0.2
[detail] expand:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radacct/172.16.0.2/detail-20131122
[detail]
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radacct/172.16.0.2/detail-20131122
[detail] expand: %t -> Fri Nov 22 11:37:07 2013
++[detail] returns ok
rlm_counter: Packet Unique ID = 'c3ecb1c16ce63600'
rlm_counter: Searching the database for key 'myUser'
rlm_counter: Key found.
rlm_counter: Counter Unique ID = 'a16826b7ad7612e4'
rlm_counter: User=myUser, Counter=126.
rlm_counter: User=myUser, New Counter=130.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[daily] returns ok
rlm_counter: Packet Unique ID = 'c3ecb1c16ce63600'
rlm_counter: Searching the database for key 'myUser'
rlm_counter: Key found.
rlm_counter: Counter Unique ID = 'a16826b7ad7612e4'
rlm_counter: User=myUser, Counter=415.
rlm_counter: User=myUser, New Counter=419.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[weekly] returns ok
rlm_counter: Packet Unique ID = 'c3ecb1c16ce63600'
rlm_counter: Searching the database for key 'myUser'
rlm_counter: Key found.
rlm_counter: Counter Unique ID = 'a16826b7ad7612e4'
rlm_counter: User=myUser, Counter=415.
rlm_counter: User=myUser, New Counter=419.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[monthly] returns ok
rlm_counter: Packet Unique ID = 'c3ecb1c16ce63600'
rlm_counter: Searching the database for key 'myUser'
rlm_counter: Key found.
rlm_counter: Counter Unique ID = 'a16826b7ad7612e4'
rlm_counter: User=myUser, Counter=415.
rlm_counter: User=myUser, New Counter=419.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[forever] returns ok
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type
== Interim-Update))
?? Evaluating (request:Acct-Status-Type == Stop) -> TRUE
?? Skipping (request:Acct-Status-Type == Interim-Update)
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type
== Interim-Update)) -> TRUE
++- entering if ((request:Acct-Status-Type == Stop) ||
(request:Acct-Status-Type == Interim-Update)) {...}
[datacounterdaily] expand: %{request:User-Name} -> myUser
[datacounterdaily] expand: %{request:Acct-Input-Octets} -> 4425
[datacounterdaily] expand: %{request:Acct-Output-Octets} -> 6386
Exec-Program output:
Exec-Program: returned: 0
+++[datacounterdaily] returns ok
[datacounterweekly] expand: %{request:User-Name} -> myUser
[datacounterweekly] expand: %{request:Acct-Input-Octets} -> 4425
[datacounterweekly] expand: %{request:Acct-Output-Octets} -> 6386
Exec-Program output:
Exec-Program: returned: 0
+++[datacounterweekly] returns ok
[datacountermonthly] expand: %{request:User-Name} -> myUser
[datacountermonthly] expand: %{request:Acct-Input-Octets} -> 4425
[datacountermonthly] expand: %{request:Acct-Output-Octets} -> 6386
Exec-Program output:
Exec-Program: returned: 0
+++[datacountermonthly] returns ok
[datacounterforever] expand: %{request:User-Name} -> myUser
[datacounterforever] expand: %{request:Acct-Input-Octets} -> 4425
[datacounterforever] expand: %{request:Acct-Output-Octets} -> 6386
Exec-Program output:
Exec-Program: returned: 0
+++[datacounterforever] returns ok
++- if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type
== Interim-Update)) returns ok
++[unix] returns ok
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
[radutmp] expand: %{User-Name} -> myUser
++[radutmp] returns ok
++- entering policy redundant {...}
[sql] expand: %{User-Name} -> myUser
[sql] sql_set_user escaped user --> 'myUser'
[sql] expand: %{Acct-Input-Gigawords} ->
[sql] ... expanding second conditional
[sql] expand: %{Acct-Input-Octets} -> 4425
[sql] expand: %{Acct-Output-Gigawords} ->
[sql] ... expanding second conditional
[sql] expand: %{Acct-Output-Octets} -> 6386
[sql] expand: %{Acct-Delay-Time} ->
[sql] ... expanding second conditional
[sql] expand: UPDATE radacct SET acctstoptime =
'%S', acctsessiontime =
'%{Acct-Session-Time}', acctinputoctets =
'%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}', acctoutputoctets =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}', acctterminatecause =
'%{Acct-Terminate-Cause}', acctstopdelay =
'%{%{Acct-Delay-Time}:-0}', connectinfo_stop =
'%{Connect-Info}' WHERE acctsessionid =
'%{Acct-Session-Id}' AND username =
'%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'
-> UPDATE radacct SET acctstoptime = '2013-11-22
11:37:07', acctsessiontime = '4', acctinputoctets =
'0' << 32 | '4425', acctoutputoctets
= '0' << 32 |
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql (sql): Released sql socket id: 3
+++[sql] returns ok
++- policy redundant returns ok
++[exec] returns noop
[attr_filter.accounting_response] expand: %{User-Name} -> myUser
attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 12 to 172.16.0.2 port 54960
Finished request 12.
Cleaning up request 12 ID 12 with timestamp +18
Going to the next request
Waking up in 0.3 seconds.
Cleaning up request 1 ID 1 with timestamp +14
Cleaning up request 2 ID 2 with timestamp +14
Cleaning up request 3 ID 3 with timestamp +14
Cleaning up request 4 ID 4 with timestamp +14
Waking up in 0.1 seconds.
Cleaning up request 5 ID 5 with timestamp +14
Cleaning up request 6 ID 6 with timestamp +14
Cleaning up request 7 ID 7 with timestamp +14
Cleaning up request 8 ID 8 with timestamp +14
Cleaning up request 9 ID 9 with timestamp +14
Cleaning up request 10 ID 10 with timestamp +14
Ready to process requests.
rad_recv: Accounting-Request packet from host 172.16.0.2 port 54960,
id=13, length=89
Acct-Status-Type = Accounting-Off
Acct-Authentic = RADIUS
NAS-Identifier = "myAP"
Called-Station-Id = "22-15-6D-84-CB-61:mySSID"
NAS-Port-Type = Wireless-802.11
Acct-Terminate-Cause = NAS-Reboot
# Executing section preacct from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
expand: %{Acct-Session-Time} ->
... expanding second conditional
expand: %{Acct-Delay-Time} ->
... expanding second conditional
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}
-> 1385116634 - 0 - 0
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} -
%{%{Acct-Delay-Time}:-0}} -> 1385116634
++[request] returns ok
[acct_unique] WARNING: Attribute NAS-Port was not found in request,
unique ID MAY be inconsistent
[acct_unique] WARNING: Attribute Acct-Session-Id was not found in
request, unique ID MAY be inconsistent
[acct_unique] WARNING: Attribute User-Name was not found in request,
unique ID MAY be inconsistent
[acct_unique] Hashing ',NAS-Identifier = "myAP",NAS-IP-Address =
172.16.0.2,,'
[acct_unique] Acct-Unique-Session-ID = "96c937b8b7290e37".
++[acct_unique] returns ok
[suffix] Proxy reply, or no User-Name. Ignoring.
++[suffix] returns ok
[ntdomain] Proxy reply, or no User-Name. Ignoring.
++[ntdomain] returns ok
++[files] returns noop
# Executing section accounting from file
/usr/pbi/freeradius-i386/etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] expand: %{Packet-Src-IP-Address} -> 172.16.0.2
[detail] expand:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radacct/172.16.0.2/detail-20131122
[detail]
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radacct/172.16.0.2/detail-20131122
[detail] expand: %t -> Fri Nov 22 11:37:14 2013
++[detail] returns ok
rlm_counter: We only run on Accounting-Stop packets.
++[daily] returns noop
rlm_counter: We only run on Accounting-Stop packets.
++[weekly] returns noop
rlm_counter: We only run on Accounting-Stop packets.
++[monthly] returns noop
rlm_counter: We only run on Accounting-Stop packets.
++[forever] returns noop
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type
== Interim-Update))
?? Evaluating (request:Acct-Status-Type == Stop) -> FALSE
?? Evaluating (request:Acct-Status-Type == Interim-Update) -> FALSE
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type
== Interim-Update)) -> FALSE
++[unix] returns noop
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
rlm_radutmp: NAS hostapd rebooted (Accounting-Off packet seen)
++[radutmp] returns ok
++- entering policy redundant {...}
[sql] Received Acct On/Off packet
[sql] expand: %{Acct-Delay-Time} ->
[sql] ... expanding second conditional
[sql] expand: UPDATE radacct SET
acctstoptime = '%S', acctsessiontime = unix_timestamp('%S') -
unix_timestamp(acctstarttime), acctterminatecause =
'%{Acct-Terminate-Cause}', acctstopdelay =
%{%{Acct-Delay-Time}:-0} WHERE acctstoptime IS NULL
AND nasipaddress = '%{NAS-IP-Address}' AND
acctstarttime <= '%S' -> UPDATE radacct SET
acctstoptime = '2013-11-22 11:37:14', acctsessiontime =
unix_timestamp('2013-11-22 11:37:14') -
unix_timestamp(acctstarttime), acctterminatecause =
'NAS-Reboot', acctstopdelay = 0 WHERE
acctstoptime IS NULL AND nasipaddress =
'172.16.0.2' AND acctstarttime <= '2013-11-22 11:37:14'
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql (sql): Released sql socket id: 2
+++[sql] returns ok
++- policy redundant returns ok
++[exec] returns noop
[attr_filter.accounting_response] expand: %{User-Name} ->
++[attr_filter.accounting_response] returns noop
Sending Accounting-Response of id 13 to 172.16.0.2 port 54960
Finished request 13.
Cleaning up request 13 ID 13 with timestamp +25
Going to the next request
Ready to process requests.
Thanks for all. King regards.
Fernando.
More information about the Freeradius-Users
mailing list