Duplicate entries and incorrect accounting and authorization
bdab at hushmail.com
bdab at hushmail.com
Thu Feb 23 16:23:07 CET 2006
I was using freeradius 1.05 with MYSQL 4.0 without any problems.
I've upgraded the OS in my server (freebsd 5.1 to 6.0), upgraded to
freeradius 1.10 and MySQL 4.1, copied the previous working raddb
directory,
initially preserving the same configuration files and I couldn't
get things working back again.
Basically I've got duplicate entries in radpostauth, no entries in
radacct and the NAS does not recognize the successful
authentication even though from the radius server point of view it
seems to get authentication right.
I've read the FAQ (my server has a single NIC), docs in the release
(before, I was using the sqlcounter module but now I've decided to
remove it since radiusd.conf already has the dailycounter and
monthlycounter functionality that I needed) but still I can not get
it right.
Here's the relevant info:
............................................
root at rds# /usr/local/sbin/radiusd -X -y
Starting - reading configuration files ...
reread_config: reading radiusd.conf
Config: including file: /usr/local/etc/raddb/proxy.conf
Config: including file: /usr/local/etc/raddb/clients.conf
Config: including file: /usr/local/etc/raddb/snmp.conf
Config: including file: /usr/local/etc/raddb/sql.conf
main: prefix = "/usr/local"
main: localstatedir = "/var"
main: logdir = "/var/log"
main: libdir = "/usr/local/lib"
main: radacctdir = "/var/log/radacct"
main: hostname_lookups = no
main: max_request_time = 30
main: cleanup_delay = 5
main: max_requests = 1024
main: delete_blocked_requests = 0
main: port = 0
main: allow_core_dumps = no
main: log_stripped_names = no
main: log_file = "/var/log/radius.log"
main: log_auth = yes
main: log_auth_badpass = no
main: log_auth_goodpass = no
main: pidfile = "/var/run/radiusd/radiusd.pid"
main: bind_address = YYY.YYY.YYY.YYY IP address [YYY.YYY.YYY.YYY]
main: user = "(null)"
main: group = "(null)"
main: usercollide = no
main: lower_user = "no"
main: lower_pass = "no"
main: nospace_user = "no"
main: nospace_pass = "no"
main: checkrad = "/usr/local/sbin/checkrad"
main: proxy_requests = yes
proxy: retry_delay = 5
proxy: retry_count = 3
proxy: synchronous = no
proxy: default_fallback = yes
proxy: dead_time = 120
proxy: post_proxy_authorize = no
proxy: wake_all_if_all_dead = no
security: max_attributes = 200
security: reject_delay = 1
security: status_server = no
main: debug_level = 0
read_config_files: reading dictionary
read_config_files: reading naslist
read_config_files: reading clients
read_config_files: reading realms
radiusd: entering modules setup
Module: Library search path is /usr/local/lib
Module: Loaded expr
Module: Instantiated expr (expr)
Module: Loaded PAP
pap: encryption_scheme = "crypt"
Module: Instantiated pap (pap)
Module: Loaded CHAP
Module: Instantiated chap (chap)
Module: Loaded MS-CHAP
mschap: use_mppe = yes
mschap: require_encryption = no
mschap: require_strong = no
mschap: with_ntdomain_hack = no
mschap: passwd = "(null)"
mschap: authtype = "MS-CHAP"
mschap: ntlm_auth = "(null)"
Module: Instantiated mschap (mschap)
Module: Loaded System
unix: cache = no
unix: passwd = "(null)"
unix: shadow = "(null)"
unix: group = "(null)"
unix: radwtmp = "/var/log/radwtmp"
unix: usegroup = no
unix: cache_reload = 600
Module: Instantiated unix (unix)
Module: Loaded preprocess
preprocess: huntgroups = "/usr/local/etc/raddb/huntgroups"
preprocess: hints = "/usr/local/etc/raddb/hints"
preprocess: with_ascend_hack = no
preprocess: ascend_channels_per_line = 23
preprocess: with_ntdomain_hack = no
preprocess: with_specialix_jetstream_hack = no
preprocess: with_cisco_vsa_hack = no
Module: Instantiated preprocess (preprocess)
Module: Loaded detail
detail: detailfile = "/var/log/radacct/%{Client-IP-Address}/auth-
detail-%Y%m%d"
detail: detailperm = 384
detail: dirperm = 493
detail: locking = no
Module: Instantiated detail (auth_log)
Module: Loaded realm
realm: format = "suffix"
realm: delimiter = "@"
realm: ignore_default = no
realm: ignore_null = no
Module: Instantiated realm (suffix)
Module: Loaded SQL
sql: driver = "rlm_sql_mysql"
sql: server = "localhost"
sql: port = ""
sql: login = "root"
sql: password = "password"
sql: radius_db = "radius"
sql: acct_table = "radacct"
sql: acct_table2 = "radacct"
sql: authcheck_table = "radcheck"
sql: authreply_table = "radreply"
sql: groupcheck_table = "radgroupcheck"
sql: groupreply_table = "radgroupreply"
sql: usergroup_table = "usergroup"
sql: nas_table = "nas"
sql: dict_table = "dictionary"
sql: sqltrace = yes
sql: sqltracefile = "/var/log/sqltrace.sql"
sql: readclients = no
sql: deletestalesessions = yes
sql: num_sql_socks = 5
sql: sql_user_name = "%{User-Name}"
sql: default_user_profile = ""
sql: query_on_not_found = no
sql: authorize_check_query = "SELECT id, UserName, Attribute,
Value, op FROM radcheck WHERE Username = '%{SQL-
User-Name}' ORDER BY id"
sql: authorize_reply_query = "SELECT id, UserName, Attribute,
Value, op FROM radreply WHERE Username = '%{SQL-
User-Name}' ORDER BY id"
sql: authorize_group_check_query = "SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,rad
groupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup
WHERE usergroup.Username = '%{SQL-User-Name}' AND
usergroup.GroupName = radgroupcheck.GroupName ORDER BY
radgroupcheck.id"
sql: authorize_group_reply_query = "SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,rad
groupreply.Value,radgroupreply.op FROM radgroupreply,usergroup
WHERE usergroup.Username = '%{SQL-User-Name}' AND
usergroup.GroupName = radgroupreply.GroupName ORDER BY
radgroupreply.id"
sql: accounting_onoff_query = "UPDATE radacct SET
AcctStopTime='%S', AcctSessionTime=unix_timestamp('%S') -
unix_timestamp(AcctStartTime), AcctTerminateCause='%{Acct-Terminate-
Cause}', AcctStopDelay = '%{Acct-Delay-Time}' WHERE
AcctSessionTime=0 AND AcctStopTime=0 AND NASIPAddress= '%{NAS-IP-
Address}' AND AcctStartTime <= '%S'"
sql: accounting_update_query = "UPDATE radacct SET
FramedIPAddress = '%{Framed-IP-Address}', AcctSessionTime
= '%{Acct-Session-Time}', AcctInputOctets = '%{Acct-Input-
Octets}', AcctOutputOctets = '%{Acct-Output-Octets}'
WHERE AcctSessionId = '%{Acct-Session-Id}' AND
UserName = '%{SQL-User-Name}' AND NASIPAddress= '%{NAS-IP-
Address}'"
sql: 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) 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-Octets}', '%{Acct-Output-Octets}', '%{Called-Station-
Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-
Protocol}', '%{Framed-IP-Address}', '0')"
sql: 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) values('%{Acct-
Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}',
'%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}',
'%S', '0', '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0',
'0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '',
'%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',
'%{Acct-Delay-Time}', '0')"
sql: accounting_start_query_alt = "UPDATE radacct SET
AcctStartTime = '%S', AcctStartDelay = '%{Acct-Delay-Time}',
ConnectInfo_start = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-
Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress =
'%{NAS-IP-Address}'"
sql: accounting_stop_query = "UPDATE radacct SET AcctStopTime =
'%S', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets =
'%{Acct-Input-Octets}', AcctOutputOctets = '%{Acct-Output-Octets}',
AcctTerminateCause = '%{Acct-Terminate-Cause}', AcctStopDelay =
'%{Acct-Delay-Time}', ConnectInfo_stop = '%{Connect-Info}' WHERE
AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-
Name}' AND NASIPAddress = '%{NAS-IP-Address}'"
sql: 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-Octets}',
'%{Acct-Output-Octets}', '%{Called-Station-Id}', '%{Calling-Station-
Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-
Protocol}', '%{Framed-IP-Address}', '0', '%{Acct-Delay-Time}')"
sql: group_membership_query = "SELECT GroupName FROM usergroup
WHERE UserName='%{SQL-User-Name}'"
sql: connect_failure_retry_delay = 60
sql: simul_count_query = ""
sql: simul_verify_query = "SELECT RadAcctId, AcctSessionId,
UserName, NASIPAddress, NASPortId, FramedIPAddress,
CallingStationId, FramedProtocol FROM radacct WHERE UserName='%{SQL-
User-Name}' AND AcctStopTime = 0"
sql: postauth_table = "radpostauth"
sql: postauth_query = "INSERT into radpostauth (id, user, pass,
reply, date) values ('', '%{User-Name}', '%{User-Password:-Chap-
Password}', '%{reply:Packet-Type}', NOW())"
sql: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-
_: /"
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded
and linked
rlm_sql (sql): Attempting to connect to root at 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
Module: Instantiated sql (sql)
Module: Loaded SQL Counter
sqlcounter: counter-name = "Daily-Session-Time"
sqlcounter: check-name = "Max-Daily-Session"
sqlcounter: key = "User-Name"
sqlcounter: sqlmod-inst = "sql"
sqlcounter: query = "SELECT SUM(AcctSessionTime -
GREATEST((%b - UNIX_TIMESTAMP(AcctStartTime)), 0)) FROM
radacct WHERE UserName='%{%k}' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'"
sqlcounter: reset = "daily"
sqlcounter: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-
_: /"
rlm_sqlcounter: Counter attribute Daily-Session-Time is number 1830
rlm_sqlcounter: Check attribute Max-Daily-Session is number 1831
rlm_sqlcounter: Current Time: 1140529038 [2006-02-21 10:37:18],
Next reset 1140577200 [2006-02-22 00:00:00]
rlm_sqlcounter: Current Time: 1140529038 [2006-02-21 10:37:18],
Prev reset 1140490800 [2006-02-21 00:00:00]
Module: Instantiated sqlcounter (dailycounter)
sqlcounter: counter-name = "Monthly-Session-Time"
sqlcounter: check-name = "Max-Monthly-Session"
sqlcounter: key = "User-Name"
sqlcounter: sqlmod-inst = "sql"
sqlcounter: query = "SELECT SUM(AcctSessionTime -
GREATEST((%b - UNIX_TIMESTAMP(AcctStartTime)), 0)) FROM
radacct WHERE UserName='%{%k}' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'"
sqlcounter: reset = "monthly"
sqlcounter: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-
_: /"
rlm_sqlcounter: Counter attribute Monthly-Session-Time is number
1832
rlm_sqlcounter: Check attribute Max-Monthly-Session is number 1833
rlm_sqlcounter: Current Time: 1140529038 [2006-02-21 10:37:18],
Next reset 1141182000 [2006-03-01 00:00:00]
rlm_sqlcounter: Current Time: 1140529038 [2006-02-21 10:37:18],
Prev reset 1138762800 [2006-02-01 00:00:00]
Module: Instantiated sqlcounter (monthlycounter)
Module: Loaded Acct-Unique-Session-Id
acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address,
Client-IP-Address, NAS-Port"
Module: Instantiated acct_unique (acct_unique)
Module: Loaded files
files: usersfile = "/usr/local/etc/raddb/users"
files: acctusersfile = "/usr/local/etc/raddb/acct_users"
files: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"
files: compat = "no"
Module: Instantiated files (files)
detail: detailfile = "/var/log/radacct/%{Client-IP-Address}/detail-
%Y%m%d"
detail: detailperm = 384
detail: dirperm = 493
detail: locking = no
Module: Instantiated detail (detail)
Module: Loaded radutmp
radutmp: filename = "/var/log/radutmp"
radutmp: username = "%{User-Name}"
radutmp: case_sensitive = yes
radutmp: check_with_nas = yes
radutmp: perm = 384
radutmp: callerid = yes
Module: Instantiated radutmp (radutmp)
Listening on authentication YYY.YYY.YYY.YYY:1812
Listening on accounting YYY.YYY.YYY.YYY:1813
Ready to process requests.
rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX:32770,
id=0, length=216
User-Name = "test0001"
CHAP-Challenge = 0xbb9b786a9857418d627cec741434bf5a
CHAP-Password = 0x00e71611e921e4fd929f9bcdd5aeff2172
NAS-IP-Address = 0.0.0.0
Service-Type = Login-User
Framed-IP-Address = 192.168.182.3
Calling-Station-Id = "00-04-23-63-0F-A7"
Called-Station-Id = "00-13-46-70-3E-CF"
NAS-Identifier = "mynas"
Acct-Session-Id = "43fb0eac00000000"
NAS-Port-Type = Wireless-802.11
NAS-Port = 0
Message-Authenticator = 0xda8261dfb84b5ea5f4ff88c67780d76d
WISPr-Logoff-URL = "http://192.168.182.1:3990/logoff"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
modcall[authorize]: module "preprocess" returns ok for request 0
radius_xlat: '/var/log/radacct/XXX.XXX.XXX.XXX/auth-detail-
20060221'
rlm_detail: /var/log/radacct/%{Client-IP-Address}/auth-detail-
%Y%m%d expands to /var/log/radacct/XXX.XXX.XXX.XXX/auth-detail-
20060221
modcall[authorize]: module "auth_log" returns ok for request 0
rlm_chap: Setting 'Auth-Type := CHAP'
modcall[authorize]: module "chap" returns ok for request 0
modcall[authorize]: module "mschap" returns noop for request 0
rlm_realm: No '@' in User-Name = "test0001", looking up realm
NULL
rlm_realm: No such realm "NULL"
modcall[authorize]: module "suffix" returns noop for request 0
radius_xlat: 'test0001'
rlm_sql (sql): sql_set_user escaped user --> 'test0001'
radius_xlat: 'SELECT id, UserName, Attribute, Value, op
FROM radcheck WHERE Username = 'test0001' ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op
FROM radcheck WHERE Username = 'test0001'
ORDER BY id
radius_xlat: 'SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,rad
groupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup
WHERE usergroup.Username = 'test0001' AND usergroup.GroupName =
radgroupcheck.GroupName ORDER BY radgroupcheck.id'
rlm_sql_mysql: query: SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,rad
groupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup
WHERE usergroup.Username = 'test0001' AND usergroup.GroupName =
radgroupcheck.GroupName ORDER BY radgroupcheck.id
radius_xlat: 'SELECT id, UserName, Attribute, Value, op
FROM radreply WHERE Username = 'test0001' ORDER BY id'
rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op
FROM radreply WHERE Username = 'test0001'
ORDER BY id
radius_xlat: 'SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,rad
groupreply.Value,radgroupreply.op FROM radgroupreply,usergroup
WHERE usergroup.Username = 'test0001' AND usergroup.GroupName =
radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql_mysql: query: SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,rad
groupreply.Value,radgroupreply.op FROM radgroupreply,usergroup
WHERE usergroup.Username = 'test0001' AND usergroup.GroupName =
radgroupreply.GroupName ORDER BY radgroupreply.id
rlm_sql (sql): Released sql socket id: 4
modcall[authorize]: module "sql" returns ok for request 0
rlm_sqlcounter: Entering module authorize code
sqlcounter_expand: 'SELECT SUM(AcctSessionTime -
GREATEST((1140490800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='%{User-Name}' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1140490800''
radius_xlat: 'SELECT SUM(AcctSessionTime -
GREATEST((1140490800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1140490800''
sqlcounter_expand: '%{sql:SELECT SUM(AcctSessionTime -
GREATEST((1140490800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime >
'1140490800'}'
radius_xlat: Running registered xlat function of module sql for
string 'SELECT SUM(AcctSessionTime -
GREATEST((1140490800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1140490800''
rlm_sql (sql): - sql_xlat
radius_xlat: 'test0001'
rlm_sql (sql): sql_set_user escaped user --> 'test0001'
radius_xlat: 'SELECT SUM(AcctSessionTime -
GREATEST((1140490800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1140490800''
radius_xlat: '/var/log/sqltrace.sql'
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql_mysql: query: SELECT SUM(AcctSessionTime -
GREATEST((1140490800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1140490800'
rlm_sql (sql): row[0] returned NULL
rlm_sql (sql): Released sql socket id: 3
radius_xlat: ''
rlm_sqlcounter: (Check item - counter) is greater than zero
rlm_sqlcounter: Authorized user test0001, check_item=54000,
counter=0
rlm_sqlcounter: Sent Reply-Item for user test0001, Type=Session-
Timeout, value=102112
modcall[authorize]: module "dailycounter" returns ok for request 0
rlm_sqlcounter: Entering module authorize code
sqlcounter_expand: 'SELECT SUM(AcctSessionTime -
GREATEST((1138762800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='%{User-Name}' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1138762800''
radius_xlat: 'SELECT SUM(AcctSessionTime -
GREATEST((1138762800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1138762800''
sqlcounter_expand: '%{sql:SELECT SUM(AcctSessionTime -
GREATEST((1138762800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime >
'1138762800'}'
radius_xlat: Running registered xlat function of module sql for
string 'SELECT SUM(AcctSessionTime -
GREATEST((1138762800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1138762800''
rlm_sql (sql): - sql_xlat
radius_xlat: 'test0001'
rlm_sql (sql): sql_set_user escaped user --> 'test0001'
radius_xlat: 'SELECT SUM(AcctSessionTime -
GREATEST((1138762800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1138762800''
radius_xlat: '/var/log/sqltrace.sql'
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql_mysql: query: SELECT SUM(AcctSessionTime -
GREATEST((1138762800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1138762800'
rlm_sql (sql): row[0] returned NULL
rlm_sql (sql): Released sql socket id: 2
radius_xlat: ''
rlm_sqlcounter: (Check item - counter) is greater than zero
rlm_sqlcounter: Authorized user test0001, check_item=54000,
counter=0
rlm_sqlcounter: Sent Reply-Item for user test0001, Type=Session-
Timeout, value=54000
modcall[authorize]: module "monthlycounter" returns ok for
request 0
modcall: leaving group authorize (returns ok) for request 0
rad_check_password: Found Auth-Type Local
auth: type Local
auth: user supplied CHAP-Password matches local User-Password
Login OK: [test0001] (from client mynas port 0 cli 00-04-23-63-0F-
A7)
Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 0
rlm_sql (sql): Processing sql_postauth
radius_xlat: 'test0001'
rlm_sql (sql): sql_set_user escaped user --> 'test0001'
radius_xlat: 'INSERT into radpostauth (id, user, pass, reply,
date) values ('', 'test0001', 'Chap-Password', 'Access-Accept',
NOW())'
radius_xlat: '/var/log/sqltrace.sql'
rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth
(id, user, pass, reply, date) values ('', 'test0001', 'Chap-
Password', 'Access-Accept', NOW())
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql_mysql: query: INSERT into radpostauth (id, user, pass,
reply, date) values ('', 'test0001', 'Chap-Password', 'Access-
Accept', NOW())
rlm_sql (sql): Released sql socket id: 1
modcall[post-auth]: module "sql" returns ok for request 0
modcall: leaving group post-auth (returns ok) for request 0
Sending Access-Accept of id 0 to XXX.XXX.XXX.XXX port 32770
Session-Timeout = 54000
Finished request 0
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX:32770,
id=0, length=216
Sending duplicate reply to client mynas:32770 - ID: 0
Re-sending Access-Accept of id 0 to XXX.XXX.XXX.XXX port 32770
--- Walking the entire request list ---
Waking up in 4 seconds...
rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX:32770,
id=0, length=216
Sending duplicate reply to client mynas:32770 - ID: 0
Re-sending Access-Accept of id 0 to XXX.XXX.XXX.XXX port 32770
--- Walking the entire request list ---
Waking up in 3 seconds...
rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX:32770,
id=0, length=216
Sending duplicate reply to client mynas:32770 - ID: 0
Re-sending Access-Accept of id 0 to XXX.XXX.XXX.XXX port 32770
--- Walking the entire request list ---
Waking up in 1 seconds...
--- Walking the entire request list ---
Cleaning up request 0 ID 0 with timestamp 43fb17c0
Nothing to do. Sleeping until we see a request.
rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX:32770,
id=0, length=216
User-Name = "test0001"
CHAP-Challenge = 0xbb9b786a9857418d627cec741434bf5a
CHAP-Password = 0x00e71611e921e4fd929f9bcdd5aeff2172
NAS-IP-Address = 0.0.0.0
Service-Type = Login-User
Framed-IP-Address = 192.168.182.3
Calling-Station-Id = "00-04-23-63-0F-A7"
Called-Station-Id = "00-13-46-70-3E-CF"
NAS-Identifier = "mynas"
Acct-Session-Id = "43fb0eac00000000"
NAS-Port-Type = Wireless-802.11
NAS-Port = 0
Message-Authenticator = 0xda8261dfb84b5ea5f4ff88c67780d76d
WISPr-Logoff-URL = "http://192.168.182.1:3990/logoff"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 1
modcall[authorize]: module "preprocess" returns ok for request 1
radius_xlat: '/var/log/radacct/XXX.XXX.XXX.XXX/auth-detail-
20060221'
rlm_detail: /var/log/radacct/%{Client-IP-Address}/auth-detail-
%Y%m%d expands to /var/log/radacct/XXX.XXX.XXX.XXX/auth-detail-
20060221
modcall[authorize]: module "auth_log" returns ok for request 1
rlm_chap: Setting 'Auth-Type := CHAP'
modcall[authorize]: module "chap" returns ok for request 1
modcall[authorize]: module "mschap" returns noop for request 1
rlm_realm: No '@' in User-Name = "test0001", looking up realm
NULL
rlm_realm: No such realm "NULL"
modcall[authorize]: module "suffix" returns noop for request 1
radius_xlat: 'test0001'
rlm_sql (sql): sql_set_user escaped user --> 'test0001'
radius_xlat: 'SELECT id, UserName, Attribute, Value, op
FROM radcheck WHERE Username = 'test0001' ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 0
rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op
FROM radcheck WHERE Username = 'test0001'
ORDER BY id
radius_xlat: 'SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,rad
groupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup
WHERE usergroup.Username = 'test0001' AND usergroup.GroupName =
radgroupcheck.GroupName ORDER BY radgroupcheck.id'
rlm_sql_mysql: query: SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,rad
groupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup
WHERE usergroup.Username = 'test0001' AND usergroup.GroupName =
radgroupcheck.GroupName ORDER BY radgroupcheck.id
radius_xlat: 'SELECT id, UserName, Attribute, Value, op
FROM radreply WHERE Username = 'test0001' ORDER BY id'
rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op
FROM radreply WHERE Username = 'test0001'
ORDER BY id
radius_xlat: 'SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,rad
groupreply.Value,radgroupreply.op FROM radgroupreply,usergroup
WHERE usergroup.Username = 'test0001' AND usergroup.GroupName =
radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql_mysql: query: SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,rad
groupreply.Value,radgroupreply.op FROM radgroupreply,usergroup
WHERE usergroup.Username = 'test0001' AND usergroup.GroupName =
radgroupreply.GroupName ORDER BY radgroupreply.id
rlm_sql (sql): Released sql socket id: 0
modcall[authorize]: module "sql" returns ok for request 1
rlm_sqlcounter: Entering module authorize code
sqlcounter_expand: 'SELECT SUM(AcctSessionTime -
GREATEST((1140490800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='%{User-Name}' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1140490800''
radius_xlat: 'SELECT SUM(AcctSessionTime -
GREATEST((1140490800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1140490800''
sqlcounter_expand: '%{sql:SELECT SUM(AcctSessionTime -
GREATEST((1140490800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime >
'1140490800'}'
radius_xlat: Running registered xlat function of module sql for
string 'SELECT SUM(AcctSessionTime -
GREATEST((1140490800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1140490800''
rlm_sql (sql): - sql_xlat
radius_xlat: 'test0001'
rlm_sql (sql): sql_set_user escaped user --> 'test0001'
radius_xlat: 'SELECT SUM(AcctSessionTime -
GREATEST((1140490800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1140490800''
radius_xlat: '/var/log/sqltrace.sql'
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql_mysql: query: SELECT SUM(AcctSessionTime -
GREATEST((1140490800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1140490800'
rlm_sql (sql): row[0] returned NULL
rlm_sql (sql): Released sql socket id: 4
radius_xlat: ''
rlm_sqlcounter: (Check item - counter) is greater than zero
rlm_sqlcounter: Authorized user test0001, check_item=54000,
counter=0
rlm_sqlcounter: Sent Reply-Item for user test0001, Type=Session-
Timeout, value=102106
modcall[authorize]: module "dailycounter" returns ok for request 1
rlm_sqlcounter: Entering module authorize code
sqlcounter_expand: 'SELECT SUM(AcctSessionTime -
GREATEST((1138762800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='%{User-Name}' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1138762800''
radius_xlat: 'SELECT SUM(AcctSessionTime -
GREATEST((1138762800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1138762800''
sqlcounter_expand: '%{sql:SELECT SUM(AcctSessionTime -
GREATEST((1138762800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime >
'1138762800'}'
radius_xlat: Running registered xlat function of module sql for
string 'SELECT SUM(AcctSessionTime -
GREATEST((1138762800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1138762800''
rlm_sql (sql): - sql_xlat
radius_xlat: 'test0001'
rlm_sql (sql): sql_set_user escaped user --> 'test0001'
radius_xlat: 'SELECT SUM(AcctSessionTime -
GREATEST((1138762800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1138762800''
radius_xlat: '/var/log/sqltrace.sql'
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql_mysql: query: SELECT SUM(AcctSessionTime -
GREATEST((1138762800 - UNIX_TIMESTAMP(AcctStartTime)), 0))
FROM radacct WHERE UserName='test0001' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1138762800'
rlm_sql (sql): row[0] returned NULL
rlm_sql (sql): Released sql socket id: 3
radius_xlat: ''
rlm_sqlcounter: (Check item - counter) is greater than zero
rlm_sqlcounter: Authorized user test0001, check_item=54000,
counter=0
rlm_sqlcounter: Sent Reply-Item for user test0001, Type=Session-
Timeout, value=54000
modcall[authorize]: module "monthlycounter" returns ok for
request 1
modcall: leaving group authorize (returns ok) for request 1
rad_check_password: Found Auth-Type Local
auth: type Local
auth: user supplied CHAP-Password matches local User-Password
Login OK: [test0001] (from client mynas port 0 cli 00-04-23-63-0F-
A7)
Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 1
rlm_sql (sql): Processing sql_postauth
radius_xlat: 'test0001'
rlm_sql (sql): sql_set_user escaped user --> 'test0001'
radius_xlat: 'INSERT into radpostauth (id, user, pass, reply,
date) values ('', 'test0001', 'Chap-Password', 'Access-Accept',
NOW())'
radius_xlat: '/var/log/sqltrace.sql'
rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth
(id, user, pass, reply, date) values ('', 'test0001', 'Chap-
Password', 'Access-Accept', NOW())
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql_mysql: query: INSERT into radpostauth (id, user, pass,
reply, date) values ('', 'test0001', 'Chap-Password', 'Access-
Accept', NOW())
rlm_sql (sql): Released sql socket id: 2
modcall[post-auth]: module "sql" returns ok for request 1
modcall: leaving group post-auth (returns ok) for request 1
Sending Access-Accept of id 0 to XXX.XXX.XXX.XXX port 32770
Session-Timeout = 54000
Finished request 1
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX:32770,
id=0, length=216
Sending duplicate reply to client mynas:32770 - ID: 0
Re-sending Access-Accept of id 0 to XXX.XXX.XXX.XXX port 32770
--- Walking the entire request list ---
Waking up in 4 seconds...
rad_recv: Access-Request packet from host XXX.XXX.XXX.XXX:32770,
id=0, length=216
Sending duplicate reply to client mynas:32770 - ID: 0
Re-sending Access-Accept of id 0 to XXX.XXX.XXX.XXX port 32770
--- Walking the entire request list ---
Waking up in 3 seconds...
--- Walking the entire request list ---
Cleaning up request 1 ID 0 with timestamp 43fb17c6
Nothing to do. Sleeping until we see a request.
..................................................
Entries in radius DB:
mysql> SELECT * FROM radcheck;
+-----+----------+---------------------+----+-------+
| id | UserName | Attribute | op | Value |
+-----+----------+---------------------+----+-------+
| 459 | test0001 | Password | == | 0001 |
| 461 | test0001 | Max-Monthly-Session | := | 54000 |
| 463 | test0001 | Max-Daily-Session | := | 54000 |
+-----+----------+---------------------+----+-------+
3 rows in set (0.00 sec)
mysql> SELECT * FROM radpostauth;
+----+----------+---------------+---------------+-------------------
--+
| id | user | pass | reply | date
|
+----+----------+---------------+---------------+-------------------
--+
| 35 | test0001 | Chap-Password | Access-Accept | 2006-02-21
10:12:12 |
| 36 | test0001 | Chap-Password | Access-Accept | 2006-02-21
10:12:18 |
+----+----------+---------------+---------------+-------------------
--+
2 rows in set (0.00 sec)
mysql> SELECT * FROM usergroup;
+-----+----------+-----------+
| id | UserName | GroupName |
+-----+----------+-----------+
| 115 | test0001 | dynamic |
+-----+----------+-----------+
1 row in set (0.00 sec)
...................................................
this is my radiusd.conf
prefix = /usr/local
exec_prefix = ${prefix}
sysconfdir = ${prefix}/etc
localstatedir = /var
sbindir = ${exec_prefix}/sbin
logdir = /var/log
raddbdir = ${sysconfdir}/raddb
radacctdir = ${logdir}/radacct
confdir = ${raddbdir}
run_dir = ${localstatedir}/run/radiusd
log_file = ${logdir}/radius.log
libdir = ${exec_prefix}/lib
pidfile = ${run_dir}/radiusd.pid
max_request_time = 30
delete_blocked_requests = no
cleanup_delay = 5
max_requests = 1024
bind_address = YYY.YYY.YYY.YYY
port = 0
hostname_lookups = no
allow_core_dumps = no
regular_expressions = yes
extended_expressions = yes
log_stripped_names = no
log_auth = yes
log_auth_badpass = no
log_auth_goodpass = no
usercollide = no
lower_user = no
lower_pass = no
nospace_user = no
nospace_pass = no
checkrad = ${sbindir}/checkrad
security {
max_attributes = 200
reject_delay = 1
status_server = no
}
proxy_requests = yes
$INCLUDE ${confdir}/proxy.conf
$INCLUDE ${confdir}/clients.conf
snmp = no
$INCLUDE ${confdir}/snmp.conf
thread pool {
start_servers = 5
max_servers = 32
min_spare_servers = 3
max_spare_servers = 10
max_requests_per_server = 0
}
modules {
pap {
encryption_scheme = crypt
}
chap {
authtype = CHAP
}
pam {
pam_auth = radiusd
}
unix {
cache = no
cache_reload = 600
radwtmp = ${logdir}/radwtmp
}
mschap {
authtype = MS-CHAP
}
ldap {
server = "ldap.your.domain"
basedn = "o=My Org,c=UA"
filter = "(uid=%{Stripped-User-Name:-%{User-Name}})"
start_tls = no
access_attr = "dialupAccess"
dictionary_mapping = ${raddbdir}/ldap.attrmap
ldap_connections_number = 5
timeout = 4
timelimit = 3
net_timeout = 1
}
realm IPASS {
format = prefix
delimiter = "/"
ignore_default = no
ignore_null = no
}
realm suffix {
format = suffix
delimiter = "@"
ignore_default = no
ignore_null = no
}
realm realmpercent {
format = suffix
delimiter = "%"
ignore_default = no
ignore_null = no
}
realm ntdomain {
format = prefix
delimiter = "\\"
ignore_default = no
ignore_null = no
}
checkval {
item-name = Calling-Station-Id
check-name = Calling-Station-Id
data-type = string
}
preprocess {
huntgroups = ${confdir}/huntgroups
hints = ${confdir}/hints
with_ascend_hack = no
ascend_channels_per_line = 23
with_ntdomain_hack = no
with_specialix_jetstream_hack = no
with_cisco_vsa_hack = no
}
files {
usersfile = ${confdir}/users
acctusersfile = ${confdir}/acct_users
preproxy_usersfile = ${confdir}/preproxy_users
compat = no
}
detail {
detailfile = ${radacctdir}/%{Client-IP-Address}/detail-%Y%m%d
detailperm = 0600
}
detail auth_log {
detailfile = ${radacctdir}/%{Client-IP-Address}/auth-detail-
%Y%m%d
detailperm = 0600
}
acct_unique {
key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-
Address, NAS-Port"
}
$INCLUDE ${confdir}/sql.conf
radutmp {
filename = ${logdir}/radutmp
username = %{User-Name}
case_sensitive = yes
check_with_nas = yes
perm = 0600
callerid = "yes"
}
radutmp sradutmp {
filename = ${logdir}/sradutmp
perm = 0644
callerid = "no"
}
attr_filter {
attrsfile = ${confdir}/attrs
}
counter daily {
filename = ${raddbdir}/db.daily
key = User-Name
count-attribute = Acct-Session-Time
reset = daily
counter-name = Daily-Session-Time
check-name = Max-Daily-Session
allowed-servicetype = Framed-User
cache-size = 5000
}
sqlcounter dailycounter {
counter-name = Daily-Session-Time
check-name = Max-Daily-Session
sqlmod-inst = sql
key = User-Name
reset = daily
query = "SELECT SUM(AcctSessionTime - \
GREATEST((%b - UNIX_TIMESTAMP(AcctStartTime)), 0))
\
FROM radacct WHERE UserName='%{%k}' AND \
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime >
'%b'"
}
sqlcounter monthlycounter {
counter-name = Monthly-Session-Time
check-name = Max-Monthly-Session
sqlmod-inst = sql
key = User-Name
reset = monthly
query = "SELECT SUM(AcctSessionTime - \
GREATEST((%b - UNIX_TIMESTAMP(AcctStartTime)), 0))
\
FROM radacct WHERE UserName='%{%k}' AND \
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime >
'%b'"
}
always fail {
rcode = fail
}
always reject {
rcode = reject
}
always ok {
rcode = ok
simulcount = 0
mpp = no
}
expr {
}
digest {
}
exec {
wait = yes
input_pairs = request
}
exec echo {
wait = yes
program = "/bin/echo %{User-Name}"
input_pairs = request
output_pairs = reply
}
ippool main_pool {
range-start = 192.168.1.1
range-stop = 192.168.3.254
netmask = 255.255.255.0
cache-size = 800
session-db = ${raddbdir}/db.ippool
ip-index = ${raddbdir}/db.ipindex
override = no
maximum-timeout = 0
}
}
instantiate {
expr
}
authorize {
preprocess
auth_log
chap
mschap
suffix
sql
dailycounter
monthlycounter
}
authenticate {
Auth-Type PAP {
pap
}
Auth-Type CHAP {
chap
}
Auth-Type MS-CHAP {
mschap
}
unix
}
preacct {
preprocess
acct_unique
suffix
files
}
accounting {
detail
unix
radutmp
sql
}
session {
radutmp
}
post-auth {
sql
}
pre-proxy {
}
post-proxy {
}
............................................
Any help would be most appreciated.
thanks!
Bill
Concerned about your privacy? Instantly send FREE secure email, no account required
http://www.hushmail.com/send?l=480
Get the best prices on SSL certificates from Hushmail
https://www.hushssl.com?l=485
More information about the Freeradius-Users
mailing list