Hi all,
I have a problem with accounting. My problem is duplicate
Anyone have a idea
Here is my Radius debug log and sql.conf file
linux:/var/log # radiusd -Xx
Mon Sep 6 14:12:29 2004 : Info: Starting - reading configuration files ...
Mon Sep 6 14:12:29 2004 : Debug: reread_config: reading radiusd.conf
Mon Sep 6 14:12:29 2004 : Debug: Config: including file:
/etc/raddb/proxy.conf
Mon Sep 6 14:12:29 2004 : Debug: Config: including file:
/etc/raddb/clients.conf
Mon Sep 6 14:12:29 2004 : Debug: Config: including file:
/etc/raddb/snmp.conf
Mon Sep 6 14:12:29 2004 : Debug: Config: including file:
/etc/raddb/sql.conf
Mon Sep 6 14:12:29 2004 : Debug: main: prefix = "/usr"
Mon Sep 6 14:12:29 2004 : Debug: main: localstatedir = "/var"
Mon Sep 6 14:12:29 2004 : Debug: main: logdir = "/var/log/radius"
Mon Sep 6 14:12:29 2004 : Debug: main: libdir = "/usr/lib/freeradius"
Mon Sep 6 14:12:29 2004 : Debug: main: radacctdir =
"/var/log/radius/radacct"
Mon Sep 6 14:12:29 2004 : Debug: main: hostname_lookups = no Mon Sep 6
14:12:29 2004 : Debug: main: max_request_time = 30 Mon Sep 6 14:12:29 2004
: Debug: main: cleanup_delay = 5 Mon Sep 6 14:12:29 2004 : Debug: main:
max_requests = 1024 Mon Sep 6 14:12:29 2004 : Debug: main:
delete_blocked_requests = 0 Mon Sep 6 14:12:29 2004 : Debug: main: port =
0 Mon Sep 6 14:12:29 2004 : Debug: main: allow_core_dumps = no Mon Sep 6
14:12:29 2004 : Debug: main: log_stripped_names = no Mon Sep 6 14:12:29
2004 : Debug: main: log_file = "/var/log/radius/radius.log"
Mon Sep 6 14:12:29 2004 : Debug: main: log_auth = no Mon Sep 6 14:12:29
2004 : Debug: main: log_auth_badpass = no Mon Sep 6 14:12:29 2004 : Debug:
main: log_auth_goodpass = no Mon Sep 6 14:12:29 2004 : Debug: main:
pidfile = "/var/run/radiusd/radiusd.pid"
Mon Sep 6 14:12:29 2004 : Debug: main: user = "radiusd"
Mon Sep 6 14:12:29 2004 : Debug: main: group = "radiusd"
Mon Sep 6 14:12:29 2004 : Debug: main: usercollide = no Mon Sep 6
14:12:29 2004 : Debug: main: lower_user = "no"
Mon Sep 6 14:12:29 2004 : Debug: main: lower_pass = "no"
Mon Sep 6 14:12:29 2004 : Debug: main: nospace_user = "no"
Mon Sep 6 14:12:29 2004 : Debug: main: nospace_pass = "no"
Mon Sep 6 14:12:29 2004 : Debug: main: checkrad = "/usr/sbin/checkrad"
Mon Sep 6 14:12:29 2004 : Debug: main: proxy_requests = yes Mon Sep 6
14:12:29 2004 : Debug: proxy: retry_delay = 5 Mon Sep 6 14:12:29 2004 :
Debug: proxy: retry_count = 3 Mon Sep 6 14:12:29 2004 : Debug: proxy:
synchronous = no Mon Sep 6 14:12:29 2004 : Debug: proxy: default_fallback
= yes Mon Sep 6 14:12:29 2004 : Debug: proxy: dead_time = 120 Mon Sep 6
14:12:29 2004 : Debug: proxy: post_proxy_authorize = yes Mon Sep 6
14:12:29 2004 : Debug: proxy: wake_all_if_all_dead = no Mon Sep 6 14:12:29
2004 : Debug: security: max_attributes = 200 Mon Sep 6 14:12:29 2004 :
Debug: security: reject_delay = 1 Mon Sep 6 14:12:29 2004 : Debug:
security: status_server = no Mon Sep 6 14:12:29 2004 : Debug: main:
debug_level = 0 Mon Sep 6 14:12:29 2004 : Debug: read_config_files:
reading dictionary Mon Sep 6 14:12:29 2004 : Debug: read_config_files:
reading naslist Mon Sep 6 14:12:29 2004 : Info: Using deprecated naslist
file. Support for this will go away soon.
Mon Sep 6 14:12:29 2004 : Debug: read_config_files: reading clients Mon
Sep 6 14:12:29 2004 : Info: Using deprecated clients file. Support for
this will go away soon.
Mon Sep 6 14:12:29 2004 : Debug: read_config_files: reading realms Mon Sep
6 14:12:29 2004 : Debug: radiusd: entering modules setup Mon Sep 6
14:12:29 2004 : Debug: Module: Library search path is /usr/lib/freeradius
Mon Sep 6 14:12:29 2004 : Debug: Module: Loaded expr Mon Sep 6 14:12:29
2004 : Debug: Module: Instantiated expr (expr) Mon Sep 6 14:12:29 2004 :
Debug: Module: Loaded PAP Mon Sep 6 14:12:29 2004 : Debug: pap:
encryption_scheme = "crypt"
Mon Sep 6 14:12:29 2004 : Debug: Module: Instantiated pap (pap) Mon Sep 6
14:12:29 2004 : Debug: Module: Loaded CHAP Mon Sep 6 14:12:29 2004 : Debug:
Module: Instantiated chap (chap) Mon Sep 6 14:12:29 2004 : Debug: Module:
Loaded MS-CHAP Mon Sep 6 14:12:29 2004 : Debug: mschap: use_mppe = yes Mon
Sep 6 14:12:29 2004 : Debug: mschap: require_encryption = no Mon Sep 6
14:12:29 2004 : Debug: mschap: require_strong = no Mon Sep 6 14:12:29 2004
: Debug: mschap: passwd = "(null)"
Mon Sep 6 14:12:29 2004 : Debug: mschap: authtype = "MS-CHAP"
Mon Sep 6 14:12:29 2004 : Debug: Module: Instantiated mschap (mschap) Mon
Sep 6 14:12:29 2004 : Debug: Module: Loaded System Mon Sep 6 14:12:29 2004
: Debug: unix: cache = no Mon Sep 6 14:12:29 2004 : Debug: unix: passwd =
"(null)"
Mon Sep 6 14:12:29 2004 : Debug: unix: shadow = "(null)"
Mon Sep 6 14:12:29 2004 : Debug: unix: group = "(null)"
Mon Sep 6 14:12:29 2004 : Debug: unix: radwtmp = "/var/log/radius/radwtmp"
Mon Sep 6 14:12:29 2004 : Debug: unix: usegroup = no Mon Sep 6 14:12:29
2004 : Debug: unix: cache_reload = 600 Mon Sep 6 14:12:29 2004 : Debug:
Module: Instantiated unix (unix) Mon Sep 6 14:12:29 2004 : Debug: Module:
Loaded eap Mon Sep 6 14:12:29 2004 : Debug: eap: default_eap_type = "md5"
Mon Sep 6 14:12:29 2004 : Debug: eap: timer_expire = 60 Mon Sep 6
14:12:29 2004 : Debug: rlm_eap: Loaded and initialized the type
md5
Mon Sep 6 14:12:29 2004 : Debug: rlm_eap: Loaded and initialized the type
leap Mon Sep 6 14:12:29 2004 : Debug: Module: Instantiated eap (eap) Mon
Sep 6 14:12:29 2004 : Debug: Module: Loaded preprocess Mon Sep 6 14:12:29
2004 : Debug: preprocess: huntgroups = "/etc/raddb/huntgroups"
Mon Sep 6 14:12:29 2004 : Debug: preprocess: hints = "/etc/raddb/hints"
Mon Sep 6 14:12:29 2004 : Debug: preprocess: with_ascend_hack = no Mon Sep
6 14:12:29 2004 : Debug: preprocess: ascend_channels_per_line = 23 Mon Sep
6 14:12:29 2004 : Debug: preprocess: with_ntdomain_hack = no Mon Sep 6
14:12:29 2004 : Debug: preprocess: with_specialix_jetstream_hack = no Mon
Sep 6 14:12:29 2004 : Debug: preprocess: with_cisco_vsa_hack = no Mon Sep
6 14:12:29 2004 : Debug: Module: Instantiated preprocess
(preprocess)
Mon Sep 6 14:12:29 2004 : Debug: Module: Loaded realm Mon Sep 6 14:12:29
2004 : Debug: realm: format = "suffix"
Mon Sep 6 14:12:29 2004 : Debug: realm: delimiter = "@"
Mon Sep 6 14:12:29 2004 : Debug: Module: Instantiated realm (suffix) Mon
Sep 6 14:12:29 2004 : Debug: Module: Loaded files Mon Sep 6 14:12:29 2004
: Debug: files: usersfile = "/etc/raddb/users"
Mon Sep 6 14:12:29 2004 : Debug: files: acctusersfile =
"/etc/raddb/acct_users"
Mon Sep 6 14:12:29 2004 : Debug: files: preproxy_usersfile =
"/etc/raddb/preproxy_users"
Mon Sep 6 14:12:29 2004 : Debug: files: compat = "no"
Mon Sep 6 14:12:29 2004 : Debug: Module: Instantiated files (files) Mon Sep
6 14:12:29 2004 : Debug: Module: Loaded Acct-Unique-Session-Id Mon Sep 6
14:12:29 2004 : Debug: acct_unique: key = "User-Name, Acct-Session-Id,
NAS-IP-Address, Client-IP-Address"
Mon Sep 6 14:12:29 2004 : Debug: Module: Instantiated acct_unique
(acct_unique)
Mon Sep 6 14:12:29 2004 : Debug: Module: Loaded detail Mon Sep 6 14:12:29
2004 : Debug: detail: detailfile =
"/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Mon Sep 6 14:12:29 2004 : Debug: detail: detailperm = 384 Mon Sep 6
14:12:29 2004 : Debug: detail: dirperm = 493 Mon Sep 6 14:12:29 2004 :
Debug: detail: locking = no Mon Sep 6 14:12:29 2004 : Debug: Module:
Instantiated detail (detail) Mon Sep 6 14:12:29 2004 : Debug: Module:
Loaded SQL Mon Sep 6 14:12:29 2004 : Debug: sql: driver = "rlm_sql_mysql"
Mon Sep 6 14:12:29 2004 : Debug: sql: server = "192.168.1.253"
Mon Sep 6 14:12:29 2004 : Debug: sql: port = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: login = "logs"
Mon Sep 6 14:12:29 2004 : Debug: sql: password = "uguncer"
Mon Sep 6 14:12:29 2004 : Debug: sql: radius_db = "radius"
Mon Sep 6 14:12:29 2004 : Debug: sql: acct_table = "radacct"
Mon Sep 6 14:12:29 2004 : Debug: sql: acct_table2 = "radacct"
Mon Sep 6 14:12:29 2004 : Debug: sql: authcheck_table = "radcheck"
Mon Sep 6 14:12:29 2004 : Debug: sql: authreply_table = "radreply"
Mon Sep 6 14:12:29 2004 : Debug: sql: groupcheck_table = "radgroupcheck"
Mon Sep 6 14:12:29 2004 : Debug: sql: groupreply_table = "radgroupreply"
Mon Sep 6 14:12:29 2004 : Debug: sql: usergroup_table = "usergroup"
Mon Sep 6 14:12:29 2004 : Debug: sql: nas_table = "nas"
Mon Sep 6 14:12:29 2004 : Debug: sql: dict_table = "dictionary"
Mon Sep 6 14:12:29 2004 : Debug: sql: sqltrace = yes Mon Sep 6 14:12:29
2004 : Debug: sql: sqltracefile = "/var/log/radius/sqltrace.sql"
Mon Sep 6 14:12:29 2004 : Debug: sql: deletestalesessions = yes Mon Sep 6
14:12:29 2004 : Debug: sql: num_sql_socks = 5 Mon Sep 6 14:12:29 2004 :
Debug: sql: sql_user_name = "%{User-Name}"
Mon Sep 6 14:12:29 2004 : Debug: sql: default_user_profile = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: query_on_not_found = no Mon Sep 6
14:12:29 2004 : Debug: sql: authorize_check_query = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: authorize_reply_query = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: authorize_group_check_query = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: authorize_group_reply_query = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: accounting_onoff_query = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: accounting_update_query = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: accounting_start_query = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: accounting_start_query_alt = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: accounting_stop_query = "INSERT into
radacct (RadAcctId, 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-Octets}', '%{Acct-Output-Octets}',
'%{Cisco-AVPair}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}',
'%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0',
'%{Acct-Delay-Time}')"
Mon Sep 6 14:12:29 2004 : Debug: sql: accounting_stop_query_alt = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: group_membership_query = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: connect_failure_retry_delay = 60 Mon
Sep 6 14:12:29 2004 : Debug: sql: simul_count_query = ""
Mon Sep 6 14:12:29 2004 : Debug: sql: simul_verify_query = ""
Mon Sep 6 14:12:29 2004 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module
rlm_sql_mysql) loaded and linked
Mon Sep 6 14:12:29 2004 : Info: rlm_sql (sql): Attempting to connect to
[EMAIL PROTECTED]:/radius Mon Sep 6 14:12:29 2004 : Debug: rlm_sql (sql):
starting 0 Mon Sep 6 14:12:29 2004 : Debug: rlm_sql (sql): Attempting to
connect rlm_sql_mysql #0 Mon Sep 6 14:12:29 2004 : Info: rlm_sql_mysql:
Starting connect to MySQL server for #0 Mon Sep 6 14:12:29 2004 : Debug:
rlm_sql (sql): Connected new DB handle, #0 Mon Sep 6 14:12:29 2004 : Debug:
rlm_sql (sql): starting 1 Mon Sep 6 14:12:29 2004 : Debug: rlm_sql (sql):
Attempting to connect rlm_sql_mysql #1 Mon Sep 6 14:12:29 2004 : Info:
rlm_sql_mysql: Starting connect to MySQL server for #1 Mon Sep 6 14:12:29
2004 : Debug: rlm_sql (sql): Connected new DB handle, #1 Mon Sep 6 14:12:29
2004 : Debug: rlm_sql (sql): starting 2 Mon Sep 6 14:12:29 2004 : Debug:
rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 Mon Sep 6 14:12:29
2004 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Mon Sep
6 14:12:29 2004 : Debug: rlm_sql (sql): Connected new DB handle, #2 Mon Sep
6 14:12:29 2004 : Debug: rlm_sql (sql): starting 3 Mon Sep 6 14:12:29 2004
: Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 Mon Sep 6
14:12:29 2004 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3
Mon Sep 6 14:12:29 2004 : Debug: rlm_sql (sql): Connected new DB handle, #3
Mon Sep 6 14:12:29 2004 : Debug: rlm_sql (sql): starting 4 Mon Sep 6
14:12:29 2004 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
Mon Sep 6 14:12:29 2004 : Info: rlm_sql_mysql: Starting connect to MySQL
server for #4 Mon Sep 6 14:12:29 2004 : Debug: rlm_sql (sql): Connected new
DB handle, #4 Mon Sep 6 14:12:29 2004 : Debug: Module: Instantiated sql
(sql) Mon Sep 6 14:12:29 2004 : Debug: Module: Loaded radutmp Mon Sep 6
14:12:29 2004 : Debug: radutmp: filename = "/var/log/radius/radutmp"
Mon Sep 6 14:12:29 2004 : Debug: radutmp: username = "%{User-Name}"
Mon Sep 6 14:12:29 2004 : Debug: radutmp: case_sensitive = yes Mon Sep 6
14:12:29 2004 : Debug: radutmp: check_with_nas = yes Mon Sep 6 14:12:29
2004 : Debug: radutmp: perm = 384 Mon Sep 6 14:12:29 2004 : Debug:
radutmp: callerid = yes Mon Sep 6 14:12:29 2004 : Debug: Module:
Instantiated radutmp (radutmp) Mon Sep 6 14:12:29 2004 : Info: Listening on
IP address *, ports 1812/udp and 1813/udp, with proxy on 1814/udp.
Mon Sep 6 14:12:29 2004 : Info: Ready to process requests.
rad_recv: Accounting-Request packet from host 10.1.1.1:1646, id=94,
length=979
Acct-Session-Id = "00054E9C"
Calling-Station-Id = "5366805457"
Called-Station-Id = "35"
h323-setup-time = "h323-setup-time=*22:10:05.595 UTC Sun Apr 7 2002"
h323-gw-id = "h323-gw-id=Ankara."
h323-conf-id = "h323-conf-id=0CB9415D 49AB11D6 B2B60011 20312620"
h323-call-origin = "h323-call-origin=originate"
h323-call-type = "h323-call-type=VoIP"
Cisco-AVPair = "h323-incoming-conf-id=0CB9415D 49AB11D6 B2B60011
20312620"
Cisco-AVPair = "subscriber=RegularLine"
Cisco-AVPair = "session-protocol=cisco"
Cisco-AVPair = "gw-rxd-cdn=ton:2,npi:1,#:5922112945"
h323-connect-time = "h323-connect-time=*22:10:06.496 UTC Sun Apr 7
2002"
Acct-Input-Octets = 5040
Acct-Output-Octets = 3731
Acct-Input-Packets = 252
Acct-Output-Packets = 188
Acct-Session-Time = 4
h323-disconnect-time = "h323-disconnect-time=*22:10:10.827 UTC Sun
Apr 7 2002"
h323-disconnect-cause = "h323-disconnect-cause=10"
h323-remote-address = "h323-remote-address=10.1.1.2"
Cisco-AVPair = "release-source=1"
h323-voice-quality = "h323-voice-quality=-1"
Cisco-AVPair = "alert-timepoint=*22:10:05.767 UTC Sun Apr 7 2002"
Cisco-AVPair = "remote-media-address=10.1.1.2"
Cisco-AVPair = "gw-rxd-cgn=ton:2,npi:1,pi:0,si:3,#:5366805457"
Cisco-AVPair = "gw-final-xlated-cdn=ton:2,npi:1,#:35"
Cisco-AVPair =
"gw-final-xlated-cgn=ton:2,npi:1,pi:0,si:3,#:5366805457"
User-Name = "5366805457"
Acct-Status-Type = Stop
Service-Type = Login-User
NAS-IP-Address = 10.1.1.1
NAS-Identifier = "Ankara"
Acct-Delay-Time = 30
Mon Sep 6 14:12:39 2004 : Debug: modcall: entering group preacct for
request 0
Mon Sep 6 14:12:39 2004 : Debug: modsingle[preacct]: calling preprocess
(rlm_preprocess) for request 0
Mon Sep 6 14:12:39 2004 : Debug: modsingle[preacct]: returned from
preprocess (rlm_preprocess) for request 0
Mon Sep 6 14:12:39 2004 : Debug: modcall[preacct]: module "preprocess"
returns noop for request 0
Mon Sep 6 14:12:39 2004 : Debug: modsingle[preacct]: calling suffix
(rlm_realm) for request 0
Mon Sep 6 14:12:39 2004 : Debug: rlm_realm: No '@' in User-Name =
"5366805457", looking up realm NULL
Mon Sep 6 14:12:39 2004 : Debug: rlm_realm: No such realm "NULL"
Mon Sep 6 14:12:39 2004 : Debug: modsingle[preacct]: returned from suffix
(rlm_realm) for request 0
Mon Sep 6 14:12:39 2004 : Debug: modcall[preacct]: module "suffix"
returns noop for request 0
Mon Sep 6 14:12:39 2004 : Debug: modsingle[preacct]: calling files
(rlm_files) for request 0
Mon Sep 6 14:12:39 2004 : Debug: modsingle[preacct]: returned from files
(rlm_files) for request 0
Mon Sep 6 14:12:39 2004 : Debug: modcall[preacct]: module "files" returns
noop for request 0
Mon Sep 6 14:12:39 2004 : Debug: modcall: group preacct returns noop for
request 0 Mon Sep 6 14:12:39 2004 : Debug: modcall: entering group
accounting for request 0
Mon Sep 6 14:12:39 2004 : Debug: modsingle[accounting]: calling
acct_unique (rlm_acct_unique) for request 0 Mon Sep 6 14:12:39 2004 :
Debug: rlm_acct_unique: Hashing 'Client-IP-Address = 10.1.1.1,NAS-IP-Address
= 10.1.1.1,Acct-Session-Id = "00054E9C",User-Name = "5366805457"'
Mon Sep 6 14:12:39 2004 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"06f0ca65b348c91b".
Mon Sep 6 14:12:39 2004 : Debug: modsingle[accounting]: returned from
acct_unique (rlm_acct_unique) for request 0
Mon Sep 6 14:12:39 2004 : Debug: modcall[accounting]: module
"acct_unique" returns ok for request 0
Mon Sep 6 14:12:39 2004 : Debug: modsingle[accounting]: calling detail
(rlm_detail) for request 0
Mon Sep 6 14:12:39 2004 : Debug: radius_xlat:
'/var/log/radius/radacct/10.1.1.1/detail-20040906'
Mon Sep 6 14:12:39 2004 : Debug: rlm_detail:
/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to
/var/log/radius/radacct/10.1.1.1/detail-20040906
Mon Sep 6 14:12:39 2004 : Debug: modsingle[accounting]: returned from
detail (rlm_detail) for request 0
Mon Sep 6 14:12:39 2004 : Debug: modcall[accounting]: module "detail"
returns ok for request 0
Mon Sep 6 14:12:39 2004 : Debug: modsingle[accounting]: calling sql
(rlm_sql) for request 0
Mon Sep 6 14:12:39 2004 : Debug: radius_xlat: '5366805457'
Mon Sep 6 14:12:39 2004 : Debug: rlm_sql (sql): sql_set_user escaped user
--> '5366805457'
Mon Sep 6 14:12:39 2004 : Debug: radius_xlat: 'INSERT into radacct
(RadAcctId, 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('', '00054E9C', '06f0ca65b348c91b', '5366805457', '', '10.1.1.1', '',
'', DATE_SUB('2004-09-06 14:12:39',INTERVAL (4 + 30) SECOND), '2004-09-06
14:12:39', '4', '', '', '', '5040', '3731', 'h323-incoming-conf-id=0CB9415D
49AB11D6 B2B60011 20312620', '5366805457', '', 'Login-User', '', '', '0',
'30')'
Mon Sep 6 14:12:39 2004 : Debug: radius_xlat:
'/var/log/radius/sqltrace.sql'
Mon Sep 6 14:12:39 2004 : Debug: rlm_sql (sql): Reserving sql socket id: 4
Mon Sep 6 14:12:39 2004 : Debug: rlm_sql_mysql: query: INSERT into radacct
(RadAcctId, 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('', '00054E9C', '06f0ca65b348c91b', '5366805457', '', '10.1.1.1', '',
'', DATE_SUB('2004-09-06 14:12:39',INTERVAL (4 + 30) SECOND), '2004-09-06
14:12:39', '4', '', '', '', '5040', '3731', 'h323-incoming-conf-id=0CB9415D
49AB11D6 B2B60011 20312620', '5366805457', '', 'Login-User', '', '', '0',
'30')
Mon Sep 6 14:12:39 2004 : Debug: rlm_sql (sql): Released sql socket id: 4
Mon Sep 6 14:12:39 2004 : Debug: modsingle[accounting]: returned from sql
(rlm_sql) for request 0
Mon Sep 6 14:12:39 2004 : Debug: modcall[accounting]: module "sql"
returns ok for request 0
Mon Sep 6 14:12:39 2004 : Debug: modsingle[accounting]: calling unix
(rlm_unix) for request 0
Mon Sep 6 14:12:39 2004 : Debug: modsingle[accounting]: returned from
unix (rlm_unix) for request 0
Mon Sep 6 14:12:39 2004 : Debug: modcall[accounting]: module "unix"
returns noop for request 0
Mon Sep 6 14:12:39 2004 : Debug: modsingle[accounting]: calling radutmp
(rlm_radutmp) for request 0
Mon Sep 6 14:12:39 2004 : Debug: radius_xlat: '/var/log/radius/radutmp'
Mon Sep 6 14:12:39 2004 : Debug: radius_xlat: '5366805457'
Mon Sep 6 14:12:39 2004 : Debug: rlm_radutmp: No NAS-Port seen. Cannot
do anything.
Mon Sep 6 14:12:39 2004 : Debug: rlm_radumtp: WARNING: checkrad will
probably not work!
Mon Sep 6 14:12:39 2004 : Debug: modsingle[accounting]: returned from
radutmp (rlm_radutmp) for request 0
Mon Sep 6 14:12:39 2004 : Debug: modcall[accounting]: module "radutmp"
returns noop for request 0
Mon Sep 6 14:12:39 2004 : Debug: modcall: group accounting returns ok for
request 0 Sending Accounting-Response of id 94 to 10.1.1.1:1646 Mon Sep 6
14:12:39 2004 : Debug: Finished request 0 Mon Sep 6 14:12:39 2004 : Debug:
Going to the next request Mon Sep 6 14:12:39 2004 : Debug: --- Walking the
entire request list --- Mon Sep 6 14:12:39 2004 : Debug: Waking up in 6
seconds...
rad_recv: Accounting-Request packet from host 10.1.1.1:1646, id=95,
length=849
Acct-Session-Id = "00054E9B"
Calling-Station-Id = "5366805457"
Called-Station-Id = "35"
h323-setup-time = "h323-setup-time=*22:10:05.583 UTC Sun Apr 7 2002"
h323-gw-id = "h323-gw-id=Ankara."
h323-conf-id = "h323-conf-id=0CB9415D 49AB11D6 B2B60011 20312620"
h323-call-origin = "h323-call-origin=answer"
h323-call-type = "h323-call-type=Telephony"
Cisco-AVPair = "h323-incoming-conf-id=0CB9415D 49AB11D6 B2B60011
20312620"
Cisco-AVPair = "subscriber=RegularLine"
Cisco-AVPair = "gw-rxd-cdn=ton:2,npi:1,#:5922112945"
Cisco-AVPair = "calling-party-category=9"
Cisco-AVPair = "transmission-medium-req=0"
h323-connect-time = "h323-connect-time=*22:10:06.504 UTC Sun Apr 7
2002"
Acct-Input-Octets = 4431
Acct-Output-Octets = 5000
Acct-Input-Packets = 223
Acct-Output-Packets = 250
Acct-Session-Time = 4
h323-disconnect-time = "h323-disconnect-time=*22:10:10.785 UTC Sun
Apr 7 2002"
h323-disconnect-cause = "h323-disconnect-cause=10"
Cisco-AVPair = "h323-ivr-out=Tariff:Unknown"
Cisco-AVPair = "release-source=1"
h323-voice-quality = "h323-voice-quality=0"
Cisco-AVPair = "gw-rxd-cgn=ton:2,npi:1,pi:0,si:3,#:5366805457"
User-Name = "5366805457"
Acct-Status-Type = Stop
NAS-Port-Type = Async
Cisco-NAS-Port = "ISDN 0/1:15:10"
NAS-Port = 0
Service-Type = Login-User
NAS-IP-Address = 10.1.1.1
NAS-Identifier = "Ankara"
Acct-Delay-Time = 30
Mon Sep 6 14:12:40 2004 : Debug: modcall: entering group preacct for
request 1
Mon Sep 6 14:12:40 2004 : Debug: modsingle[preacct]: calling preprocess
(rlm_preprocess) for request 1
Mon Sep 6 14:12:40 2004 : Debug: modsingle[preacct]: returned from
preprocess (rlm_preprocess) for request 1
Mon Sep 6 14:12:40 2004 : Debug: modcall[preacct]: module "preprocess"
returns noop for request 1
Mon Sep 6 14:12:40 2004 : Debug: modsingle[preacct]: calling suffix
(rlm_realm) for request 1
Mon Sep 6 14:12:40 2004 : Debug: rlm_realm: No '@' in User-Name =
"5366805457", looking up realm NULL
Mon Sep 6 14:12:40 2004 : Debug: rlm_realm: No such realm "NULL"
Mon Sep 6 14:12:40 2004 : Debug: modsingle[preacct]: returned from suffix
(rlm_realm) for request 1
Mon Sep 6 14:12:40 2004 : Debug: modcall[preacct]: module "suffix"
returns noop for request 1
Mon Sep 6 14:12:40 2004 : Debug: modsingle[preacct]: calling files
(rlm_files) for request 1
Mon Sep 6 14:12:40 2004 : Debug: modsingle[preacct]: returned from files
(rlm_files) for request 1
Mon Sep 6 14:12:40 2004 : Debug: modcall[preacct]: module "files" returns
noop for request 1
Mon Sep 6 14:12:40 2004 : Debug: modcall: group preacct returns noop for
request 1 Mon Sep 6 14:12:40 2004 : Debug: modcall: entering group
accounting for request 1
Mon Sep 6 14:12:40 2004 : Debug: modsingle[accounting]: calling
acct_unique (rlm_acct_unique) for request 1 Mon Sep 6 14:12:40 2004 :
Debug: rlm_acct_unique: Hashing 'Client-IP-Address = 10.1.1.1,NAS-IP-Address
= 10.1.1.1,Acct-Session-Id = "00054E9B",User-Name = "5366805457"'
Mon Sep 6 14:12:40 2004 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"d25ab42402d52d25".
Mon Sep 6 14:12:40 2004 : Debug: modsingle[accounting]: returned from
acct_unique (rlm_acct_unique) for request 1
Mon Sep 6 14:12:40 2004 : Debug: modcall[accounting]: module
"acct_unique" returns ok for request 1
Mon Sep 6 14:12:40 2004 : Debug: modsingle[accounting]: calling detail
(rlm_detail) for request 1
Mon Sep 6 14:12:40 2004 : Debug: radius_xlat:
'/var/log/radius/radacct/10.1.1.1/detail-20040906'
Mon Sep 6 14:12:40 2004 : Debug: rlm_detail:
/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to
/var/log/radius/radacct/10.1.1.1/detail-20040906
Mon Sep 6 14:12:40 2004 : Debug: modsingle[accounting]: returned from
detail (rlm_detail) for request 1
Mon Sep 6 14:12:40 2004 : Debug: modcall[accounting]: module "detail"
returns ok for request 1
Mon Sep 6 14:12:40 2004 : Debug: modsingle[accounting]: calling sql
(rlm_sql) for request 1
Mon Sep 6 14:12:40 2004 : Debug: radius_xlat: '5366805457'
Mon Sep 6 14:12:40 2004 : Debug: rlm_sql (sql): sql_set_user escaped user
--> '5366805457'
Mon Sep 6 14:12:40 2004 : Debug: radius_xlat: 'INSERT into radacct
(RadAcctId, 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('', '00054E9B', 'd25ab42402d52d25', '5366805457', '', '10.1.1.1',
'0', 'Async', DATE_SUB('2004-09-06 14:12:40',INTERVAL (4 + 30) SECOND),
'2004-09-06 14:12:40', '4', '', '', '', '4431', '5000',
'h323-incoming-conf-id=0CB9415D 49AB11D6 B2B60011 20312620', '5366805457',
'', 'Login-User', '', '', '0', '30')'
Mon Sep 6 14:12:40 2004 : Debug: radius_xlat:
'/var/log/radius/sqltrace.sql'
Mon Sep 6 14:12:40 2004 : Debug: rlm_sql (sql): Reserving sql socket id: 3
Mon Sep 6 14:12:40 2004 : Debug: rlm_sql_mysql: query: INSERT into radacct
(RadAcctId, 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('', '00054E9B', 'd25ab42402d52d25', '5366805457', '', '10.1.1.1',
'0', 'Async', DATE_SUB('2004-09-06 14:12:40',INTERVAL (4 + 30) SECOND),
'2004-09-06 14:12:40', '4', '', '', '', '4431', '5000',
'h323-incoming-conf-id=0CB9415D 49AB11D6 B2B60011 20312620', '5366805457',
'', 'Login-User', '', '', '0', '30') Mon Sep 6 14:12:40 2004 : Debug:
rlm_sql (sql): Released sql socket id: 3
Mon Sep 6 14:12:40 2004 : Debug: modsingle[accounting]: returned from sql
(rlm_sql) for request 1
Mon Sep 6 14:12:40 2004 : Debug: modcall[accounting]: module "sql"
returns ok for request 1
Mon Sep 6 14:12:40 2004 : Debug: modsingle[accounting]: calling unix
(rlm_unix) for request 1
Mon Sep 6 14:12:40 2004 : Debug: modsingle[accounting]: returned from
unix (rlm_unix) for request 1
Mon Sep 6 14:12:40 2004 : Debug: modcall[accounting]: module "unix"
returns ok for request 1
Mon Sep 6 14:12:40 2004 : Debug: modsingle[accounting]: calling radutmp
(rlm_radutmp) for request 1
Mon Sep 6 14:12:40 2004 : Debug: radius_xlat: '/var/log/radius/radutmp'
Mon Sep 6 14:12:40 2004 : Debug: radius_xlat: '5366805457'
Mon Sep 6 14:12:40 2004 : Debug: modsingle[accounting]: returned from
radutmp (rlm_radutmp) for request 1
Mon Sep 6 14:12:40 2004 : Debug: modcall[accounting]: module "radutmp"
returns ok for request 1
Mon Sep 6 14:12:40 2004 : Debug: modcall: group accounting returns ok for
request 1 Sending Accounting-Response of id 95 to 10.1.1.1:1646 Mon Sep 6
14:12:40 2004 : Debug: Finished request 1 Mon Sep 6 14:12:40 2004 : Debug:
Going to the next request Mon Sep 6 14:12:40 2004 : Debug: --- Walking the
entire request list --- Mon Sep 6 14:12:40 2004 : Debug: Waking up in 5
seconds...
Mon Sep 6 14:12:45 2004 : Debug: --- Walking the entire request list ---
Mon Sep 6 14:12:45 2004 : Debug: Cleaning up request 0 ID 94 with timestamp
413c4627
Mon Sep 6 14:12:45 2004 : Debug: Waking up in 1 seconds...
Mon Sep 6 14:12:46 2004 : Debug: --- Walking the entire request list ---
Mon Sep 6 14:12:46 2004 : Debug: Cleaning up request 1 ID 95 with timestamp
413c4628
Mon Sep 6 14:12:46 2004 : Debug: Nothing to do. Sleeping until we see a
request.
rad_recv: Accounting-Request packet from host 10.1.1.1:1646, id=96,
length=978
Acct-Session-Id = "00054E85"
Calling-Station-Id = "5335291616"
Called-Station-Id = "35"
h323-setup-time = "h323-setup-time=*22:09:11.226 UTC Sun Apr 7 2002"
h323-gw-id = "h323-gw-id=Ankara."
h323-conf-id = "h323-conf-id=EC513026 49AA11D6 B2B10011 20312620"
h323-call-origin = "h323-call-origin=originate"
h323-call-type = "h323-call-type=VoIP"
Cisco-AVPair = "h323-incoming-conf-id=EC513026 49AA11D6 B2B10011
20312620"
Cisco-AVPair = "subscriber=RegularLine"
Cisco-AVPair = "session-protocol=cisco"
Cisco-AVPair = "gw-rxd-cdn=ton:2,npi:1,#:5922112936"
h323-connect-time = "h323-connect-time=*22:09:12.095 UTC Sun Apr 7
2002"
Acct-Input-Octets = 38360
Acct-Output-Octets = 72395
Acct-Input-Packets = 1931
Acct-Output-Packets = 3625
Acct-Session-Time = 73
h323-disconnect-time = "h323-disconnect-time=*22:10:25.417 UTC Sun
Apr 7 2002"
h323-disconnect-cause = "h323-disconnect-cause=10"
h323-remote-address = "h323-remote-address=10.1.1.2"
Cisco-AVPair = "release-source=1"
h323-voice-quality = "h323-voice-quality=2"
Cisco-AVPair = "alert-timepoint=*22:09:11.407 UTC Sun Apr 7 2002"
Cisco-AVPair = "remote-media-address=10.1.1.2"
Cisco-AVPair = "gw-rxd-cgn=ton:2,npi:1,pi:0,si:3,#:5335291616"
Cisco-AVPair = "gw-final-xlated-cdn=ton:2,npi:1,#:35"
Cisco-AVPair =
"gw-final-xlated-cgn=ton:2,npi:1,pi:0,si:3,#:5335291616"
User-Name = "5335291616"
Acct-Status-Type = Stop
Service-Type = Login-User
NAS-IP-Address = 10.1.1.1
NAS-Identifier = "Ankara"
Acct-Delay-Time = 30
Mon Sep 6 14:12:55 2004 : Debug: modcall: entering group preacct for
request 2
Mon Sep 6 14:12:55 2004 : Debug: modsingle[preacct]: calling preprocess
(rlm_preprocess) for request 2
Mon Sep 6 14:12:55 2004 : Debug: modsingle[preacct]: returned from
preprocess (rlm_preprocess) for request 2
Mon Sep 6 14:12:55 2004 : Debug: modcall[preacct]: module "preprocess"
returns noop for request 2
Mon Sep 6 14:12:55 2004 : Debug: modsingle[preacct]: calling suffix
(rlm_realm) for request 2
Mon Sep 6 14:12:55 2004 : Debug: rlm_realm: No '@' in User-Name =
"5335291616", looking up realm NULL
Mon Sep 6 14:12:55 2004 : Debug: rlm_realm: No such realm "NULL"
Mon Sep 6 14:12:55 2004 : Debug: modsingle[preacct]: returned from suffix
(rlm_realm) for request 2
Mon Sep 6 14:12:55 2004 : Debug: modcall[preacct]: module "suffix"
returns noop for request 2
Mon Sep 6 14:12:55 2004 : Debug: modsingle[preacct]: calling files
(rlm_files) for request 2
Mon Sep 6 14:12:55 2004 : Debug: modsingle[preacct]: returned from files
(rlm_files) for request 2
Mon Sep 6 14:12:55 2004 : Debug: modcall[preacct]: module "files" returns
noop for request 2
Mon Sep 6 14:12:55 2004 : Debug: modcall: group preacct returns noop for
request 2 Mon Sep 6 14:12:55 2004 : Debug: modcall: entering group
accounting for request 2
Mon Sep 6 14:12:55 2004 : Debug: modsingle[accounting]: calling
acct_unique (rlm_acct_unique) for request 2 Mon Sep 6 14:12:55 2004 :
Debug: rlm_acct_unique: Hashing 'Client-IP-Address = 10.1.1.1,NAS-IP-Address
= 10.1.1.1,Acct-Session-Id = "00054E85",User-Name = "5335291616"'
Mon Sep 6 14:12:55 2004 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"6b8a60fcfa2d1d07".
Mon Sep 6 14:12:55 2004 : Debug: modsingle[accounting]: returned from
acct_unique (rlm_acct_unique) for request 2
Mon Sep 6 14:12:55 2004 : Debug: modcall[accounting]: module
"acct_unique" returns ok for request 2
Mon Sep 6 14:12:55 2004 : Debug: modsingle[accounting]: calling detail
(rlm_detail) for request 2
Mon Sep 6 14:12:55 2004 : Debug: radius_xlat:
'/var/log/radius/radacct/10.1.1.1/detail-20040906'
Mon Sep 6 14:12:55 2004 : Debug: rlm_detail:
/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to
/var/log/radius/radacct/10.1.1.1/detail-20040906
Mon Sep 6 14:12:55 2004 : Debug: modsingle[accounting]: returned from
detail (rlm_detail) for request 2
Mon Sep 6 14:12:55 2004 : Debug: modcall[accounting]: module "detail"
returns ok for request 2
Mon Sep 6 14:12:55 2004 : Debug: modsingle[accounting]: calling sql
(rlm_sql) for request 2
Mon Sep 6 14:12:55 2004 : Debug: radius_xlat: '5335291616'
Mon Sep 6 14:12:55 2004 : Debug: rlm_sql (sql): sql_set_user escaped user
--> '5335291616'
Mon Sep 6 14:12:55 2004 : Debug: radius_xlat: 'INSERT into radacct
(RadAcctId, 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('', '00054E85', '6b8a60fcfa2d1d07', '5335291616', '', '10.1.1.1', '',
'', DATE_SUB('2004-09-06 14:12:55',INTERVAL (73 + 30) SECOND), '2004-09-06
14:12:55', '73', '', '', '', '38360', '72395',
'h323-incoming-conf-id=EC513026 49AA11D6 B2B10011 20312620', '5335291616',
'', 'Login-User', '', '', '0', '30')'
Mon Sep 6 14:12:55 2004 : Debug: radius_xlat:
'/var/log/radius/sqltrace.sql'
Mon Sep 6 14:12:55 2004 : Debug: rlm_sql (sql): Reserving sql socket id: 2
Mon Sep 6 14:12:55 2004 : Debug: rlm_sql_mysql: query: INSERT into radacct
(RadAcctId, 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('', '00054E85', '6b8a60fcfa2d1d07', '5335291616', '', '10.1.1.1', '',
'', DATE_SUB('2004-09-06 14:12:55',INTERVAL (73 + 30) SECOND), '2004-09-06
14:12:55', '73', '', '', '', '38360', '72395',
'h323-incoming-conf-id=EC513026 49AA11D6 B2B10011 20312620', '5335291616',
'', 'Login-User', '', '', '0', '30') Mon Sep 6 14:12:55 2004 : Debug:
rlm_sql (sql): Released sql socket id: 2
Mon Sep 6 14:12:55 2004 : Debug: modsingle[accounting]: returned from sql
(rlm_sql) for request 2
Mon Sep 6 14:12:55 2004 : Debug: modcall[accounting]: module "sql"
returns ok for request 2
Mon Sep 6 14:12:55 2004 : Debug: modsingle[accounting]: calling unix
(rlm_unix) for request 2
Mon Sep 6 14:12:55 2004 : Debug: modsingle[accounting]: returned from
unix (rlm_unix) for request 2
Mon Sep 6 14:12:55 2004 : Debug: modcall[accounting]: module "unix"
returns noop for request 2
Mon Sep 6 14:12:55 2004 : Debug: modsingle[accounting]: calling radutmp
(rlm_radutmp) for request 2
Mon Sep 6 14:12:55 2004 : Debug: radius_xlat: '/var/log/radius/radutmp'
Mon Sep 6 14:12:55 2004 : Debug: radius_xlat: '5335291616'
Mon Sep 6 14:12:55 2004 : Debug: rlm_radutmp: No NAS-Port seen. Cannot
do anything.
Mon Sep 6 14:12:55 2004 : Debug: rlm_radumtp: WARNING: checkrad will
probably not work!
Mon Sep 6 14:12:55 2004 : Debug: modsingle[accounting]: returned from
radutmp (rlm_radutmp) for request 2
Mon Sep 6 14:12:55 2004 : Debug: modcall[accounting]: module "radutmp"
returns noop for request 2
Mon Sep 6 14:12:55 2004 : Debug: modcall: group accounting returns ok for
request 2 Sending Accounting-Response of id 96 to 10.1.1.1:1646 Mon Sep 6
14:12:55 2004 : Debug: Finished request 2 Mon Sep 6 14:12:55 2004 : Debug:
Going to the next request Mon Sep 6 14:12:55 2004 : Debug: --- Walking the
entire request list --- Mon Sep 6 14:12:55 2004 : Debug: Waking up in 6
seconds...
rad_recv: Accounting-Request packet from host 10.1.1.1:1646, id=97,
length=849
Acct-Session-Id = "00054E84"
Calling-Station-Id = "5335291616"
Called-Station-Id = "35"
h323-setup-time = "h323-setup-time=*22:09:11.214 UTC Sun Apr 7 2002"
h323-gw-id = "h323-gw-id=Ankara."
h323-conf-id = "h323-conf-id=EC513026 49AA11D6 B2B10011 20312620"
h323-call-origin = "h323-call-origin=answer"
h323-call-type = "h323-call-type=Telephony"
Cisco-AVPair = "h323-incoming-conf-id=EC513026 49AA11D6 B2B10011
20312620"
Cisco-AVPair = "subscriber=RegularLine"
Cisco-AVPair = "gw-rxd-cdn=ton:2,npi:1,#:5922112936"
Cisco-AVPair = "calling-party-category=9"
Cisco-AVPair = "transmission-medium-req=0"
h323-connect-time = "h323-connect-time=*22:09:12.099 UTC Sun Apr 7
2002"
Acct-Input-Octets = 73055
Acct-Output-Octets = 38360
Acct-Input-Packets = 3658
Acct-Output-Packets = 1931
Acct-Session-Time = 73
h323-disconnect-time = "h323-disconnect-time=*22:10:25.373 UTC Sun
Apr 7 2002"
h323-disconnect-cause = "h323-disconnect-cause=10"
Cisco-AVPair = "h323-ivr-out=Tariff:Unknown"
Cisco-AVPair = "release-source=1"
h323-voice-quality = "h323-voice-quality=0"
Cisco-AVPair = "gw-rxd-cgn=ton:2,npi:1,pi:0,si:3,#:5335291616"
User-Name = "5335291616"
Acct-Status-Type = Stop
NAS-Port-Type = Async
Cisco-NAS-Port = "ISDN 0/1:15:11"
NAS-Port = 0
Service-Type = Login-User
NAS-IP-Address = 10.1.1.1
NAS-Identifier = "Ankara"
Acct-Delay-Time = 30
Mon Sep 6 14:12:57 2004 : Debug: modcall: entering group preacct for
request 3
Mon Sep 6 14:12:57 2004 : Debug: modsingle[preacct]: calling preprocess
(rlm_preprocess) for request 3
Mon Sep 6 14:12:57 2004 : Debug: modsingle[preacct]: returned from
preprocess (rlm_preprocess) for request 3
Mon Sep 6 14:12:57 2004 : Debug: modcall[preacct]: module "preprocess"
returns noop for request 3
Mon Sep 6 14:12:57 2004 : Debug: modsingle[preacct]: calling suffix
(rlm_realm) for request 3
Mon Sep 6 14:12:57 2004 : Debug: rlm_realm: No '@' in User-Name =
"5335291616", looking up realm NULL
Mon Sep 6 14:12:57 2004 : Debug: rlm_realm: No such realm "NULL"
Mon Sep 6 14:12:57 2004 : Debug: modsingle[preacct]: returned from suffix
(rlm_realm) for request 3
Mon Sep 6 14:12:57 2004 : Debug: modcall[preacct]: module "suffix"
returns noop for request 3
Mon Sep 6 14:12:57 2004 : Debug: modsingle[preacct]: calling files
(rlm_files) for request 3
Mon Sep 6 14:12:57 2004 : Debug: modsingle[preacct]: returned from files
(rlm_files) for request 3
Mon Sep 6 14:12:57 2004 : Debug: modcall[preacct]: module "files" returns
noop for request 3
Mon Sep 6 14:12:57 2004 : Debug: modcall: group preacct returns noop for
request 3 Mon Sep 6 14:12:57 2004 : Debug: modcall: entering group
accounting for request 3
Mon Sep 6 14:12:57 2004 : Debug: modsingle[accounting]: calling
acct_unique (rlm_acct_unique) for request 3 Mon Sep 6 14:12:57 2004 :
Debug: rlm_acct_unique: Hashing 'Client-IP-Address = 10.1.1.1,NAS-IP-Address
= 10.1.1.1,Acct-Session-Id = "00054E84",User-Name = "5335291616"'
Mon Sep 6 14:12:57 2004 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"9d74bfd719489e12".
Mon Sep 6 14:12:57 2004 : Debug: modsingle[accounting]: returned from
acct_unique (rlm_acct_unique) for request 3
Mon Sep 6 14:12:57 2004 : Debug: modcall[accounting]: module
"acct_unique" returns ok for request 3
Mon Sep 6 14:12:57 2004 : Debug: modsingle[accounting]: calling detail
(rlm_detail) for request 3
Mon Sep 6 14:12:57 2004 : Debug: radius_xlat:
'/var/log/radius/radacct/10.1.1.1/detail-20040906'
Mon Sep 6 14:12:57 2004 : Debug: rlm_detail:
/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to
/var/log/radius/radacct/10.1.1.1/detail-20040906
Mon Sep 6 14:12:57 2004 : Debug: modsingle[accounting]: returned from
detail (rlm_detail) for request 3
Mon Sep 6 14:12:57 2004 : Debug: modcall[accounting]: module "detail"
returns ok for request 3
Mon Sep 6 14:12:57 2004 : Debug: modsingle[accounting]: calling sql
(rlm_sql) for request 3
Mon Sep 6 14:12:57 2004 : Debug: radius_xlat: '5335291616'
Mon Sep 6 14:12:57 2004 : Debug: rlm_sql (sql): sql_set_user escaped user
--> '5335291616'
Mon Sep 6 14:12:57 2004 : Debug: radius_xlat: 'INSERT into radacct
(RadAcctId, 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('', '00054E84', '9d74bfd719489e12', '5335291616', '', '10.1.1.1',
'0', 'Async', DATE_SUB('2004-09-06 14:12:57',INTERVAL (73 + 30) SECOND),
'2004-09-06 14:12:57', '73', '', '', '', '73055', '38360',
'h323-incoming-conf-id=EC513026 49AA11D6 B2B10011 20312620', '5335291616',
'', 'Login-User', '', '', '0', '30')'
Mon Sep 6 14:12:57 2004 : Debug: radius_xlat:
'/var/log/radius/sqltrace.sql'
Mon Sep 6 14:12:57 2004 : Debug: rlm_sql (sql): Reserving sql socket id: 1
Mon Sep 6 14:12:57 2004 : Debug: rlm_sql_mysql: query: INSERT into radacct
(RadAcctId, 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('', '00054E84', '9d74bfd719489e12', '5335291616', '', '10.1.1.1',
'0', 'Async', DATE_SUB('2004-09-06 14:12:57',INTERVAL (73 + 30) SECOND),
'2004-09-06 14:12:57', '73', '', '', '', '73055', '38360',
'h323-incoming-conf-id=EC513026 49AA11D6 B2B10011 20312620', '5335291616',
'', 'Login-User', '', '', '0', '30') Mon Sep 6 14:12:57 2004 : Debug:
rlm_sql (sql): Released sql socket id: 1
Mon Sep 6 14:12:57 2004 : Debug: modsingle[accounting]: returned from sql
(rlm_sql) for request 3
Mon Sep 6 14:12:57 2004 : Debug: modcall[accounting]: module "sql"
returns ok for request 3
Mon Sep 6 14:12:57 2004 : Debug: modsingle[accounting]: calling unix
(rlm_unix) for request 3
Mon Sep 6 14:12:57 2004 : Debug: modsingle[accounting]: returned from
unix (rlm_unix) for request 3
Mon Sep 6 14:12:57 2004 : Debug: modcall[accounting]: module "unix"
returns ok for request 3
Mon Sep 6 14:12:57 2004 : Debug: modsingle[accounting]: calling radutmp
(rlm_radutmp) for request 3
Mon Sep 6 14:12:57 2004 : Debug: radius_xlat: '/var/log/radius/radutmp'
Mon Sep 6 14:12:57 2004 : Debug: radius_xlat: '5335291616'
Mon Sep 6 14:12:57 2004 : Debug: modsingle[accounting]: returned from
radutmp (rlm_radutmp) for request 3
Mon Sep 6 14:12:57 2004 : Debug: modcall[accounting]: module "radutmp"
returns ok for request 3
Mon Sep 6 14:12:57 2004 : Debug: modcall: group accounting returns ok for
request 3 Sending Accounting-Response of id 97 to 10.1.1.1:1646 Mon Sep 6
14:12:57 2004 : Debug: Finished request 3 Mon Sep 6 14:12:57 2004 : Debug:
Going to the next request Mon Sep 6 14:12:57 2004 : Debug: --- Walking the
entire request list --- Mon Sep 6 14:12:57 2004 : Debug: Waking up in 4
seconds...
Mon Sep 6 14:13:01 2004 : Debug: --- Walking the entire request list ---
Mon Sep 6 14:13:01 2004 : Debug: Cleaning up request 2 ID 96 with timestamp
413c4637
Mon Sep 6 14:13:01 2004 : Debug: Waking up in 2 seconds...
Mon Sep 6 14:13:03 2004 : Debug: --- Walking the entire request list ---
Mon Sep 6 14:13:03 2004 : Debug: Cleaning up request 3 ID 97 with timestamp
413c4639
Mon Sep 6 14:13:03 2004 : Debug: Nothing to do. Sleeping until we see a
request.
#######################################################################
# Accounting Queries
#######################################################################
# accounting_onoff_query - query for Accounting On/Off
packets
# accounting_update_query - query for Accounting update
packets
# accounting_start_query - query for Accounting start packets
# accounting_start_query_alt - query for Accounting start packets
# (alternate in case first query
fails)
# accounting_stop_query - query for Accounting stop packets
# accounting_stop_query_alt - query for Accounting start packets
# (alternate in case first query
doesn't
# affect any existing rows in the
table)
#######################################################################
#accounting_onoff_query = "UPDATE ${acct_table1} SET
AcctStopTime='%S', AcctSessionTime=unix_timestamp('%S') -
unix_timestamp(AcctStartTime), AcctTerminateCause='%{Acct-$
accounting_onoff_query = ""
#accounting_update_query = "UPDATE ${acct_table1} SET
FramedIPAddress = '%{Framed-IP-Address}' WHERE AcctSessionId =
'%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name$
accounting_update_query = ""
#accounting_start_query = "INSERT into ${acct_table1} (RadAcctId,
AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId,
NASPortType, AcctStartTime, Acct$
accounting_start_query = ""
#accounting_start_query_alt = "UPDATE ${acct_table1} SET
AcctStartTime = '%S', AcctStartDelay = '%{Acct-Delay-Time}',
ConnectInfo_start = '%{Connect-Info}' WHERE AcctSe$
accounting_start_query_alt = ""
#accounting_stop_query = "UPDATE ${acct_table2} SET AcctStopTime =
'%S', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets =
'%{Acct-Input-Octets}', AcctOutputOc$
accounting_stop_query = "INSERT into ${acct_table2} (RadAcctId,
AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId,
NASPortType, AcctStartTime, AcctSt$
#accounting_stop_query_alt = "INSERT into ${acct_table2} (RadAcctId,
AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId,
NASPortType, AcctStartTime, A$
accounting_stop_query_alt = ""
-
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
