Monday, April 11, 2022

Oracle Write Consistency and ORA-30926: "unable to get a stable set of rows in the source tables"

(1)-Oracle Write Consistency and ORA-00600: [13030], [20]      (2)-Oracle Write Consistency and ORA-30926      


We will discuss Oracle Write Consistency and different error messages in two Blogs.

Following previous Blog: Oracle Write Consistency and ORA-00600: [13030], [20],
this Blog will show Write Consistency and ORA-30926: "unable to get a stable set of rows in the source tables".

We will show that error message depends on column declaration:
  for column "not null", it is ORA-00600: [13030], [20]
  for column "null",     it is ORA-30926: "unable to get a stable set of rows in the source tables"
Note: Tested in Oracle 19.13, 19.7, 18.9, 12.1


1. Test Setup


We use the same test code of previous Blog, but change column txt from "not null" to nullable:

alter table test_tab modify txt varchar2(1) null;

  --alter table test_tab modify (txt not null);
So its DDL looks like:

create table test_tab (id number, txt varchar2(1), constraint test_tab_pk primary key (id));          


2. Test Run


We run the same test as previous Blog:

Open two Sqlplus sessions: SID-1 and SID-2.

At T1, SID-1 updates txt from 'A' to 'B' for id=2.

--========== 1. SID-1@T1 ==========--
                   
begin
  update test_tab set txt = 'A'; 
  commit;                        
   
  -- block id=2 update                              
  update test_tab                
     set txt = 'B'               
   where txt = 'A'               
     and id  = 2;
  dbms_output.put_line('At '||localtimestamp ||': update id=2 from A to B');                
end;
/        

---- Output ----
At 18:52:20: update id=2 from A to B
At T2, SID-2 updates txt from 'A' to 'B' with filter condition: "test_pkg.non_deterministic_fun(id, 10) > 0", which sleeps 10 seconds before return. Its output toggles as 0 or 1 in successive call for the given id.

--========== 2. SID-2@T2 ==========--

alter session set nls_timestamp_format ='HH24:MI:SS.ff3';  

alter session set tracefile_identifier = 'Null_Error_1';
alter session set events 'trace[DML]   disk=high ';       
exec dbms_monitor.session_trace_enable;

--ALTER SESSION SET "_fix_control"='30681521:0';

begin
  test_pkg.set_cnt(0, 0);   -- reset package state
  
  update test_tab           -- update /*+ RETRY_ON_ROW_CHANGE */ test_tab -- hint has no effect
     set txt = 'B'
   where txt = 'A'
     and test_pkg.non_deterministic_fun(id, 10) > 0;
end;
/

---- Output ----
At 18:53:01: Reset Package Variables: b_1_cnt=0, b_2_cnt=0
At 18:53:11: b_1_cnt=1, non_deterministic_fun(1, 10)=1
At 18:53:21: b_2_cnt=1, non_deterministic_fun(2, 10)=1
At 18:54:28: b_1_cnt=2, non_deterministic_fun(1, 10)=0
At 18:54:38: b_1_cnt=3, non_deterministic_fun(1, 10)=1

ORA-30926: unable to get a stable set of rows in the source tables
ORA-06512: at line 4
      Elapsed: 00:01:37.37
At T3, SID-1 sleeps 30 seconds and commits its T1 update.
Sleeps another 5 seconds.
Then updates txt from 'A' to 'B' for id=1 and commit.

--========== 3. SID-1@T3 ==========--

begin
  dbms_output.put_line('At '||localtimestamp ||': wait id=2 update for 30 seconds');
  test_pkg.prt_tx_locks;
  dbms_lock.sleep(30);
  commit;
  
  dbms_output.put_line('At '||localtimestamp ||': commit id=2 update. Then wait 5 seconds');
  dbms_lock.sleep(5);          -- This wait to de-block id=2 is critical, otherwise no error
  update test_tab
     set txt = 'B'
   where txt = 'A'
     and id  = 1;
  test_pkg.prt_tx_locks;
  commit;
  dbms_output.put_line('At '||localtimestamp ||': update id=1 from A to B, and commit');
end;
/

---- Output ----
At 18:53:48: wait id=2 update for 30 seconds
At 18:54:18: commit id=2 update. Then wait 5 seconds
At 18:54:23: update id=1 from A to B, and commit
      Elapsed: 00:00:35.10
From test output, we can see the update sequence:

At 18:52:20: SID-1 update id=2 from A to B.
At 18:53:01: SID-2 start running. get into "phase=NOT LOCKED". sleep 10 seconds. 
At 18:53:11: SID-2 update id=1 because non_deterministic_fun(1, 10)=1. sleep 10 seconds.
At 18:53:21: SID-2 update id=2, but SID-1 does not commit "id=2 update", it is blocked by "TX" lock for 52 seconds (ela= 52217121).
At 18:54:18: SID-1 commit "id=2 update". SID-2 is unlocked.
             SID-2 restart update, get into "phase=LOCK" with "SELECT FOR UPDATE". sleep 10 seconds.
At 18:54:23: SID-1 update id=1 from A to B, and commit.
At 18:54:28: SID-2 get into "phase=NOT LOCKED". id=1 check non_deterministic_fun(1, 10)=0. sleep 10 seconds. 
At 18:54:38: SID-2 id=1 check non_deterministic_fun(1, 10)=1.
             SID-2 raise ORA-30926: unable to get a stable set of rows in the source tables
Here SID-2 DML UTS tracing file (only related lines extracted).
  
===================== *** 18:53:01
PARSING IN CURSOR #140130541280008 sqlid='6jabvd6xa3vfh'
UPDATE TEST_TAB SET TXT = 'B' WHERE TXT = 'A' AND TEST_PKG.NON_DETERMINISTIC_FUN(ID, 10) > 0

updThreePhaseExe: objn=3122646 phase=NOT LOCKED
updaul: phase is NOT LOCKED snap oldsnap env: 
===================== *** 18:53:11
WAIT #140130541280008: nam='PL/SQL lock timer' ela= 10000747 tim=12530784547085
===================== *** 18:53:21
WAIT #140130541280008: nam='PL/SQL lock timer' ela= 10000350 tim=12530794548111
===================== *** 18:54:18
WAIT #140130541280008: nam='enq: TX - row lock contention' ela= 57331903 name|mode=1415053318 usn<<16 | slot=7929886 sequence=75843 obj#=3122646 tim=12530851880410
dmlTrace:file:line (kdu.c:3505) cmpf 20 rowcol 1 piececol 1
updThreePhaseExe: objn=3122646 phase=LOCK
===================== *** 18:54:28
WAIT #140130541280008: nam='PL/SQL lock timer' ela= 10000913 tim=12530861882109
updThreePhaseExe: objn=3122646 phase=ALL LOCKED
===================== *** 18:54:38
WAIT #140130541280008: nam='PL/SQL lock timer' ela= 10000212 tim=12530871883059
Block header dump:  0x000c9786
 
 Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x0079.01e.00012843  0x00c037cf.2339.04  --U-    1  fsc 0x0000.5dd736a1
0x02   0x007d.01e.00011c65  0x00c00edd.1dbf.0c  --U-    1  fsc 0x0000.5dd736ac
===============
block_row_dump:
tab 0, row 0, @0x1f90
tl: 8 fb: --H-FL-- lb: 0x2  cc: 2
col  0: [ 2]  c1 02
col  1: [ 1]  42
tab 0, row 1, @0x1f88
tl: 8 fb: --H-FL-- lb: 0x1  cc: 2
col  0: [ 2]  c1 03
col  1: [ 1]  42

  kflag
   [0] CMPCOL
   cmpp (2) c1 02
   [1] CMPCOL UPDCOL
   cmpp (1) 41
   updp (1) 42
updThreePhaseExe: Table 0 Code 20 Cannot update, all rows locked: 002fa5d6.000c9786.0

EXEC #140130541280008:c=126042,e=97365970,p=0,cr=23,cu=10,mis=0,r=0,dep=1,og=1,plh=1551061149,tim=12530871911513
ERROR #140130541280008:err=30926 tim=12530871911558
We can see that all the test output is almost identical to previous Blog: Write Consistency and error ORA-00600: [13030], [20]. but error messages are different.
  when column "txt not null", it is ORA-00600: [13030], [20]
  when column "txt null",     it is ORA-30926: "unable to get a stable set of rows in the source tables"

3. Related Work


Oracle MOS: How to Troubleshoot ORA-30926 Errors? (Doc ID 471956.1) wrote:
  Applies to:
    Oracle Database - Enterprise Edition - Version 8.1.7.4 to 11.2.0.4 [Release 8.1.7 to 11.2]

  ORA-30926 (formerly ORA-600 [13012]) 
  
  30926, 00000, "unable to get a stable set of rows in the source tables"  
  // *Cause:  A stable set of rows could not be got because of large dml
  //          activity or a non-deterministic where clause.
  // *Action: Remove any non-deterministic where clauses and reissue the dml.
  
  Troubleshooting Steps
    - If the error occurs in your SQLPLUS session, use:
    SQL> alter session set events '30926 trace name errorstack level 3';
            Run the failing script/procedure etc.
         This event can be disabled by ending the session or by using:
    SQL> alter session set events '30926 trace name errorstack off'; 

So ORA-30926 was formerly ORA-600 [13012] for column "null", similar to ORA-600 [13030] for column "not null".

We also tried with trace event 30926 in SID-2:

--========== 2. SID-2@T2 ==========--

alter session set max_dump_file_size = UNLIMITED;
alter session set tracefile_identifier = 'Null_Error_2';
alter session set events ë30926 trace name errorstack level 3í;

--ALTER SESSION SET "_fix_control"='30681521:0';

begin
  test_pkg.set_cnt(0, 0);   -- reset package state
  
  update test_tab           -- update /*+ RETRY_ON_ROW_CHANGE */ test_tab -- hint has no effect
     set txt = 'B'
   where txt = 'A'
     and test_pkg.non_deterministic_fun(id, 10) > 0;
end;
/

alter session set events ë30926 trace name errorstack offí; 
Here the trace file (only related lines extracted):

DML restarted sqlid : 6jabvd6xa3vfh
dmlTrace:file:line (kdu.c:3505) cmpf 20 rowcol 1 piececol 1

Block header dump:  0x000c9786
 Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x007e.015.00011c86  0x00c02dbd.1ea0.03  --U-    1  fsc 0x0000.5df1e217
0x02   0x007f.01d.00013bad  0x00c01fbf.20ca.03  --U-    1  fsc 0x0000.5df1e212
data_block_dump,data header at 0x135a18064
===============
tab 0, row 0, @0x1f90
tl: 8 fb: --H-FL-- lb: 0x1  cc: 2
col  0: [ 2]  c1 02
col  1: [ 1]  42
tab 0, row 1, @0x1f88
tl: 8 fb: --H-FL-- lb: 0x2  cc: 2
col  0: [ 2]  c1 03
col  1: [ 1]  42

  kflag
   [0] CMPCOL
   cmpp (2) c1 02
   [1] CMPCOL UPDCOL
   cmpp (1) 41
   updp (1) 42
updThreePhaseExe: Table 0 Code 20 Cannot update, all rows locked: 002fa5d6.000c9786.0

30926 trace name errorstack level 3
trace [RDBMS.DML] {callstack: fname dmlTrace} disk=high trace("DML restarted sqlid : %\n", sqlid())
It looks like DML UTS in Blog: Write consistency and DML restart (Mahmoud Hatem) and shows the same trace event to find update statement hitting the write consistency.

  alter system set events 'trace[DML] {callstack: fname dmlTrace} disk=high trace("DML restarted sqlid : %\n", sqlid())';