FreeRadius with SQL and Asterisk - FreeRadius inserts acct data toSQL database , but the data seems useless

Antun Mihalicek amihalicek at inge-mark.hr
Mon Jan 7 10:10:53 CET 2008


Hi!
First of all, I apologize if I sent this to non-appropriate mailing 
list, but nevertheless I hope  that you can help me.
I installed FreeRadius because I wanted to see how it works in 
conjunction with Asterisk, only for accounting purposes. 
In my case, I managed to configure Asterisk to send RADIUS packets to 
FreeRadius server, as we can see from file
/var/log/radius/radacct/127.0.0.1/detail-20080107:

> Mon Jan  7 09:38:45 2008
>         Acct-Status-Type = Stop
>         Asterisk-Acc-Code = ""
>         Asterisk-Src = "amihalicek"
>         Asterisk-Dst = "s"
>         Asterisk-Dst-Ctx = "default"
>         Asterisk-Clid = "amihalicek"
>         Asterisk-Chan = "SIP/5061-08b5f250"
>         Asterisk-Dst-Chan = ""
>         Asterisk-Last-App = "BackGround"
>         Asterisk-Last-Data = "demo-congrats"
>         Asterisk-Start-Time = "2008-01-07 08:38:38 +0000"
>         Asterisk-Answer-Time = "2008-01-07 08:38:39 +0000"
>         Asterisk-End-Time = "2008-01-07 08:38:45 +0000"
>         Asterisk-Duration = 7
>         Asterisk-Bill-Sec = 6
>         Asterisk-Disposition = "ANSWERED"
>         Asterisk-AMA-Flags = "DOCUMENTATION"
>         Asterisk-Unique-ID = "1199695118.0"
>         Asterisk-User-Field = ""
>         User-Name = "SIP/5061-08b5f250"
>         Acct-Session-Id = "1199695118.0"
>         NAS-Port = 0
>         Acct-Delay-Time = 0
>         NAS-IP-Address = 127.0.0.1
>         Client-IP-Address = 127.0.0.1
>         Acct-Unique-Session-Id = "e8e8e47588d22eed"
>         Timestamp = 1199695125

The problems start when I configure FreeRadius to insert RADIUS 
accounting data into SQL, in my case - postgreSQL database. I followed 
the steps on http://wiki.freeradius.org/SQL_HOWTO.  FreeRadius creates 
SQL insert indeed,  as you can see down below, but the thing is that the 
data from this table is totally useless, as e.g. acctstartime and 
acctstoptime fields are equal, which doesn't make sense.  If we see the  
/var/log/radius/radacct/127.0.0.1/detail-20080107 file (see above), we 
can see that all of the AvPs are created in the SQL table, except the 
ones which have "Asterisk" as prefix (e.g. Asterisk-Acc-Code, 
Asterisk-Src, etc).  I thought that FreeRadius will somehow map these 
values from Asterisk to values which can be put to radacct table, e.g. 
Asterisk-Start-Time  ---> acctstarttime, etc. Obviously, it doesn't.  
I've been googling for whole day concerning this problem, and I wasn't 
able to find anything related to it, so probably other users had no 
problems with that.  I assume that I would have to create a custom table 
for supporting asterisk RADIUS packets, but I wasn't able to find 
anything on google.  I would appreciate any  kind of help, hint, or 
advice.  Below  you can also see debug output from freeRADIUS.

Thank you very much and sorry for the long e-mail,
Antun

Radacct table form postgreSQL:
> radius=# select * from 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 | xascendsessionsvrkey | start-time | 
> starttime | asteriskstarttime
> -----------+---------------+------------------+-------------------+-------+--------------+-----------+-------------+------------------------+------------------------+-----------------+---------------+-------------------+------------------+-----------------+------------------+-----------------+------------------+--------------------+-------------+----------------+-----------------+----------------+---------------+----------------------+------------+-----------+-------------------
>         1  |  1199695118.0  | e8e8e47588d22eed | SIP/5061-08b5f250 
> |       | 127.0.0.1    | 0         |             | 2008-01-07 
> 09:38:45+01 | 2008-01-07 09:38:45+01 |                 |               
> |                   |                  |               0 
> |                0 |                 |                  
> |                    |             |                |                 
> |                |             0 |                      |            
> |           |
FreeRadius DEBUG:
> [amihalicek at antun sbin]$ ./radiusd -X
> Starting - reading configuration files ...
> reread_config:  reading radiusd.conf
> Config:   including file: /home/amihalicek/radius/etc/raddb/proxy.conf
> Config:   including file: /home/amihalicek/radius/etc/raddb/clients.conf
> Config:   including file: /home/amihalicek/radius/etc/raddb/snmp.conf
> Config:   including file: /home/amihalicek/radius/etc/raddb/eap.conf
> Config:   including file: 
> /home/amihalicek/radius/etc/raddb/postgresql.conf
>  main: prefix = "/home/amihalicek/radius"
>  main: localstatedir = "/home/amihalicek/radius/var"
>  main: logdir = "/home/amihalicek/radius/var/log/radius"
>  main: libdir = "/home/amihalicek/radius/lib"
>  main: radacctdir = "/home/amihalicek/radius/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 = 0
>  main: allow_core_dumps = no
>  main: log_stripped_names = no
>  main: log_file = "/home/amihalicek/radius/var/log/radius/radius.log"
>  main: log_auth = no
>  main: log_auth_badpass = no
>  main: log_auth_goodpass = no
>  main: pidfile = "/home/amihalicek/radius/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 = "/home/amihalicek/radius/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
> radiusd:  entering modules setup
> Module: Library search path is /home/amihalicek/radius/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 DIGEST
> Module: Instantiated digest (digest)
> 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 = "/home/amihalicek/radius/etc/raddb/huntgroups"
>  preprocess: hints = "/home/amihalicek/radius/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 = "/home/amihalicek/radius/etc/raddb/users"
>  files: acctusersfile = "/home/amihalicek/radius/etc/raddb/acct_users"
>  files: preproxy_usersfile = 
> "/home/amihalicek/radius/etc/raddb/preproxy_users"
>  files: compat = "no"
> Module: Instantiated files (files)
> Module: Loaded SQL
>  sql: driver = "rlm_sql_postgresql"
>  sql: server = "localhost"
>  sql: port = ""
>  sql: login = "radius"
>  sql: password = "radius"
>  sql: radius_db = "radius"
>  sql: nas_table = "nas"
>  sql: sqltrace = yes
>  sql: sqltracefile = "/home/amihalicek/radius/var/log/radius/sqltrace.sql"
>  sql: readclients = no
>  sql: deletestalesessions = yes
>  sql: num_sql_socks = 5
>  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, usergroup 
> ??WHERE usergroup.Username = '%{SQL-User-Name}' AND 
> usergroup.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,usergroup 
> ??WHERE usergroup.Username = '%{SQL-User-Name}' AND 
> usergroup.GroupName = radgroupreply.GroupName ??ORDER BY radgroupreply.id"
>  sql: accounting_onoff_query = "UPDATE radacct   SET AcctStopTime = 
> ('%S'::timestamp - '%{Acct-Delay-Time:-0}'::interval),   
> AcctSessionTime = (EXTRACT(EPOCH FROM('%S'::timestamp with time zone 
> -                     AcctStartTime::timestamp with time zone 
> -                     '%{Acct-Delay-Time:-0}'::interval)))::BIGINT,   
> AcctTerminateCause='%{Acct-Terminate-Cause}',   AcctStopDelay = 0   
> WHERE AcctSessionTime IS NULL   AND AcctStopTime IS NULL   AND 
> NASIPAddress= '%{NAS-IP-Address}'   AND AcctStartTime <= '%S'::timestamp"
>  sql: accounting_update_query = "UPDATE radacct   SET FramedIPAddress 
> = NULLIF('%{Framed-IP-Address}', '')::inet,   AcctSessionTime = 
> (EXTRACT(EPOCH FROM('%S'::timestamp with time zone 
> -                     AcctStartTime::timestamp with time zone 
> -                     '%{Acct-Delay-Time:-0}'::interval)))::BIGINT,   
> AcctInputOctets = (('%{Acct-Input-Gigawords:-0}'::bigint << 32) 
> +                     '%{Acct-Input-Octets:-0}'::bigint),   
> AcctOutputOctets = (('%{Acct-Output-Gigawords:-0}'::bigint << 32) 
> +                     '%{Acct-Output-Octets:-0}'::bigint)   WHERE 
> AcctSessionId = '%{Acct-Session-Id}'   AND UserName = 
> '%{SQL-User-Name}'   AND NASIPAddress= '%{NAS-IP-Address}'   AND 
> AcctStopTime IS NULL"
>  sql: accounting_update_query_alt = "INSERT into radacct   
> (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, 
> NASPortId, NASPortType, AcctStartTime,   AcctSessionTime, 
> AcctAuthentic, AcctInputOctets, AcctOutputOctets, CalledStationId, 
> CallingStationId, ??ServiceType, FramedProtocol, FramedIPAddress, 
> XAscendSessionSvrKey) ??values('%{Acct-Session-Id}', 
> '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', 
> '%{NAS-IP-Address}', ??'%{NAS-Port}', 
> '%{NAS-Port-Type}',                 ('%S'::timestamp -  
> '%{Acct-Delay-Time:-0}'::interval - 
> '%{Acct-Session-Time:-0}'::interval), ??'%{Acct-Session-Time}', 
> '%{Acct-Authentic}', ??(('%{Acct-Input-Gigawords:-0}'::bigint << 32) + 
> '%{Acct-Input-Octets:-0}'::bigint), 
> ??(('%{Acct-Output-Gigawords:-0}'::bigint << 32) + 
> '%{Acct-Output-Octets:-0}'::bigint), '%{Called-Station-Id}', 
> ??'%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', 
> ??NULLIF('%{Framed-IP-Address}', '')::inet, 
> '%{X-Ascend-Session-Svr-Key}')"
>  sql: accounting_start_query = "INSERT into radacct ??(AcctSessionId, 
> AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, 
> AcctStartTime, AcctAuthentic, ??ConnectInfo_start, CalledStationId, 
> CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, 
> AcctStartDelay, XAscendSessionSvrKey) ??values('%{Acct-Session-Id}', 
> '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', 
> '%{NAS-IP-Address}', ??'%{NAS-Port}', '%{NAS-Port-Type}', 
> ('%S'::timestamp - '%{Acct-Delay-Time:-0}'::interval), 
> '%{Acct-Authentic}', '%{Connect-Info}', ??'%{Called-Station-Id}', 
> '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', 
> ??NULLIF('%{Framed-IP-Address}', '')::inet, 0, 
> '%{X-Ascend-Session-Svr-Key}')"
>  sql: accounting_start_query_alt = "UPDATE radacct ??SET AcctStartTime 
> = ('%S'::timestamp - '%{Acct-Delay-Time:-0}'::interval), 
> AcctStartDelay = 0, ??ConnectInfo_start = '%{Connect-Info}' WHERE 
> AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' 
> ??AND NASIPAddress = '%{NAS-IP-Address}' AND AcctStopTime IS NULL"
>  sql: accounting_stop_query = "UPDATE radacct ??SET AcctStopTime = 
> ('%S'::timestamp - '%{Acct-Delay-Time:-0}'::interval), 
> ??AcctSessionTime = NULLIF('%{Acct-Session-Time}', '')::bigint, 
> ??AcctInputOctets = (('%{Acct-Input-Gigawords:-0}'::bigint << 32) + 
> '%{Acct-Input-Octets:-0}'::bigint), ??AcctOutputOctets = 
> (('%{Acct-Output-Gigawords:-0}'::bigint << 32) + 
> '%{Acct-Output-Octets:-0}'::bigint), ??AcctTerminateCause = 
> '%{Acct-Terminate-Cause}', AcctStopDelay = 0, ??FramedIPAddress = 
> NULLIF('%{Framed-IP-Address}', '')::inet, ConnectInfo_stop = 
> '%{Connect-Info}' ??WHERE AcctSessionId = '%{Acct-Session-Id}' AND 
> UserName = '%{SQL-User-Name}' ??AND NASIPAddress = '%{NAS-IP-Address}' 
> AND AcctStopTime IS NULL"
>  sql: accounting_stop_query_alt = "INSERT into radacct 
> ??(AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, 
> NASPortId, NASPortType, AcctStartTime, AcctStopTime, 
> ??AcctSessionTime, AcctAuthentic, ConnectInfo_stop, AcctInputOctets, 
> AcctOutputOctets, CalledStationId, CallingStationId, 
> ??AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress, 
> AcctStopDelay) ??values('%{Acct-Session-Id}', 
> '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', 
> '%{NAS-IP-Address}', ??'%{NAS-Port}', '%{NAS-Port-Type}', 
> ('%S'::timestamp -  '%{Acct-Delay-Time:-0}'::interval - 
> '%{Acct-Session-Time:-0}'::interval), ??('%S'::timestamp - 
> '%{Acct-Delay-Time:-0}'::interval), NULLIF('%{Acct-Session-Time}', 
> '')::bigint, ??'%{Acct-Authentic}', '%{Connect-Info}', 
> ??(('%{Acct-Input-Gigawords:-0}'::bigint << 32) + 
> '%{Acct-Input-Octets:-0}'::bigint), 
> ??(('%{Acct-Output-Gigawords:-0}'::bigint << 32) + 
> '%{Acct-Output-Octets:-0}'::bigint), '%{Called-Station-Id}', 
> ??'%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', 
> '%{Service-Type}', '%{Framed-Protocol}', 
> ??NULLIF('%{Framed-IP-Address}', '')::inet, 0)"
>  sql: group_membership_query = "SELECT GroupName FROM usergroup WHERE 
> UserName='%{SQL-User-Name}'"
>  sql: connect_failure_retry_delay = 60
>  sql: simul_count_query = ""
>  sql: simul_verify_query = ""
>  sql: postauth_query = "INSERT INTO radpostauth (username, pass, 
> reply, authdate) VALUES ('%{User-Name}', 
> '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', NOW())"
>  sql: safe-characters = 
> "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
> rlm_sql (sql): Driver rlm_sql_postgresql (module rlm_sql_postgresql) 
> loaded and linked
> rlm_sql (sql): Attempting to connect to radius at localhost:/radius
> rlm_sql (sql): starting 0
> rlm_sql (sql): Attempting to connect rlm_sql_postgresql #0
> rlm_sql (sql): Connected new DB handle, #0
> rlm_sql (sql): starting 1
> rlm_sql (sql): Attempting to connect rlm_sql_postgresql #1
> rlm_sql (sql): Connected new DB handle, #1
> rlm_sql (sql): starting 2
> rlm_sql (sql): Attempting to connect rlm_sql_postgresql #2
> rlm_sql (sql): Connected new DB handle, #2
> rlm_sql (sql): starting 3
> rlm_sql (sql): Attempting to connect rlm_sql_postgresql #3
> rlm_sql (sql): Connected new DB handle, #3
> rlm_sql (sql): starting 4
> rlm_sql (sql): Attempting to connect rlm_sql_postgresql #4
> rlm_sql (sql): Connected new DB handle, #4
> 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 = 
> "/home/amihalicek/radius/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 System
>  unix: cache = no
>  unix: passwd = "(null)"
>  unix: shadow = "(null)"
>  unix: group = "(null)"
>  unix: radwtmp = "/home/amihalicek/radius/var/log/radius/radwtmp"
>  unix: usegroup = no
>  unix: cache_reload = 600
> Module: Instantiated unix (unix)
> Module: Loaded radutmp
>  radutmp: filename = "/home/amihalicek/radius/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)
> Listening on authentication *:1812
> Listening on accounting *:1813
> Ready to process requests.
> rad_recv: Accounting-Request packet from host 127.0.0.1:32773, id=148, 
> length=405
>         Acct-Status-Type = Stop
>         Asterisk-Acc-Code = ""
>         Asterisk-Src = "amihalicek"
>         Asterisk-Dst = "s"
>         Asterisk-Dst-Ctx = "default"
>         Asterisk-Clid = "amihalicek"
>         Asterisk-Chan = "SIP/5061-08b5f250"
>         Asterisk-Dst-Chan = ""
>         Asterisk-Last-App = "BackGround"
>         Asterisk-Last-Data = "demo-congrats"
>         Asterisk-Start-Time = "2008-01-07 08:38:38 +0000"
>         Asterisk-Answer-Time = "2008-01-07 08:38:39 +0000"
>         Asterisk-End-Time = "2008-01-07 08:38:45 +0000"
>         Asterisk-Duration = 7
>         Asterisk-Bill-Sec = 6
>         Asterisk-Disposition = "ANSWERED"
>         Asterisk-AMA-Flags = "DOCUMENTATION"
>         Asterisk-Unique-ID = "1199695118.0"
>         Asterisk-User-Field = ""
>         User-Name = "SIP/5061-08b5f250"
>         Acct-Session-Id = "1199695118.0"
>         NAS-Port = 0
>         Acct-Delay-Time = 0
>         NAS-IP-Address = 127.0.0.1
>   Processing the preacct section of radiusd.conf
> modcall: entering group preacct for request 0
>   modcall[preacct]: module "preprocess" returns noop for request 0
> rlm_acct_unique: Hashing 'NAS-Port = 0,Client-IP-Address = 
> 127.0.0.1,NAS-IP-Address = 127.0.0.1,Acct-Session-Id = 
> "1199695118.0",User-Name = "SIP/5061-08b5f250"'
> rlm_acct_unique: Acct-Unique-Session-ID = "e8e8e47588d22eed".
>   modcall[preacct]: module "acct_unique" returns ok for request 0
>     rlm_realm: No '@' in User-Name = "SIP/5061-08b5f250", looking up 
> realm NULL
>     rlm_realm: No such realm "NULL"
>   modcall[preacct]: module "suffix" returns noop for request 0
>   modcall[preacct]: module "files" returns noop for request 0
> modcall: leaving group preacct (returns ok) for request 0
>   Processing the accounting section of radiusd.conf
> modcall: entering group accounting for request 0
> radius_xlat:  
> '/home/amihalicek/radius/var/log/radius/radacct/127.0.0.1/detail-20080107'
> rlm_detail: 
> /home/amihalicek/radius/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d 
> expands to 
> /home/amihalicek/radius/var/log/radius/radacct/127.0.0.1/detail-20080107
>   modcall[accounting]: module "detail" returns ok for request 0
>   modcall[accounting]: module "unix" returns ok for request 0
> radius_xlat:  '/home/amihalicek/radius/var/log/radius/radutmp'
> radius_xlat:  'SIP/5061-08b5f250'
> rlm_radutmp: Logout for NAS localhost port 0, but no Login record
>   modcall[accounting]: module "radutmp" returns ok for request 0
> radius_xlat:  'SIP/5061-08b5f250'
> rlm_sql (sql): sql_set_user escaped user --> 'SIP/5061-08b5f250'
> radius_xlat:  'UPDATE radacct ??SET AcctStopTime = ('2008-01-07 
> 09:38:45'::timestamp - '0'::interval), ??AcctSessionTime = NULLIF('', 
> '')::bigint, ??AcctInputOctets = (('0'::bigint << 32) + '0'::bigint), 
> ??AcctOutputOctets = (('0'::bigint << 32) + '0'::bigint), 
> ??AcctTerminateCause = '', AcctStopDelay = 0, ??FramedIPAddress = 
> NULLIF('', '')::inet, ConnectInfo_stop = '' ??WHERE AcctSessionId = 
> '1199695118.0' AND UserName = 'SIP/5061-08b5f250' ??AND NASIPAddress = 
> '127.0.0.1' AND AcctStopTime IS NULL'
> radius_xlat:  '/home/amihalicek/radius/var/log/radius/sqltrace.sql'
> rlm_sql (sql): Reserving sql socket id: 4
> rlm_sql_postgresql: query: UPDATE radacct ??SET AcctStopTime = 
> ('2008-01-07 09:38:45'::timestamp - '0'::interval), ??AcctSessionTime 
> = NULLIF('', '')::bigint, ??AcctInputOctets = (('0'::bigint << 32) + 
> '0'::bigint), ??AcctOutputOctets = (('0'::bigint << 32) + 
> '0'::bigint), ??AcctTerminateCause = '', AcctStopDelay = 0, 
> ??FramedIPAddress = NULLIF('', '')::inet, ConnectInfo_stop = '' 
> ??WHERE AcctSessionId = '1199695118.0' AND UserName = 
> 'SIP/5061-08b5f250' ??AND NASIPAddress = '127.0.0.1' AND AcctStopTime 
> IS NULL
> rlm_sql_postgresql: Status: PGRES_COMMAND_OK
> rlm_sql_postgresql: affected rows = 0
> radius_xlat:  'stop packet with zero session length. [user 
> 'SIP/5061-08b5f250', nas '127.0.0.1']'
> rlm_sql (sql) in sql_accounting: stop packet with zero session length. 
> [user 'SIP/5061-08b5f250', nas '127.0.0.1']
> rlm_sql (sql): Released sql socket id: 4
> radius_xlat:  'INSERT into radacct ??(AcctSessionId, AcctUniqueId, 
> UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, 
> AcctStopTime, ??AcctSessionTime, AcctAuthentic, ConnectInfo_stop, 
> AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, 
> ??AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress, 
> AcctStopDelay) ??values('1199695118.0', 'e8e8e47588d22eed', 
> 'SIP/5061-08b5f250', '', '127.0.0.1', ??'0', '', ('2008-01-07 
> 09:38:45'::timestamp -  '0'::interval - '0'::interval), ??('2008-01-07 
> 09:38:45'::timestamp - '0'::interval), NULLIF('', '')::bigint, ??'', 
> '', ??(('0'::bigint << 32) + '0'::bigint), ??(('0'::bigint << 32) + 
> '0'::bigint), '', ??'', '', '', '', ??NULLIF('', '')::inet, 0)'
> radius_xlat:  '/home/amihalicek/radius/var/log/radius/sqltrace.sql'
> rlm_sql_postgresql: query: INSERT into radacct ??(AcctSessionId, 
> AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, 
> AcctStartTime, AcctStopTime, ??AcctSessionTime, AcctAuthentic, 
> ConnectInfo_stop, AcctInputOctets, AcctOutputOctets, CalledStationId, 
> CallingStationId, ??AcctTerminateCause, ServiceType, FramedProtocol, 
> FramedIPAddress, AcctStopDelay) ??values('1199695118.0', 
> 'e8e8e47588d22eed', 'SIP/5061-08b5f250', '', '127.0.0.1', ??'0', '', 
> ('2008-01-07 09:38:45'::timestamp -  '0'::interval - '0'::interval), 
> ??('2008-01-07 09:38:45'::timestamp - '0'::interval), NULLIF('', 
> '')::bigint, ??'', '', ??(('0'::bigint << 32) + '0'::bigint), 
> ??(('0'::bigint << 32) + '0'::bigint), '', ??'', '', '', '', 
> ??NULLIF('', '')::inet, 0)
> rlm_sql_postgresql: Status: PGRES_COMMAND_OK
> rlm_sql_postgresql: affected rows = 1
> rlm_sql (sql): Released sql socket id: 4
>   modcall[accounting]: module "sql" returns noop for request 0
> modcall: leaving group accounting (returns ok) for request 0
> Sending Accounting-Response of id 148 to 127.0.0.1 port 32773
> Finished request 0
> Going to the next request
> --- Walking the entire request list ---
> Waking up in 6 seconds...
> --- Walking the entire request list ---
> Cleaning up request 0 ID 148 with timestamp 4781e515
> Nothing to do.  Sleeping until we see a request.







 




More information about the Freeradius-Users mailing list