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@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@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@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@hxdsl' Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): sql_set_user escaped user --> 'test@hxdsl' Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'test@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@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@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@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@hxdsl' AND Class REGEXP '^NU' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='test@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@hxdsl' AND Class REGEXP '^NU' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='test@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@hxdsl' AND Class REGEXP '^NU' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='test@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@hxdsl' Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): sql_set_user escaped user --> 'test@hxdsl' Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'SELECT IF((SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='test@hxdsl' AND Class REGEXP '^NU' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='test@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@hxdsl' AND Class REGEXP '^NS' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='test@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@hxdsl' AND Class REGEXP '^NS' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='test@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@hxdsl' AND Class REGEXP '^NS' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='test@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@hxdsl' Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): sql_set_user escaped user --> 'test@hxdsl' Fri Feb 8 17:27:26 2008 : Debug: radius_xlat: 'SELECT IF((SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='test@hxdsl' AND Class REGEXP '^NS' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '1201816800'),(SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024 from radacct WHERE UserName='test@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@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@hxdsl' Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): sql_set_user escaped user --> 'test@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@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@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@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@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@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@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@hxdsl' Fri Feb 8 17:27:26 2008 : Debug: rlm_sql (sql): sql_set_user escaped user --> 'test@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@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@lists.freeradius.org [mailto:freeradius-users-bounces+keith=hostworx.co.za@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