I did explain what I was trying to do with the failover and the attr_rewrite function, what more can a person say about the attrib rewrite, other than the attribute rewrite is supposed to check for an attribute in a packet in this case the reply packet, if it finds the attribute, change it and basically carry on But when it checks for the attribute in the reply packet, it says it can't find it, but it still does the attrib-rewrite changes the values and then moans it couldn’t find the value pair. This is obviously not normal in my opinion, and thus I asked about a specific problem. I only attached the debug portion as it is specific to the problem. When you take your car to the garage for a brake problem, you don’t explain how the engine, fan, wheels, boot opener works, you say the car does not stop when I push the breaks. If the mechanic asks for more info then you tell him. rlm_attr_rewrite: No match found for attribute Configuration-Token with
value 'SHAPED_NORMAL'
radius_xlat: 'UNSHAPED_NORMAL'
radius_xlat: 'SHAPED_NORMAL'
rlm_attr_rewrite: Changed value for attribute Configuration-Token from 'UNSHAPED_NORMAL' to 'SHAPED_NORMAL'
rlm_attr_rewrite: Could not find value pair for attribute Configuration-Token
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 Edvin Seferovic Sent: Friday, February 08, 2008 12:14 PM To: 'FreeRadius users mailing list' Subject: RE: Newslists Constructive answer like always is to analyze what you want to achieve with freeradius. Rethink the configuration, read the documentation for you setup needs and ask straight-forward question. You cannot just post the debug output and hope that someone can understand what you actually need. Try to elaborate your setup, the steps you have already done and of course the debugging output. Alan will probably give you simple answer like yes/no and point to the right direction. But again - you cannot expect someone to do the installation and setup for you ! People are usually paid for that ! Although Alan might be sarcastic, he has never let anyone down who was willing to learn and accept the mistakes ( including myself ). Regards, E:S -----Original Message----- From: freeradius-users-bounces+edvin.seferovic=kolp.at@lists.freeradius.org [mailto:freeradius-users-bounces+edvin.seferovic=kolp.at@lists.freeradius.org] On Behalf Of Keith Dovale - HostworX.co.za Sent: Freitag, 08. Februar 2008 10:46 To: 'FreeRadius users mailing list' Subject: RE: Newslists No not at all, and I don’t expect it. But at least someone like yourself, who seems to be the guru on freeradius, could at least reply with a constructive answer rather than replying with sarcastic comments. My question is where did I announce I don’t read the documentation that is the first thing I went to. I have gone through the read me's, faq's etc and have followed their directions regarding this, it’s the debug that is giving the error. And responding with weird checks, that is exactly why I posted here as there is no google results / faqs, etc that answer my question. Regards Keith -----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 9:44 AM To: FreeRadius users mailing list Subject: Re: Newslists Keith Dovale - HostworX.co.za wrote:
My Honest opinion of this news list / user group is that it is not helpful at all, it seems if you are not in the click, no one helps, does anyone moderate this or not ? I have posted twice now and no one replies…
Is there a contractual obligation requiring people to support you? In any case, you haven't followed the instructions in the FAQ, README, INSTALL, etc. You've already announced that you don't read the documentation people write, so why would anyone write more on this list?
Regards
Keith
*From:* Keith Dovale - HostworX.co.za [mailto:keith@HostworX.co.za] *Sent:* Thursday, February 07, 2008 9:08 PM *To:* ' *Subject:* attr rewrite issue
Hi Guys, some help please .
I am trying to do a attr rewrite to change an Attribute value then do a check based on the attribute that is changed, if the check fails do another attrib rewrite to the next value and do another check, until either the check fails or passes. There is basically only 4 checks in the group statement in the authorise section which do
Attrib rewrite
Do check
(If it fails do)
Attrib rewrite
Do check
(If it fails do)
Attrib check
Do rewrite
(If it fails do)
Attrib check
Do rewrite
Reject
Pass
When it runs it checks the reply packet for an attribute Configuration-Token which is defined in the radgroupreply for the users but it seems it cannot find it and gives an error. As below
rlm_sqlcounter: (Check item - counter) is less than zero
rlm_sqlcounter: Rejected user keith, check_item=0, counter=0
modcall[authorize]: module "MonthlyUnShaped" returns reject for request 2
radius_xlat: 'UNSHAPED_NORMAL'
rlm_attr_rewrite: No match found for attribute Configuration-Token with value 'SHAPED_NORMAL'
radius_xlat: 'UNSHAPED_NORMAL'
radius_xlat: 'SHAPED_NORMAL'
rlm_attr_rewrite: Changed value for attribute Configuration-Token from 'UNSHAPED_NORMAL' to 'SHAPED_NORMAL'
rlm_attr_rewrite: Could not find value pair for attribute Configuration-Token
modcall[authorize]: module "AttrRewrite_MonthlyBlendedShaped" returns ok for request 2
can anyone help
------------------------------------------------------------------------
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Keith Dovale - HostworX.co.za wrote:
what more can a person say about the attrib rewrite, other than the attribute rewrite is supposed to check for an attribute in a packet in this case the reply packet, if it finds the attribute, change it and basically carry on
While that is possible, it's not evident from the debug log you posted.
But when it checks for the attribute in the reply packet, it says it can't find it, but it still does the attrib-rewrite changes the values and then moans it couldn’t find the value pair. This is obviously not normal in my opinion, and thus I asked about a specific problem. I only attached the debug portion as it is specific to the problem.
See my previous response.
When you take your car to the garage for a brake problem, you don’t explain how the engine, fan, wheels, boot opener works, you say the car does not stop when I push the breaks. If the mechanic asks for more info then you tell him.
Mechanics are used to people claiming all sorts of interesting problems with there cars that are unrelated to what is *really* broken. C: My car won't start! The starter motor is broken! M: Is there gas in the car? C: Err... no. M: Right then... here's the bill. Alan DeKok.
Dear GOD, I am quite prepared to pay someone to resolve my problems if necessary, however the point of this news list is supposed to be people helping people, learn from others who have been there etc, and not being a bill gates society. 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... 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. 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... -----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:07 PM To: FreeRadius users mailing list Subject: Re: Newslists Keith Dovale - HostworX.co.za wrote:
what more can a person say about the attrib rewrite, other than the attribute rewrite is supposed to check for an attribute in a packet in this case the reply packet, if it finds the attribute, change it and basically carry on
While that is possible, it's not evident from the debug log you posted.
But when it checks for the attribute in the reply packet, it says it can't find it, but it still does the attrib-rewrite changes the values and then moans it couldn’t find the value pair. This is obviously not normal in my opinion, and thus I asked about a specific problem. I only attached the debug portion as it is specific to the problem.
See my previous response.
When you take your car to the garage for a brake problem, you don’t explain how the engine, fan, wheels, boot opener works, you say the car does not stop when I push the breaks. If the mechanic asks for more info then you tell him.
Mechanics are used to people claiming all sorts of interesting problems with there cars that are unrelated to what is *really* broken. C: My car won't start! The starter motor is broken! M: Is there gas in the car? C: Err... no. M: Right then... here's the bill. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
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.
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
Keith Dovale - HostworX.co.za wrote:
Ok you asked for the debug log here it is.
The extra '-x' (which prints the time) is unnecessary, and makes it harder to read the output. Still..
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)
One instance of attr_rewrite...
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
The thing about the attr_rewrite module is that it looks at ALL attributes in the list. In this case, you have two Configuration-Tokens. One has value "SHAPED_NORMAL", and the other "UNSHAPED_NORMAL". It doesn't match the first, but it does match the second. After that, it says it couldn't find any more. There is a bug. The first "no match found" line prints the value of the attribute that didn't match, NOT the value it was looking for. Carefully reading the debug output makes this clear: - it says "no match" - it says "changed value from UNSHAPED_NORMAL" - returns from module AttrRewrite_MonthlyBlendedShaped i.e. the FIRST line is wrong. You were getting confused because you have *other* attr_rewrite modules which re-write SHAPED_NORMAL. So reading the debug log here, it looked like it was trying to re-write SHAPED_NORMAL. But it wasn't, because it was NOT running the AttrRewrite_MonthlyLocal module. The only issue I see is that one debug line is wrong, and therefore confusing. Is there anything else? Alan DeKok.
Alan, I appreciate you coming back to me, I apologise for my inappropriate comments yesterday, I am as frustrated to hell. I should have asked what was required first. Ok what confuses me is, A user logs in with shaped access, the group reply sets Configuration token to SHAPED_NORMAL ok nowhere else is the Configuration-Token setup. The attrib-rewrite for unshaped kicks in and should check to see if the Configuration-token is UNSHAPED_LOCAL and if it can't find it rewrite it to SHAPED_LOCAL is that not right. Then if the sqlcounter fails move into the next attrib-rewrite. But in the debug it is looking for SHAPED_NORMAL in the UNSHAPED attrib rewrite. Fri Feb 8 17:27:26 2008 : Debug: rlm_attr_rewrite: No match found for
attribute Configuration-Token with value 'SHAPED_NORMAL'
You say it looks at all the attributes where does is see I have SHAPED_NORMAL and UNSHAPED_NORMAL set ? This confuses me a little, surely when the rewrite does its job it overwrites the existing attribute values or does it just add another ? 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: Saturday, February 09, 2008 9:43 AM To: FreeRadius users mailing list Subject: Re: Newslists Keith Dovale - HostworX.co.za wrote:
Ok you asked for the debug log here it is.
The extra '-x' (which prints the time) is unnecessary, and makes it harder to read the output. Still..
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)
One instance of attr_rewrite...
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
The thing about the attr_rewrite module is that it looks at ALL attributes in the list. In this case, you have two Configuration-Tokens. One has value "SHAPED_NORMAL", and the other "UNSHAPED_NORMAL". It doesn't match the first, but it does match the second. After that, it says it couldn't find any more. There is a bug. The first "no match found" line prints the value of the attribute that didn't match, NOT the value it was looking for. Carefully reading the debug output makes this clear: - it says "no match" - it says "changed value from UNSHAPED_NORMAL" - returns from module AttrRewrite_MonthlyBlendedShaped i.e. the FIRST line is wrong. You were getting confused because you have *other* attr_rewrite modules which re-write SHAPED_NORMAL. So reading the debug log here, it looked like it was trying to re-write SHAPED_NORMAL. But it wasn't, because it was NOT running the AttrRewrite_MonthlyLocal module. The only issue I see is that one debug line is wrong, and therefore confusing. Is there anything else? Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Keith Dovale - HostworX.co.za wrote:
A user logs in with shaped access, the group reply sets Configuration token to SHAPED_NORMAL ok nowhere else is the Configuration-Token setup.
The attrib-rewrite for unshaped kicks in and should check to see if the Configuration-token is UNSHAPED_LOCAL and if it can't find it rewrite it to SHAPED_LOCAL is that not right.
Yes.
Then if the sqlcounter fails move into the next attrib-rewrite.
But in the debug it is looking for SHAPED_NORMAL in the UNSHAPED attrib rewrite.
No. As I said, that debug message is wrong. Alan DeKok.
Ok but then The thing about the attr_rewrite module is that it looks at ALL attributes in the list. In this case, you have two Configuration-Tokens. One has value "SHAPED_NORMAL", and the other "UNSHAPED_NORMAL". It doesn't match the first, but it does match the second. After that, it says it couldn't find any more. Where does it get the second Configuration-Token from ? 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: Saturday, February 09, 2008 6:17 PM To: FreeRadius users mailing list Subject: Re: Newslists Keith Dovale - HostworX.co.za wrote:
A user logs in with shaped access, the group reply sets Configuration token to SHAPED_NORMAL ok nowhere else is the Configuration-Token setup.
The attrib-rewrite for unshaped kicks in and should check to see if the Configuration-token is UNSHAPED_LOCAL and if it can't find it rewrite it to SHAPED_LOCAL is that not right.
Yes.
Then if the sqlcounter fails move into the next attrib-rewrite.
But in the debug it is looking for SHAPED_NORMAL in the UNSHAPED attrib rewrite.
No. As I said, that debug message is wrong. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Hi,
Ok but then
The thing about the attr_rewrite module is that it looks at ALL attributes in the list. In this case, you have two Configuration-Tokens. One has value "SHAPED_NORMAL", and the other "UNSHAPED_NORMAL". It doesn't match the first, but it does match the second. After that, it says it couldn't find any more.
Where does it get the second Configuration-Token from ?
well, from your debug I see this: 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 there are 2 "Configuration-Token" attributes. possibly because it was added in an incorrect way, or adjusted/set incorrectly originally? alan
Hi, Yes this is why I started looking at the debugs to see what was happening and found the attribute rewrite issue where it says it cannot find the configuration token, if I take the Configuration token out of the radgroup reply it shows one, if I take the attrib-rewrites out it only shows one in the access accept packet. So it looks like the Attrib rewrite is actually adding a second attrib rather than editing the original one, and thus the errors in the debug log. Does the radius give the resultant reply to attrib rewrite to check before sending it out, is there a way to programmatically display the reply attributes somehow, so I can see what the reply packet looks like before the attrib rewrite edits it, by maybe logging to a file or something 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 A.L.M.Buxey@lboro.ac.uk Sent: Saturday, February 09, 2008 11:33 PM To: FreeRadius users mailing list Subject: Re: Newslists Hi,
Ok but then
The thing about the attr_rewrite module is that it looks at ALL attributes in the list. In this case, you have two Configuration-Tokens. One has value "SHAPED_NORMAL", and the other "UNSHAPED_NORMAL". It doesn't match the first, but it does match the second. After that, it says it couldn't find any more.
Where does it get the second Configuration-Token from ?
well, from your debug I see this: 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 there are 2 "Configuration-Token" attributes. possibly because it was added in an incorrect way, or adjusted/set incorrectly originally? alan - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Hi,
Yes this is why I started looking at the debugs to see what was happening and found the attribute rewrite issue where it says it cannot find the configuration token, if I take the Configuration token out of the radgroup reply it shows one, if I take the attrib-rewrites out it only shows one in the access accept packet.
_how_ are you adding it via the radgroup reply? which operator are you using? alan
hi, ..and i'd like to add that, once again, we are not seeing the whole picture - eg your configuration files and/or SQL tables. this case hence drags on and on........... alan
Sql tables are standard RadCheck test@hxdsl Cleartext-Password := test test@hxdsl Max-Monthly-Blended-UnShaped := 0 test@hxdsl Max-Monthly-Blended-Shaped := 3145728 test@hxdsl Max-Monthly-Local := 0 test@hxdsl Max-Monthly-Prepaid-Limit-Total := 0 test@hxdsl Max-Monthly-Blended-Limit := 0 Radgroupcheck DSLSHAPED Auth-Type := Local DSLUNSHAPED Auth-Type := Local DSLLOCAL Auth-Type := Local DISABLED Auth-Type := Reject Radgroupreply DSLSHAPED Acct-Interim-Interval := 3600 DSLSHAPED Session-Timeout := 84600 DSLSHAPED Configuration-Token := SHAPED_NORMAL DSLUNSHAPED Acct-Interim-Interval := 3600 DSLUNSHAPED Session-Timeout := 84600 DSLUNSHAPED Configuration-Token := UNSHAPED_NORMAL DSLLOCAL Acct-Interim-Interval := 3600 DSLLOCAL Session-Timeout := 84600 DSLLOCAL Configuration-Token := LOCAL_NORMAL DSLLIMITED Configuration-Token := LOCAL_LIMITED RADIUSD.CONF prefix = .. exec_prefix = ${prefix} sysconfdir = ${prefix}/etc localstatedir = ${prefix}/var sbindir = ${exec_prefix}/sbin logdir = ${localstatedir}/log/radius raddbdir = ${sysconfdir}/raddb radacctdir = ${logdir}/radacct certsdir = ${sysconfdir}/raddb/certs/FreeRADIUS.net/DemoCerts confdir = ${raddbdir} run_dir = ${localstatedir}/run/radiusd log_file = ${logdir}/radius.log libdir = ${exec_prefix}/lib pidfile = ${run_dir}/radiusd.pid max_request_time = 60 delete_blocked_requests = no cleanup_delay = 6 max_requests = 25600 bind_address = xx.xx.xx.xx port = 0 hostname_lookups = no allow_core_dumps = no regular_expressions = yes extended_expressions = yes log_stripped_names = no log_auth = yes log_auth_badpass = yes log_auth_goodpass = yes usercollide = no lower_user = after lower_pass = no nospace_user = after nospace_pass = before security { max_attributes = 200 reject_delay = 1 status_server = no } proxy_requests = yes $INCLUDE ${confdir}/proxy.conf $INCLUDE ${confdir}/clients.conf snmp = no $INCLUDE ${confdir}/snmp.conf thread pool { start_servers = 5 max_servers = 32 min_spare_servers = 3 max_spare_servers = 10 max_requests_per_server = 500 } modules { pap { auto_header = yes } chap { authtype = CHAP } pam { pam_auth = radiusd } unix { cache = no cache_reload = 600 radwtmp = ${logdir}/radwtmp } realm hxdsl { format = suffix delimiter = "@" ignore_default = no ignore_null = no } checkval { item-name = Calling-Station-Id check-name = Calling-Station-Id data-type = string } attr_rewrite AttrRewrite_MonthlyBlendedUnshaped { attribute = Configuration-Token searchin = reply searchfor = "SHAPED_NORMAL" replacewith = "UNSHAPED_NORMAL" ignore_case = yes new_attribute = no max_matches = 3 append = no } attr_rewrite AttrRewrite_MonthlyBlendedShaped { attribute = Configuration-Token searchin = reply searchfor = "UNSHAPED_NORMAL" replacewith = "SHAPED_NORMAL" ignore_case = yes new_attribute = no max_matches = 3 append = no } attr_rewrite AttrRewrite_MonthlyLocal { attribute = Configuration-Token searchin = reply searchfor = "SHAPED_NORMAL" replacewith = "LOCAL_NORMAL" ignore_case = yes new_attribute = no max_matches = 3 append = no } attr_rewrite AttrRewrite_Limited { attribute = Configuration-Token searchin = reply searchfor = "LOCAL_NORMAL" replacewith = "LOCAL_LIMITED" ignore_case = yes new_attribute = no max_matches = 3 append = no } preprocess { huntgroups = ${confdir}/huntgroups hints = ${confdir}/hints with_ascend_hack = no ascend_channels_per_line = 23 with_ntdomain_hack = no with_specialix_jetstream_hack = no with_cisco_vsa_hack = no } files { usersfile = ${confdir}/users acctusersfile = ${confdir}/acct_users preproxy_usersfile = ${confdir}/preproxy_users compat = no } detail reply_logUn { detailfile = ${radacctdir}/reply-detailU-%Y%m%d.log detailperm = 0777 } detail reply_logUnFin { detailfile = ${radacctdir}/reply-detailUF-%Y%m%d.log detailperm = 0777 } detail reply_logSh { detailfile = ${radacctdir}/reply-detailS-%Y%m%d.log detailperm = 0777 } detail reply_logShFin { detailfile = ${radacctdir}/reply-detailSF-%Y%m%d.log detailperm = 0777 } detail reply_logLoc { detailfile = ${radacctdir}/reply-detailL-%Y%m%d.log detailperm = 0777 } detail reply_logLocFin { detailfile = ${radacctdir}/reply-detailLF-%Y%m%d.log detailperm = 0777 } detail reply_logEnd { detailfile = ${radacctdir}/reply-detailE-%Y%m%d.log detailperm = 0777 } detail radrelay { detailfile = ${radacctdir}/detail-radrelay.log detailperm = 0600 locking = yes } detail { detailfile = ${radacctdir}/%{Client-IP-Address}/detail-%Y%m%d.log detailperm = 0777 } detail auth_log { detailfile = ${radacctdir}/%{Client-IP-Address}/auth-detail-%Y%m%d.log detailperm = 0777 } detail reply_log { detailfile = ${radacctdir}/%{Client-IP-Address}/reply-detail-%Y%m%d.log detailperm = 0777 } detail pre_proxy_log { detailfile = ${radacctdir}/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d.log detailperm = 0777 } detail post_proxy_log { detailfile = ${radacctdir}/%{Client-IP-Address}/post-proxy-detail-%Y%m%d.log detailperm = 0777 } sql_log { path = ${radacctdir}/sql-relay acct_table = "radacct" postauth_table = "radpostauth" Start = "INSERT INTO ${acct_table} (AcctSessionId, UserName, NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, AcctSessionTime, AcctTerminateCause) VALUES ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', '%{Framed-IP-Address}', '%S', '0', '0', '');" Stop = "INSERT INTO ${acct_table} (AcctSessionId, UserName, NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, AcctSessionTime, AcctTerminateCause) VALUES ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', '%{Framed-IP-Address}', '0', '%S', '%{Acct-Session-Time}', '%{Acct-Terminate-Cause}');" Alive = "INSERT INTO ${acct_table} (AcctSessionId, UserName, NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, AcctSessionTime, AcctTerminateCause) VALUES ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', '%{Framed-IP-Address}', '0', '0', '%{Acct-Session-Time}','');" Post-Auth = "INSERT INTO ${postauth_table}(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}');" } acct_unique { key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" } $INCLUDE ${confdir}/sql.conf radutmp { filename = ${logdir}/radutmp username = %{User-Name} case_sensitive = yes check_with_nas = yes perm = 0777 callerid = "yes" } radutmp sradutmp { filename = ${logdir}/sradutmp perm = 0777 callerid = "no" } attr_filter { attrsfile = ${confdir}/attrs } sqlcounter MonthlyUnShaped { counter-name = Monthly-Traffic-UnShaped check-name = Max-Monthly-Blended-UnShaped reply-name = Session-Timeout sqlmod-inst = sql key = User-Name reset = monthly Reply-Message = You have reached your Unshaped bandwidth cap for this Month query = "SELECT IF(((SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024)- (Select Value from radcheck where UserName='%{%k}' and Attribute = 'Max-Prepaid-Limit') from radacct WHERE UserName='%{%k}' AND Class REGEXP '^NU' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'),((SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024)- (Select Value from radcheck where UserName='%{%k}' and Attribute = 'Max-Prepaid-Limit') from radacct WHERE UserName='%{%k}' AND Class REGEXP '^NU' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'),0)" } sqlcounter MonthlyShaped { counter-name = Monthly-Traffic-Shaped check-name = Max-Monthly-Blended-Shaped reply-name = Session-Timeout sqlmod-inst = sql key = User-Name reset = monthly Reply-Message = You have reached your SHaped bandwidth cap for this Month query = "SELECT IF(((SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024)- (Select Value from radcheck where UserName='%{%k}' and Attribute = 'Max-Prepaid-Limit') from radacct WHERE UserName='%{%k}' AND Class REGEXP '^NS' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'),((SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024)- (Select Value from radcheck where UserName='%{%k}' and Attribute = 'Max-Prepaid-Limit') from radacct WHERE UserName='%{%k}' AND Class REGEXP '^NS' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'),0)" } sqlcounter MonthlyLocal { counter-name = Monthly-Traffic-Local check-name = Max-Monthly-Local reply-name = Session-Timeout sqlmod-inst = sql key = User-Name reset = monthly Reply-Message = You have reached your Local bandwidth cap for this Month query = "SELECT IF(((SELECT (sum(AcctInputOctets) + SUM(AcctOutputOctets))/1024)- (Select Value from radcheck where UserName='%{%k}' and Attribute = 'Max-Prepaid-Limit') from radacct WHERE UserName='%{%k}' AND Class REGEXP '^NL' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'),SELECT ((SUM(AcctInputOctets) + SUM(AcctOutputOctets))/1024)- (Select Value from radcheck where UserName='%{%k}' and Attribute = 'Max-Prepaid-Limit') from radacct WHERE UserName='%{%k}' AND Class REGEXP '^NL' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'),0)" } always fail { rcode = fail } always reject { rcode = reject } always ok { rcode = ok simulcount = 0 mpp = no } expr { } digest { } exec { wait = yes input_pairs = request } exec echo { wait = yes program = "/bin/echo %{User-Name}" input_pairs = request output_pairs = reply } exec POD { wait = yes program = "../../perl/bin/perl.exe ${confdir}/DisconChkAlt.pl %{User-Name} %{Framed-IP-Address} %{NAS-IP-Address} %{X-Ascend-Session-Svr-Key}" input_pairs = request output_pairs = reply # packet_type = Accounting-Request } } instantiate { exec expr MonthlyUnShaped MonthlyShaped MonthlyLocal } authorize { auth_log # digest hxdsl sql group { reply_logUn AttrRewrite_MonthlyBlendedUnshaped reply_logUnFin MonthlyUnShaped { reject = 1 ok = return } reply_logSh AttrRewrite_MonthlyBlendedShaped reply_logShFin MonthlyShaped { reject = 1 ok = return } reply_logLoc AttrRewrite_MonthlyLocal reply_logLocFin MonthlyLocal { reject = 1 ok = return } AttrRewrite_Limited } reply_logEnd pap } authenticate { Auth-Type PAP { pap } unix } preacct { preprocess acct_unique hxdsl files } accounting { detail sql Acct-Type LOCAL-AUTH { sql radrelay } Acct-Type REMOTE-AUTH { sql } Acct-Type interim { sql POD } } session { sql } post-auth { sql sql_log Post-Auth-Type REJECT { # Login failed: log to SQL database. sql sql_log } } pre-proxy { # pre_proxy_log } post-proxy { # post_proxy_log } 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 A.L.M.Buxey@lboro.ac.uk Sent: Sunday, February 10, 2008 12:36 PM To: FreeRadius users mailing list Subject: Re: Newslists hi, ..and i'd like to add that, once again, we are not seeing the whole picture - eg your configuration files and/or SQL tables. this case hence drags on and on........... alan - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
hi, spending more time posting pseudo-insults and complaints to people posting bahaviour RATHER than the config/file-debug etc as requested aint going to help anyone. sure, some sarcastic comments arent necessary, but the basic method of using this list doesnt change. as previously mentioned, this list is occupied by folk doing lots of other PAID work. none of us are paid for getting peoples configs working (and trust me, various commercial enterprised have come online solely through free help from this list). thus, we request some bare minimum details to help. the other possibility is you are a trail-blazer. in which case noone can help you with your requirements. at least then if you do figure it out, you too can post to other people in the future to make snide remarks at their ineptitude (which you feel is happening now) alan
Hi,
But when it checks for the attribute in the reply packet, it says it can't find it, but it still does the attrib-rewrite changes the values and then moans it couldn’t find the value pair. This is obviously not normal in my opinion, and thus I asked about a specific problem. I only attached the debug portion as it is specific to the problem.
post the relevant part of your config file? We arent seeing the whole picture. when you take a car to the garage, the mechanic hears your story AND sees the car. alan
I posted this all before, I just trimmed the debug file down to where the error was... The attrib rewrite section ... attr_rewrite AttrRewrite_MonthlyBlendedUnshaped { attribute = Configuration-Token searchin = reply searchfor = "LOCAL_LIMITED" replacewith = "UNSHAPED_NORMAL" ignore_case = yes new_attribute = yes max_matches = 1 append = no } attr_rewrite AttrRewrite_MonthlyBlendedShaped { attribute = Configuration-Token searchin = reply searchfor = "UNSHAPED_NORMAL" replacewith = "SHAPED_NORMAL" ignore_case = yes new_attribute = no max_matches = 1 append = no } attr_rewrite AttrRewrite_MonthlyLocal { attribute = Configuration-Token searchin = reply searchfor = "SHAPED_NORMAL" replacewith = "LOCAL_NORMAL" ignore_case = yes new_attribute = no max_matches = 1 append = no } attr_rewrite AttrRewrite_Limited { attribute = Configuration-Token searchin = reply searchfor = "LOCAL_NORMAL" replacewith = "LOCAL_LIMITED" ignore_case = yes new_attribute = no max_matches = 1 append = no } The authorize section authorize { auth_log # digest hxdsl sql group { AttrRewrite_MonthlyBlendedUnshaped MonthlyUnShaped { reject = 1 ok = return } AttrRewrite_MonthlyBlendedShaped MonthlyShaped { reject = 1 ok = return } AttrRewrite_MonthlyLocal MonthlyLocal { reject = 1 ok = return } AttrRewrite_Limited } pap } -----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 A.L.M.Buxey@lboro.ac.uk Sent: Friday, February 08, 2008 4:39 PM To: FreeRadius users mailing list Subject: Re: Newslists Hi,
But when it checks for the attribute in the reply packet, it says it can't find it, but it still does the attrib-rewrite changes the values and then moans it couldn’t find the value pair. This is obviously not normal in my opinion, and thus I asked about a specific problem. I only attached the debug portion as it is specific to the problem.
post the relevant part of your config file? We arent seeing the whole picture. when you take a car to the garage, the mechanic hears your story AND sees the car. alan - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
participants (3)
-
A.L.M.Buxey＠lboro.ac.uk -
Alan DeKok -
Keith Dovale - HostworX.co.za