Hi
I've been trying to debug why accounting information isn't making it
into the SQL database on our main FR server (2.1.11) - it seems that
this has been the case since upgrading from version 1.something ancient
a few months back.
I have a fairly simple MySQL backed setup - and minimal changes of the
config files to enable this; just to be clear this was a fresh install
of the OS + FreeRADIUS so no danger of old configuration files still
lurking around.
sql is uncommented in both the authorization and accounting sections of
the sites-available/default file (accounting section shown below), and
the sql module is enabled in radiusd.conf - the server works just fine
for auth via SQL as can be seen in the debug.
accounting {
#
# Create a 'detail'ed log of the packets.
# Note that accounting requests which are proxied
# are also logged in the detail file.
detail
# daily
# Update the wtmp file
#
# If you don't use "radlast", you can delete this line.
unix
#
# For Simultaneous-Use tracking.
#
# Due to packet losses in the network, the data here
# may be incorrect. There is little we can do about it.
radutmp
# sradutmp
# Return an address to the IP Pool when we see a stop record.
# main_pool
#
# Log traffic to an SQL database.
#
# See "Accounting queries" in sql.conf
sql
#
# If you receive stop packets with zero session length,
# they will NOT be logged in the database. The SQL module
# will print a message (only in debugging mode), and will
# return "noop".
#
# You can ignore these packets by uncommenting the following
# three lines. Otherwise, the server will not respond to the
# accounting request, and the NAS will retransmit.
#
# if (noop) {
# ok
# }
#
# Instead of sending the query to the SQL server,
# write it into a log file.
#
# sql_log
# Cisco VoIP specific bulk accounting
# pgsql-voip
# For Exec-Program and Exec-Program-Wait
exec
# Filter attributes from the accounting response.
attr_filter.accounting_response
#
# See "Autz-Type Status-Server" for how this works.
#
# Acct-Type Status-Server {
#
# }
}
I can see accounting requests being received, but there seems to be no
sql module action happening to insert them into the database; but I
cannot see why from the debug. I've not changed any of the pre-defined
SQL queries.
The debug log attached (it was a bit big to post inline) has had three
minor hand-amendments:
- SQL server password removed.
- Shared secret for the two clients removed.
- The very long list of clients loaded from SQL reduced to the router
being tested.
Any pointers/suggestions gratefully received.
Regards,
Paul.
[root@auth1 ~]# radiusd -X
FreeRADIUS Version 2.1.11, for host i386-portbld-freebsd8.2, built on Aug 25
2011 at 19:01:41
Copyright (C) 1999-2009 The FreeRADIUS server project and contributors.
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE.
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License v2.
Starting - reading configuration files ...
including configuration file /usr/local/etc/raddb/radiusd.conf
including configuration file /usr/local/etc/raddb/proxy.conf
including files in directory /usr/local/etc/raddb/modules/
including configuration file /usr/local/etc/raddb/modules/wimax
including configuration file /usr/local/etc/raddb/modules/always
including configuration file /usr/local/etc/raddb/modules/attr_filter
including configuration file /usr/local/etc/raddb/modules/attr_rewrite
including configuration file /usr/local/etc/raddb/modules/chap
including configuration file /usr/local/etc/raddb/modules/checkval
including configuration file /usr/local/etc/raddb/modules/counter
including configuration file /usr/local/etc/raddb/modules/cui
including configuration file /usr/local/etc/raddb/modules/detail
including configuration file /usr/local/etc/raddb/modules/detail.example.com
including configuration file /usr/local/etc/raddb/modules/detail.log
including configuration file /usr/local/etc/raddb/modules/digest
including configuration file /usr/local/etc/raddb/modules/dynamic_clients
including configuration file /usr/local/etc/raddb/modules/echo
including configuration file /usr/local/etc/raddb/modules/etc_group
including configuration file /usr/local/etc/raddb/modules/exec
including configuration file /usr/local/etc/raddb/modules/expiration
including configuration file /usr/local/etc/raddb/modules/expr
including configuration file /usr/local/etc/raddb/modules/files
including configuration file /usr/local/etc/raddb/modules/inner-eap
including configuration file /usr/local/etc/raddb/modules/ippool
including configuration file /usr/local/etc/raddb/modules/krb5
including configuration file /usr/local/etc/raddb/modules/ldap
including configuration file /usr/local/etc/raddb/modules/linelog
including configuration file /usr/local/etc/raddb/modules/logintime
including configuration file /usr/local/etc/raddb/modules/mac2ip
including configuration file /usr/local/etc/raddb/modules/mschap
including configuration file /usr/local/etc/raddb/modules/mac2vlan
including configuration file /usr/local/etc/raddb/modules/ntlm_auth
including configuration file /usr/local/etc/raddb/modules/opendirectory
including configuration file /usr/local/etc/raddb/modules/otp
including configuration file /usr/local/etc/raddb/modules/pam
including configuration file /usr/local/etc/raddb/modules/pap
including configuration file /usr/local/etc/raddb/modules/passwd
including configuration file /usr/local/etc/raddb/modules/perl
including configuration file /usr/local/etc/raddb/modules/policy
including configuration file /usr/local/etc/raddb/modules/preprocess
including configuration file /usr/local/etc/raddb/modules/radutmp
including configuration file /usr/local/etc/raddb/modules/realm
including configuration file /usr/local/etc/raddb/modules/redis
including configuration file /usr/local/etc/raddb/modules/rediswho
including configuration file /usr/local/etc/raddb/modules/replicate
including configuration file /usr/local/etc/raddb/modules/smbpasswd
including configuration file /usr/local/etc/raddb/modules/smsotp
including configuration file /usr/local/etc/raddb/modules/soh
including configuration file /usr/local/etc/raddb/modules/sql_log
including configuration file
/usr/local/etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /usr/local/etc/raddb/modules/sradutmp
including configuration file /usr/local/etc/raddb/modules/unix
including configuration file /usr/local/etc/raddb/modules/acct_unique
including configuration file /usr/local/etc/raddb/eap.conf
including configuration file /usr/local/etc/raddb/sql.conf
including configuration file /usr/local/etc/raddb/sql/mysql/dialup.conf
including configuration file /usr/local/etc/raddb/sqlippool.conf
including configuration file /usr/local/etc/raddb/sql/postgresql/ippool.conf
including configuration file /usr/local/etc/raddb/policy.conf
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
including configuration file /usr/local/etc/raddb/sites-enabled/control-socket
main {
user = "freeradius"
group = "freeradius"
allow_core_dumps = no
}
including dictionary file /usr/local/etc/raddb/dictionary
main {
name = "radiusd"
prefix = "/usr/local"
localstatedir = "/var"
sbindir = "/usr/local/sbin"
logdir = "/var/log"
run_dir = "/var/run/radiusd"
libdir = "/usr/local/lib/freeradius-2.1.11"
radacctdir = "/var/log/radacct"
hostname_lookups = no
max_request_time = 30
cleanup_delay = 5
max_requests = 1024
pidfile = "/var/run/radiusd/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
}
security {
max_attributes = 200
reject_delay = 1
status_server = yes
}
}
radiusd: #### Loading Realms and Home Servers ####
proxy server {
retry_delay = 5
retry_count = 3
default_fallback = no
dead_time = 120
wake_all_if_all_dead = no
}
home_server localhost {
ipaddr = 127.0.0.1
port = 1812
type = "auth"
secret = "testing123"
response_window = 20
max_outstanding = 65536
require_message_authenticator = yes
zombie_period = 40
status_check = "status-server"
ping_interval = 30
check_interval = 30
num_answers_to_alive = 3
num_pings_to_alive = 3
revive_interval = 120
status_check_timeout = 4
coa {
irt = 2
mrt = 16
mrc = 5
mrd = 30
}
}
home_server_pool my_auth_failover {
type = fail-over
home_server = localhost
}
realm example.com {
auth_pool = my_auth_failover
}
realm LOCAL {
}
radiusd: #### Loading Clients ####
radiusd: #### Instantiating modules ####
instantiate {
Module: Linked to module rlm_exec
Module: Instantiating module "exec" from file /usr/local/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/local/etc/raddb/modules/expr
Module: Linked to module rlm_expiration
Module: Instantiating module "expiration" from file
/usr/local/etc/raddb/modules/expiration
expiration {
reply-message = "Password Has Expired "
}
Module: Linked to module rlm_logintime
Module: Instantiating module "logintime" from file
/usr/local/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/local/etc/raddb/radiusd.conf
modules {
Module: Checking authenticate {...} for more modules to load
Module: Linked to module rlm_pap
Module: Instantiating module "pap" from file /usr/local/etc/raddb/modules/pap
pap {
encryption_scheme = "auto"
auto_header = no
}
Module: Linked to module rlm_chap
Module: Instantiating module "chap" from file /usr/local/etc/raddb/modules/chap
Module: Linked to module rlm_mschap
Module: Instantiating module "mschap" from file
/usr/local/etc/raddb/modules/mschap
mschap {
use_mppe = yes
require_encryption = no
require_strong = no
with_ntdomain_hack = no
allow_retry = yes
}
Module: Linked to module rlm_digest
Module: Instantiating module "digest" from file
/usr/local/etc/raddb/modules/digest
Module: Linked to module rlm_eap
Module: Instantiating module "eap" from file /usr/local/etc/raddb/eap.conf
eap {
default_eap_type = "md5"
timer_expire = 60
ignore_unknown_eap_types = no
cisco_accounting_username_bug = no
max_sessions = 4096
}
Module: Linked to sub-module rlm_eap_md5
Module: Instantiating eap-md5
Module: Linked to sub-module rlm_eap_leap
Module: Instantiating eap-leap
Module: Linked to sub-module rlm_eap_gtc
Module: Instantiating eap-gtc
gtc {
challenge = "Password: "
auth_type = "PAP"
}
Module: Linked to sub-module rlm_eap_tls
Module: Instantiating eap-tls
tls {
rsa_key_exchange = no
dh_key_exchange = yes
rsa_key_length = 512
dh_key_length = 512
verify_depth = 0
CA_path = "/usr/local/etc/raddb/certs"
pem_file_type = yes
private_key_file = "/usr/local/etc/raddb/certs/server.pem"
certificate_file = "/usr/local/etc/raddb/certs/server.pem"
CA_file = "/usr/local/etc/raddb/certs/ca.pem"
private_key_password = "whatever"
dh_file = "/usr/local/etc/raddb/certs/dh"
random_file = "/usr/local/etc/raddb/certs/random"
fragment_size = 1024
include_length = yes
check_crl = no
cipher_list = "DEFAULT"
make_cert_command = "/usr/local/etc/raddb/certs/bootstrap"
cache {
enable = no
lifetime = 24
max_entries = 255
}
verify {
}
ocsp {
enable = no
override_cert_url = yes
url = "http://127.0.0.1/ocsp/";
}
}
Module: Linked to sub-module rlm_eap_ttls
Module: Instantiating eap-ttls
ttls {
default_eap_type = "md5"
copy_request_to_tunnel = no
use_tunneled_reply = no
virtual_server = "inner-tunnel"
include_length = yes
}
Module: Linked to sub-module rlm_eap_peap
Module: Instantiating eap-peap
peap {
default_eap_type = "mschapv2"
copy_request_to_tunnel = no
use_tunneled_reply = no
proxy_tunneled_request_as_eap = yes
virtual_server = "inner-tunnel"
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/local/etc/raddb/modules/preprocess
preprocess {
huntgroups = "/usr/local/etc/raddb/huntgroups"
hints = "/usr/local/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
}
Module: Linked to module rlm_realm
Module: Instantiating module "suffix" from file
/usr/local/etc/raddb/modules/realm
realm suffix {
format = "suffix"
delimiter = "@"
ignore_default = no
ignore_null = no
}
Module: Linked to module rlm_sql
Module: Instantiating module "sql" from file /usr/local/etc/raddb/sql.conf
sql {
driver = "rlm_sql_mysql"
server = "localhost"
port = ""
login = "radius"
password = "xxxxxxxxx"
radius_db = "radius"
read_groups = yes
sqltrace = no
sqltracefile = "/var/log/sqltrace.sql"
readclients = yes
deletestalesessions = yes
num_sql_socks = 5
lifetime = 0
max_queries = 0
sql_user_name = "%{User-Name}"
default_user_profile = ""
nas_query = "SELECT id, nasname, shortname, type, secret, server FROM
nas"
authorize_check_query = "SELECT id, username, attribute, value, op
FROM radcheck WHERE username = '%{SQL-User-Name}'
ORDER BY id"
authorize_reply_query = "SELECT id, username, attribute, value, op
FROM radreply WHERE username = '%{SQL-User-Name}'
ORDER BY id"
authorize_group_check_query = "SELECT id, groupname, attribute,
Value, op FROM radgroupcheck WHERE groupname =
'%{Sql-Group}' ORDER BY id"
authorize_group_reply_query = "SELECT id, groupname, attribute,
value, op FROM radgroupreply WHERE groupname =
'%{Sql-Group}' ORDER BY id"
accounting_onoff_query = " UPDATE radacct SET
acctstoptime = '%S', acctsessiontime =
unix_timestamp('%S') -
unix_timestamp(acctstarttime), acctterminatecause =
'%{Acct-Terminate-Cause}', acctstopdelay =
%{%{Acct-Delay-Time}:-0} WHERE acctstoptime IS NULL AND
nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <=
'%S'"
accounting_update_query = " UPDATE radacct SET
framedipaddress = '%{Framed-IP-Address}', acctsessiontime
= '%{Acct-Session-Time}', acctinputoctets =
'%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}', acctoutputoctets =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid =
'%{Acct-Session-Id}' AND username = '%{SQL-User-Name}'
AND nasipaddress = '%{NAS-IP-Address}'"
accounting_update_query_alt = " INSERT INTO radacct
(acctsessionid, acctuniqueid, username, realm,
nasipaddress, nasportid, nasporttype, acctstarttime,
acctsessiontime, acctauthentic, connectinfo_start,
acctinputoctets, acctoutputoctets, calledstationid,
callingstationid, servicetype, framedprotocol,
framedipaddress, acctstartdelay, xascendsessionsvrkey)
VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
'%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}',
'%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S',
INTERVAL (%{%{Acct-Session-Time}:-0} +
%{%{Acct-Delay-Time}:-0}) SECOND),
'%{Acct-Session-Time}', '%{Acct-Authentic}', '',
'%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' <<
32 | '%{%{Acct-Output-Octets}:-0}',
'%{Called-Station-Id}', '%{Calling-Station-Id}',
'%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',
'0', '%{X-Ascend-Session-Svr-Key}')"
accounting_start_query = " INSERT INTO radacct
(acctsessionid, acctuniqueid, username, realm,
nasipaddress, nasportid, nasporttype, acctstarttime,
acctstoptime, acctsessiontime, acctauthentic,
connectinfo_start, connectinfo_stop, acctinputoctets,
acctoutputoctets, calledstationid, callingstationid,
acctterminatecause, servicetype, framedprotocol,
framedipaddress, acctstartdelay, acctstopdelay,
xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}',
'%{Acct-Unique-Session-Id}', '%{SQL-User-Name}',
'%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',
'%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}',
'%{Connect-Info}', '', '0', '0',
'%{Called-Station-Id}', '%{Calling-Station-Id}', '',
'%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',
'%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')"
accounting_start_query_alt = " UPDATE radacct SET
acctstarttime = '%S', acctstartdelay =
'%{%{Acct-Delay-Time}:-0}', connectinfo_start = '%{Connect-Info}'
WHERE acctsessionid = '%{Acct-Session-Id}' AND username
= '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'"
accounting_stop_query = " UPDATE radacct SET
acctstoptime = '%S', acctsessiontime =
'%{Acct-Session-Time}', acctinputoctets =
'%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}', acctoutputoctets =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}', acctterminatecause =
'%{Acct-Terminate-Cause}', acctstopdelay =
'%{%{Acct-Delay-Time}:-0}', connectinfo_stop = '%{Connect-Info}'
WHERE acctsessionid = '%{Acct-Session-Id}' AND username
= '%{SQL-User-Name}' AND nasipaddress =
'%{NAS-IP-Address}'"
accounting_stop_query_alt = " INSERT INTO radacct
(acctsessionid, acctuniqueid, username, realm, nasipaddress,
nasportid, nasporttype, acctstarttime, acctstoptime,
acctsessiontime, acctauthentic, connectinfo_start,
connectinfo_stop, acctinputoctets, acctoutputoctets,
calledstationid, callingstationid, acctterminatecause,
servicetype, framedprotocol, framedipaddress, acctstartdelay,
acctstopdelay) VALUES ('%{Acct-Session-Id}',
'%{Acct-Unique-Session-Id}', '%{SQL-User-Name}',
'%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',
'%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL
(%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0})
SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '',
'%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32
| '%{%{Acct-Input-Octets}:-0}',
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}',
'%{Calling-Station-Id}', '%{Acct-Terminate-Cause}',
'%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',
'0', '%{%{Acct-Delay-Time}:-0}')"
group_membership_query = "SELECT groupname FROM radusergroup
WHERE username = '%{SQL-User-Name}' ORDER BY priority"
connect_failure_retry_delay = 60
simul_count_query = ""
simul_verify_query = "SELECT radacctid, acctsessionid, username,
nasipaddress, nasportid, framedipaddress,
callingstationid, framedprotocol
FROM radacct WHERE username =
'%{SQL-User-Name}' AND acctstoptime IS NULL"
postauth_query = "INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES (
'%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S')"
safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
}
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (sql): Attempting to connect to radius@localhost:/radius
rlm_sql (sql): starting 0
rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
rlm_sql_mysql: Starting connect to MySQL server for #0
rlm_sql (sql): Connected new DB handle, #0
rlm_sql (sql): starting 1
rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
rlm_sql_mysql: Starting connect to MySQL server for #1
rlm_sql (sql): Connected new DB handle, #1
rlm_sql (sql): starting 2
rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
rlm_sql_mysql: Starting connect to MySQL server for #2
rlm_sql (sql): Connected new DB handle, #2
rlm_sql (sql): starting 3
rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
rlm_sql_mysql: Starting connect to MySQL server for #3
rlm_sql (sql): Connected new DB handle, #3
rlm_sql (sql): starting 4
rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
rlm_sql_mysql: Starting connect to MySQL server for #4
rlm_sql (sql): Connected new DB handle, #4
rlm_sql (sql): Processing generate_sql_clients
rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname,
type, secret, server FROM nas
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Read entry nasname=127.0.0.1,shortname=localhost,secret=secret1
rlm_sql (sql): Adding client 127.0.0.1 (localhost, server=<none>) to clients
list
rlm_sql (sql): Read entry
nasname=217.65.160.124,shortname=lo0-edge1.thd,secret=secret1
rlm_sql (sql): Adding client 217.65.160.124 (lo0-edge1.thd, server=<none>) to
clients list
rlm_sql (sql): Released sql socket id: 4
Module: Checking preacct {...} for more modules to load
Module: Linked to module rlm_acct_unique
Module: Instantiating module "acct_unique" from file
/usr/local/etc/raddb/modules/acct_unique
acct_unique {
key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address,
NAS-Port"
}
Module: Linked to module rlm_files
Module: Instantiating module "files" from file
/usr/local/etc/raddb/modules/files
files {
usersfile = "/usr/local/etc/raddb/users"
acctusersfile = "/usr/local/etc/raddb/acct_users"
preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"
compat = "no"
}
Module: Checking accounting {...} for more modules to load
Module: Linked to module rlm_detail
Module: Instantiating module "detail" from file
/usr/local/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: Linked to module rlm_unix
Module: Instantiating module "unix" from file /usr/local/etc/raddb/modules/unix
unix {
radwtmp = "/var/log/radwtmp"
}
Module: Linked to module rlm_radutmp
Module: Instantiating module "radutmp" from file
/usr/local/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/local/etc/raddb/modules/attr_filter
attr_filter attr_filter.accounting_response {
attrsfile = "/usr/local/etc/raddb/attrs.accounting_response"
key = "%{User-Name}"
}
Module: Checking session {...} for more modules to load
Module: Checking post-proxy {...} for more modules to load
Module: Checking post-auth {...} for more modules to load
Module: Instantiating module "attr_filter.access_reject" from file
/usr/local/etc/raddb/modules/attr_filter
attr_filter attr_filter.access_reject {
attrsfile = "/usr/local/etc/raddb/attrs.access_reject"
key = "%{User-Name}"
}
} # modules
} # server
server inner-tunnel { # from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel
modules {
Module: Checking authenticate {...} for more modules to load
Module: Checking authorize {...} for more modules to load
Module: Checking session {...} for more modules to load
Module: Checking post-proxy {...} for more modules to load
Module: Checking post-auth {...} for more modules to load
} # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
type = "auth"
ipaddr = *
port = 0
}
listen {
type = "acct"
ipaddr = *
port = 0
}
listen {
type = "control"
listen {
socket = "/var/run/radiusd/radiusd.sock"
}
}
listen {
type = "auth"
ipaddr = 127.0.0.1
port = 18120
}
... adding new socket proxy address * port 62480
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on command file /var/run/radiusd/radiusd.sock
Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel
Listening on proxy address * port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 217.65.160.124 port 1645, id=106,
length=90
Framed-Protocol = PPP
User-Name = "paultest"
CHAP-Password = 0x0101d1dbcb3db111238cec35dfdc1b15ea
NAS-Port-Type = Virtual
NAS-Port = 0
NAS-Port-Id = "1/0/0/270"
Service-Type = Framed-User
NAS-IP-Address = 217.65.160.124
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
[chap] Setting 'Auth-Type := CHAP'
++[chap] returns ok
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "paultest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
[sql] expand: %{User-Name} -> paultest
[sql] sql_set_user escaped user --> 'paultest'
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 = 'paultest' ORDER BY id
WARNING: Found User-Password == "...".
WARNING: Are you sure you don't mean Cleartext-Password?
WARNING: See "man rlm_pap" for more information.
[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 = 'paultest' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup WHERE
username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname
FROM radusergroup WHERE username = 'paultest' ORDER
BY priority
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING: Auth-Type already set. Not setting to PAP
++[pap] returns noop
Found Auth-Type = CHAP
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!! Replacing User-Password in config items with Cleartext-Password. !!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!! Please update your configuration so that the "known good" !!!
!!! clear text password is in Cleartext-Password, and not in User-Password. !!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+- entering group CHAP {...}
[chap] login attempt by "paultest" with CHAP password
[chap] Using clear text password "LetMeIn123" for user paultest authentication.
[chap] chap user paultest authenticated succesfully
++[chap] returns ok
Login OK: [paultest] (from client lo0-edge1.thd port 0)
# Executing section post-auth from file
/usr/local/etc/raddb/sites-enabled/default
+- entering group post-auth {...}
++[exec] returns noop
Sending Access-Accept of id 106 to 217.65.160.124 port 1645
Framed-IP-Address := 217.198.56.1
Service-Type := Framed-User
Framed-Netmask := 255.255.255.255
Framed-MTU := 1458
Framed-Protocol := PPP
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Accounting-Request packet from host 217.65.160.124 port 1646, id=57,
length=135
Acct-Session-Id = "000002A4"
Framed-Protocol = PPP
Framed-IP-Address = 217.198.56.1
User-Name = "paultest"
Acct-Authentic = RADIUS
Acct-Status-Type = Start
NAS-Port-Type = Virtual
NAS-Port = 0
NAS-Port-Id = "1/0/0/270"
Service-Type = Framed-User
NAS-IP-Address = 217.65.160.124
NAS-Identifier = "new-edge1.thd.prtsystems.net"
Acct-Delay-Time = 0
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address =
217.65.160.124,NAS-IP-Address = 217.65.160.124,Acct-Session-Id =
"000002A4",User-Name = "paultest"'
[acct_unique] Acct-Unique-Session-ID = "af771c19265bb6e9".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "paultest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
# Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] expand: %{Packet-Src-IP-Address} -> 217.65.160.124
[detail] expand:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radacct/217.65.160.124/detail-20111208
[detail]
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radacct/217.65.160.124/detail-20111208
[detail] expand: %t -> Thu Dec 8 22:40:07 2011
++[detail] returns ok
++[unix] returns fail
Finished request 1.
Cleaning up request 1 ID 57 with timestamp +17
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Accounting-Request packet from host 217.65.160.124 port 1646, id=58,
length=135
Acct-Session-Id = "000002A4"
Framed-Protocol = PPP
Framed-IP-Address = 217.198.56.1
User-Name = "paultest"
Acct-Authentic = RADIUS
Acct-Status-Type = Start
NAS-Port-Type = Virtual
NAS-Port = 0
NAS-Port-Id = "1/0/0/270"
Service-Type = Framed-User
NAS-IP-Address = 217.65.160.124
NAS-Identifier = "new-edge1.thd.prtsystems.net"
Acct-Delay-Time = 4
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address =
217.65.160.124,NAS-IP-Address = 217.65.160.124,Acct-Session-Id =
"000002A4",User-Name = "paultest"'
[acct_unique] Acct-Unique-Session-ID = "af771c19265bb6e9".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "paultest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
# Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] expand: %{Packet-Src-IP-Address} -> 217.65.160.124
[detail] expand:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radacct/217.65.160.124/detail-20111208
[detail]
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radacct/217.65.160.124/detail-20111208
[detail] expand: %t -> Thu Dec 8 22:40:12 2011
++[detail] returns ok
++[unix] returns fail
Finished request 2.
Cleaning up request 2 ID 58 with timestamp +22
Going to the next request
Waking up in 0.3 seconds.
Cleaning up request 0 ID 106 with timestamp +17
Ready to process requests.
rad_recv: Accounting-Request packet from host 217.65.160.124 port 1646, id=59,
length=135
Acct-Session-Id = "000002A4"
Framed-Protocol = PPP
Framed-IP-Address = 217.198.56.1
User-Name = "paultest"
Acct-Authentic = RADIUS
Acct-Status-Type = Start
NAS-Port-Type = Virtual
NAS-Port = 0
NAS-Port-Id = "1/0/0/270"
Service-Type = Framed-User
NAS-IP-Address = 217.65.160.124
NAS-Identifier = "new-edge1.thd.prtsystems.net"
Acct-Delay-Time = 9
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address =
217.65.160.124,NAS-IP-Address = 217.65.160.124,Acct-Session-Id =
"000002A4",User-Name = "paultest"'
[acct_unique] Acct-Unique-Session-ID = "af771c19265bb6e9".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "paultest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
# Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] expand: %{Packet-Src-IP-Address} -> 217.65.160.124
[detail] expand:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radacct/217.65.160.124/detail-20111208
[detail]
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radacct/217.65.160.124/detail-20111208
[detail] expand: %t -> Thu Dec 8 22:40:17 2011
++[detail] returns ok
++[unix] returns fail
Finished request 3.
Cleaning up request 3 ID 59 with timestamp +27
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 217.65.160.124 port 1646, id=60,
length=135
Acct-Session-Id = "000002A4"
Framed-Protocol = PPP
Framed-IP-Address = 217.198.56.1
User-Name = "paultest"
Acct-Authentic = RADIUS
Acct-Status-Type = Start
NAS-Port-Type = Virtual
NAS-Port = 0
NAS-Port-Id = "1/0/0/270"
Service-Type = Framed-User
NAS-IP-Address = 217.65.160.124
NAS-Identifier = "new-edge1.thd.prtsystems.net"
Acct-Delay-Time = 14
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address =
217.65.160.124,NAS-IP-Address = 217.65.160.124,Acct-Session-Id =
"000002A4",User-Name = "paultest"'
[acct_unique] Acct-Unique-Session-ID = "af771c19265bb6e9".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "paultest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
# Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] expand: %{Packet-Src-IP-Address} -> 217.65.160.124
[detail] expand:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radacct/217.65.160.124/detail-20111208
[detail]
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radacct/217.65.160.124/detail-20111208
[detail] expand: %t -> Thu Dec 8 22:40:22 2011
++[detail] returns ok
++[unix] returns fail
Finished request 4.
Cleaning up request 4 ID 60 with timestamp +32
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 217.65.160.124 port 1646, id=62,
length=171
Acct-Session-Id = "000002A4"
Framed-Protocol = PPP
Framed-IP-Address = 217.198.56.1
User-Name = "paultest"
Acct-Authentic = RADIUS
Acct-Session-Time = 254
Acct-Input-Octets = 263705
Acct-Output-Octets = 5616726
Acct-Input-Packets = 2973
Acct-Output-Packets = 4254
Acct-Terminate-Cause = User-Request
Acct-Status-Type = Stop
NAS-Port-Type = Virtual
NAS-Port = 0
NAS-Port-Id = "1/0/0/270"
Service-Type = Framed-User
NAS-IP-Address = 217.65.160.124
NAS-Identifier = "new-edge1.thd.prtsystems.net"
Acct-Delay-Time = 0
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address =
217.65.160.124,NAS-IP-Address = 217.65.160.124,Acct-Session-Id =
"000002A4",User-Name = "paultest"'
[acct_unique] Acct-Unique-Session-ID = "af771c19265bb6e9".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "paultest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
# Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] expand: %{Packet-Src-IP-Address} -> 217.65.160.124
[detail] expand:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radacct/217.65.160.124/detail-20111208
[detail]
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radacct/217.65.160.124/detail-20111208
[detail] expand: %t -> Thu Dec 8 22:44:21 2011
++[detail] returns ok
++[unix] returns fail
Finished request 5.
Cleaning up request 5 ID 62 with timestamp +271
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 217.65.160.124 port 1646, id=63,
length=171
Acct-Session-Id = "000002A4"
Framed-Protocol = PPP
Framed-IP-Address = 217.198.56.1
User-Name = "paultest"
Acct-Authentic = RADIUS
Acct-Session-Time = 254
Acct-Input-Octets = 263705
Acct-Output-Octets = 5616726
Acct-Input-Packets = 2973
Acct-Output-Packets = 4254
Acct-Terminate-Cause = User-Request
Acct-Status-Type = Stop
NAS-Port-Type = Virtual
NAS-Port = 0
NAS-Port-Id = "1/0/0/270"
Service-Type = Framed-User
NAS-IP-Address = 217.65.160.124
NAS-Identifier = "new-edge1.thd.prtsystems.net"
Acct-Delay-Time = 4
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address =
217.65.160.124,NAS-IP-Address = 217.65.160.124,Acct-Session-Id =
"000002A4",User-Name = "paultest"'
[acct_unique] Acct-Unique-Session-ID = "af771c19265bb6e9".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "paultest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
# Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] expand: %{Packet-Src-IP-Address} -> 217.65.160.124
[detail] expand:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radacct/217.65.160.124/detail-20111208
[detail]
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radacct/217.65.160.124/detail-20111208
[detail] expand: %t -> Thu Dec 8 22:44:25 2011
++[detail] returns ok
++[unix] returns fail
Finished request 6.
Cleaning up request 6 ID 63 with timestamp +275
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 217.65.160.124 port 1646, id=64,
length=171
Acct-Session-Id = "000002A4"
Framed-Protocol = PPP
Framed-IP-Address = 217.198.56.1
User-Name = "paultest"
Acct-Authentic = RADIUS
Acct-Session-Time = 254
Acct-Input-Octets = 263705
Acct-Output-Octets = 5616726
Acct-Input-Packets = 2973
Acct-Output-Packets = 4254
Acct-Terminate-Cause = User-Request
Acct-Status-Type = Stop
NAS-Port-Type = Virtual
NAS-Port = 0
NAS-Port-Id = "1/0/0/270"
Service-Type = Framed-User
NAS-IP-Address = 217.65.160.124
NAS-Identifier = "new-edge1.thd.prtsystems.net"
Acct-Delay-Time = 9
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address =
217.65.160.124,NAS-IP-Address = 217.65.160.124,Acct-Session-Id =
"000002A4",User-Name = "paultest"'
[acct_unique] Acct-Unique-Session-ID = "af771c19265bb6e9".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "paultest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
# Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] expand: %{Packet-Src-IP-Address} -> 217.65.160.124
[detail] expand:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radacct/217.65.160.124/detail-20111208
[detail]
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radacct/217.65.160.124/detail-20111208
[detail] expand: %t -> Thu Dec 8 22:44:31 2011
++[detail] returns ok
++[unix] returns fail
Finished request 7.
Cleaning up request 7 ID 64 with timestamp +281
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 217.65.160.124 port 1646, id=65,
length=171
Acct-Session-Id = "000002A4"
Framed-Protocol = PPP
Framed-IP-Address = 217.198.56.1
User-Name = "paultest"
Acct-Authentic = RADIUS
Acct-Session-Time = 254
Acct-Input-Octets = 263705
Acct-Output-Octets = 5616726
Acct-Input-Packets = 2973
Acct-Output-Packets = 4254
Acct-Terminate-Cause = User-Request
Acct-Status-Type = Stop
NAS-Port-Type = Virtual
NAS-Port = 0
NAS-Port-Id = "1/0/0/270"
Service-Type = Framed-User
NAS-IP-Address = 217.65.160.124
NAS-Identifier = "new-edge1.thd.prtsystems.net"
Acct-Delay-Time = 14
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address =
217.65.160.124,NAS-IP-Address = 217.65.160.124,Acct-Session-Id =
"000002A4",User-Name = "paultest"'
[acct_unique] Acct-Unique-Session-ID = "af771c19265bb6e9".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "paultest", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
# Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
+- entering group accounting {...}
[detail] expand: %{Packet-Src-IP-Address} -> 217.65.160.124
[detail] expand:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/radacct/217.65.160.124/detail-20111208
[detail]
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /var/log/radacct/217.65.160.124/detail-20111208
[detail] expand: %t -> Thu Dec 8 22:44:35 2011
++[detail] returns ok
++[unix] returns fail
Finished request 8.
Cleaning up request 8 ID 65 with timestamp +285
Going to the next request
Ready to process requests.
^C
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
