This is some of the output of radiusd -X Starting - reading configuration files ... reread_config: reading radiusd.conf Config: including file: /usr/local/etc/raddb/proxy.conf Config: including file: /usr/local/etc/raddb/clients.conf Config: including file: /usr/local/etc/raddb/snmp.conf Config: including file: /usr/local/etc/raddb/eap.conf Config: including file: /usr/local/etc/raddb/mssql.conf main: prefix = "/usr/local" main: localstatedir = "/usr/local/var" main: logdir = "/usr/local/var/log/radius" main: libdir = "/usr/local/lib" main: radacctdir = "/usr/local/var/log/radius/radacct" main: hostname_lookups = no main: max_request_time = 30 main: cleanup_delay = 5 main: max_requests = 1024 main: delete_blocked_requests = 0 main: port = 1812 main: allow_core_dumps = no main: log_stripped_names = no main: log_file = "/usr/local/var/log/radius/radius.log" main: log_auth = yes main: log_auth_badpass = yes main: log_auth_goodpass = yes main: pidfile = "/usr/local/var/run/radiusd/radiusd.pid" main: user = "(null)" main: group = "(null)" main: usercollide = no main: lower_user = "no" main: lower_pass = "no" main: nospace_user = "no" main: nospace_pass = "no" main: checkrad = "/usr/local/sbin/checkrad" main: proxy_requests = yes proxy: retry_delay = 5 proxy: retry_count = 3 proxy: synchronous = no proxy: default_fallback = yes proxy: dead_time = 120 proxy: post_proxy_authorize = no proxy: wake_all_if_all_dead = no security: max_attributes = 200 security: reject_delay = 1 security: status_server = no main: debug_level = 0 read_config_files: reading dictionary read_config_files: reading naslist Using deprecated naslist file. Support for this will go away soon. read_config_files: reading clients read_config_files: reading realms listen: port = 1645 listen: type = "auth" listen: port = 1646 listen: type = "acct" radiusd: entering modules setup Module: Library search path is /usr/local/lib Module: Loaded exec exec: wait = yes exec: program = "(null)" exec: input_pairs = "request" exec: output_pairs = "(null)" exec: packet_type = "(null)" rlm_exec: Wait=yes but no output defined. Did you mean output=none? Module: Instantiated exec (exec) Module: Loaded expr Module: Instantiated expr (expr) Module: Loaded PAP pap: encryption_scheme = "crypt" pap: auto_header = yes Module: Instantiated pap (pap) Module: Loaded CHAP Module: Instantiated chap (chap) Module: Loaded MS-CHAP mschap: use_mppe = yes mschap: require_encryption = no mschap: require_strong = no mschap: with_ntdomain_hack = no mschap: passwd = "(null)" mschap: ntlm_auth = "(null)" Module: Instantiated mschap (mschap) Module: Loaded System unix: cache = no unix: passwd = "(null)" unix: shadow = "(null)" unix: group = "(null)" unix: radwtmp = "/usr/local/var/log/radius/radwtmp" unix: usegroup = no unix: cache_reload = 600 Module: Instantiated unix (unix) Module: Loaded eap eap: default_eap_type = "md5" eap: timer_expire = 60 eap: ignore_unknown_eap_types = no eap: cisco_accounting_username_bug = no rlm_eap: Loaded and initialized type md5 rlm_eap: Loaded and initialized type leap gtc: challenge = "Password: " gtc: auth_type = "PAP" rlm_eap: Loaded and initialized type gtc mschapv2: with_ntdomain_hack = no rlm_eap: Loaded and initialized type mschapv2 Module: Instantiated eap (eap) Module: Loaded preprocess preprocess: huntgroups = "/usr/local/etc/raddb/huntgroups" preprocess: hints = "/usr/local/etc/raddb/hints" preprocess: with_ascend_hack = no preprocess: ascend_channels_per_line = 23 preprocess: with_ntdomain_hack = no preprocess: with_specialix_jetstream_hack = no preprocess: with_cisco_vsa_hack = no preprocess: with_alvarion_vsa_hack = no Module: Instantiated preprocess (preprocess) Module: Loaded realm realm: format = "suffix" realm: delimiter = "@" realm: ignore_default = no realm: ignore_null = no Module: Instantiated realm (suffix) Module: Loaded files files: usersfile = "/usr/local/etc/raddb/users" files: acctusersfile = "/usr/local/etc/raddb/acct_users" files: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users" files: compat = "no" Module: Instantiated files (files) Module: Loaded SQL sql: driver = "rlm_sql_unixodbc" sql: server = "MSSQL" sql: port = "" sql: login = "xxxxx" sql: password = "xxxxx" sql: radius_db = "radius" sql: nas_table = "nas" sql: sqltrace = no sql: sqltracefile = "/usr/local/var/log/radius/sqltrace.sql" sql: readclients = no sql: deletestalesessions = yes sql: num_sql_socks = 35 sql: sql_user_name = "%{User-Name}" sql: default_user_profile = "" sql: query_on_not_found = no sql: authorize_check_query = "SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id" sql: authorize_reply_query = "SELECT id,UserName,Attribute,Value,op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id" sql: authorize_group_check_query = "SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,radusergroup WHERE radusergroup.Username = '%{SQL-User-Name}' AND radusergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id" sql: authorize_group_reply_query = "SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,radusergroup WHERE radusergroup.Username = '%{SQL-User-Name}' AND radusergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id" sql: accounting_onoff_query = "" sql: accounting_update_query = "EXEC acct_update '%S', '%{Acct-Session-Time}', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Acct-Input-Gigawords}', '%{Acct-Output-Gigawords}', 'Acct-Update', '%{Acct-Delay-Time}', '%{Connect-Info}', '%{Acct-Session-Id}', '%{SQL-User-Name}', '%{NAS-IP-Address}', '%{Acct-Unique-Session-Id}', '%{Realm}', '0', '%{NAS-Port-Type}', '%{Acct-Authentic}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}';" sql: accounting_update_query_alt = "INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctSessionTime, AcctAuthentic, ConnectInfo_start, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, XAscendSessionSvrKey) VALUES('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port-Id}', '%{NAS-Port-Type}', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{X-Ascend-Session-Svr-Key}');INSERT into radlac values ('%{Acct-Unique-Session-Id}','%{Tunnel-Client-Auth-Id}', '%{SQL-User-Name}', '%S')" sql: accounting_start_query = "INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, AcctStopDelay, XAscendSessionSvrKey) VALUES('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port-Id}', '%{NAS-Port-Type}', '%S', '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{Acct-Delay-Time}', '0', '%{X-Ascend-Session-Svr-Key}'); INSERT into radlac values ('%{Acct-Unique-Session-Id}','%{Tunnel-Client-Auth-Id}', '%{SQL-User-Name}', '%S')" sql: accounting_start_query_alt = "" sql: accounting_stop_query = "EXEC acct_stop '%S', '%{Acct-Session-Time}', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Acct-Input-Gigawords}', '%{Acct-Output-Gigawords}', '%{Acct-Terminate-Cause}', '%{Acct-Delay-Time}', '%{Connect-Info}', '%{Acct-Session-Id}', '%{SQL-User-Name}', '%{NAS-IP-Address}';" sql: accounting_stop_query_alt = "" sql: group_membership_query = "" sql: connect_failure_retry_delay = 60 sql: simul_count_query = "SELECT COUNT(*) FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime = 0" sql: simul_verify_query = "SELECT RadAcctId, AcctSessionId, UserName, NASIPAddress, NASPortId, FramedIPAddress, CallingStationId, FramedProtocol FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime = 0" sql: postauth_query = "" sql: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" rlm_sql (sql): Driver rlm_sql_unixodbc (module rlm_sql_unixodbc) loaded and linked rlm_sql (sql): Attempting to connect to xxxxx@MSSQL:/radius rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #0 rlm_sql (sql): Connected new DB handle, #0 rlm_sql (sql): starting 1 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #1 rlm_sql (sql): Connected new DB handle, #1 rlm_sql (sql): starting 2 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #2 rlm_sql (sql): Connected new DB handle, #2 rlm_sql (sql): starting 3 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #3 rlm_sql (sql): Connected new DB handle, #3 rlm_sql (sql): starting 4 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #4 rlm_sql (sql): Connected new DB handle, #4 rlm_sql (sql): starting 5 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #5 rlm_sql (sql): Connected new DB handle, #5 rlm_sql (sql): starting 6 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #6 rlm_sql (sql): Connected new DB handle, #6 rlm_sql (sql): starting 7 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #7 rlm_sql (sql): Connected new DB handle, #7 rlm_sql (sql): starting 8 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #8 rlm_sql (sql): Connected new DB handle, #8 rlm_sql (sql): starting 9 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #9 rlm_sql (sql): Connected new DB handle, #9 rlm_sql (sql): starting 10 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #10 rlm_sql (sql): Connected new DB handle, #10 rlm_sql (sql): starting 11 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #11 rlm_sql (sql): Connected new DB handle, #11 rlm_sql (sql): starting 12 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #12 rlm_sql (sql): Connected new DB handle, #12 rlm_sql (sql): starting 13 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #13 rlm_sql (sql): Connected new DB handle, #13 rlm_sql (sql): starting 14 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #14 rlm_sql (sql): Connected new DB handle, #14 rlm_sql (sql): starting 15 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #15 rlm_sql (sql): Connected new DB handle, #15 rlm_sql (sql): starting 16 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #16 rlm_sql (sql): Connected new DB handle, #16 rlm_sql (sql): starting 17 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #17 rlm_sql (sql): Connected new DB handle, #17 rlm_sql (sql): starting 18 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #18 rlm_sql (sql): Connected new DB handle, #18 rlm_sql (sql): starting 19 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #19 rlm_sql (sql): Connected new DB handle, #19 rlm_sql (sql): starting 20 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #20 rlm_sql (sql): Connected new DB handle, #20 rlm_sql (sql): starting 21 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #21 rlm_sql (sql): Connected new DB handle, #21 rlm_sql (sql): starting 22 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #22 rlm_sql (sql): Connected new DB handle, #22 rlm_sql (sql): starting 23 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #23 rlm_sql (sql): Connected new DB handle, #23 rlm_sql (sql): starting 24 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #24 rlm_sql (sql): Connected new DB handle, #24 rlm_sql (sql): starting 25 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #25 rlm_sql (sql): Connected new DB handle, #25 rlm_sql (sql): starting 26 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #26 rlm_sql (sql): Connected new DB handle, #26 rlm_sql (sql): starting 27 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #27 rlm_sql (sql): Connected new DB handle, #27 rlm_sql (sql): starting 28 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #28 rlm_sql (sql): Connected new DB handle, #28 rlm_sql (sql): starting 29 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #29 rlm_sql (sql): Connected new DB handle, #29 rlm_sql (sql): starting 30 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #30 rlm_sql (sql): Connected new DB handle, #30 rlm_sql (sql): starting 31 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #31 rlm_sql (sql): Connected new DB handle, #31 rlm_sql (sql): starting 32 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #32 rlm_sql (sql): Connected new DB handle, #32 rlm_sql (sql): starting 33 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #33 rlm_sql (sql): Connected new DB handle, #33 rlm_sql (sql): starting 34 rlm_sql (sql): Attempting to connect rlm_sql_unixodbc #34 rlm_sql (sql): Connected new DB handle, #34 Module: Instantiated sql (sql) Module: Loaded Acct-Unique-Session-Id acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Module: Instantiated acct_unique (acct_unique) Module: Loaded detail detail: detailfile = "/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" detail: detailperm = 384 detail: dirperm = 493 detail: locking = no Module: Instantiated detail (detail) Module: Loaded radutmp radutmp: filename = "/usr/local/var/log/radius/radutmp" radutmp: username = "%{User-Name}" radutmp: case_sensitive = yes radutmp: check_with_nas = yes radutmp: perm = 384 radutmp: callerid = yes Module: Instantiated radutmp (radutmp) Module: Loaded IPPOOL ippool: session-db = "/usr/local/etc/raddb/db.ippool" ippool: ip-index = "/usr/local/etc/raddb/db.ipindex" ippool: range-start = 192.168.8.1 IP address [192.168.8.1] ippool: range-stop = 192.168.8.254 IP address [192.168.8.254] ippool: netmask = 255.255.255.0 IP address [255.255.255.0] ippool: cache-size = 25400 ippool: override = yes ippool: maximum-timeout = 0 Module: Instantiated ippool (pool) Listening on authentication *:1645 Listening on accounting *:1646 Ready to process requests. rad_recv: Accounting-Request packet from host xxx.xxx.xxx.xxx:1646, id=165, length=240 Acct-Session-Id = "00023865" Tunnel-Type:0 = L2TP Tunnel-Medium-Type:0 = IPv4 Tunnel-Server-Endpoint:0 = "xxx.xxx.xxx.xxx" Tunnel-Client-Endpoint:0 = "xxx.xxx.xxx.xxx" Tunnel-Assignment-Id:0 = "1" Tunnel-Client-Auth-Id:0 = "xxxxxxx" Tunnel-Server-Auth-Id:0 = "xxxxxxx" Acct-Tunnel-Connection = "739313803" Framed-Protocol = PPP Framed-IP-Address = xxx.xxx.xxx.xxx User-Name = "" Acct-Session-Time = 15270 Acct-Input-Octets = 193292 Acct-Output-Octets = 180794 Acct-Input-Packets = 3115 Acct-Output-Packets = 3120 Acct-Authentic = RADIUS Acct-Status-Type = Interim-Update NAS-Port-Type = Virtual NAS-Port = 204 NAS-Port-Id = "Uniq-Sess-ID204" Connect-Info = "153354240" Service-Type = Framed-User NAS-IP-Address = xxx.xxx.xxx.xxx Acct-Delay-Time = 0 Processing the preacct section of radiusd.conf modcall: entering group preacct for request 46 modcall[preacct]: module "preprocess" returns noop for request 46 rlm_acct_unique: Hashing 'NAS-Port = 204,Client-IP-Address = xxx.xxx.xxx.xxx,NAS-IP-Address = xxx.xxx.xxx.xxx,Acct-Session-Id = "00023865",User-Name = "xxxxxxx@xxxx"' rlm_acct_unique: Acct-Unique-Session-ID = "75aa601bea890dcd". modcall[preacct]: module "acct_unique" returns ok for request 46 rlm_realm: Looking up realm "xxxx" for User-Name = "xxxxxxx@xxxx" rlm_realm: Found realm "DEFAULT" rlm_realm: Adding Stripped-User-Name = "xxxxxxx" rlm_realm: Proxying request from user xxxxxxx to realm DEFAULT rlm_realm: Adding Realm = "DEFAULT" rlm_realm: Accounting realm is LOCAL. modcall[preacct]: module "suffix" returns noop for request 46 modcall[preacct]: module "files" returns noop for request 46 modcall: leaving group preacct (returns ok) for request 46 Processing the accounting section of radiusd.conf modcall: entering group accounting for request 46 radius_xlat: '/usr/local/var/log/radius/radacct/xxx.xxx.xxx.xxx/detail-20090318' rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/xxx.xxx.xxx.xxx/detail-20090318 modcall[accounting]: module "detail" returns ok for request 46 modcall[accounting]: module "unix" returns noop for request 46 radius_xlat: '/usr/local/var/log/radius/radutmp' radius_xlat: 'royalceramic@aya.sy' modcall[accounting]: module "radutmp" returns ok for request 46 rlm_ippool: This is not an Accounting-Stop. Return NOOP. modcall[accounting]: module "pool" returns noop for request 46 radius_xlat: 'xxxxxx@xxxx' rlm_sql (sql): sql_set_user escaped user --> 'xxxxxx@xxxx' radius_xlat: 'EXEC acct_update '2009-03-18 22:45:41', '15270', '193292', '180794', '', '', 'Acct-Update', '0', '153354240', '00023865', 'xxxxxx@xxxx', 'xxx.xxx.xxx.xxx', '75aa601bea890dcd', 'DEFAULT', '0', 'Virtual', 'RADIUS', '', '', 'Framed-User', 'PPP', 'xxx.xxx.xxx.xxx';' rlm_sql (sql): Reserving sql socket id: 19 rlm_sql (sql): Released sql socket id: 19 modcall[accounting]: module "sql" returns ok for request 46 modcall: leaving group accounting (returns ok) for request 46 Sending Accounting-Response of id 165 to 10.10.10.5 port 1646 Finished request 46 Going to the next request --- Walking the entire request list --- Waking up in 6 seconds... rad_recv: Accounting-Request packet from host xxx.xxx.xxx.xxx:1646, id=166, length=237 Acct-Session-Id = "0002380B" Tunnel-Type:0 = L2TP Tunnel-Medium-Type:0 = IPv4 Tunnel-Server-Endpoint:0 = "xxx.xxx.xxx.xxx" Tunnel-Client-Endpoint:0 = "xxx.xxx.xxx.xxx" Tunnel-Assignment-Id:0 = "1" Tunnel-Client-Auth-Id:0 = "xxxxxxxx" Tunnel-Server-Auth-Id:0 = "xxxxxxxx" Acct-Tunnel-Connection = "3987015321" Framed-Protocol = PPP Framed-IP-Address = xxx.xxx.xxx.xxx User-Name = "xxxxxxxx@xxxx" Acct-Session-Time = 17096 Acct-Input-Octets = 253790 Acct-Output-Octets = 426579 Acct-Input-Packets = 3165 Acct-Output-Packets = 3240 Acct-Authentic = RADIUS Acct-Status-Type = Interim-Update NAS-Port-Type = Virtual NAS-Port = 894 NAS-Port-Id = "Uniq-Sess-ID894" Connect-Info = "153354240" Service-Type = Framed-User NAS-IP-Address = xxx.xxx.xxx.xxx Acct-Delay-Time = 0 Processing the preacct section of radiusd.conf modcall: entering group preacct for request 47 modcall[preacct]: module "preprocess" returns noop for request 47 rlm_acct_unique: Hashing 'NAS-Port = 894,Client-IP-Address = xxx.xxx.xxx.xxx,NAS-IP-Address = xxx.xxx.xxx.xxx,Acct-Session-Id = "0002380B",User-Name = "xxxxxxxx@xxxx"' rlm_acct_unique: Acct-Unique-Session-ID = "2aa4d04abb7544a1". modcall[preacct]: module "acct_unique" returns ok for request 47 rlm_realm: Looking up realm "xxxx" for User-Name = "xxxxxxx@xxxxx" rlm_realm: Found realm "DEFAULT" rlm_realm: Adding Stripped-User-Name = "xxxxxxxx" rlm_realm: Proxying request from user xxxxxxxx to realm DEFAULT rlm_realm: Adding Realm = "DEFAULT" rlm_realm: Accounting realm is LOCAL. modcall[preacct]: module "suffix" returns noop for request 47 modcall[preacct]: module "files" returns noop for request 47 modcall: leaving group preacct (returns ok) for request 47 Processing the accounting section of radiusd.conf modcall: entering group accounting for request 47 radius_xlat: '/usr/local/var/log/radius/radacct/xxx.xxx.xxx.xxx/detail-20090318' rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/xxx.xxx.xxx.xxx/detail-20090318 modcall[accounting]: module "detail" returns ok for request 47 modcall[accounting]: module "unix" returns noop for request 47 radius_xlat: '/usr/local/var/log/radius/radutmp' radius_xlat: 'xxxxxxxxx@xxxx' modcall[accounting]: module "radutmp" returns ok for request 47 rlm_ippool: This is not an Accounting-Stop. Return NOOP. modcall[accounting]: module "pool" returns noop for request 47 radius_xlat: 'xxxxxxxx@xxxx' rlm_sql (sql): sql_set_user escaped user --> 'xxxxxxxxxx@xxxx' radius_xlat: 'EXEC acct_update '2009-03-18 22:45:44', '17096', '253790', '426579', '', '', 'Acct-Update', '0', '153354240', '0002380B', 'xxxxxxx@xxxx', 'xxx.xxx.xxx.xxx', '2aa4d04abb7544a1', 'DEFAULT', '0', 'Virtual', 'RADIUS', '', '', 'Framed-User', 'PPP', 'xxx.xxx.xxx.xxx';' rlm_sql (sql): Reserving sql socket id: 18 rlm_sql (sql): Couldn't update SQL accounting ALIVE record - 00000 rlm_sql (sql): Released sql socket id: 18 modcall[accounting]: module "sql" returns fail for request 47 modcall: leaving group accounting (returns fail) for request 47 Finished request 47 Going to the next request --- Walking the entire request list --- Waking up in 3 seconds...Going to the next request --- Walking the entire request list --- Waking up in 1 seconds... rad_recv: Access-Request packet from host xxx.xxx.xxx.xxx:1645, id=252, length=98 User-Name = "xxxxx@xxx" User-Password = "xxxxxxx" NAS-Port-Type = Virtual NAS-Port = 799 NAS-Port-Id = "Uniq-Sess-ID799" Connect-Info = "153354240" Service-Type = Dialout-Framed-User NAS-IP-Address = xxx.xxx.xxx.xxx Processing the authorize section of radiusd.conf modcall: entering group authorize for request 193 modcall[authorize]: module "preprocess" returns ok for request 193 modcall[authorize]: module "chap" returns noop for request 193 modcall[authorize]: module "mschap" returns noop for request 193 rlm_realm: No '@' in User-Name = "xxxxxxx", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 193 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 193 users: Matched entry DEFAULT at line 153 modcall[authorize]: module "files" returns ok for request 193 radius_xlat: 'xxxxxxxx' rlm_sql (sql): sql_set_user escaped user --> 'xxxxxx' radius_xlat: 'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE Username = 'xxxxxx' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 6 rlm_sql_getvpdata: database query error rlm_sql (sql): SQL query error; rejecting user rlm_sql (sql): Released sql socket id: 6 modcall[authorize]: module "sql" returns fail for request 193 modcall: leaving group authorize (returns fail) for request 193 most of the output of the debug is normal but every now and then I get these errors also the authentications sometimes takes long time, about 30 seconds to get the accept packet from the radius I really appreciate your help Best Regards Ahmed Adel ________________________________ From: "tnt@kalik.net" <tnt@kalik.net> To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Sent: Tuesday, March 17, 2009 6:18:19 PM Subject: Re: Accounting error

I hope anyone can help me with these errors I have in the radius.log file:

Error: rlm_sql_getvpdata: database query error Error: rlm_sql (sql): SQL query error; rejecting user Error: rlm_sql (sql): Couldn't update SQL accounting ALIVE record - 00000

I am using freeradius 1.1.7 with freetds and MSSQL 2005 as the backend database, the radius receives interim accounting update packets to calculate users utlized bandwidth and the data is inserted into the MSSQL database using SQL Procedures.

Does anyone knows what may cause these errors to occure, note that when I run radius -X most of the update statements return with status ok and for the statements that return with this error, they run fine from the MSSQL console.

Post the radiusd -X output showing those errors. Ivan Kalik Kalik Informatika ISP - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

The procedures work most of the time plus on the failing cases when I run the procedure by my self it works, anyway what about the other error: radius_xlat: 'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE Username = 'xxxxxx' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 6 rlm_sql_getvpdata: database query error rlm_sql (sql): SQL query error; rejecting user do you know what my cause this?? Best Regards Ahmed Adel ________________________________ From: "tnt@kalik.net" <tnt@kalik.net> To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Sent: Wednesday, March 18, 2009 11:38:15 PM Subject: Re: Accounting error

radius_xlat: 'EXEC acct_update '2009-03-18 22:45:44', '17096', '253790', '426579', '', '', 'Acct-Update', '0', '153354240', '0002380B', 'xxxxxxx@xxxx', 'xxx.xxx.xxx.xxx', '2aa4d04abb7544a1', 'DEFAULT', '0', 'Virtual', 'RADIUS', '', '', 'Framed-User', 'PPP', 'xxx.xxx.xxx.xxx';' rlm_sql (sql): Reserving sql socket id: 18 rlm_sql (sql): Couldn't update SQL accounting ALIVE record - 00000 rlm_sql (sql): Released sql socket id: 18

most of the output of the debug is normal but every now and then I get these errors also the authentications sometimes takes long time, about 30 seconds to get the accept packet from the radius

I really appreciate your help

But you are not using freeradius queries for accounting. You are using some custom stored procedure. It's failing sometimes. We have no idea what does that procedure do. Ask someone who does. Ivan Kalik Kalik Informatika ISP - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

Thank you very much, I will try to connect to another server and tell you if the problem still exists. Best Regards Ahmed Adel ________________________________ From: "tnt@kalik.net" <tnt@kalik.net> To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Sent: Thursday, March 19, 2009 12:05:15 AM Subject: Re: Accounting error

The procedures work most of the time plus on the failing cases when I run the procedure by my self it works, anyway what about the other error:

radius_xlat: 'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE Username = 'xxxxxx' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 6 rlm_sql_getvpdata: database query error rlm_sql (sql): SQL query error; rejecting user

do you know what my cause this??

That's not accounting. I didn't look at that. Problem in both cases is - MS SQL server. It looks like it died. It stopped responding. Ivan Kalik Kalik Informatika ISP - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html