Newslists
Keith Dovale - HostworX.co.za
keith at hostworx.co.za
Fri Feb 8 16:40:37 CET 2008
Ok you asked for the debug log here it is.
Fri Feb 8 17:24:47 2008 : Info: Starting - reading configuration files ...
Fri Feb 8 17:24:47 2008 : Debug: reread_config: reading radiusd.conf
Fri Feb 8 17:24:47 2008 : Debug: Config: including file:
../etc/raddb/proxy.conf
Fri Feb 8 17:24:47 2008 : Debug: Config: including file:
../etc/raddb/clients.conf
Fri Feb 8 17:24:47 2008 : Debug: Config: including file:
../etc/raddb/snmp.conf
Fri Feb 8 17:24:47 2008 : Debug: Config: including file:
../etc/raddb/sql.conf
Fri Feb 8 17:24:47 2008 : Debug: main: prefix = ".."
Fri Feb 8 17:24:47 2008 : Debug: main: localstatedir = "../var"
Fri Feb 8 17:24:47 2008 : Debug: main: logdir = "../var/log/radius"
Fri Feb 8 17:24:47 2008 : Debug: main: libdir = "../lib"
Fri Feb 8 17:24:47 2008 : Debug: main: radacctdir =
"../var/log/radius/radacct"
Fri Feb 8 17:24:47 2008 : Debug: main: hostname_lookups = no
Fri Feb 8 17:24:47 2008 : Debug: main: max_request_time = 60
Fri Feb 8 17:24:47 2008 : Debug: main: cleanup_delay = 6
Fri Feb 8 17:24:47 2008 : Debug: main: max_requests = 25600
Fri Feb 8 17:24:47 2008 : Debug: main: delete_blocked_requests = 0
Fri Feb 8 17:24:47 2008 : Debug: main: port = 0
Fri Feb 8 17:24:47 2008 : Debug: main: allow_core_dumps = no
Fri Feb 8 17:24:47 2008 : Debug: main: log_stripped_names = no
Fri Feb 8 17:24:47 2008 : Debug: main: log_file =
"../var/log/radius/radius.log"
Fri Feb 8 17:24:47 2008 : Debug: main: log_auth = yes
Fri Feb 8 17:24:47 2008 : Debug: main: log_auth_badpass = yes
Fri Feb 8 17:24:47 2008 : Debug: main: log_auth_goodpass = yes
Fri Feb 8 17:24:47 2008 : Debug: main: pidfile =
"../var/run/radiusd/radiusd.pid"
Fri Feb 8 17:24:47 2008 : Debug: main: bind_address = xx.xx.xx.xx IP
address [xx.xx.xx.xx]
Fri Feb 8 17:24:47 2008 : Debug: main: user = "(null)"
Fri Feb 8 17:24:47 2008 : Debug: main: group = "(null)"
Fri Feb 8 17:24:47 2008 : Debug: main: usercollide = no
Fri Feb 8 17:24:47 2008 : Debug: main: lower_user = "after"
Fri Feb 8 17:24:47 2008 : Debug: main: lower_pass = "no"
Fri Feb 8 17:24:47 2008 : Debug: main: nospace_user = "after"
Fri Feb 8 17:24:47 2008 : Debug: main: nospace_pass = "before"
Fri Feb 8 17:24:47 2008 : Debug: main: checkrad = "../sbin/checkrad"
Fri Feb 8 17:24:47 2008 : Debug: main: proxy_requests = yes
Fri Feb 8 17:24:47 2008 : Debug: proxy: retry_delay = 5
Fri Feb 8 17:24:47 2008 : Debug: proxy: retry_count = 3
Fri Feb 8 17:24:47 2008 : Debug: proxy: synchronous = no
Fri Feb 8 17:24:47 2008 : Debug: proxy: default_fallback = yes
Fri Feb 8 17:24:47 2008 : Debug: proxy: dead_time = 120
Fri Feb 8 17:24:47 2008 : Debug: proxy: post_proxy_authorize = no
Fri Feb 8 17:24:47 2008 : Debug: proxy: wake_all_if_all_dead = no
Fri Feb 8 17:24:47 2008 : Debug: security: max_attributes = 200
Fri Feb 8 17:24:47 2008 : Debug: security: reject_delay = 1
Fri Feb 8 17:24:47 2008 : Debug: security: status_server = no
Fri Feb 8 17:24:47 2008 : Debug: main: debug_level = 0
Fri Feb 8 17:24:47 2008 : Debug: read_config_files: reading dictionary
Fri Feb 8 17:24:47 2008 : Debug: read_config_files: reading naslist
Fri Feb 8 17:24:47 2008 : Info: Using deprecated naslist file. Support for
this will go away soon.
Fri Feb 8 17:24:47 2008 : Debug: read_config_files: reading clients
Fri Feb 8 17:24:47 2008 : Debug: read_config_files: reading realms
Fri Feb 8 17:24:47 2008 : Debug: radiusd: entering modules setup
Fri Feb 8 17:24:47 2008 : Debug: Module: Library search path is ../lib
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded exec
Fri Feb 8 17:24:47 2008 : Debug: exec: wait = yes
Fri Feb 8 17:24:47 2008 : Debug: exec: program = "(null)"
Fri Feb 8 17:24:47 2008 : Debug: exec: input_pairs = "request"
Fri Feb 8 17:24:47 2008 : Debug: exec: output_pairs = "(null)"
Fri Feb 8 17:24:47 2008 : Debug: exec: packet_type = "(null)"
Fri Feb 8 17:24:47 2008 : Info: rlm_exec: Wait=yes but no output defined.
Did you mean output=none?
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated exec (exec)
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded expr
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated expr (expr)
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded SQL Counter
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: counter-name =
"Monthly-Traffic-UnShaped"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: check-name =
"Max-Monthly-Blended-UnShaped"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: reply-name =
"Session-Timeout"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: key = "User-Name"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: sqlmod-inst = "sql"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: query = "SELECT IF((SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='%{%k}' AND Class REGEXP '^NU' AND UNIX_TIMESTAMP(AcctStartTime) +
AcctSessionTime > '%b'),(SELECT (sum(AcctInputOctets) +
SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='%{%k}' AND Class
REGEXP '^NU' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'),0)"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: reset = "monthly"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Reply attribute
Session-Timeout is number 27
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Counter attribute
Monthly-Traffic-UnShaped is number 3005
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Check attribute
Max-Monthly-Blended-UnShaped is number 3006
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Current Time: 1202484287
[2008-02-08 17:24:47], Next reset 1204322400 [2008-03-01 00:00:00]
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Current Time: 1202484287
[2008-02-08 17:24:47], Prev reset 1201816800 [2008-02-01 00:00:00]
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated sqlcounter
(MonthlyUnShaped)
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: counter-name =
"Monthly-Traffic-Shaped"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: check-name =
"Max-Monthly-Blended-Shaped"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: reply-name =
"Session-Timeout"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: key = "User-Name"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: sqlmod-inst = "sql"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: query = "SELECT IF((SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='%{%k}' AND Class REGEXP '^NS' AND UNIX_TIMESTAMP(AcctStartTime) +
AcctSessionTime > '%b'),(SELECT (sum(AcctInputOctets) +
SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='%{%k}' AND Class
REGEXP '^NS' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'),0)"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: reset = "monthly"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Reply attribute
Session-Timeout is number 27
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Counter attribute
Monthly-Traffic-Shaped is number 3007
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Check attribute
Max-Monthly-Blended-Shaped is number 3008
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Current Time: 1202484287
[2008-02-08 17:24:47], Next reset 1204322400 [2008-03-01 00:00:00]
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Current Time: 1202484287
[2008-02-08 17:24:47], Prev reset 1201816800 [2008-02-01 00:00:00]
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated sqlcounter
(MonthlyShaped)
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: counter-name =
"Monthly-Traffic-Local"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: check-name =
"Max-Monthly-Local"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: reply-name =
"Session-Timeout"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: key = "User-Name"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: sqlmod-inst = "sql"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: query = "SELECT IF((SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='%{%k}' AND Class REGEXP '^NL' AND UNIX_TIMESTAMP(AcctStartTime) +
AcctSessionTime > '%b'),SELECT (sum(AcctInputOctets) +
SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='%{%k}' AND Class
REGEXP '^NL' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'),0)"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: reset = "monthly"
Fri Feb 8 17:24:47 2008 : Debug: sqlcounter: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Reply attribute
Session-Timeout is number 27
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Counter attribute
Monthly-Traffic-Local is number 3009
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Check attribute
Max-Monthly-Local is number 3010
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Current Time: 1202484287
[2008-02-08 17:24:47], Next reset 1204322400 [2008-03-01 00:00:00]
Fri Feb 8 17:24:47 2008 : Debug: rlm_sqlcounter: Current Time: 1202484287
[2008-02-08 17:24:47], Prev reset 1201816800 [2008-02-01 00:00:00]
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated sqlcounter
(MonthlyLocal)
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded PAP
Fri Feb 8 17:24:47 2008 : Debug: pap: encryption_scheme = "crypt"
Fri Feb 8 17:24:47 2008 : Debug: pap: auto_header = yes
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated pap (pap)
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded System
Fri Feb 8 17:24:47 2008 : Debug: unix: cache = no
Fri Feb 8 17:24:47 2008 : Debug: unix: passwd = "(null)"
Fri Feb 8 17:24:47 2008 : Debug: unix: shadow = "(null)"
Fri Feb 8 17:24:47 2008 : Debug: unix: group = "(null)"
Fri Feb 8 17:24:47 2008 : Debug: unix: radwtmp =
"../var/log/radius/radwtmp"
Fri Feb 8 17:24:47 2008 : Debug: unix: usegroup = no
Fri Feb 8 17:24:47 2008 : Debug: unix: cache_reload = 600
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated unix (unix)
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded detail
Fri Feb 8 17:24:47 2008 : Debug: detail: detailfile =
"../var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d.log"
Fri Feb 8 17:24:47 2008 : Debug: detail: detailperm = 511
Fri Feb 8 17:24:47 2008 : Debug: detail: dirperm = 493
Fri Feb 8 17:24:47 2008 : Debug: detail: locking = no
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated detail (auth_log)
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded realm
Fri Feb 8 17:24:47 2008 : Debug: realm: format = "suffix"
Fri Feb 8 17:24:47 2008 : Debug: realm: delimiter = "@"
Fri Feb 8 17:24:47 2008 : Debug: realm: ignore_default = no
Fri Feb 8 17:24:47 2008 : Debug: realm: ignore_null = no
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated realm (hxdsl)
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded SQL
Fri Feb 8 17:24:47 2008 : Debug: sql: driver = "rlm_sql_mysql"
Fri Feb 8 17:24:47 2008 : Debug: sql: server = "xx.xx.xx.xx"
Fri Feb 8 17:24:47 2008 : Debug: sql: port = ""
Fri Feb 8 17:24:47 2008 : Debug: sql: login = "xxxxx"
Fri Feb 8 17:24:47 2008 : Debug: sql: password = "xxxxxxx"
Fri Feb 8 17:24:47 2008 : Debug: sql: radius_db = "radiushx"
Fri Feb 8 17:24:47 2008 : Debug: sql: nas_table = "nas"
Fri Feb 8 17:24:47 2008 : Debug: sql: sqltrace = no
Fri Feb 8 17:24:47 2008 : Debug: sql: sqltracefile =
"../var/log/radius/sqltrace.sql"
Fri Feb 8 17:24:47 2008 : Debug: sql: readclients = yes
Fri Feb 8 17:24:47 2008 : Debug: sql: deletestalesessions = yes
Fri Feb 8 17:24:47 2008 : Debug: sql: num_sql_socks = 10
Fri Feb 8 17:24:47 2008 : Debug: sql: sql_user_name = "%{User-Name}"
Fri Feb 8 17:24:47 2008 : Debug: sql: default_user_profile = ""
Fri Feb 8 17:24:47 2008 : Debug: sql: query_on_not_found = no
Fri Feb 8 17:24:47 2008 : Debug: sql: authorize_check_query = "SELECT id,
UserName, Attribute, Value, op FROM radcheck WHERE Username =
'%{SQL-User-Name}' ORDER BY id"
Fri Feb 8 17:24:47 2008 : Debug: sql: authorize_reply_query = "SELECT id,
UserName, Attribute, Value, op FROM radreply WHERE Username =
'%{SQL-User-Name}' ORDER BY id"
Fri Feb 8 17:24:47 2008 : Debug: sql: authorize_group_check_query =
"SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupche
ck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE
usergroup.Username = '%{SQL-User-Name}' AND usergroup.GroupName =
radgroupcheck.GroupName ORDER BY radgroupcheck.id"
Fri Feb 8 17:24:47 2008 : Debug: sql: authorize_group_reply_query =
"SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgrouprep
ly.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE
usergroup.Username = '%{SQL-User-Name}' AND usergroup.GroupName =
radgroupreply.GroupName ORDER BY radgroupreply.id"
Fri Feb 8 17:24:47 2008 : Debug: 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'"
Fri Feb 8 17:24:47 2008 : Debug: sql: accounting_update_query = "UPDATE
radacct SET FramedIPAddress = '%{Framed-IP-Address}', Timestamp = '%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}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND
UserName = '%{SQL-User-Name}' AND NASIPAddress = '%{NAS-IP-Address}'"
Fri Feb 8 17:24:47 2008 : Debug: 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, XAscendSessionSvrKey, TelkomType, Class,
Timestamp) 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}', '%{Telkom-Access-Type}', '%{Class}'}', '%S')"
Fri Feb 8 17:24:47 2008 : Debug: 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, XAscendSessionSvrKey,TelkomType, Class) 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}', '0',
'%{X-Ascend-Session-Svr-Key}', '%{Telkom-Access-Type}', '%{Class}')"
Fri Feb 8 17:24:47 2008 : Debug: 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}'"
Fri Feb 8 17:24:47 2008 : Debug: sql: 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}'"
Fri Feb 8 17:24:47 2008 : Debug: 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-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}')"
Fri Feb 8 17:24:47 2008 : Debug: sql: group_membership_query = "SELECT
GroupName FROM usergroup WHERE UserName='%{SQL-User-Name}'"
Fri Feb 8 17:24:47 2008 : Debug: sql: connect_failure_retry_delay = 60
Fri Feb 8 17:24:47 2008 : Debug: sql: simul_count_query = "SELECT COUNT(*)
FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime = 0"
Fri Feb 8 17:24:47 2008 : Debug: sql: simul_verify_query = "SELECT
RadAcctId, AcctSessionId, UserName, NASIPAddress, NASPortId,
FramedIPAddress, CallingStationId, FramedProtocol FROM radacct WHERE
UserName='%{SQL-User-Name}' AND AcctStopTime = 0"
Fri Feb 8 17:24:47 2008 : Debug: sql: postauth_query = "INSERT INTO
radpostauth(user, pass, reply, date, IPAddress, NasIpAddress, NasPort,
Class, TelkomType, SessionKey) VALUES ('%{User-Name}',
'%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', '%S',
'%{Framed-IP-Address}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{Class}',
'%{Telkom-Access-Type}', '%{X-Ascend-Session-Svr-Key}');"
Fri Feb 8 17:24:47 2008 : Debug: sql: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Fri Feb 8 17:24:47 2008 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module
rlm_sql_mysql) loaded and linked
Fri Feb 8 17:24:47 2008 : Info: rlm_sql (sql): Attempting to connect to
root at 196.125.134.36:/radius
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): starting 0
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #0
Fri Feb 8 17:24:47 2008 : Info: rlm_sql_mysql: Starting connect to MySQL
server for #0
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Connected new DB handle, #0
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): starting 1
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #1
Fri Feb 8 17:24:47 2008 : Info: rlm_sql_mysql: Starting connect to MySQL
server for #1
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Connected new DB handle, #1
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): starting 2
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #2
Fri Feb 8 17:24:47 2008 : Info: rlm_sql_mysql: Starting connect to MySQL
server for #2
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Connected new DB handle, #2
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): starting 3
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #3
Fri Feb 8 17:24:47 2008 : Info: rlm_sql_mysql: Starting connect to MySQL
server for #3
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Connected new DB handle, #3
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): starting 4
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #4
Fri Feb 8 17:24:47 2008 : Info: rlm_sql_mysql: Starting connect to MySQL
server for #4
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Connected new DB handle, #4
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): starting 5
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #5
Fri Feb 8 17:24:47 2008 : Info: rlm_sql_mysql: Starting connect to MySQL
server for #5
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Connected new DB handle, #5
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): starting 6
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #6
Fri Feb 8 17:24:47 2008 : Info: rlm_sql_mysql: Starting connect to MySQL
server for #6
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Connected new DB handle, #6
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): starting 7
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #7
Fri Feb 8 17:24:47 2008 : Info: rlm_sql_mysql: Starting connect to MySQL
server for #7
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Connected new DB handle, #7
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): starting 8
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #8
Fri Feb 8 17:24:47 2008 : Info: rlm_sql_mysql: Starting connect to MySQL
server for #8
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Connected new DB handle, #8
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): starting 9
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #9
Fri Feb 8 17:24:47 2008 : Info: rlm_sql_mysql: Starting connect to MySQL
server for #9
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Connected new DB handle, #9
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): - generate_sql_clients
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Query: SELECT * FROM nas
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Reserving sql socket id: 9
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.3.76,shortname=Telkom376,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.3.76
(Telkom376) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.3.77,shortname=Telkom377,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.3.77
(Telkom377) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.3.70,shortname=Telkom370,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.3.70
(Telkom370) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.3.71,shortname=Telkom371,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.3.71
(Telkom371) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.3.86,shortname=Telkom386,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.3.86
(Telkom386) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.3.87,shortname=Telkom387,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.3.87
(Telkom387) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.1.86,shortname=Telkom186,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.1.86
(Telkom186) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.1.87,shortname=Telkom187,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.1.87
(Telkom187) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.1.91,shortname=Telkom191,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.1.91
(Telkom191) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.1.92,shortname=Telkom196,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.1.92
(Telkom196) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.1.93,shortname=Telkom193,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.1.93
(Telkom193) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.1.88,shortname=Telkom188,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.1.88
(Telkom188) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.43.1.89,shortname=Telkom189,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.43.1.89
(Telkom189) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.15.135.51,shortname=HXSecondary,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.15.135.51
(HXSecondary) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.15.135.52,shortname=Testing,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.15.135.52
(Testing) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.15.135.54,shortname=Testing,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client 196.15.135.54
(Testing) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Read entry
nasname=196.125.135.32,shortname=HXPrimary,secret=Secret
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Adding client
196.125.135.32 (HXPrimary) to clients list
Fri Feb 8 17:24:47 2008 : Debug: rlm_sql (sql): Released sql socket id: 9
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated sql (sql)
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded attr_rewrite
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: attribute =
"Configuration-Token"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: searchfor = "LOCAL_LIMITED"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: searchin = "reply"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: replacewith =
"UNSHAPED_NORMAL"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: append = no
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: ignore_case = yes
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: new_attribute = yes
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: max_matches = 1
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated attr_rewrite
(AttrRewrite_MonthlyBlendedUnshaped)
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: attribute =
"Configuration-Token"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: searchfor =
"UNSHAPED_NORMAL"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: searchin = "reply"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: replacewith =
"SHAPED_NORMAL"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: append = no
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: ignore_case = yes
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: new_attribute = no
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: max_matches = 1
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated attr_rewrite
(AttrRewrite_MonthlyBlendedShaped)
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: attribute =
"Configuration-Token"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: searchfor = "SHAPED_NORMAL"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: searchin = "reply"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: replacewith =
"LOCAL_NORMAL"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: append = no
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: ignore_case = yes
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: new_attribute = no
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: max_matches = 1
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated attr_rewrite
(AttrRewrite_MonthlyLocal)
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: attribute =
"Configuration-Token"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: searchfor = "LOCAL_NORMAL"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: searchin = "reply"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: replacewith =
"LOCAL_LIMITED"
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: append = no
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: ignore_case = yes
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: new_attribute = no
Fri Feb 8 17:24:47 2008 : Debug: attr_rewrite: max_matches = 1
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated attr_rewrite
(AttrRewrite_Limited)
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded preprocess
Fri Feb 8 17:24:47 2008 : Debug: preprocess: huntgroups =
"../etc/raddb/huntgroups"
Fri Feb 8 17:24:47 2008 : Debug: preprocess: hints = "../etc/raddb/hints"
Fri Feb 8 17:24:47 2008 : Debug: preprocess: with_ascend_hack = no
Fri Feb 8 17:24:47 2008 : Debug: preprocess: ascend_channels_per_line = 23
Fri Feb 8 17:24:47 2008 : Debug: preprocess: with_ntdomain_hack = no
Fri Feb 8 17:24:47 2008 : Debug: preprocess: with_specialix_jetstream_hack
= no
Fri Feb 8 17:24:47 2008 : Debug: preprocess: with_cisco_vsa_hack = no
Fri Feb 8 17:24:47 2008 : Debug: preprocess: with_alvarion_vsa_hack = no
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated preprocess
(preprocess)
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded Acct-Unique-Session-Id
Fri Feb 8 17:24:47 2008 : Debug: acct_unique: key = "User-Name,
Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated acct_unique
(acct_unique)
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded files
Fri Feb 8 17:24:47 2008 : Debug: files: usersfile = "../etc/raddb/users"
Fri Feb 8 17:24:47 2008 : Debug: files: acctusersfile =
"../etc/raddb/acct_users"
Fri Feb 8 17:24:47 2008 : Debug: files: preproxy_usersfile =
"../etc/raddb/preproxy_users"
Fri Feb 8 17:24:47 2008 : Debug: files: compat = "no"
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated files (files)
Fri Feb 8 17:24:47 2008 : Debug: detail: detailfile =
"../var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d.log"
Fri Feb 8 17:24:47 2008 : Debug: detail: detailperm = 511
Fri Feb 8 17:24:47 2008 : Debug: detail: dirperm = 493
Fri Feb 8 17:24:47 2008 : Debug: detail: locking = no
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated detail (detail)
Fri Feb 8 17:24:47 2008 : Debug: detail: detailfile =
"../var/log/radius/radacct/detail-radrelay.log"
Fri Feb 8 17:24:47 2008 : Debug: detail: detailperm = 384
Fri Feb 8 17:24:47 2008 : Debug: detail: dirperm = 493
Fri Feb 8 17:24:47 2008 : Debug: detail: locking = yes
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated detail (radrelay)
Fri Feb 8 17:24:47 2008 : Debug: exec: wait = yes
Fri Feb 8 17:24:47 2008 : Debug: exec: program = "../../perl/bin/perl.exe
../etc/raddb/DisconChkAlt.pl %{User-Name} %{Framed-IP-Address}
%{NAS-IP-Address} %{X-Ascend-Session-Svr-Key}"
Fri Feb 8 17:24:47 2008 : Debug: exec: input_pairs = "request"
Fri Feb 8 17:24:47 2008 : Debug: exec: output_pairs = "reply"
Fri Feb 8 17:24:47 2008 : Debug: exec: packet_type = "(null)"
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated exec (POD)
Fri Feb 8 17:24:47 2008 : Debug: Module: Loaded sql_log
Fri Feb 8 17:24:47 2008 : Debug: sql_log: path =
"../var/log/radius/radacct/sql-relay"
Fri Feb 8 17:24:47 2008 : Debug: sql_log: Post-Auth = "INSERT INTO
radpostauth(user, pass, reply, date, IPAddress, NasIpAddress, NasPort,
Class, TelkomType, SessionKey) VALUES ('%{User-Name}',
'%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', '%S',
'%{Framed-IP-Address}', '%{NAS-IP-Address}', '%{NASPort}', '%{Class}',
'%{Telkom-Access-Type}', '%{X-Ascend-Session-Svr-Key}');"
Fri Feb 8 17:24:47 2008 : Debug: sql_log: sql_user_name = ""
Fri Feb 8 17:24:47 2008 : Debug: sql_log: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Fri Feb 8 17:24:47 2008 : Debug: Module: Instantiated sql_log (sql_log)
Fri Feb 8 17:24:47 2008 : Debug: Initializing the thread pool...
Fri Feb 8 17:24:47 2008 : Debug: thread: start_servers = 5
Fri Feb 8 17:24:47 2008 : Debug: thread: max_servers = 32
Fri Feb 8 17:24:47 2008 : Debug: thread: min_spare_servers = 3
Fri Feb 8 17:24:47 2008 : Debug: thread: max_spare_servers = 10
Fri Feb 8 17:24:47 2008 : Debug: thread: max_requests_per_server = 500
Fri Feb 8 17:24:47 2008 : Debug: thread: cleanup_delay = 5
Fri Feb 8 17:24:47 2008 : Debug: Thread spawned new child 1. Total threads
in pool: 1
Fri Feb 8 17:24:47 2008 : Debug: Thread 1 waiting to be assigned a request
Fri Feb 8 17:24:47 2008 : Debug: Thread spawned new child 2. Total threads
in pool: 2
Fri Feb 8 17:24:47 2008 : Debug: Thread 2 waiting to be assigned a request
Fri Feb 8 17:24:47 2008 : Debug: Thread spawned new child 3. Total threads
in pool: 3
Fri Feb 8 17:24:47 2008 : Debug: Thread 3 waiting to be assigned a request
Fri Feb 8 17:24:47 2008 : Debug: Thread spawned new child 4. Total threads
in pool: 4
Fri Feb 8 17:24:47 2008 : Debug: Thread 4 waiting to be assigned a request
Fri Feb 8 17:24:47 2008 : Debug: Thread spawned new child 5. Total threads
in pool: 5
Fri Feb 8 17:24:47 2008 : Debug: Thread 5 waiting to be assigned a request
Fri Feb 8 17:24:47 2008 : Debug: Thread pool initialized
Fri Feb 8 17:24:47 2008 : Debug: Listening on authentication
196.125.135.32:1812
Fri Feb 8 17:24:47 2008 : Debug: Listening on accounting
196.125.135.32:1813
Fri Feb 8 17:24:47 2008 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 196.43.1.92:1820, id=195,
length=124
Fri Feb 8 17:27:26 2008 : Debug: --- Walking the entire request list ---
Fri Feb 8 17:27:26 2008 : Debug: Thread 4 got semaphore
Fri Feb 8 17:27:26 2008 : Debug: Cleaning up request 2 ID 139 with
timestamp 47ac74d4
Fri Feb 8 17:27:26 2008 : Debug: Thread 4 handling request 3, (1 handled so
far)
Fri Feb 8 17:27:26 2008 : Debug: Waking up in 5 seconds...
Fri Feb 8 17:27:26 2008 : Debug: Threads: total/active/spare
threads = 5/1/4
Framed-Protocol = PPP
User-Name = "test at hxdsl"
User-Password = "password"
NAS-Port-Type = Virtual
NAS-Port = 1107362176
NAS-Port-Id = "4/0/2/1.384"
Connect-Info = "AutoShapedVC"
Service-Type = Framed-User
NAS-IP-Address = 196.43.27.44
Telkom-Access-Type = "DSL"
Proxy-State = 0x313030
Fri Feb 8 17:27:26 2008 : Debug: rad_rmspace_pair: User-Password now
'password'
Fri Feb 8 17:27:26 2008 : Debug: Processing the authorize section of
radiusd.conf
Fri Feb 8 17:27:26 2008 : Debug: modcall: entering group authorize for
request 3
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: calling auth_log
(rlm_detail) for request 3
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat:
'../var/log/radius/radacct//auth-detail-20080208.log'
Fri Feb 8 17:27:26 2008 : Debug: rlm_detail:
../var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d.log
expands to ../var/log/radius/radacct//auth-detail-20080208.log
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: returned from
auth_log (rlm_detail) for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall[authorize]: module "auth_log"
returns ok for request 3
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: calling hxdsl
(rlm_realm) for request 3
Fri Feb 8 17:27:26 2008 : Debug: rlm_realm: Looking up realm "hxdsl"
for User-Name = "test at hxdsl"
Fri Feb 8 17:27:26 2008 : Debug: rlm_realm: Found realm "HXdsl"
Fri Feb 8 17:27:26 2008 : Debug: rlm_realm: Adding Stripped-User-Name =
"test"
Fri Feb 8 17:27:26 2008 : Debug: rlm_realm: Proxying request from user
test to realm HXdsl
Fri Feb 8 17:27:26 2008 : Debug: rlm_realm: Adding Realm = "HXdsl"
Fri Feb 8 17:27:26 2008 : Debug: rlm_realm: Authentication realm is
LOCAL.
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: returned from
hxdsl (rlm_realm) for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall[authorize]: module "hxdsl"
returns noop for request 3
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: calling sql
(rlm_sql) for request 3
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'test at hxdsl'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): sql_set_user escaped user
--> 'test at hxdsl'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'SELECT id, UserName,
Attribute, Value, op FROM radcheck WHERE Username = 'test at hxdsl' ORDER BY
id'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): Reserving sql socket id: 5
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupche
ck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE
usergroup.Username = 'test at hxdsl' AND usergroup.GroupName =
radgroupcheck.GroupName ORDER BY radgroupcheck.id'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'SELECT id, UserName,
Attribute, Value, op FROM radreply WHERE Username = 'test at hxdsl' ORDER BY
id'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgrouprep
ly.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE
usergroup.Username = 'test at hxdsl' AND usergroup.GroupName =
radgroupreply.GroupName ORDER BY radgroupreply.id'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): Released sql socket id: 5
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: returned from sql
(rlm_sql) for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall[authorize]: module "sql" returns
ok for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall: entering group for request 3
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: calling
AttrRewrite_MonthlyBlendedUnshaped (rlm_attr_rewrite) for request 3
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'UNSHAPED_NORMAL'
Fri Feb 8 17:27:26 2008 : Debug: rlm_attr_rewrite: Added attribute
Configuration-Token with value 'UNSHAPED_NORMAL'
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: returned from
AttrRewrite_MonthlyBlendedUnshaped (rlm_attr_rewrite) for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall[authorize]: module
"AttrRewrite_MonthlyBlendedUnshaped" returns ok for request 3
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: calling
MonthlyUnShaped (rlm_sqlcounter) for request 3
Fri Feb 8 17:27:26 2008 : Debug: rlm_sqlcounter: Entering module authorize
code
Fri Feb 8 17:27:26 2008 : Debug: sqlcounter_expand: 'SELECT IF((SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='%{User-Name}' AND Class REGEXP '^NU' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='%{User-Name}' AND Class REGEXP '^NU' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),0)'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'SELECT IF((SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='test at hxdsl' AND Class REGEXP '^NU' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='test at hxdsl' AND Class REGEXP '^NU' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),0)'
Fri Feb 8 17:27:26 2008 : Debug: sqlcounter_expand: '%{sql:SELECT
IF((SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct
WHERE UserName='test at hxdsl' AND Class REGEXP '^NU' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='test at hxdsl' AND Class REGEXP '^NU' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),0)}'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: Running registered xlat
function of module sql for string 'SELECT IF((SELECT (sum(AcctInputOctets) +
SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='test at hxdsl' AND
Class REGEXP '^NU' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime >
'1201816800'),(SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024
from radacct WHERE UserName='test at hxdsl' AND Class REGEXP '^NU' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),0)'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): - sql_xlat
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'test at hxdsl'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): sql_set_user escaped user
--> 'test at hxdsl'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'SELECT IF((SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='test at hxdsl' AND Class REGEXP '^NU' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='test at hxdsl' AND Class REGEXP '^NU' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),0)'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): Reserving sql socket id: 4
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): - sql_xlat finished
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): Released sql socket id: 4
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: '0'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sqlcounter: (Check item - counter) is
less than zero
Fri Feb 8 17:27:26 2008 : Debug: rlm_sqlcounter: Rejected user test,
check_item=0, counter=0
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: returned from
MonthlyUnShaped (rlm_sqlcounter) for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall[authorize]: module
"MonthlyUnShaped" returns reject for request 3
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: calling
AttrRewrite_MonthlyBlendedShaped (rlm_attr_rewrite) for request 3
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'UNSHAPED_NORMAL'
Fri Feb 8 17:27:26 2008 : Debug: rlm_attr_rewrite: No match found for
attribute Configuration-Token with value 'SHAPED_NORMAL'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'UNSHAPED_NORMAL'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'SHAPED_NORMAL'
Fri Feb 8 17:27:26 2008 : Debug: rlm_attr_rewrite: Changed value for
attribute Configuration-Token from 'UNSHAPED_NORMAL' to 'SHAPED_NORMAL'
Fri Feb 8 17:27:26 2008 : Debug: rlm_attr_rewrite: Could not find value
pair for attribute Configuration-Token
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: returned from
AttrRewrite_MonthlyBlendedShaped (rlm_attr_rewrite) for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall[authorize]: module
"AttrRewrite_MonthlyBlendedShaped" returns ok for request 3
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: calling
MonthlyShaped (rlm_sqlcounter) for request 3
Fri Feb 8 17:27:26 2008 : Debug: rlm_sqlcounter: Entering module authorize
code
Fri Feb 8 17:27:26 2008 : Debug: sqlcounter_expand: 'SELECT IF((SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='%{User-Name}' AND Class REGEXP '^NS' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='%{User-Name}' AND Class REGEXP '^NS' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),0)'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'SELECT IF((SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='test at hxdsl' AND Class REGEXP '^NS' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='test at hxdsl' AND Class REGEXP '^NS' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),0)'
Fri Feb 8 17:27:26 2008 : Debug: sqlcounter_expand: '%{sql:SELECT
IF((SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct
WHERE UserName='test at hxdsl' AND Class REGEXP '^NS' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='test at hxdsl' AND Class REGEXP '^NS' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),0)}'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: Running registered xlat
function of module sql for string 'SELECT IF((SELECT (sum(AcctInputOctets) +
SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='test at hxdsl' AND
Class REGEXP '^NS' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime >
'1201816800'),(SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024
from radacct WHERE UserName='test at hxdsl' AND Class REGEXP '^NS' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),0)'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): - sql_xlat
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'test at hxdsl'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): sql_set_user escaped user
--> 'test at hxdsl'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'SELECT IF((SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='test at hxdsl' AND Class REGEXP '^NS' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT
(sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE
UserName='test at hxdsl' AND Class REGEXP '^NS' AND
UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),0)'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): Reserving sql socket id: 3
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): - sql_xlat finished
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): Released sql socket id: 3
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: '2244323'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sqlcounter: (Check item - counter) is
greater than zero
Fri Feb 8 17:27:26 2008 : Debug: rlm_sqlcounter: Authorized user test,
check_item=3145728, counter=2244323
Fri Feb 8 17:27:26 2008 : Debug: rlm_sqlcounter: Sent Reply-Item for user
test, Type=Session-Timeout, value=86340
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: returned from
MonthlyShaped (rlm_sqlcounter) for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall[authorize]: module
"MonthlyShaped" returns ok for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall: leaving group (returns ok) for
request 3
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: calling pap
(rlm_pap) for request 3
Fri Feb 8 17:27:26 2008 : Debug: rlm_pap: Found existing Auth-Type, not
changing it.
Fri Feb 8 17:27:26 2008 : Debug: modsingle[authorize]: returned from pap
(rlm_pap) for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall[authorize]: module "pap" returns
noop for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall: leaving group authorize (returns
ok) for request 3
Fri Feb 8 17:27:26 2008 : Debug: rad_check_password: Found Auth-Type
Local
Fri Feb 8 17:27:26 2008 : Debug: auth: type Local
Fri Feb 8 17:27:26 2008 : Debug: auth: user supplied User-Password matches
local User-Password
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'Your maximum monthly usage
time has been reached'
Fri Feb 8 17:27:26 2008 : Auth: Login OK: [test at hxdsl/password] (from
client Telkom196 port 1107362176)
Fri Feb 8 17:27:26 2008 : Debug: Processing the post-auth section of
radiusd.conf
Fri Feb 8 17:27:26 2008 : Debug: modcall: entering group post-auth for
request 3
Fri Feb 8 17:27:26 2008 : Debug: modsingle[post-auth]: calling sql
(rlm_sql) for request 3
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): Processing sql_postauth
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'test at hxdsl'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): sql_set_user escaped user
--> 'test at hxdsl'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'INSERT INTO
radpostauth(user, pass, reply, date, IPAddress, NasIpAddress, NasPort,
Class, TelkomType, SessionKey) VALUES ('test at hxdsl', 'password',
'Access-Accept', '2008-02-08 17:27:26', '', '196.43.27.44', '1107362176',
'', 'DSL', '');'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql) in sql_postauth: query is
INSERT INTO radpostauth(user, pass, reply, date, IPAddress, NasIpAddress,
NasPort, Class, TelkomType, SessionKey) VALUES ('test at hxdsl', 'password',
'Access-Accept', '2008-02-08 17:27:26', '', '196.43.27.44', '1107362176',
'', 'DSL', '');
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): Reserving sql socket id: 2
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): Released sql socket id: 2
Fri Feb 8 17:27:26 2008 : Debug: modsingle[post-auth]: returned from sql
(rlm_sql) for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall[post-auth]: module "sql" returns
ok for request 3
Fri Feb 8 17:27:26 2008 : Debug: modsingle[post-auth]: calling sql_log
(rlm_sql_log) for request 3
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql_log (sql_log): Processing
sql_log_postauth
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'INSERT INTO
radpostauth(user, pass, reply, date, IPAddress, NasIpAddress, NasPort,
Class, TelkomType, SessionKey) VALUES ('test at hxdsl', 'password',
'Access-Accept', '2008-02-08 17:27:26', '', '196.43.27.44', '', '', 'DSL',
'');'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat:
'../var/log/radius/radacct/sql-relay'
Fri Feb 8 17:27:26 2008 : Debug: modsingle[post-auth]: returned from
sql_log (rlm_sql_log) for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall[post-auth]: module "sql_log"
returns ok for request 3
Fri Feb 8 17:27:26 2008 : Debug: modcall: leaving group post-auth (returns
ok) for request 3
Sending Access-Accept of id 195 to 196.43.1.92 port 1820
Framed-Protocol := PPP
Configuration-Token := "SHAPED_NORMAL"
Session-Timeout := 86340
Acct-Interim-Interval := 3600
Configuration-Token = "SHAPED_NORMAL"
Reply-Message = "Your maximum monthly usage time has been reached"
Proxy-State = 0x313030
Fri Feb 8 17:27:26 2008 : Debug: Finished request 3
Fri Feb 8 17:27:26 2008 : Debug: Going to the next request
Fri Feb 8 17:27:26 2008 : Debug: Thread 4 waiting to be assigned a request
rad_recv: Accounting-Request packet from host 196.43.1.88:1820, id=51,
length=173
Fri Feb 8 17:27:26 2008 : Debug: Waking up in 5 seconds...
Fri Feb 8 17:27:26 2008 : Debug: Threads: total/active/spare threads =
5/0/5
Fri Feb 8 17:27:26 2008 : Debug: Thread 5 got semaphore
Fri Feb 8 17:27:26 2008 : Debug: Thread 5 handling request 4, (1 handled so
far)
Acct-Session-Id = "4/0/2/1.384_01F89BA5"
Framed-Protocol = PPP
Framed-IP-Address = 41.246.151.136
User-Name = "test at hxdsl"
X-Ascend-Connect-Progress = LAN-Session-Up
Acct-Authentic = RADIUS
Acct-Status-Type = Start
NAS-Port-Type = Virtual
NAS-Port = 1107362176
NAS-Port-Id = "4/0/2/1.384"
Connect-Info = "AutoShapedVC"
Class = "NS1"
Service-Type = Framed-User
NAS-IP-Address = 196.43.27.44
X-Ascend-Session-Svr-Key = "BF1BD89B"
Acct-Delay-Time = 0
Telkom-Access-Type = "DSL"
Proxy-State = 0x313034
Fri Feb 8 17:27:26 2008 : Debug: Processing the preacct section of
radiusd.conf
Fri Feb 8 17:27:26 2008 : Debug: modcall: entering group preacct for
request 4
Fri Feb 8 17:27:26 2008 : Debug: modsingle[preacct]: calling preprocess
(rlm_preprocess) for request 4
Fri Feb 8 17:27:26 2008 : Debug: modsingle[preacct]: returned from
preprocess (rlm_preprocess) for request 4
Fri Feb 8 17:27:26 2008 : Debug: modcall[preacct]: module "preprocess"
returns noop for request 4
Fri Feb 8 17:27:26 2008 : Debug: modsingle[preacct]: calling acct_unique
(rlm_acct_unique) for request 4
Fri Feb 8 17:27:26 2008 : Debug: rlm_acct_unique: Hashing 'NAS-Port =
1107362176,Client-IP-Address = 196.43.1.88,NAS-IP-Address =
196.43.27.44,Acct-Session-Id = "4/0/2/1.384_01F89BA5",User-Name =
"test at hxdsl"'
Fri Feb 8 17:27:26 2008 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"59413fe714c59e1f".
Fri Feb 8 17:27:26 2008 : Debug: modsingle[preacct]: returned from
acct_unique (rlm_acct_unique) for request 4
Fri Feb 8 17:27:26 2008 : Debug: modcall[preacct]: module "acct_unique"
returns ok for request 4
Fri Feb 8 17:27:26 2008 : Debug: modsingle[preacct]: calling hxdsl
(rlm_realm) for request 4
Fri Feb 8 17:27:26 2008 : Debug: rlm_realm: Looking up realm "hxdsl"
for User-Name = "test at hxdsl"
Fri Feb 8 17:27:26 2008 : Debug: rlm_realm: Found realm "HXdsl"
Fri Feb 8 17:27:26 2008 : Debug: rlm_realm: Adding Stripped-User-Name =
"test"
Fri Feb 8 17:27:26 2008 : Debug: rlm_realm: Proxying request from user
test to realm HXdsl
Fri Feb 8 17:27:26 2008 : Debug: rlm_realm: Adding Realm = "HXdsl"
Fri Feb 8 17:27:26 2008 : Debug: rlm_realm: Accounting realm is LOCAL.
Fri Feb 8 17:27:26 2008 : Debug: modsingle[preacct]: returned from hxdsl
(rlm_realm) for request 4
Fri Feb 8 17:27:26 2008 : Debug: modcall[preacct]: module "hxdsl" returns
noop for request 4
Fri Feb 8 17:27:26 2008 : Debug: modsingle[preacct]: calling files
(rlm_files) for request 4
Fri Feb 8 17:27:26 2008 : Debug: acct_users: Matched entry DEFAULT at
line 27
Fri Feb 8 17:27:26 2008 : Debug: modsingle[preacct]: returned from files
(rlm_files) for request 4
Fri Feb 8 17:27:26 2008 : Debug: modcall[preacct]: module "files" returns
ok for request 4
Fri Feb 8 17:27:26 2008 : Debug: modcall: leaving group preacct (returns
ok) for request 4
Fri Feb 8 17:27:26 2008 : Debug: Found Acct-Type LOCAL-AUTH
Fri Feb 8 17:27:26 2008 : Debug: Processing the accounting section of
radiusd.conf
Fri Feb 8 17:27:26 2008 : Debug: modcall: entering group LOCAL-AUTH for
request 4
Fri Feb 8 17:27:26 2008 : Debug: modsingle[accounting]: calling sql
(rlm_sql) for request 4
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'test at hxdsl'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): sql_set_user escaped user
--> 'test at hxdsl'
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: '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,TelkomType, Class) VALUES ('4/0/2/1.384_01F89BA5',
'59413fe714c59e1f', 'test at hxdsl', 'HXdsl', '196.43.27.44', '1107362176',
'Virtual', '2008-02-08 17:27:26', '0', '0', 'RADIUS', 'AutoShapedVC', '',
'0', '0', '', '', '', 'Framed-User', 'PPP', '41.246.151.136', '0', '0',
'BF1BD89B', 'DSL', 'NS1')'
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): Reserving sql socket id: 1
Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): Released sql socket id: 1
Fri Feb 8 17:27:26 2008 : Debug: modsingle[accounting]: returned from sql
(rlm_sql) for request 4
Fri Feb 8 17:27:26 2008 : Debug: modcall[accounting]: module "sql"
returns ok for request 4
Fri Feb 8 17:27:26 2008 : Debug: modsingle[accounting]: calling radrelay
(rlm_detail) for request 4
Fri Feb 8 17:27:26 2008 : Debug: radius_xlat:
'../var/log/radius/radacct/detail-radrelay.log'
Fri Feb 8 17:27:26 2008 : Debug: rlm_detail:
../var/log/radius/radacct/detail-radrelay.log expands to
../var/log/radius/radacct/detail-radrelay.log
Fri Feb 8 17:27:26 2008 : Debug: rlm_detail: Acquired filelock, tried 1
time(s)
Fri Feb 8 17:27:26 2008 : Debug: rlm_detail: Released filelock
Fri Feb 8 17:27:26 2008 : Debug: modsingle[accounting]: returned from
radrelay (rlm_detail) for request 4
Fri Feb 8 17:27:26 2008 : Debug: modcall[accounting]: module "radrelay"
returns ok for request 4
Fri Feb 8 17:27:26 2008 : Debug: modcall: leaving group LOCAL-AUTH (returns
ok) for request 4
Regards
Keith Dovale
-----Original Message-----
From: freeradius-users-bounces+keith=hostworx.co.za at lists.freeradius.org
[mailto:freeradius-users-bounces+keith=hostworx.co.za at lists.freeradius.org]
On Behalf Of Alan DeKok
Sent: Friday, February 08, 2008 4:51 PM
To: FreeRadius users mailing list
Subject: Re: Newslists
Keith Dovale - HostworX.co.za wrote:
> All I can say is, if you spent as much time helping people as you did
coming up with crap comments the world would be a better place. I have been
subscribed to this news list for a short while now, and you of all people
continually give people sarcastic comments.. Get a Life...
Hmm... I've spent nearly 10 years on this list helping people. I've
told you multiple times what you need to do for anyone to help you.
Yet... you haven't done anything.
> You have spent more time giving me crap comments, than one decent one
saying exactly what you would expect or need to look at this issue to
resolve it. You constantly have some crap comment to make, Like I said
before I will find out from another source.
You have been told multiple times that we need the entire debug log.
Yet you still refuse to post it.
> Instead of coming out with what you require you make these little noises
about how pathetic the poster is and shirk them off. You obviously have
SDS...
Er... no. You've been told multiple times. Apparently you haven't
read the instructions, or you haven't understood them, or you don't
intend to follow them.
If you can't be bothered to follow the simplest of instructions,
there's little anyone can do to help you.
Alan Dekok.
-
List info/subscribe/unsubscribe? See
http://www.freeradius.org/list/users.html
More information about the Freeradius-Users
mailing list