Hi All, I'm having some issues with the acct-session-id, where special characters for instance [] being converted to it's hex equivalent. For example below, the Acct-Session-Id = "301[]426932183" when inserted into the accounting table it is inserted as 301=5B=5D426932183. I have noticed the same happens with the sql-group. Please advise how I could insert the data as received without conversion. Thanks Sajeewa @ ispONE ================================================================== Wed May 27 09:19:48 2009 : Info: FreeRADIUS Version 2.0.4, for host i486-pc-linux-gnu, built on Sep 7 2008 at 23:35:34 Wed May 27 09:19:48 2009 : Info: Copyright (C) 1999-2008 The FreeRADIUS server project and contributors. Wed May 27 09:19:48 2009 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Wed May 27 09:19:48 2009 : Info: PARTICULAR PURPOSE. Wed May 27 09:19:48 2009 : Info: You may redistribute copies of FreeRADIUS under the terms of the Wed May 27 09:19:48 2009 : Info: GNU General Public License. Wed May 27 09:19:48 2009 : Info: Starting - reading configuration files ... Wed May 27 09:19:48 2009 : Debug: including configuration file /etc/freeradius/radiusd_dial.conf Wed May 27 09:19:48 2009 : Debug: including configuration file /etc/freeradius/proxy_dial.conf Wed May 27 09:19:48 2009 : Debug: including configuration file /etc/freeradius/clients_dial.conf Wed May 27 09:19:48 2009 : Debug: including configuration file /etc/freeradius/sql_dial.conf Wed May 27 09:19:48 2009 : Debug: including configuration file /etc/freeradius/sql_prepaid_counter.conf Wed May 27 09:19:48 2009 : Debug: including configuration file /etc/freeradius/policy.conf Wed May 27 09:19:48 2009 : Debug: including files in directory /etc/freeradius/sites-enabled/ Wed May 27 09:19:48 2009 : Debug: including configuration file /etc/freeradius/sites-enabled/default_dial Wed May 27 09:19:48 2009 : Debug: including dictionary file /etc/freeradius/dictionary Wed May 27 09:19:48 2009 : Debug: main { Wed May 27 09:19:48 2009 : Debug: prefix = "/usr" Wed May 27 09:19:48 2009 : Debug: localstatedir = "/var" Wed May 27 09:19:48 2009 : Debug: logdir = "/var/log/freeradius" Wed May 27 09:19:48 2009 : Debug: libdir = "/usr/lib/freeradius" Wed May 27 09:19:48 2009 : Debug: radacctdir = "/var/log/freeradius/radacct" Wed May 27 09:19:48 2009 : Debug: hostname_lookups = no Wed May 27 09:19:48 2009 : Debug: max_request_time = 30 Wed May 27 09:19:48 2009 : Debug: cleanup_delay = 5 Wed May 27 09:19:48 2009 : Debug: max_requests = 1024 Wed May 27 09:19:48 2009 : Debug: allow_core_dumps = no Wed May 27 09:19:48 2009 : Debug: pidfile = "/var/run/freeradius/freeradius_dial.pid" Wed May 27 09:19:48 2009 : Debug: user = "freerad" Wed May 27 09:19:48 2009 : Debug: group = "freerad" Wed May 27 09:19:48 2009 : Debug: checkrad = "/usr/sbin/checkrad" Wed May 27 09:19:48 2009 : Debug: debug_level = 0 Wed May 27 09:19:48 2009 : Debug: proxy_requests = yes Wed May 27 09:19:48 2009 : Debug: security { Wed May 27 09:19:48 2009 : Debug: max_attributes = 200 Wed May 27 09:19:48 2009 : Debug: reject_delay = 0 Wed May 27 09:19:48 2009 : Debug: status_server = yes Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: client 144.130.4.5 { Wed May 27 09:19:48 2009 : Debug: ipaddr = 144.130.4.5 Wed May 27 09:19:48 2009 : Debug: require_message_authenticator = no Wed May 27 09:19:48 2009 : Debug: secret = "11oneONEV6" Wed May 27 09:19:48 2009 : Debug: shortname = "telstra-1" Wed May 27 09:19:48 2009 : Debug: nastype = "other" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: client 144.130.7.5 { Wed May 27 09:19:48 2009 : Debug: ipaddr = 144.130.7.5 Wed May 27 09:19:48 2009 : Debug: require_message_authenticator = no Wed May 27 09:19:48 2009 : Debug: secret = "11oneONEV6" Wed May 27 09:19:48 2009 : Debug: shortname = "telstra-2" Wed May 27 09:19:48 2009 : Debug: nastype = "other" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: client 192.168.0.19 { Wed May 27 09:19:48 2009 : Debug: ipaddr = 192.168.0.19 Wed May 27 09:19:48 2009 : Debug: require_message_authenticator = no Wed May 27 09:19:48 2009 : Debug: secret = "11oneONEV6" Wed May 27 09:19:48 2009 : Debug: shortname = "test-1" Wed May 27 09:19:48 2009 : Debug: nastype = "other" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: client 192.168.0.212 { Wed May 27 09:19:48 2009 : Debug: ipaddr = 192.168.0.212 Wed May 27 09:19:48 2009 : Debug: require_message_authenticator = no Wed May 27 09:19:48 2009 : Debug: secret = "secret" Wed May 27 09:19:48 2009 : Debug: shortname = "test-2" Wed May 27 09:19:48 2009 : Debug: nastype = "other" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: client 192.168.0.151 { Wed May 27 09:19:48 2009 : Debug: ipaddr = 192.168.0.151 Wed May 27 09:19:48 2009 : Debug: require_message_authenticator = no Wed May 27 09:19:48 2009 : Debug: secret = "secret" Wed May 27 09:19:48 2009 : Debug: shortname = "test-3" Wed May 27 09:19:48 2009 : Debug: nastype = "other" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: radiusd_dial: #### Loading Realms and Home Servers #### Wed May 27 09:19:48 2009 : Debug: proxy server { Wed May 27 09:19:48 2009 : Debug: retry_delay = 5 Wed May 27 09:19:48 2009 : Debug: retry_count = 3 Wed May 27 09:19:48 2009 : Debug: default_fallback = no Wed May 27 09:19:48 2009 : Debug: dead_time = 120 Wed May 27 09:19:48 2009 : Debug: wake_all_if_all_dead = no Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: home_server hugonet_1 { Wed May 27 09:19:48 2009 : Debug: ipaddr = 114.111.142.98 Wed May 27 09:19:48 2009 : Debug: port = 1813 Wed May 27 09:19:48 2009 : Debug: type = "acct" Wed May 27 09:19:48 2009 : Debug: secret = "w89100kwq" Wed May 27 09:19:48 2009 : Debug: response_window = 20 Wed May 27 09:19:48 2009 : Debug: max_outstanding = 65536 Wed May 27 09:19:48 2009 : Debug: zombie_period = 40 Wed May 27 09:19:48 2009 : Debug: status_check = "request" Wed May 27 09:19:48 2009 : Debug: ping_check = "none" Wed May 27 09:19:48 2009 : Debug: ping_interval = 30 Wed May 27 09:19:48 2009 : Debug: check_interval = 30 Wed May 27 09:19:48 2009 : Debug: num_answers_to_alive = 3 Wed May 27 09:19:48 2009 : Debug: num_pings_to_alive = 3 Wed May 27 09:19:48 2009 : Debug: revive_interval = 300 Wed May 27 09:19:48 2009 : Debug: status_check_timeout = 4 Wed May 27 09:19:48 2009 : Debug: username = "statuscheck@ispone.com.au" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: home_server_pool hugonet_failover { Wed May 27 09:19:48 2009 : Debug: type = fail-over Wed May 27 09:19:48 2009 : Debug: home_server = hugonet_1 Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: realm hugonet.com.au { Wed May 27 09:19:48 2009 : Debug: acct_pool = hugonet_failover Wed May 27 09:19:48 2009 : Debug: nostrip Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: home_server planetisp_1 { Wed May 27 09:19:48 2009 : Debug: ipaddr = 210.50.6.202 Wed May 27 09:19:48 2009 : Debug: port = 1646 Wed May 27 09:19:48 2009 : Debug: type = "acct" Wed May 27 09:19:48 2009 : Debug: secret = "62gys8j" Wed May 27 09:19:48 2009 : Debug: response_window = 20 Wed May 27 09:19:48 2009 : Debug: max_outstanding = 65536 Wed May 27 09:19:48 2009 : Debug: zombie_period = 40 Wed May 27 09:19:48 2009 : Debug: status_check = "request" Wed May 27 09:19:48 2009 : Debug: ping_check = "none" Wed May 27 09:19:48 2009 : Debug: ping_interval = 30 Wed May 27 09:19:48 2009 : Debug: check_interval = 30 Wed May 27 09:19:48 2009 : Debug: num_answers_to_alive = 3 Wed May 27 09:19:48 2009 : Debug: num_pings_to_alive = 3 Wed May 27 09:19:48 2009 : Debug: revive_interval = 300 Wed May 27 09:19:48 2009 : Debug: status_check_timeout = 4 Wed May 27 09:19:48 2009 : Debug: username = "statuscheck@ispone.com.au" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: home_server_pool planetisp_failover { Wed May 27 09:19:48 2009 : Debug: type = fail-over Wed May 27 09:19:48 2009 : Debug: home_server = planetisp_1 Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: realm planetisp.com.au { Wed May 27 09:19:48 2009 : Debug: acct_pool = planetisp_failover Wed May 27 09:19:48 2009 : Debug: nostrip Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: realm 21century.com.au { Wed May 27 09:19:48 2009 : Debug: acct_pool = planetisp_failover Wed May 27 09:19:48 2009 : Debug: nostrip Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: realm computersmobile.com.au { Wed May 27 09:19:48 2009 : Debug: acct_pool = planetisp_failover Wed May 27 09:19:48 2009 : Debug: nostrip Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: home_server tecknowlogy_1 { Wed May 27 09:19:48 2009 : Debug: ipaddr = 202.125.168.246 Wed May 27 09:19:48 2009 : Debug: port = 1813 Wed May 27 09:19:48 2009 : Debug: type = "acct" Wed May 27 09:19:48 2009 : Debug: secret = "2rtYhamfG" Wed May 27 09:19:48 2009 : Debug: response_window = 20 Wed May 27 09:19:48 2009 : Debug: max_outstanding = 65536 Wed May 27 09:19:48 2009 : Debug: zombie_period = 40 Wed May 27 09:19:48 2009 : Debug: status_check = "request" Wed May 27 09:19:48 2009 : Debug: ping_check = "none" Wed May 27 09:19:48 2009 : Debug: ping_interval = 30 Wed May 27 09:19:48 2009 : Debug: check_interval = 30 Wed May 27 09:19:48 2009 : Debug: num_answers_to_alive = 3 Wed May 27 09:19:48 2009 : Debug: num_pings_to_alive = 3 Wed May 27 09:19:48 2009 : Debug: revive_interval = 300 Wed May 27 09:19:48 2009 : Debug: status_check_timeout = 4 Wed May 27 09:19:48 2009 : Debug: username = "statuscheck@ispone.com.au" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: home_server_pool tecknowlogy_failover { Wed May 27 09:19:48 2009 : Debug: type = fail-over Wed May 27 09:19:48 2009 : Debug: home_server = tecknowlogy_1 Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: realm rtele.com.au { Wed May 27 09:19:48 2009 : Debug: acct_pool = tecknowlogy_failover Wed May 27 09:19:48 2009 : Debug: nostrip Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: home_server waterfront_1 { Wed May 27 09:19:48 2009 : Debug: ipaddr = 203.123.80.196 Wed May 27 09:19:48 2009 : Debug: port = 1813 Wed May 27 09:19:48 2009 : Debug: type = "acct" Wed May 27 09:19:48 2009 : Debug: secret = "tkwuIm278va" Wed May 27 09:19:48 2009 : Debug: response_window = 20 Wed May 27 09:19:48 2009 : Debug: max_outstanding = 65536 Wed May 27 09:19:48 2009 : Debug: zombie_period = 40 Wed May 27 09:19:48 2009 : Debug: status_check = "request" Wed May 27 09:19:48 2009 : Debug: ping_check = "none" Wed May 27 09:19:48 2009 : Debug: ping_interval = 30 Wed May 27 09:19:48 2009 : Debug: check_interval = 30 Wed May 27 09:19:48 2009 : Debug: num_answers_to_alive = 3 Wed May 27 09:19:48 2009 : Debug: num_pings_to_alive = 3 Wed May 27 09:19:48 2009 : Debug: revive_interval = 300 Wed May 27 09:19:48 2009 : Debug: status_check_timeout = 4 Wed May 27 09:19:48 2009 : Debug: username = "statuscheck@ispone.com.au" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: home_server_pool waterfront_failover { Wed May 27 09:19:48 2009 : Debug: type = fail-over Wed May 27 09:19:48 2009 : Debug: home_server = waterfront_1 Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: realm waterfront.net.au { Wed May 27 09:19:48 2009 : Debug: acct_pool = waterfront_failover Wed May 27 09:19:48 2009 : Debug: nostrip Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: home_server beagle_1 { Wed May 27 09:19:48 2009 : Debug: ipaddr = 202.4.231.249 Wed May 27 09:19:48 2009 : Debug: port = 1813 Wed May 27 09:19:48 2009 : Debug: type = "acct" Wed May 27 09:19:48 2009 : Debug: secret = "tkwuIm278va" Wed May 27 09:19:48 2009 : Debug: response_window = 20 Wed May 27 09:19:48 2009 : Debug: max_outstanding = 65536 Wed May 27 09:19:48 2009 : Debug: zombie_period = 40 Wed May 27 09:19:48 2009 : Debug: status_check = "request" Wed May 27 09:19:48 2009 : Debug: ping_check = "none" Wed May 27 09:19:48 2009 : Debug: ping_interval = 30 Wed May 27 09:19:48 2009 : Debug: check_interval = 30 Wed May 27 09:19:48 2009 : Debug: num_answers_to_alive = 3 Wed May 27 09:19:48 2009 : Debug: num_pings_to_alive = 3 Wed May 27 09:19:48 2009 : Debug: revive_interval = 300 Wed May 27 09:19:48 2009 : Debug: status_check_timeout = 4 Wed May 27 09:19:48 2009 : Debug: username = "statuscheck@ispone.com.au" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: home_server_pool beagle_failover { Wed May 27 09:19:48 2009 : Debug: type = fail-over Wed May 27 09:19:48 2009 : Debug: home_server = beagle_1 Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: realm beagle.com.au { Wed May 27 09:19:48 2009 : Debug: acct_pool = beagle_failover Wed May 27 09:19:48 2009 : Debug: nostrip Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: home_server summit_1 { Wed May 27 09:19:48 2009 : Debug: ipaddr = 203.94.170.204 Wed May 27 09:19:48 2009 : Debug: port = 1646 Wed May 27 09:19:48 2009 : Debug: type = "acct" Wed May 27 09:19:48 2009 : Debug: secret = "b92e1e3ab274" Wed May 27 09:19:48 2009 : Debug: response_window = 20 Wed May 27 09:19:48 2009 : Debug: max_outstanding = 65536 Wed May 27 09:19:48 2009 : Debug: zombie_period = 40 Wed May 27 09:19:48 2009 : Debug: status_check = "request" Wed May 27 09:19:48 2009 : Debug: ping_check = "none" Wed May 27 09:19:48 2009 : Debug: ping_interval = 30 Wed May 27 09:19:48 2009 : Debug: check_interval = 30 Wed May 27 09:19:48 2009 : Debug: num_answers_to_alive = 3 Wed May 27 09:19:48 2009 : Debug: num_pings_to_alive = 3 Wed May 27 09:19:48 2009 : Debug: revive_interval = 300 Wed May 27 09:19:48 2009 : Debug: status_check_timeout = 4 Wed May 27 09:19:48 2009 : Debug: username = "statuscheck@ispone.com.au" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: home_server_pool summit_failover { Wed May 27 09:19:48 2009 : Debug: type = fail-over Wed May 27 09:19:48 2009 : Debug: home_server = summit_1 Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: realm summit.net.au { Wed May 27 09:19:48 2009 : Debug: acct_pool = summit_failover Wed May 27 09:19:48 2009 : Debug: nostrip Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: realm DEFAULT { Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: radiusd_dial: #### Instantiating modules #### Wed May 27 09:19:48 2009 : Debug: instantiate { Wed May 27 09:19:48 2009 : Debug: (Loaded rlm_exec, checking if it's valid) Wed May 27 09:19:48 2009 : Debug: Module: Linked to module rlm_exec Wed May 27 09:19:48 2009 : Debug: Module: Instantiating echo Wed May 27 09:19:48 2009 : Debug: exec echo { Wed May 27 09:19:48 2009 : Debug: wait = yes Wed May 27 09:19:48 2009 : Debug: program = "/bin/echo %{User-Name}" Wed May 27 09:19:48 2009 : Debug: input_pairs = "request" Wed May 27 09:19:48 2009 : Debug: output_pairs = "reply" Wed May 27 09:19:48 2009 : Debug: packet_type = "Access-Reject" Wed May 27 09:19:48 2009 : Debug: shell_escape = yes Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: (Loaded rlm_expr, checking if it's valid) Wed May 27 09:19:48 2009 : Debug: Module: Linked to module rlm_expr Wed May 27 09:19:48 2009 : Debug: Module: Instantiating expr Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: radiusd_dial: #### Loading Virtual Servers #### Wed May 27 09:19:48 2009 : Debug: server { Wed May 27 09:19:48 2009 : Debug: modules { Wed May 27 09:19:48 2009 : Debug: Module: Checking authenticate {...} for more modules to load Wed May 27 09:19:48 2009 : Debug: (Loaded rlm_pap, checking if it's valid) Wed May 27 09:19:48 2009 : Debug: Module: Linked to module rlm_pap Wed May 27 09:19:48 2009 : Debug: Module: Instantiating pap Wed May 27 09:19:48 2009 : Debug: pap { Wed May 27 09:19:48 2009 : Debug: encryption_scheme = "auto" Wed May 27 09:19:48 2009 : Debug: auto_header = no Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: (Loaded rlm_chap, checking if it's valid) Wed May 27 09:19:48 2009 : Debug: Module: Linked to module rlm_chap Wed May 27 09:19:48 2009 : Debug: Module: Instantiating chap Wed May 27 09:19:48 2009 : Debug: Module: Checking authorize {...} for more modules to load Wed May 27 09:19:48 2009 : Debug: (Loaded rlm_preprocess, checking if it's valid) Wed May 27 09:19:48 2009 : Debug: Module: Linked to module rlm_preprocess Wed May 27 09:19:48 2009 : Debug: Module: Instantiating preprocess Wed May 27 09:19:48 2009 : Debug: preprocess { Wed May 27 09:19:48 2009 : Debug: huntgroups = "/etc/freeradius/huntgroups_dial" Wed May 27 09:19:48 2009 : Debug: hints = "/etc/freeradius/hints_dial" Wed May 27 09:19:48 2009 : Debug: with_ascend_hack = no Wed May 27 09:19:48 2009 : Debug: ascend_channels_per_line = 23 Wed May 27 09:19:48 2009 : Debug: with_ntdomain_hack = no Wed May 27 09:19:48 2009 : Debug: with_specialix_jetstream_hack = no Wed May 27 09:19:48 2009 : Debug: with_cisco_vsa_hack = no Wed May 27 09:19:48 2009 : Debug: with_alvarion_vsa_hack = no Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: (Loaded rlm_realm, checking if it's valid) Wed May 27 09:19:48 2009 : Debug: Module: Linked to module rlm_realm Wed May 27 09:19:48 2009 : Debug: Module: Instantiating suffix Wed May 27 09:19:48 2009 : Debug: realm suffix { Wed May 27 09:19:48 2009 : Debug: format = "suffix" Wed May 27 09:19:48 2009 : Debug: delimiter = "@" Wed May 27 09:19:48 2009 : Debug: ignore_default = no Wed May 27 09:19:48 2009 : Debug: ignore_null = no Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: (Loaded rlm_sql, checking if it's valid) Wed May 27 09:19:48 2009 : Debug: Module: Linked to module rlm_sql Wed May 27 09:19:48 2009 : Debug: Module: Instantiating auth_1 Wed May 27 09:19:48 2009 : Debug: sql auth_1 { Wed May 27 09:19:48 2009 : Debug: driver = "rlm_sql_mysql" Wed May 27 09:19:48 2009 : Debug: server = "localhost" Wed May 27 09:19:48 2009 : Debug: port = "" Wed May 27 09:19:48 2009 : Debug: login = "dial_radius" Wed May 27 09:19:48 2009 : Debug: password = "radius912m87" Wed May 27 09:19:48 2009 : Debug: radius_db = "Radius" Wed May 27 09:19:48 2009 : Debug: read_groups = yes Wed May 27 09:19:48 2009 : Debug: sqltrace = no Wed May 27 09:19:48 2009 : Debug: sqltracefile = "/var/log/freeradius/sqltrace_dial.sql" Wed May 27 09:19:48 2009 : Debug: readclients = no Wed May 27 09:19:48 2009 : Debug: deletestalesessions = yes Wed May 27 09:19:48 2009 : Debug: num_sql_socks = 5 Wed May 27 09:19:48 2009 : Debug: sql_user_name = "" Wed May 27 09:19:48 2009 : Debug: default_user_profile = "" Wed May 27 09:19:48 2009 : Debug: nas_query = "SELECT id,nasname,shortname,type,secret FROM nas" Wed May 27 09:19:48 2009 : Debug: authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{User-Name}' ORDER BY id" Wed May 27 09:19:48 2009 : Debug: authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{User-Name}' ORDER BY id" Wed May 27 09:19:48 2009 : Debug: authorize_group_check_query = "SELECT id, groupname, attribute, value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id" Wed May 27 09:19:48 2009 : Debug: authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id" Wed May 27 09:19:48 2009 : Debug: accounting_onoff_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_update_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_update_query_alt = "" Wed May 27 09:19:48 2009 : Debug: accounting_start_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_start_query_alt = "" Wed May 27 09:19:48 2009 : Debug: accounting_stop_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_stop_query_alt = "" Wed May 27 09:19:48 2009 : Debug: group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{User-Name}' ORDER BY priority" Wed May 27 09:19:48 2009 : Debug: connect_failure_retry_delay = 10 Wed May 27 09:19:48 2009 : Debug: simul_count_query = "" Wed May 27 09:19:48 2009 : Debug: simul_verify_query = "SELECT ACCTSESSIONID, USERNAME, NASIDENTIFIER, NASPORT, FRAMEDIPADDRESS, CALLINGSTATIONID, SERVICETYPE FROM RADONLINE WHERE USERNAME = '%{User-Name}'" Wed May 27 09:19:48 2009 : Debug: postauth_query = "" Wed May 27 09:19:48 2009 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Info: rlm_sql (auth_1): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Wed May 27 09:19:48 2009 : Info: rlm_sql (auth_1): Attempting to connect to dial_radius@localhost:/Radius Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): starting 0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): Attempting to connect rlm_sql_mysql #0 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): Connected new DB handle, #0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): starting 1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): Attempting to connect rlm_sql_mysql #1 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): Connected new DB handle, #1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): starting 2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): Attempting to connect rlm_sql_mysql #2 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): Connected new DB handle, #2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): starting 3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): Attempting to connect rlm_sql_mysql #3 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): Connected new DB handle, #3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): starting 4 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): Attempting to connect rlm_sql_mysql #4 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_1): Connected new DB handle, #4 Wed May 27 09:19:48 2009 : Debug: (Loaded rlm_sqlcounter, checking if it's valid) Wed May 27 09:19:48 2009 : Debug: Module: Linked to module rlm_sqlcounter Wed May 27 09:19:48 2009 : Debug: Module: Instantiating dial_prepaid_counter Wed May 27 09:19:48 2009 : Debug: sqlcounter dial_prepaid_counter { Wed May 27 09:19:48 2009 : Debug: counter-name = "Max-All-Session-Time" Wed May 27 09:19:48 2009 : Debug: check-name = "Max-All-Session" Wed May 27 09:19:48 2009 : Debug: key = "User-Name" Wed May 27 09:19:48 2009 : Debug: sqlmod-inst = "prepaid" Wed May 27 09:19:48 2009 : Debug: query = "SELECT SESSIONTIMEUSED FROM PREPAIDDIALUPTIME WHERE USERNAME = '%{%k}'" Wed May 27 09:19:48 2009 : Debug: reset = "never" Wed May 27 09:19:48 2009 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: rlm_sqlcounter: Reply attribute set to Session-Timeout. Wed May 27 09:19:48 2009 : Debug: rlm_sqlcounter: Counter attribute Max-All-Session-Time is number 11273 Wed May 27 09:19:48 2009 : Debug: rlm_sqlcounter: Check attribute Max-All-Session is number 11274 Wed May 27 09:19:48 2009 : Debug: rlm_sqlcounter: Current Time: 1243379988 [2009-05-27 09:19:48], Next reset 0 [2009-05-27 09:00:00] Wed May 27 09:19:48 2009 : Debug: rlm_sqlcounter: Current Time: 1243379988 [2009-05-27 09:19:48], Prev reset 0 [2009-05-27 09:00:00] Wed May 27 09:19:48 2009 : Debug: Module: Checking preacct {...} for more modules to load Wed May 27 09:19:48 2009 : Debug: Module: Checking accounting {...} for more modules to load Wed May 27 09:19:48 2009 : Debug: Module: Instantiating accounting_1 Wed May 27 09:19:48 2009 : Debug: sql accounting_1 { Wed May 27 09:19:48 2009 : Debug: driver = "rlm_sql_mysql" Wed May 27 09:19:48 2009 : Debug: server = "localhost" Wed May 27 09:19:48 2009 : Debug: port = "" Wed May 27 09:19:48 2009 : Debug: login = "dial_radius" Wed May 27 09:19:48 2009 : Debug: password = "radius912m87" Wed May 27 09:19:48 2009 : Debug: radius_db = "Radius" Wed May 27 09:19:48 2009 : Debug: read_groups = yes Wed May 27 09:19:48 2009 : Debug: sqltrace = no Wed May 27 09:19:48 2009 : Debug: sqltracefile = "/var/log/freeradius/sqltrace_dial.sql" Wed May 27 09:19:48 2009 : Debug: readclients = no Wed May 27 09:19:48 2009 : Debug: deletestalesessions = yes Wed May 27 09:19:48 2009 : Debug: num_sql_socks = 5 Wed May 27 09:19:48 2009 : Debug: sql_user_name = "" Wed May 27 09:19:48 2009 : Debug: default_user_profile = "" Wed May 27 09:19:48 2009 : Debug: nas_query = "SELECT id,nasname,shortname,type,secret FROM nas" Wed May 27 09:19:48 2009 : Debug: authorize_check_query = "" Wed May 27 09:19:48 2009 : Debug: authorize_reply_query = "" Wed May 27 09:19:48 2009 : Debug: authorize_group_check_query = "" Wed May 27 09:19:48 2009 : Debug: authorize_group_reply_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_onoff_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_update_query = "INSERT DELAYED INTO RADUSAGE_%Y%m (USERNAME, TIME_STAMP, ACCTSTATUSTYPE, ACCTDELAYTIME, ACCTINPUTOCTETS, ACCTOUTPUTOCTETS, ACCTSESSIONID, ACCTSESSIONTIME, ACCTTERMINATECAUSE, FRAMEDIPADDRESS, NASIDENTIFIER, NASPORT, DNIS, CALLINGSTATIONID, CALLZONE) VALUES ('%{User-Name}','%T','3','%{Acct-Delay-Time}','%{Acct-Input-Octets}','%{Acct-Output-Octets}','%{Acct-Session-Id}','%{Acct-Session-Time}','%{Ascend-Disconnect-Cause}','%{Framed-IP-Address}','%{NAS-IP-Address}','%{NAS-Port}','%{Called-Station-Id}','%{Calling-Station-Id}','%{X-Ascend-Billing-Number}')" Wed May 27 09:19:48 2009 : Debug: accounting_update_query_alt = "" Wed May 27 09:19:48 2009 : Debug: accounting_start_query = "INSERT DELAYED INTO RADUSAGE_%Y%m (USERNAME, TIME_STAMP, ACCTSTATUSTYPE, ACCTDELAYTIME, ACCTINPUTOCTETS, ACCTOUTPUTOCTETS, ACCTSESSIONID, ACCTSESSIONTIME, ACCTTERMINATECAUSE, FRAMEDIPADDRESS, NASIDENTIFIER, NASPORT, DNIS, CALLINGSTATIONID, CALLZONE) VALUES ('%{User-Name}','%T','1','%{Acct-Delay-Time}','%{Acct-Input-Octets}','%{Acct-Output-Octets}','%{Acct-Session-Id}','%{Acct-Session-Time}','%{Ascend-Disconnect-Cause}','%{Framed-IP-Address}','%{NAS-IP-Address}','%{NAS-Port}','%{Called-Station-Id}','%{Calling-Station-Id}','%{X-Ascend-Billing-Number}')" Wed May 27 09:19:48 2009 : Debug: accounting_start_query_alt = "" Wed May 27 09:19:48 2009 : Debug: accounting_stop_query = "INSERT DELAYED INTO RADUSAGE_%Y%m (USERNAME, TIME_STAMP, ACCTSTATUSTYPE, ACCTDELAYTIME, ACCTINPUTOCTETS, ACCTOUTPUTOCTETS, ACCTSESSIONID, ACCTSESSIONTIME, ACCTTERMINATECAUSE, FRAMEDIPADDRESS, NASIDENTIFIER, NASPORT, DNIS, CALLINGSTATIONID, CALLZONE) VALUES ('%{User-Name}','%T','2','%{Acct-Delay-Time}','%{Acct-Input-Octets}','%{Acct-Output-Octets}','%{Acct-Session-Id}','%{Acct-Session-Time}','%{Ascend-Disconnect-Cause}','%{Framed-IP-Address}','%{NAS-IP-Address}','%{NAS-Port}','%{Called-Station-Id}','%{Calling-Station-Id}','%{X-Ascend-Billing-Number}')" Wed May 27 09:19:48 2009 : Debug: accounting_stop_query_alt = "" Wed May 27 09:19:48 2009 : Debug: connect_failure_retry_delay = 10 Wed May 27 09:19:48 2009 : Debug: simul_count_query = "" Wed May 27 09:19:48 2009 : Debug: simul_verify_query = "" Wed May 27 09:19:48 2009 : Debug: postauth_query = "" Wed May 27 09:19:48 2009 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Info: rlm_sql (accounting_1): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Wed May 27 09:19:48 2009 : Info: rlm_sql (accounting_1): Attempting to connect to dial_radius@localhost:/Radius Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): starting 0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): Attempting to connect rlm_sql_mysql #0 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): Connected new DB handle, #0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): starting 1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): Attempting to connect rlm_sql_mysql #1 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): Connected new DB handle, #1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): starting 2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): Attempting to connect rlm_sql_mysql #2 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): Connected new DB handle, #2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): starting 3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): Attempting to connect rlm_sql_mysql #3 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): Connected new DB handle, #3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): starting 4 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): Attempting to connect rlm_sql_mysql #4 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_1): Connected new DB handle, #4 Wed May 27 09:19:48 2009 : Debug: Module: Instantiating accounting_2 Wed May 27 09:19:48 2009 : Debug: sql accounting_2 { Wed May 27 09:19:48 2009 : Debug: driver = "rlm_sql_mysql" Wed May 27 09:19:48 2009 : Debug: server = "localhost" Wed May 27 09:19:48 2009 : Debug: port = "" Wed May 27 09:19:48 2009 : Debug: login = "dial_radius" Wed May 27 09:19:48 2009 : Debug: password = "radius912m87" Wed May 27 09:19:48 2009 : Debug: radius_db = "Radius" Wed May 27 09:19:48 2009 : Debug: read_groups = yes Wed May 27 09:19:48 2009 : Debug: sqltrace = no Wed May 27 09:19:48 2009 : Debug: sqltracefile = "/var/log/freeradius/sqltrace_dial.sql" Wed May 27 09:19:48 2009 : Debug: readclients = no Wed May 27 09:19:48 2009 : Debug: deletestalesessions = yes Wed May 27 09:19:48 2009 : Debug: num_sql_socks = 5 Wed May 27 09:19:48 2009 : Debug: sql_user_name = "" Wed May 27 09:19:48 2009 : Debug: default_user_profile = "" Wed May 27 09:19:48 2009 : Debug: nas_query = "SELECT id,nasname,shortname,type,secret FROM nas" Wed May 27 09:19:48 2009 : Debug: authorize_check_query = "" Wed May 27 09:19:48 2009 : Debug: authorize_reply_query = "" Wed May 27 09:19:48 2009 : Debug: authorize_group_check_query = "" Wed May 27 09:19:48 2009 : Debug: authorize_group_reply_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_onoff_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_update_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_update_query_alt = "" Wed May 27 09:19:48 2009 : Debug: accounting_start_query = "INSERT INTO RADONLINE (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, NASPORTTYPE, SERVICETYPE, CALLINGSTATIONID, CALLEDSTATIONID, CALLZONE) VALUES ('%{User-Name}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{Acct-Session-Id}', '%T', '%{Framed-IP-Address}', '0%{NAS-Port-Type}', '%{Service-Type}', '%{Calling-Station-Id}', '%{Called-Station-Id}', '%{X-Ascend-Billing-Number}')" Wed May 27 09:19:48 2009 : Debug: accounting_start_query_alt = "" Wed May 27 09:19:48 2009 : Debug: accounting_stop_query = "DELETE FROM RADONLINE WHERE USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND NASPORT = '%{NAS-Port}'" Wed May 27 09:19:48 2009 : Debug: accounting_stop_query_alt = "" Wed May 27 09:19:48 2009 : Debug: connect_failure_retry_delay = 10 Wed May 27 09:19:48 2009 : Debug: simul_count_query = "" Wed May 27 09:19:48 2009 : Debug: simul_verify_query = "" Wed May 27 09:19:48 2009 : Debug: postauth_query = "" Wed May 27 09:19:48 2009 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Info: rlm_sql (accounting_2): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Wed May 27 09:19:48 2009 : Info: rlm_sql (accounting_2): Attempting to connect to dial_radius@localhost:/Radius Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): starting 0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): Attempting to connect rlm_sql_mysql #0 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): Connected new DB handle, #0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): starting 1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): Attempting to connect rlm_sql_mysql #1 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): Connected new DB handle, #1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): starting 2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): Attempting to connect rlm_sql_mysql #2 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): Connected new DB handle, #2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): starting 3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): Attempting to connect rlm_sql_mysql #3 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): Connected new DB handle, #3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): starting 4 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): Attempting to connect rlm_sql_mysql #4 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Wed May 27 09:19:48 2009 : Debug: rlm_sql (accounting_2): Connected new DB handle, #4 Wed May 27 09:19:48 2009 : Debug: Module: Instantiating prepaid Wed May 27 09:19:48 2009 : Debug: sql prepaid { Wed May 27 09:19:48 2009 : Debug: driver = "rlm_sql_mysql" Wed May 27 09:19:48 2009 : Debug: server = "localhost" Wed May 27 09:19:48 2009 : Debug: port = "" Wed May 27 09:19:48 2009 : Debug: login = "dial_radius" Wed May 27 09:19:48 2009 : Debug: password = "radius912m87" Wed May 27 09:19:48 2009 : Debug: radius_db = "Radius" Wed May 27 09:19:48 2009 : Debug: read_groups = yes Wed May 27 09:19:48 2009 : Debug: sqltrace = no Wed May 27 09:19:48 2009 : Debug: sqltracefile = "/var/log/freeradius/sqltrace_dial.sql" Wed May 27 09:19:48 2009 : Debug: readclients = no Wed May 27 09:19:48 2009 : Debug: deletestalesessions = yes Wed May 27 09:19:48 2009 : Debug: num_sql_socks = 5 Wed May 27 09:19:48 2009 : Debug: sql_user_name = "" Wed May 27 09:19:48 2009 : Debug: default_user_profile = "" Wed May 27 09:19:48 2009 : Debug: nas_query = "SELECT id,nasname,shortname,type,secret FROM nas" Wed May 27 09:19:48 2009 : Debug: authorize_check_query = "" Wed May 27 09:19:48 2009 : Debug: authorize_reply_query = "" Wed May 27 09:19:48 2009 : Debug: authorize_group_check_query = "" Wed May 27 09:19:48 2009 : Debug: authorize_group_reply_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_onoff_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_update_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_update_query_alt = "" Wed May 27 09:19:48 2009 : Debug: accounting_start_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_start_query_alt = "" Wed May 27 09:19:48 2009 : Debug: accounting_stop_query = "UPDATE PREPAIDDIALUPTIME SET SESSIONTIMEUSED = (SESSIONTIMEUSED + %{Acct-Session-Time}) WHERE USERNAME = '%{User-Name}'" Wed May 27 09:19:48 2009 : Debug: accounting_stop_query_alt = "" Wed May 27 09:19:48 2009 : Debug: connect_failure_retry_delay = 10 Wed May 27 09:19:48 2009 : Debug: simul_count_query = "" Wed May 27 09:19:48 2009 : Debug: simul_verify_query = "" Wed May 27 09:19:48 2009 : Debug: postauth_query = "" Wed May 27 09:19:48 2009 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Info: rlm_sql (prepaid): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Wed May 27 09:19:48 2009 : Info: rlm_sql (prepaid): Attempting to connect to dial_radius@localhost:/Radius Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): starting 0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): Attempting to connect rlm_sql_mysql #0 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): Connected new DB handle, #0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): starting 1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): Attempting to connect rlm_sql_mysql #1 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): Connected new DB handle, #1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): starting 2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): Attempting to connect rlm_sql_mysql #2 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): Connected new DB handle, #2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): starting 3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): Attempting to connect rlm_sql_mysql #3 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): Connected new DB handle, #3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): starting 4 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): Attempting to connect rlm_sql_mysql #4 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Wed May 27 09:19:48 2009 : Debug: rlm_sql (prepaid): Connected new DB handle, #4 Wed May 27 09:19:48 2009 : Debug: Module: Checking session {...} for more modules to load Wed May 27 09:19:48 2009 : Debug: Module: Checking post-auth {...} for more modules to load Wed May 27 09:19:48 2009 : Debug: Module: Instantiating auth_reject Wed May 27 09:19:48 2009 : Debug: sql auth_reject { Wed May 27 09:19:48 2009 : Debug: driver = "rlm_sql_mysql" Wed May 27 09:19:48 2009 : Debug: server = "localhost" Wed May 27 09:19:48 2009 : Debug: port = "" Wed May 27 09:19:48 2009 : Debug: login = "dial_radius" Wed May 27 09:19:48 2009 : Debug: password = "radius912m87" Wed May 27 09:19:48 2009 : Debug: radius_db = "Radius" Wed May 27 09:19:48 2009 : Debug: read_groups = yes Wed May 27 09:19:48 2009 : Debug: sqltrace = no Wed May 27 09:19:48 2009 : Debug: sqltracefile = "/var/log/freeradius/sqltrace_dial.sql" Wed May 27 09:19:48 2009 : Debug: readclients = no Wed May 27 09:19:48 2009 : Debug: deletestalesessions = yes Wed May 27 09:19:48 2009 : Debug: num_sql_socks = 5 Wed May 27 09:19:48 2009 : Debug: sql_user_name = "" Wed May 27 09:19:48 2009 : Debug: default_user_profile = "" Wed May 27 09:19:48 2009 : Debug: nas_query = "SELECT id,nasname,shortname,type,secret FROM nas" Wed May 27 09:19:48 2009 : Debug: authorize_check_query = "" Wed May 27 09:19:48 2009 : Debug: authorize_reply_query = "" Wed May 27 09:19:48 2009 : Debug: authorize_group_check_query = "" Wed May 27 09:19:48 2009 : Debug: authorize_group_reply_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_onoff_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_update_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_update_query_alt = "" Wed May 27 09:19:48 2009 : Debug: accounting_start_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_start_query_alt = "" Wed May 27 09:19:48 2009 : Debug: accounting_stop_query = "" Wed May 27 09:19:48 2009 : Debug: accounting_stop_query_alt = "" Wed May 27 09:19:48 2009 : Debug: connect_failure_retry_delay = 10 Wed May 27 09:19:48 2009 : Debug: simul_count_query = "" Wed May 27 09:19:48 2009 : Debug: simul_verify_query = "" Wed May 27 09:19:48 2009 : Debug: postauth_query = "INSERT DELAYED INTO RADAUTHLOG (REASON, TIME_STAMP, TYPE, USERNAME, CALLEDSTATIONID, CALLINGSTATIONID, PASS_WORD, CALLZONE) values ('%{%{Module-Failure-Message}:-%{reply:Packet-Type}}','%S','0','%{User-Name}','%{Called-Station-Id}','%{Calling-Station-Id}','%{%{User-Password}:-%{Chap-Password}}','%{Ascend-Billing-Number}')" Wed May 27 09:19:48 2009 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Info: rlm_sql (auth_reject): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Wed May 27 09:19:48 2009 : Info: rlm_sql (auth_reject): Attempting to connect to dial_radius@localhost:/Radius Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): starting 0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): Attempting to connect rlm_sql_mysql #0 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): Connected new DB handle, #0 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): starting 1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): Attempting to connect rlm_sql_mysql #1 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): Connected new DB handle, #1 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): starting 2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): Attempting to connect rlm_sql_mysql #2 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): Connected new DB handle, #2 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): starting 3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): Attempting to connect rlm_sql_mysql #3 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): Connected new DB handle, #3 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): starting 4 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): Attempting to connect rlm_sql_mysql #4 Wed May 27 09:19:48 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Wed May 27 09:19:48 2009 : Debug: rlm_sql (auth_reject): Connected new DB handle, #4 Wed May 27 09:19:48 2009 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Wed May 27 09:19:48 2009 : Debug: Module: Linked to module rlm_attr_filter Wed May 27 09:19:48 2009 : Debug: Module: Instantiating attr_filter.access_reject Wed May 27 09:19:48 2009 : Debug: attr_filter attr_filter.access_reject { Wed May 27 09:19:48 2009 : Debug: attrsfile = "/etc/freeradius/attrs.access_reject" Wed May 27 09:19:48 2009 : Debug: key = "%{User-Name}" Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: radiusd_dial: #### Opening IP addresses and Ports #### Wed May 27 09:19:48 2009 : Debug: listen { Wed May 27 09:19:48 2009 : Debug: type = "auth" Wed May 27 09:19:48 2009 : Debug: ipaddr = 192.168.0.212 Wed May 27 09:19:48 2009 : Debug: port = 1645 Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: listen { Wed May 27 09:19:48 2009 : Debug: type = "acct" Wed May 27 09:19:48 2009 : Debug: ipaddr = 192.168.0.212 Wed May 27 09:19:48 2009 : Debug: port = 1646 Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: main { Wed May 27 09:19:48 2009 : Debug: snmp = no Wed May 27 09:19:48 2009 : Debug: smux_password = "" Wed May 27 09:19:48 2009 : Debug: snmp_write_access = no Wed May 27 09:19:48 2009 : Debug: } Wed May 27 09:19:48 2009 : Debug: Listening on authentication address 192.168.0.212 port 1645 Wed May 27 09:19:48 2009 : Debug: Listening on accounting address 192.168.0.212 port 1646 Wed May 27 09:19:48 2009 : Debug: Listening on proxy address 192.168.0.212 port 1647 Wed May 27 09:19:48 2009 : Debug: Ready to process requests. rad_recv: Accounting-Request packet from host 192.168.0.19 port 1778, id=1, length=164 User-Name = "sajeewaw@isp1.net.au" Acct-Status-Type = Start NAS-Port-Type = Async Client-Port-Id = 1227 Acct-Status-Type = Start Acct-Delay-Time = 4 Caller-ID = "0386249797" Client-Port-DNIS = "0198308020" Framed-Protocol = PPP Framed-Address = 121.79.64.225 X-Ascend-Billing-Number = "W5" User-Service-Type = Framed Client-Id = 124.254.72.20 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Delay-Time = 0 Acct-Session-Time = 0 Acct-Session-Id = "301[]426932183" Wed May 27 09:19:54 2009 : Debug: +- entering group preacct Wed May 27 09:19:54 2009 : Debug: modsingle[preacct]: calling preprocess (rlm_preprocess) for request 0 Wed May 27 09:19:54 2009 : Debug: expand: %{User-Name} -> sajeewaw@isp1.net.au Wed May 27 09:19:54 2009 : Debug: modsingle[preacct]: returned from preprocess (rlm_preprocess) for request 0 Wed May 27 09:19:54 2009 : Debug: ++[preprocess] returns ok Wed May 27 09:19:54 2009 : Debug: modsingle[preacct]: calling suffix (rlm_realm) for request 0 Wed May 27 09:19:54 2009 : Debug: rlm_realm: Looking up realm "isp1.net.au" for User-Name = "sajeewaw@isp1.net.au" Wed May 27 09:19:54 2009 : Debug: rlm_realm: Found realm "DEFAULT" Wed May 27 09:19:54 2009 : Debug: rlm_realm: Adding Stripped-User-Name = "sajeewaw" Wed May 27 09:19:54 2009 : Debug: rlm_realm: Adding Realm = "DEFAULT" Wed May 27 09:19:54 2009 : Debug: rlm_realm: Accounting realm is LOCAL. Wed May 27 09:19:54 2009 : Debug: modsingle[preacct]: returned from suffix (rlm_realm) for request 0 Wed May 27 09:19:54 2009 : Debug: ++[suffix] returns noop Wed May 27 09:19:54 2009 : Debug: +- entering group accounting Wed May 27 09:19:54 2009 : Debug: modsingle[accounting]: calling accounting_1 (rlm_sql) for request 0 Wed May 27 09:19:54 2009 : Debug: expand: INSERT DELAYED INTO RADUSAGE_%Y%m (USERNAME, TIME_STAMP, ACCTSTATUSTYPE, ACCTDELAYTIME, ACCTINPUTOCTETS, ACCTOUTPUTOCTETS, ACCTSESSIONID, ACCTSESSIONTIME, ACCTTERMINATECAUSE, FRAMEDIPADDRESS, NASIDENTIFIER, NASPORT, DNIS, CALLINGSTATIONID, CALLZONE) VALUES ('%{User-Name}','%T','1','%{Acct-Delay-Time}','%{Acct-Input-Octets}','%{Acct-Output-Octets}','%{Acct-Session-Id}','%{Acct-Session-Time}','%{Ascend-Disconnect-Cause}','%{Framed-IP-Address}','%{NAS-IP-Address}','%{NAS-Port}','%{Called-Station-Id}','%{Calling-Station-Id}','%{X-Ascend-Billing-Number}') -> INSERT DELAYED INTO RADUSAGE_200905 (USERNAME, TIME_STAMP, ACCTSTATUSTYPE, ACCTDELAYTIME, ACCTINPUTOCTETS, ACCTOUTPUTOCTETS, ACCTSESSIONID, ACCTSESSIONTIME, ACCTTERMINATECAUSE, FRAMEDIPADDRESS, NASIDENTIFIER, NASPORT, DNIS, CALLINGSTATIONID, CALLZONE) VALUES ('sajeewaw@isp1.net.au','2009-05-27-09.19.54.000000','1','4','0','0','301=5B=5D426932183','0','','121.79.64.225','124.254.72.20','1227','0198308020','0386249797','W5') Wed May 27 09:19:54 2009 : Debug: rlm_sql (accounting_1): Reserving sql socket id: 4 Wed May 27 09:19:54 2009 : Debug: rlm_sql (accounting_1): Released sql socket id: 4 Wed May 27 09:19:54 2009 : Debug: modsingle[accounting]: returned from accounting_1 (rlm_sql) for request 0 Wed May 27 09:19:54 2009 : Debug: ++[accounting_1] returns ok Wed May 27 09:19:54 2009 : Debug: modsingle[accounting]: calling accounting_2 (rlm_sql) for request 0 Wed May 27 09:19:54 2009 : Debug: expand: INSERT INTO RADONLINE (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, NASPORTTYPE, SERVICETYPE, CALLINGSTATIONID, CALLEDSTATIONID, CALLZONE) VALUES ('%{User-Name}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{Acct-Session-Id}', '%T', '%{Framed-IP-Address}', '0%{NAS-Port-Type}', '%{Service-Type}', '%{Calling-Station-Id}', '%{Called-Station-Id}', '%{X-Ascend-Billing-Number}') -> INSERT INTO RADONLINE (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP, FRAMEDIPADDRESS, NASPORTTYPE, SERVICETYPE, CALLINGSTATIONID, CALLEDSTATIONID, CALLZONE) VALUES ('sajeewaw@isp1.net.au', '124.254.72.20', '1227', '301=5B=5D426932183', '2009-05-27-09.19.54.000000', '121.79.64.225', '0Async', 'Framed', '0386249797', '0198308020', 'W5') Wed May 27 09:19:54 2009 : Debug: rlm_sql (accounting_2): Reserving sql socket id: 4 Wed May 27 09:19:54 2009 : Debug: rlm_sql (accounting_2): Released sql socket id: 4 Wed May 27 09:19:54 2009 : Debug: modsingle[accounting]: returned from accounting_2 (rlm_sql) for request 0 Wed May 27 09:19:54 2009 : Debug: ++[accounting_2] returns ok Wed May 27 09:19:54 2009 : Debug: modsingle[accounting]: calling prepaid (rlm_sql) for request 0 Wed May 27 09:19:54 2009 : Debug: expand: -> Wed May 27 09:19:54 2009 : Debug: rlm_sql (prepaid): Reserving sql socket id: 4 Wed May 27 09:19:54 2009 : Debug: rlm_sql (prepaid): Released sql socket id: 4 Wed May 27 09:19:54 2009 : Debug: modsingle[accounting]: returned from prepaid (rlm_sql) for request 0 Wed May 27 09:19:54 2009 : Debug: ++[prepaid] returns ok Sending Accounting-Response of id 1 to 192.168.0.19 port 1778 Wed May 27 09:19:54 2009 : Debug: Finished request 0. Wed May 27 09:19:54 2009 : Debug: Cleaning up request 0 ID 1 with timestamp +6 Wed May 27 09:19:54 2009 : Debug: Going to the next request Wed May 27 09:19:54 2009 : Debug: Ready to process requests. Regards, Sajeewa Warnakulasuriya Systems Development Manager ispONE is a wholesale ISP built to help internet access resellers and independent ISPs to compete in the Australian marketplace through ONE Brand, ONE Provider, ONE Solution. Level 14 520 Collins Street Melbourne 3000 VIC Phone: 1300 663 400 Fax: 1300 665 400 E-Mail: sajeewaw@ispone.com.au Web: http://www.ispone.com.au/