Title: Radius Sending Rollback Message?
Radius Sending Rollback Message
A rather curious scenario of events:
In our setup of Radius, we use an Oracle database. Ordinarily, when NAS sends Accounting Start messages to Radius, Radius sends Update messages to Oracle. Periodically, something odd happens - Radius sends a Rollback message to Oracle which undoes the Update. This Rollback message is really not wanted as the Oracle DB doesnt get updated, but I havent got a clue why this happens. Please let me know if you've seen this before or if you know why this would happen. Help greatly appreciated.
Some more details are below.
(Radius-Oracle communicate with:
Data Manipulation Language (DML) consists of UPDATEs, INSERTs and MERGEs.
Transaction Control consists of COMMIT, SAVEPOINT, ROLLBACK and SET TRANSCATION.)
Here are the two failing sessions, (containing 4 UPDATE messages from the radius server) that did not successfully update the oracle DB.
UPDATE radacct SET Status = 1, NASIPAddress = '10.10.32.4', AcctStartTime = to_d
ate('2005-11-18 14:12:21','-MM-DD HH24:MI:SS'), CalledStationId = 'wx', XDI
AL= '213.55.204.140', FramedIPAddress= '10.12.33.152' WHERE CallingStationId =
'8380323'
UPDATE radacct SET Status = 0 , AcctStopTime = to_date('2005-11-18 14:28:20','Y
YYY-MM-DD HH24:MI:SS') WHERE CallingStationId = decode('8380323','', '0
00', '8380323')
UPDATE radacct SET Status = 1, NASIPAddress = '10.10.32.4', AcctStartTime = to_d
ate('2005-11-18 14:29:10','-MM-DD HH24:MI:SS'), CalledStationId = 'wx', XDI
AL= '213.55.204.140', FramedIPAddress= '10.12.23.199' WHERE CallingStationId =
'8380323'
UPDATE radacct SET Status = 0 , AcctStopTime = to_date('2005-11-18 15:13:04','Y
YYY-MM-DD HH24:MI:SS') WHERE CallingStationId = decode('8380323','', '0
00', '8380323')
The Oracle DB listener trace for the first message shows the DML was received ok but the end of a trace shows a ROLLBACK (this undoes all the DMLs since the last COMMIT was sent). Details:
UPDATE radacct SET Status = :SYS_B_0, NASIPAddress = :SYS_B_1,
AcctStartTime = to_date(:SYS_B_2,:SYS_B_3), CalledStationId =
:SYS_B_4, XDIAL= :SYS_B_5, FramedIPAddress = :SYS_B_6
WHERE
CallingStationId =:SYS_B_7
call count cpu elapsed disk query current rows
--- -- -- -- -- -- --
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.01 0.00 2 3 14 1
Fetch 0 0.00 0.00 0 0 0 0
--- -- -- -- -- -- --
total 2 0.01 0.01 2 3 14 1
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 162
Rows Row Source Operation
--- ---
1 UPDATE
1 INDEX UNIQUE SCAN PK_RADACCT (object id 622971)
SELECT CallingStationId,
FramedIpAddress
from radius.radacct
where rowid = :b1
and Status = 1
call count cpu elapsed disk query current rows
--- -- -- -- -- -- --
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 1 0 1
--- -- -- -- -- -- --
total 3 0.00 0.00 0 1 0 1
Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 162 (recursive depth: 1)
Rows Row Source Operation
--- ---
1 TABLE ACCESS BY USER ROWID RADACCT
UPDATE radius.radacct
set Status = 0
where Status = 1
and FramedIpAddress = :b2
and CallingStationId != :b1
call count cpu elapsed disk query current rows
--- -- -- -- -- -- --
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.03 0.04 0 2066 0 0
Fetch 0 0.00 0.00 0 0 0 0
--- -- -- -- -- -- --
total 2 0.03 0.04 0 2066 0 0
Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 162 (recursive depth: 1)
Rows Row Source Operation
--- ---
0 UPDATE
0 TABLE ACCESS BY INDEX ROWID RADACCT
2587 INDEX RANGE SCAN RADACCT_IX4 (object id 464104)
rollback
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
