Hi all.
I faced with a problem on FR 0.5:
when using FR 0.4 I have my a single record for both Start and STOP
accounting requests.
Since I have changed to FR 0.5 my accounting records double with stop of the
session.
I use PostgreSQL 7.1 as a DB engine.
My sql.conf file has two SQL-entries for STOP packet: accounting_stop_query
and accounting_stop_query_alt. ( as asked in "manual")
The description of sql.conf says that accounting_stop_query_alt is called
when no rows affected during execution of accounting_stop_query.
But logs say that both queries are run.
here are SQL-queries from sql.conf
accounting_stop_query = "UPDATE ${acct_table1} SET AcctStopTime = '%S',
AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets =
'%{Acct-Input-Octets}', AcctOutputOctets = '%{Acct-Output-Octets}',
AcctTerminateCause = '%{Acct-Terminate-Cause}', AcctStopDelay =
'%{Acct-Delay-Time}', ConnectInfo_stop = '%{Connect-Info}' WHERE
AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND
NASIPAddress = '%{NAS-IP-Address}'"
accounting_stop_query_alt = "INSERT into radacct (AcctSessionId,
AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType,
AcctStartTime, AcctStopTime, AcctSessionTime, AcctAuthentic,
ConnectInfo_start, ConnectInfo_stop, AcctInputOctets, AcctOutputOctets,
CalledStationId, CallingStationId, AcctTerminateCause, ServiceType,
FramedProtocol, FramedIPAddress, AcctStartDelay, AcctStopDelay)
values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
'%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', CASE WHEN
'%{NAS-Port-Id}'='' then 0 else '%{NAS-Port-Id}' end, '%{NAS-Port-Type}',
'2000-01-01 00:00:00', '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}',
'', '%{Connect-Info}', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}',
'%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}',
'%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0',
'%{Acct-Delay-Time}')"
and here are some logs:
sql_set_user: escaped user --> 'kern'
radius_xlat: 'UPDATE radacct SET AcctStopTime = '2002-04-05 17:43:29',
AcctSessionTime = '4969', AcctInputOctets = '5398', AcctOutputOctets =
'5400', AcctTerminateCause = 'User-Request', AcctStopDelay = '0',
ConnectInfo_stop = '' WHERE AcctSessionId = '00000037' AND UserName = 'kern'
AND NASIPAddress = '10.0.0.1''
rlm_sql: Reserving sql socket id: 4
query: UPDATE radacct SET AcctStopTime = '2002-04-05 17:43:29',
AcctSessionTime = '4969', AcctInputOctets = '5398', AcctOutputOctets =
'5400', AcctTerminateCause = 'User-Request', AcctStopDelay = '0',
ConnectInfo_stop = '' WHERE AcctSessionId = '00000037' AND UserName = 'kern'
AND NASIPAddress = '10.0.0.1'
rlm_postgresql Status: PGRES_COMMAND_OK
sql_postgresql: affected rows = 1
radius_xlat: 'INSERT into radacct (AcctSessionId, AcctUniqueId, UserName,
Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctStopTime,
AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_stop,
AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId,
AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress,
AcctStartDelay, AcctStopDelay) values('00000037', '438e097a903ed8eb',
'kern', '', '10.0.0.1', CASE WHEN '0'='' then 0 else '0' end, 'Virtual',
'2000-01-01 00:00:00', '2002-04-05 17:43:29', '4969', 'RADIUS', '', '',
'5398', '5400', '', '', 'User-Request', 'Framed-User', 'PPP',
'192.168.10.4', '0', '0')'
query: INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm,
NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctStopTime,
AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_stop,
AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId,
AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress,
AcctStartDelay, AcctStopDelay) values('00000037', '438e097a903ed8eb',
'kern', '', '10.0.0.1', CASE WHEN '0'='' then 0 else '0' end, 'Virtual',
'2000-01-01 00:00:00', '2002-04-05 17:43:29', '4969', 'RADIUS', '', '',
'5398', '5400', '', '', 'User-Request', 'Framed-User', 'PPP',
'192.168.10.4', '0', '0')
rlm_postgresql Status: PGRES_COMMAND_OK
sql_postgresql: affected rows = 1
As shown, the first query is accounting_stop_query. The amount of affected
rows is 1, but FR continues with accounting_stop_query_alt.
I have compiled and installed rlm_postgresql module from FR 0.4 and the
problem disappears. Therefore I decided that the problem is in
rlm_sql_postgresql.
I have tried several CVSs, but the *probable* bug is still alive.
Thanx,
Timophey.
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
