Radius Sending Rollback Message?

8 Dec 2005

      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','YYYY-MM-DD HH24:MI:SS'), CalledStationId = 'wx', XDI
AL= '213.55.204.140',  FramedIPAddress= '10.12.33.152' WHERE CallingStationId = 
 '11118380323'                                                                  
UPDATE radacct SET  Status = 0 , AcctStopTime = to_date('2005-11-18 14:28:20','Y
YYY-MM-DD HH24:MI:SS')  WHERE CallingStationId = decode('11118380323','', '11110
000000', '11118380323')  

UPDATE radacct SET Status = 1, NASIPAddress = '10.10.32.4', AcctStartTime = to_d
ate('2005-11-18 14:29:10','YYYY-MM-DD HH24:MI:SS'), CalledStationId = 'wx', XDI
AL= '213.55.204.140',  FramedIPAddress= '10.12.23.199' WHERE CallingStationId = 
 '11118380323'                                                                  
UPDATE radacct SET  Status = 0 , AcctStopTime = to_date('2005-11-18 15:13:04','Y
YYY-MM-DD HH24:MI:SS')  WHERE CallingStationId = decode('11118380323','', '11110
000000', '11118380323') 

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

Radius Sending Rollback Message?

Sharma Raj