Wednesday, October 4, 2017

Result Cache:0 rows updated Invalidations (IV)

We have hit a new case of Result Cache Invalidations, in which result_cache Table has "0 rows updated". If we update another non result_cache Table in the same transaction, Result Cache becomes Invalid.

At the end of this Blog, we also give a Workaround.

This is the 4th case of Result Cache Invalidation, which can cause Result Cache: RC Latch Contention.
1. PL/SQL Function Result Cache Invalidation (I) (DML and Select for Update)
2. Result Cache: RC Latch Contention and RESULT_CACHE_MAX_SIZE (II))
3. Result Cache: RC Latch Contention and PL/SQL Exception Handler (III)
4. Result Cache:0 rows updated Invalidations (IV) 
Note: All tests are done in Oracle 11.2.0.4, 12.1.0.2, 12.2.0.1 on AIX, Solaris, Linux with 6 physical processors.

Update (25-Jan-2018): The reported issue accepted as Bug and public visible.
    Bug 26964029 : RESULT CACHE INVALIDATED EVEN THOUGH UPDATE ZERO ROWS


1. Test Setup



alter session set nls_date_format = 'yyyy-MON-dd hh24:mi:ss';

drop table noise_tab;

create table noise_tab as select level x, rpad('ABC', 100, 'X') y from dual connect by level <= 3; 

drop table rc_tab;

create table rc_tab as select level id, level*10 val from dual connect by level <= 5;

create or replace function get_val (p_id number) return number result_cache as
  l_val     number;
begin
  select val into l_val from rc_tab where id = p_id;
  return l_val;
end;
/

create or replace procedure run_test as
  l_val number;
begin
  for i in 1 .. 5 loop
    l_val := get_val(i);
  end loop;
end;
/


2. Test_1. Pure Test, No Invalid



----------------- Test 1. Pure Test, No Invalid -----------------

exec dbms_result_cache.flush;

exec run_test;

select creation_timestamp, type, status, name from v$result_cache_objects;

update rc_tab set val = val+1 where 1 = 2;

commit;

select creation_timestamp, type, status, name from v$result_cache_objects;


3. Test_2. Noise Test, Invalid



----------------- Test 2. Noise Test, Invalid -----------------

exec dbms_result_cache.flush;

exec run_test;

select creation_timestamp, type, status, name from v$result_cache_objects;

update rc_tab set val = val+1 where 1 = 2;

update noise_tab set y = 'xx' where x = 2;

commit;

select creation_timestamp, type, status, name from v$result_cache_objects;


4. Test Output



--============================= Test Output =============================--

SQL > ----------------- Test 1. Pure Test, No Invalid -----------------
SQL > exec dbms_result_cache.flush;

SQL > exec run_test;

SQL > select creation_timestamp, type, status, name from v$result_cache_objects;

CREATION_TIMESTAMP   TYPE       STATUS    NAME
-------------------- ---------- --------- -------------------------------------------------------------------
2017-OCT-04 13:38:34 Dependency Published K.RC_TAB
2017-OCT-04 13:38:34 Dependency Published K.GET_VAL
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1

7 rows selected.

SQL > update rc_tab set val = val+1 where 1 = 2;

0 rows updated.

SQL > commit;

SQL > select creation_timestamp, type, status, name from v$result_cache_objects;

CREATION_TIMESTAMP   TYPE       STATUS    NAME
-------------------- ---------- --------- -------------------------------------------------------------------
2017-OCT-04 13:38:34 Dependency Published K.RC_TAB
2017-OCT-04 13:38:34 Dependency Published K.GET_VAL
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1

7 rows selected.

SQL > ----------------- Test 2. Noise Test, Invalid -----------------

SQL > exec dbms_result_cache.flush;

SQL > exec run_test;

SQL > select creation_timestamp, type, status, name from v$result_cache_objects;

CREATION_TIMESTAMP   TYPE       STATUS    NAME
-------------------- ---------- --------- -------------------------------------------------------------------
2017-OCT-04 13:38:34 Dependency Published K.RC_TAB
2017-OCT-04 13:38:34 Dependency Published K.GET_VAL
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1

7 rows selected.

SQL > update rc_tab set val = val+1 where 1 = 2;

0 rows updated.

SQL > update noise_tab set y = 'xx' where x = 2;

1 row updated.

SQL > commit;

SQL >
SQL > select creation_timestamp, type, status, name from v$result_cache_objects;

CREATION_TIMESTAMP   TYPE       STATUS    NAME
-------------------- ---------- --------- -------------------------------------------------------------------
2017-OCT-04 13:38:34 Dependency Published K.RC_TAB
2017-OCT-04 13:38:34 Dependency Published K.GET_VAL
2017-OCT-04 13:38:34 Result     Invalid   "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Invalid   "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Invalid   "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Invalid   "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
2017-OCT-04 13:38:34 Result     Invalid   "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1

7 rows selected.


5. Workaround



exec dbms_result_cache.flush;

exec run_test;

select creation_timestamp, type, status, name from v$result_cache_objects;

--lock table rc_tab in ROW EXCLUSIVE mode;
lock table rc_tab in EXCLUSIVE mode;

begin
  if  1 = 2 then
     update rc_tab set val = val+1;
  end if;
end;
/

update noise_tab set y = 'xx' where x = 2;

commit;

select creation_timestamp, type, status, name from v$result_cache_objects;

--============================= Workaround Output =============================--

SQL > exec dbms_result_cache.flush;

SQL > exec run_test;

SQL > select creation_timestamp, type, status, name from v$result_cache_objects;

 CREATION_TI TYPE       STATUS    NAME
 ----------- ---------- --------- ---------------------------------------------------------------------------
 09-OCT-2017 Dependency Published K.RC_TAB
 09-OCT-2017 Dependency Published K.GET_VAL
 09-OCT-2017 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
 09-OCT-2017 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
 09-OCT-2017 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
 09-OCT-2017 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
 09-OCT-2017 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1

 7 rows selected.

SQL > lock table rc_tab in EXCLUSIVE mode;

 Table(s) Locked.

SQL > begin
   2    if  1 = 2 then
   3       update rc_tab set val = val+1;
   4    end if;
   5  end;
   6  /

SQL > update noise_tab set y = 'xx' where x = 2;

 1 row updated.

SQL > commit;

SQL > select creation_timestamp, type, status, name from v$result_cache_objects;

 CREATION_TI TYPE       STATUS    NAME
 ----------- ---------- --------- ---------------------------------------------------------------------------
 09-OCT-2017 Dependency Published K.RC_TAB
 09-OCT-2017 Dependency Published K.GET_VAL
 09-OCT-2017 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
 09-OCT-2017 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
 09-OCT-2017 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
 09-OCT-2017 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
 09-OCT-2017 Result     Published "K"."GET_VAL"::8."GET_VAL"#3048d2af80817a01 #1
 
 7 rows selected.


6. v$result_cache_statistics


V$RESULT_CACHE_STATISTICS contains 3 Rows reporting different kind of Invalidations. To recap all our previous discussion on triggering originals of Result Cache Invalidation, we can try to map those Rows to the originals.

ID 8. Invalidation Count: DML updates caused, see: PL/SQL Function Result Cache Invalidation (I) and Result Cache:0 rows updated Invalidations (IV)

ID 9. Delete Count Invalid:  PL/SQL RC Exception Handler related Result Cache, see: RC Latch Contention and PL/SQL Exception Handler (III)

ID 10. Delete Count Valid: Memory Limit Reached, see: Result Cache: RC Latch Contention and RESULT_CACHE_MAX_SIZE (II)

ID 11. Hash Chain Length:  length of hash chain. When no invalid, it is 1 or a constant number. When invalidate/create, it is a range.

If Result Cache experienced a heavy Invalidations, and got recreated, we can see the difference of "ID 5. Create Count Success" before and after recreated, and that of "ID 9. Delete Count Invalid" are quite close. In such case, if we rebuild the Invalidations by a few parallel sessions, latch free of "Result Cache: RC Latch" will appear at the top wait events. It could be fixed by either to flush Result Cache and rebuild from fresh, or use a single session to recreate them.


Update (18Mar2018)


In Blog: RESULT_CACHE hint expiration options , dependencies test showed one case of Result Cache Invalidation by "0 rows deleted".

drop table DEMO;
create table DEMO as select rownum id from xmltable('1 to 100000');
exec if dbms_result_cache.flush then dbms_output.put_line('Flushed.'); end if;

set autotrace on
select /*+ result_cache */ count(*) from DEMO;

set autotrace off
select * from v$result_cache_dependency;
  --
  --  RESULT_ID  DEPEND_ID  OBJECT_NO     CON_ID
  --  --------- ---------- ---------- ----------
  --          1          0    2305802          0
          
select id,type,status,name,cache_id,invalidations from v$result_cache_objects order by id;
  --  ID TYPE       STATUS    NAME                                          CACHE_ID                   INVALIDATIONS
  --  -- ---------- --------- --------------------------------------------- -------------------------- -------------
  --   0 Dependency Published K.DEMO                                        K.DEMO                                 0
  --   1 Result     Published select /*+ result_cache */ count(*) from DEMO 74s7myvzxca2u8jn4yfkftapdg             0

delete from DEMO where null is not null;
  --  0 rows deleted.
  
commit;

select * from v$result_cache_dependency;
  --  no rows selected
  
select id,type,status,name,cache_id,invalidations from v$result_cache_objects order by id;
  -- ID TYPE       STATUS    NAME                                          CACHE_ID                   INVALIDATIONS
  -- -- ---------- --------- --------------------------------------------- -------------------------- -------------
  --  0 Dependency Published K.DEMO                                        K.DEMO                                 1
  --  1 Result     Invalid   select /*+ result_cache */ count(*) from DEMO 3du8t8wtmx913djt9nvwm561sb             0
As we know, in order to record plan_table, "autotrace on" started a new transaction after first select statement with some DML like:

  DELETE FROM PLAN_TABLE WHERE STATEMENT_ID=:1
  insert into plan_table (statement_id, timestamp, operation ..
We can verify it by:

set autotrace off
commit;

select sum(s.sid), count(*)from v$transaction t, v$session s where t.addr=s.taddr and s.sid = sys.dbms_support.mysid;
  --  SUM(S.SID)   COUNT(*)
  --  ---------- ----------
  --                      0

set autotrace on

select dummy from dual;

select sum(s.sid), count(*)from v$transaction t, v$session s where t.addr=s.taddr and s.sid = sys.dbms_support.mysid;
  --  SUM(S.SID)   COUNT(*)
  --  ---------- ----------
  --         543          1
Removing "set autotrace on" and rerun the above test, there is no more such Invalid.

The original Blog got updated by a new Blog: Result cache invalidation caused by DML locks with deep analysis. Additionally it shows the Invalidation changes triggered by referential integrity in 12c, which needs to be further investigated.