Friday, July 21, 2017

nls_database_parameters, dc_props, latch: row cache objects

This Blog will demonstrate latch: row cache objects on Dictionary Cache dc_props when querying nls_database_parameters.

Note: all tests are done in Oracle 12.1.0.2.0.

Reference: NLS understanding in this Blog is acquired and cited from:
    Oracle MOS: The Priority of NLS Parameters Explained (Where To Define NLS Parameters) (Doc ID 241047.1)


1. latch: row cache objects


At first, find v$rowcache.cache# mapping to v$latch_children.child#, then query nls_database_parameters, collecting statistics before and after test:

select r.kqrstcid cache#, r.kqrsttxt parameter, c.child#  --, r.*, c.* 
from x$kqrst r, v$latch_children c 
where r.kqrstcln = c.child# 
  and r.kqrsttxt = 'dc_props'
  and c.name     = 'row cache objects';

 CACHE# PARAMETER  CHILD#
------- --------- -------
     15 dc_props       18

select r.cache#, r.type, r.parameter, r.gets, r.count, c.name, c.child#, c.gets latch_gets
from v$rowcache r, v$latch_children c
where r.parameter = 'dc_props' and c.name = 'row cache objects' and c.child# = 18;  

 CACHE#   TYPE PARAMETER     GETS  COUNT              NAME  CHILD#  LATCH_GETS
------- ------ --------- -------- ------ ----------------- ------- -----------
     15 PARENT dc_props    140920     60 row cache objects      18      422820
                                                                    
select value from nls_database_parameters where parameter = 'NLS_CHARACTERSET';
  VALUE   
  --------
  AL32UTF8
  
select r.cache#, r.type, r.parameter, r.gets, r.count, c.name, c.child#, c.gets latch_gets
from v$rowcache r, v$latch_children c
where r.parameter = 'dc_props' and c.name = 'row cache objects' and c.child# = 18;  

 CACHE#   TYPE PARAMETER     GETS  COUNT              NAME  CHILD#  LATCH_GETS
------- ------ --------- -------- ------ ----------------- ------- -----------
     15 PARENT dc_props    140980     60 row cache objects      18      423000
We can see that dc_props GETs increased 60 (140980 - 140920), and LATCH_GETS increased 180 (423000 - 422820).

nls_database_parameters is defined by:

create or replace force view sys.nls_database_parameters (parameter, value) as
  select name, substr (value$, 1, 64) from x$props where name like 'NLS%';
A query on v$rowcache_parent for 'dc_props' shows:

select cache_name, existent, count(*) cnt from v$rowcache_parent 
 where cache_name = 'dc_props' group by cache_name, existent;

  CACHE_NAME  EXISTENT   CNT
  ----------- --------- ----
  dc_props    Y           37
  dc_props    N           23
It contains 60 rows, of which 37 are existing objects, 23 are not. Total number of 'dc_props' Cache entries: v$rowcache.COUNT = 60 is corresponding to 60 parent objects of v$rowcache_parent.

37 existing objects can be confirmed by:

select count(*) from x$props; 
   COUNT(*)
  ---------
         37
These 37 existing objects are probably originated from:

select * from sys.props$;
select * from database_properties;
Since the query on nls_database_parameters is a TABLE FULL scan on X$PROPS.

select value from nls_database_parameters where parameter = 'NLS_CHARACTERSET';

----------------------------------------------------------------------------
| Id  | Operation        | Name    | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------
|   0 | SELECT STATEMENT |         |     1 |    28 |     0   (0)| 00:00:01 |
|*  1 |  FIXED TABLE FULL| X$PROPS |     1 |    28 |     0   (0)| 00:00:01 |
----------------------------------------------------------------------------
and v$rowcache_parent contains 60 rows for 'dc_props', a TABLE FULL scan makes 60 GETs in v$rowcache, although the underlying X$PROPS contains only 37 EXISTENT objects. It seems that NON-EXISTENT objects also require the similar handling.

For each rowcache GET, it requires 3 "latch: row cache objects" GETs, that is why we have 180 LATCH_GETS.
(see Oracle Core: Essential Internals for DBAs and Developers Page 167:
    there was a common pattern indicating three latch gets for each dictionary cache get)

Oracle 12c V$ROWCACHE_PARENT wrote:

V$ROWCACHE_PARENT displays information for parent objects in the data dictionary. There is one row per lock owner, and one waiter for each object. This row shows the mode held or requested. For objects with no owners or waiters, a single row is displayed.

In case of acute wait of latch: row cache objects, we can try to find the lock owner or waiter by:

select s.sid, s.program, r.* 
  from v$rowcache_parent r, v$session s
 where cache_name = 'dc_props' 
   and (lock_mode != '0' or lock_request != '0')
   and r.saddr = s.saddr(+);
In essence, dc_props seems the Dictionary Cache (Row Cache) of Sys Table: sys.props$.


2. NLS_CHARACTERSET semantics and Solutions


Oracle stores NLS settings in 3 levels: database/instance/session:
  nls_database_parameters
  nls_instance_parameters
  nls_session_parameters
  
and the precedence is ordered from low to high.
(Note: Any setting explicit used in SQL will always take precedence about all other settings)
In application semantics, session specific NLS settings should be selected because of precedence.

Additionally, it defines:
  v$nls_parameters 
A view that shows the current session parameters and the *DATABASE* characterset as seen in the NLS_DATABASE_PARAMETERS view.

MOS Doc ID 241047.1 Section C) The Database Parameters - NLS_DATABASE_PARAMETERS wrote:

These parameters are "overruled" by NLS_INSTANCE_PARAMETERS and NLS_SESSION_PARAMETERS.
The only exception are the NLS_CHARACTERSET and NLS_NCHAR_CHARACTERSET settings.
The NLS_CHARACTERSET and NLS_NCHAR_CHARACTERSET parameters cannot be overruled by instance or session parameters.
They are defined by the value specified in "create database ..." and are not intended to be changed afterwords dynamically.

Look the definition of nls_session_parameters:

CREATE OR REPLACE FORCE VIEW SYS.NLS_SESSION_PARAMETERS (PARAMETER, VALUE) AS
SELECT SUBSTR (parameter, 1, 30), SUBSTR (VALUE, 1, 64)
  FROM v$nls_parameters
 WHERE     parameter != 'NLS_CHARACTERSET'
       AND parameter != 'NLS_NCHAR_CHARACTERSET';
and definition of gv$nls_parameters (underlying view):

SELECT inst_id,
       parameter,
       VALUE,
       con_id
  FROM x$nls_parameters
 WHERE parameter != 'NLS_SPECIAL_CHARS'
and count each by:

select count(*) from nls_session_parameters;  
   COUNT(*)
  ---------
         17
  
select count(*) from v$nls_parameters;             
   COUNT(*)
  ---------
         19  
The discrepancy are exactly the two excluded NLS_(NCHAR)_CHARACTERSET parameters, nls_session_parameters is a subset of v$nls_parameters.

select parameter, value from v$nls_parameters 
minus
select parameter, value from nls_session_parameters;

  PARAMETER              VALUE
  ---------------------- ---------
  NLS_CHARACTERSET       AL32UTF8
  NLS_NCHAR_CHARACTERSET AL16UTF16
Therefore, in order to avoid latch: row cache objects on dc_props, we can run the equivalent:

  select value from v$nls_parameters where parameter = 'NLS_CHARACTERSET';
instead of query:

  select value from nls_database_parameters where parameter = 'NLS_CHARACTERSET';
The later generates 60 rowcache GETs, and 180 latch: row cache objects on dc_props for each run. Therefore, severe row cache objects latch contention occurs if we frequently query nls_database_parameters.

We can verify this solution by:

select r.cache#, r.type, r.parameter, r.gets, r.count, c.name, c.child#, c.gets latch_gets
from v$rowcache r, v$latch_children c
where r.parameter = 'dc_props' and c.name = 'row cache objects' and c.child# = 18;  

 CACHE#   TYPE PARAMETER    GETS  COUNT              NAME  CHILD#  LATCH_GETS
------- ------ --------- ------- ------ ----------------- ------- -----------
     15 PARENT dc_props   141046     60 row cache objects      18      423198
                                                                    
select value from v$nls_parameters where parameter = 'NLS_CHARACTERSET';
  VALUE   
  --------
  AL32UTF8
   
select r.cache#, r.type, r.parameter, r.gets, r.count, c.name, c.child#, c.gets latch_gets
from v$rowcache r, v$latch_children c
where r.parameter = 'dc_props' and c.name = 'row cache objects' and c.child# = 18;  

 CACHE#   TYPE PARAMETER    GETS  COUNT              NAME  CHILD#  LATCH_GETS
------- ------ --------- ------- ------ ----------------- ------- -----------
     15 PARENT dc_props   141046     60 row cache objects      18      423198
Obviously there are neither rowcache GETs, nor latch: row cache objects, because NLS session parameters (v$nls_parameters) are stored in session memory UGA and are not visible for other sessions, whereas nls_database_parameters is setup in a DB wide globally shared space (SGA) and have to be protected by latch: row cache objects.

In general, latch: row cache objects is documented as protecting data dictionary cache, but we saw that it is also used to safeguard X$PROPS.

Similar to v$nls_parameters, database NLS_CHARACTERSET can also be gotten by:

select sys_context('userenv','language') from dual;
select userenv ('language') from dual;    -- userenv 12c deprecated 
without rowcache GETs and latch: row cache objects.

sys_context('userenv','language') returns the language and territory currently used by the current session, along with the database character set in UNIX-like format:
   language_territory.characterset
Usually SYS_CONTEXT returns the value of parameter associated with the context namespace at the current instant for the current session. Since database NLS_CHARACTERSET is a database wide parameter, sys_context returns the correct value.

Further more, MOS Doc ID 241047.1 explained the difference between database character set and OS env NLS_LANG character set:

The database character set is not the same as the character set of the NLS_LANG that you started this connection with!
The OS environment NLS_LANG (from where you started this connection) is reflected in v$session_connect_info.CLIENT_CHARSET:

  select CLIENT_CHARSET, v.* from v$session_connect_info v;
MOS Doc ID 241047.1 wrote:

D1) sys.props$
    SQL>select name,value$ from sys.props$ where name like '%NLS%';
    This gives the same info as NLS_DATABASE_PARAMETERS. You should use NLS_DATABASE_PARAMETERS instead of props$

We saw that NLS_DATABASE_PARAMETERS is underlined by X$PROPS, whereas SYS.PROPS$ is a real table. The former select generates row cache GETs and requires latch: row cache objects, the later not. Therefore from performance point of view, they are not the same.

In summary:
(A). nls_database_parameters is underlined by x$props, which requires latch: row cache objects on Dictionary Cache dc_props.

(B). v$nls_parameters is underlined by x$nls_parameters.

(C). sys_context('userenv','language') is underlined by sys.props$, which is a real table.
     It returns the language and territory of current session in UNIX (NLS_LANG) like format: 
        language_territory.characterset

(D). nls_session_parameters is a subset of v$nls_parameters.
     v$nls_parameters has two additional rows of *DATABASE* characterset (NLS_CHARACTERSET, NLS_NCHAR_CHARACTERSET) 
     from nls_database_parameters.
   
(E). To find *DATABASE* characterset (NLS_CHARACTERSET, NLS_NCHAR_CHARACTERSET), 
     both nls_database_parameters and v$nls_parameters can be used. 
     The difference is that nls_database_parameters requires "latch: row cache objects", but v$nls_parameters not.


3. 'latch: row cache objects' Contention Test


Launch 2 Jobs (see appended Test Code), monitor "latch: row cache objects" contentions.

SQL > exec nls_select_jobs(2, 1e9);

column p1text format a10                
column p2text format a10 
column p3text format a10                                      
column event format a25 

SQL > select sid, event, p1text, p1, p1raw, p2text, p2, p2raw, p3text, p3, p3raw
        from v$session where program like '%(J0%';

    SID EVENT                     P1TEXT           P1 P1RAW            P2TEXT    P2 P2RAW            P3TEXT   P3 P3RAW
  ----- ------------------------- -------- ---------- ---------------- ------- ---- ---------------- ------- --- -----
      6 latch: row cache objects  address  6376016176 000000017C0A4930 number   411 000000000000019B tries     0 00
    287 latch: row cache objects  address  6376016176 000000017C0A4930 number   411 000000000000019B tries     0 00
  
--After Test stop all jobs by:
--SQL > exec clean_jobs;
Display the top latch misses and their locations, which are kqrpre and kqreqd. The sum of SLEEP_COUNT is close to sum of WTR_SLP_COUNT. Their data distribution could indicate certain Holder-Waiter logic.

column PARENT_NAME format a30                                                     
column WHERE format a20 

SQL > select * from (select * from v$latch_misses order by sleep_count desc)
       where rownum <= 5;

  PARENT_NAME                  WHERE                NWFAIL_COUNT SLEEP_COUNT WTR_SLP_COUNT LONGHOLD_COUNT LOCATION
  ---------------------------- -------------------- ------------ ----------- ------------- -------------- ----------------
  row cache objects            kqrpre: find obj                0       64009         94027              0 kqrpre: find obj
  row cache objects            kqreqd: reget                   0       61416         30578              0 kqreqd: reget
  row cache objects            kqreqd                          0       35943         36768              0 kqreqd
  space background task latch  ktsj_grab_task                  0           4             4              0 ktsj_grab_task
  call allocation              ksuxds                          0           3             3              0 ksuxds

(Note: WHERE column is obsolete, it is always equal to the value in LOCATION)


4. Blocker and Waiter Demo


As a demo, we manually create 'latch: row cache objects' blocking. In one Session (SID 123, SPID 3456), stop it before it release the held 'latch: row cache objects', so it becomes a latch Holder, then run sql. Session is stopped with a callstack.

$ > dtrace -w  -n \
'pid$target::kqreqd:entry  /execname == "oracle"/ {self->rin = 1;}
pid$target::kslgetl:return  /execname == "oracle" && self->rin > 0 / 
{@[pid, ustack(5, 0)] = count(); stop(); exit(0);}
' -p 3456 

  -- Blocker SID = 123 --
  oracle`kslgetl+0x185
  oracle`kkdlpExecSql+0x20c
  oracle`kkdlpftld+0x147
  oracle`qerfxFetch+0x125f
  oracle`opifch2+0x188b
  
$ > pstack 3456
 0000000001ec38f8 kqreqd () + d8
 00000000028ee50c kkdlpExecSql () + 20c
 000000000757a7f7 kkdlpftld () + 147
 000000000204467f qerfxFetch () + 125f
 0000000001ee765b opifch2 () + 188b  


SQL (123) > exec nls_select(1);

// one can also use:
// dtrace -w -n 'pid$target::kqrLockAndPinPo:entry {@[pid, ustack(5, 0)] = count(); stop(); exit(0);}' -p 3456 
In a second session, run the same statement. It will be blocked, and pstack prints out its requesting code path.

SQL (789) > exec nls_select(1);

$ > pstack 5678

  -- Waiter SID = 789 --
  fffffd7ffc9d3e3b semsys   (2, 1000001f, fffffd7fffdf0af8, 1, 124a)
  0000000001ab90f5 sskgpwwait () + 1e5
  0000000001ab8c95 skgpwwait () + c5
  0000000001aaae69 kslges () + 5b9
  0000000001ebd12e kqrpre1 () + 72e
  00000000028ee49b kkdlpExecSql () + 19b
  000000000757a7f7 kkdlpftld () + 147
  000000000204467f qerfxFetch () + 125f
  0000000001ee765b opifch2 () + 188b


select sid, event, p1text, p1, p1raw, p2text, p2, p2raw, p3text, p3, p3raw, blocking_session, final_blocking_session
 from v$session s where sid in (123, 789);
 
   SID EVENT                        P1TEXT             P1 P1RAW            P2TEXT   P2 P2RAW            P3TEXT  P3 P3RAW BLOCKING_SESSION FINAL_BLOCKING_SESSION
  ---- ---------------------------- ---------- ---------- ---------------- ------ ---- ---------------- ------ --- ----- ---------------- ----------------------
   123 SQL*Net message from client  driver id  1413697536 0000000054435000 #bytes    1 0000000000000001          0 00                                       
   789 latch: row cache objects     address    6376016176 000000017C0A4930 number  411 000000000000019B tries    0 00                   5                      5
 
select * from v$latchholder;
select * from v$session_blockers where sid in (123, 789);
select * from v$session_wait where sid in (123, 789);
select * from v$session_wait_history where sid in (123, 789) order by seq# desc, sid;


5. rowcache Gets vs. latch Gets


For each rowcache GET, it requires 3 "latch: row cache objects" GETs as revealed by Book: Oracle Core: Essential Internals for DBAs and Developers (Page 167).

With following dtrace, we can see the code path and call count. All of them stem from kkdl (dictionary lookup) subroutines.

As demonstrated at the Blog's beginning, 'dc_props' contains 60 rows, 1000 runs will result in 60'000 rowcache Gets, and 180'000 latch Gets. Interestingly the output shows that 60 'dc_props' rowcache rows seems splitted into two Buckets (kkdlpftld+0x147 and kkdlpftld+0x351), each with 30 rows.

SQL > exec nls_select(1000);

sudo dtrace -n \
'pid$target::kqreqd:entry  /execname == "oracle"/ {self->rin = 1;}
pid$target::kslgetl:entry  /execname == "oracle"/ {self->lin = 1;}
pid$target::kqreqd:return  /self->rin > 0/ {@ROWCO_CNT[ustack(6, 0)] = count(); self->rin = 0;}
pid$target::kslgetl:return /self->lin > 0/ {@LATCH_CNT[ustack(6, 0)] = count(); self->lin = 0;}  
' -p 7482 

//---- rowcache Gets ----
    oracle`kqreqd+0x359        // row cache ...
    a.out`kkdlpftld+0x351      // dictionary lookup ...
    a.out`qerfxFetch+0x125f    // fixed table Fetch
    oracle`opifch2+0x188b      // fetch main routine
    oracle`opiefn0+0x1f7       // initialize opi
    oracle`opipls+0x352c
  30000
  
    oracle`kqreqd+0x359
    a.out`kkdlpftld+0x147
    a.out`qerfxFetch+0x125f
    oracle`opifch2+0x188b
    oracle`opiefn0+0x1f7
    oracle`opipls+0x352c
  30000
  

//------- latch Gets -------  
    oracle`kslgetl+0x185         // get latch
    a.out`kkdlpExecSql+0x19b
    a.out`kkdlpftld+0x351
    a.out`qerfxFetch+0x125f
    oracle`opifch2+0x188b
    oracle`opiefn0+0x1f7
  30000
  
    oracle`kslgetl+0x185
    a.out`kkdlpExecSql+0x19b
    a.out`kkdlpftld+0x147
    a.out`qerfxFetch+0x125f
    oracle`opifch2+0x188b
    oracle`opiefn0+0x1f7
  30000
  
    oracle`kslgetl+0x185
    a.out`kkdlpExecSql+0x20c
    a.out`kkdlpftld+0x351
    a.out`qerfxFetch+0x125f
    oracle`opifch2+0x188b
    oracle`opiefn0+0x1f7
  60000
  
    oracle`kslgetl+0x185
    a.out`kkdlpExecSql+0x20c
    a.out`kkdlpftld+0x147
    a.out`qerfxFetch+0x125f
    oracle`opifch2+0x188b
    oracle`opiefn0+0x1f7
  60000
Following documents have a deep investigation of Latches and Mutexes:
  New features of Latches and Mutexes in Oracle 12c.
  Latch, mutex and beyond
  Latch, mutex and beyond(Dtrace)
  Oracle 12 and latches
  Oracle 12 and latches, part 2
The kslgetl (get the exclusive latch) and ksl_get_shared_latch functions take the following arguments:
  1-latch address
  2-immediate get (0 means yes, 1 means no)
  3-where (X$KSLLW.INDX)
  4-why   (X$KSLWSC.INDX)
  5-mode (8=shared,16=exclusive; only for ksl_get_shared_latch function)
kslgetl() performs:
  – sskgslgf (immediate latch get)
  – kslges (kernel service latch get spinning, wait latch get)
  — kskthbwt
  — kslwlmod (setup wait list)
  — sskgslgf (immediate latch get)
  — skgpwwait (sleep latch get)
  — semop

6. row cache objects Queries


When there are contentions on 'latch: row cache objects', the instant and historical associated dc objects can be found by:

select c.addr, c.latch#, c.child#, c.name, c.gets latch_gets, c.misses, c.sleeps, c.spin_gets, c.wait_time, c.gets/(nullif(r.gets, 0)) ratio
      ,r.cache#, r.type, r.parameter, r.count, r.gets rowcache_gets, r.getmisses
      ,s.sid, s.serial#, program, s.user#, s.username, s.sql_id, s.row_wait_obj#
      ,(select owner||'.'||object_name from dba_objects where object_id = s.row_wait_obj#) object_name
      ,s.event, s.p1text, s.p1, s.p1raw, s.p2text, s.p2, s.p2raw, s.p3text, s.p3, s.p3raw
      ,(select  owner || '.' || object_name
              || case when procedure_name is not null then '.' || procedure_name end
         from dba_procedures
        where     object_id = s.plsql_entry_object_id and subprogram_id = s.plsql_entry_subprogram_id)
         plsql_entry
      ,(select   owner || '.'|| object_name
              || case when procedure_name is not null then  '.' || procedure_name end
         from dba_procedures
        where  object_id = s.plsql_object_id and subprogram_id = s.plsql_subprogram_id)
         plsql   
      ,(select dbms_lob.substr (sql_text, 50, 1) from dba_hist_sqltext where sql_id = s.sql_id and rownum = 1)
       sql_txt   
from v$session s, v$latch_children c, x$kqrst x, v$rowcache r
where (s.event = 'latch: row cache objects' or s.p2 = c.latch#)
  and s.p1raw = c.addr 
  and c.child# = x.kqrstcln
  and x.kqrstcid = r.cache#
  and c.name = 'row cache objects' 
--  and r.parameter = 'dc_props' and c.child# = 18
order by sid; 
  
with sq as (select /*+ materialize */ * from v$active_session_history where sample_time > sysdate - 10/1440)  -- last 10 minutes
select /*+ leading(sq) */
      c.addr, c.latch#, c.child#, c.name, c.gets latch_gets, c.misses, c.sleeps, c.spin_gets, c.wait_time, c.gets/(nullif(r.gets, 0)) ratio
      ,r.cache#, r.type, r.parameter, r.count, r.gets rowcache_gets, r.getmisses
      ,s.sample_time, s.session_id, s.session_serial#, program, s.user_id, s.sql_id, s.current_obj#
      ,(select owner||'.'||object_name from dba_objects where object_id = s.current_obj#) object_name
      ,s.event, s.p1text, s.p1, to_char(s.p1, 'XXXXXXXXXXXXXXXXXXXX') p1raw
      ,s.p2text, s.p2, to_char(s.p2, 'XXXXXXXXXXXXXXXXXXXX') p2raw 
      ,s.p3text, s.p3, to_char(s.p3, 'XXXXXXXXXXXXXXXXXXXX') p3raw
      ,(select  owner || '.' || object_name
              || case when procedure_name is not null then '.' || procedure_name end
         from dba_procedures
        where     object_id = s.plsql_entry_object_id and subprogram_id = s.plsql_entry_subprogram_id)
         plsql_entry
      ,(select   owner || '.'|| object_name
              || case when procedure_name is not null then  '.' || procedure_name end
         from dba_procedures
        where  object_id = s.plsql_object_id and subprogram_id = s.plsql_subprogram_id)
         plsql   
      ,(select dbms_lob.substr (sql_text, 50, 1) from dba_hist_sqltext where sql_id = s.sql_id and rownum = 1)
       sql_txt   
from sq s, v$latch_children c, x$kqrst x, v$rowcache r
where (s.event = 'latch: row cache objects' or s.p2 = c.latch#)
  and c.addr like '%'||(trim(to_char(p1, 'XXXXXXXXXXXXXXXXXXXX')))||'%'  
  and c.child# = x.kqrstcln
  and x.kqrstcid = r.cache#
  and c.name = 'row cache objects' 
--  and r.parameter = 'dc_props' and c.child# = 18
order by s.sample_time desc, s.session_id, s.session_serial#; 
Here two respective queries in short of access to x$kqrst. Then map CHILD# to dc CACHE# with a mapping table (created from a test DB of same Oracle Version by the query at the beginning of Blog).

select c.addr, c.latch#, c.child#, c.name, c.gets latch_gets, c.misses, c.sleeps, c.spin_gets, c.wait_time
      ,s.sid, s.serial#, program, s.user#, s.username, s.sql_id, s.row_wait_obj#
      ,(select owner||'.'||object_name from dba_objects where object_id = s.row_wait_obj#) object_name
      ,s.event, s.p1text, s.p1, s.p1raw, s.p2text, s.p2, s.p2raw, s.p3text, s.p3, s.p3raw
      ,(select  owner || '.' || object_name
              || case when procedure_name is not null then '.' || procedure_name end
         from dba_procedures
        where     object_id = s.plsql_entry_object_id and subprogram_id = s.plsql_entry_subprogram_id)
         plsql_entry
      ,(select   owner || '.'|| object_name
              || case when procedure_name is not null then  '.' || procedure_name end
         from dba_procedures
        where  object_id = s.plsql_object_id and subprogram_id = s.plsql_subprogram_id)
         plsql   
      ,(select dbms_lob.substr (sql_text, 50, 1) from dba_hist_sqltext where sql_id = s.sql_id and rownum = 1)
       sql_txt   
from v$session s, v$latch_children c
where (s.event = 'latch: row cache objects' or s.p2 = c.latch#)
  and s.p1raw = c.addr 
  and c.name = 'row cache objects'
--  and c.child# = 18
order by sid; 
  
with sq as (select /*+ materialize */ * from v$active_session_history where sample_time > sysdate - 10/1440)  -- last 10 minutes
select /*+ leading(sq) */
      c.addr, c.latch#, c.child#, c.name, c.gets latch_gets, c.misses, c.sleeps, c.spin_gets, c.wait_time
      ,s.sample_time, s.session_id, s.session_serial#, program, s.user_id, s.sql_id, s.current_obj#
      ,(select owner||'.'||object_name from dba_objects where object_id = s.current_obj#) object_name
      ,s.event, s.p1text, s.p1, to_char(s.p1, 'XXXXXXXXXXXXXXXXXXXX') p1raw
      ,s.p2text, s.p2, to_char(s.p2, 'XXXXXXXXXXXXXXXXXXXX') p2raw 
      ,s.p3text, s.p3, to_char(s.p3, 'XXXXXXXXXXXXXXXXXXXX') p3raw
      ,(select  owner || '.' || object_name
              || case when procedure_name is not null then '.' || procedure_name end
         from dba_procedures
        where     object_id = s.plsql_entry_object_id and subprogram_id = s.plsql_entry_subprogram_id)
         plsql_entry
      ,(select   owner || '.'|| object_name
              || case when procedure_name is not null then  '.' || procedure_name end
         from dba_procedures
        where  object_id = s.plsql_object_id and subprogram_id = s.plsql_subprogram_id)
         plsql   
      ,(select dbms_lob.substr (sql_text, 50, 1) from dba_hist_sqltext where sql_id = s.sql_id and rownum = 1)
       sql_txt   
from sq s, v$latch_children c
where (s.event = 'latch: row cache objects' or s.p2 = c.latch#)
  and c.addr like '%'||(trim(to_char(p1, 'XXXXXXXXXXXXXXXXXXXX')))||'%'  
  and c.name = 'row cache objects' 
--  and c.child# = 18
order by s.sample_time desc, s.session_id, s.session_serial#; 


LATCH_CHILD  CACHE# PARAMETER (Oracle Version 12.1.0.2.0)
----------- ------- -------------------------------------
          1       3 dc_rollback_segments
          2       1 dc_free_extents
          3       4 dc_used_extents
          4       2 dc_segments
          5       0 dc_tablespaces
          6       5 dc_tablespace_quotas
          7       6 dc_files
          8       7 dc_users
          8      10 dc_users
          9       8 dc_object_grants
          9       8 dc_objects
         10      17 dc_global_oids
         11      12 dc_constraints
         12      13 dc_sequences
         13      16 dc_histogram_data
         13      16 dc_histogram_defs
         14      54 dc_sql_prs_errors
         15      32 kqlsubheap_object
         16      19 dc_partition_scns
         16      19 dc_table_scns
         17      18 dc_outlines
         18      15 dc_props
         19      14 dc_profiles
       ....      ....


7. Test Code



create or replace procedure nls_select(p_cnt number) as
            l_val VARCHAR2 (256 Byte);
begin
for i in 1..p_cnt loop
  select value into l_val from nls_database_parameters where parameter = 'NLS_CHARACTERSET';
end loop;
end;
/

create or replace procedure nls_select_jobs(p_job_cnt number, p_cnt number) as
  l_job_id pls_integer;
begin
  for i in 1.. p_job_cnt loop
    dbms_job.submit(l_job_id, 'begin while true loop nls_select('||p_cnt||'); end loop; end;');
  end loop;
  commit;
end;    
/

create or replace procedure clean_jobs as
begin
  for c in (select job from dba_jobs) loop
    begin
       dbms_job.remove (c.job);
    exception when others then null;
    end;
    commit;
  end loop;

  for c in (select d.job, d.sid, (select serial# from v$session where sid = d.sid) ser 
              from dba_jobs_running d) loop
    begin
      execute immediate
             'alter system kill session '''|| c.sid|| ',' || c.ser|| ''' immediate';
      dbms_job.remove (c.job);
    exception when others then null;
    end;
    commit;
  end loop;
  
  -- select * from dba_jobs;
  -- select * from dba_jobs_running;
end;
/

-- exec nls_select_jobs(2, 1e9);
-- exec clean_jobs; -- stop all jobs

v$database select and control file sequential read

V$DATABASE is one single row view, displaying information about the database from the control file. Its content is a direct mapping of control files without intermediate cache area. Each query on v$database is translated as a few physical I/O reads.

Note: all tests are done in Oracle 12.1.0.2.0.


1. control file sequential read Watching


Run query and trace by Event 10046:

SQL (sid 35) > select name from v$database;

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        2      0.00       0.00          0          0          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.00          0          0          0           1

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  MERGE JOIN CARTESIAN (cr=0 pr=0 pw=0 time=311 us cost=0 size=12 card=1)
      1   FIXED TABLE FULL X$KCCDI (cr=0 pr=0 pw=0 time=176 us cost=0 size=12 card=1)
      1   BUFFER SORT (cr=0 pr=0 pw=0 time=134 us cost=0 size=0 card=1)
      1    FIXED TABLE FULL X$KCCDI2 (cr=0 pr=0 pw=0 time=121 us cost=0 size=0 card=1)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  control file sequential read                    7        0.00          0.00
********************************************************************************

We can see that each name query on v$database triggers 7 control file sequential read. The similar statistics can be observed by:

select * from v$session_event where event = 'control file sequential read' and sid = 35; 
select * from v$system_event  where event = 'control file sequential read';

Run the same query again and truss unix process:

SQL (sid 35) > select name from v$database;

oracle@testdb $ truss -t pread -p 4326
  pread(257, "15C2\0\001\0\0\0\0\0\0\0".., 16384, 16384) = 16384
  pread(257, "15C2\0\007\0\0\08A141D\0".., 16384, 114688) = 16384
  pread(257, "15C2\0\0\t\0\0\08A141D\0".., 16384, 147456) = 16384
  pread(257, "15C2\0\001\0\0\0\0\0\0\0".., 16384, 16384) = 16384
  pread(257, "15C2\0\007\0\0\08A141D\0".., 16384, 114688) = 16384
  pread(257, "15C2\0\0\t\0\0\08A141D\0".., 16384, 147456) = 16384
  pread(257, "15C2\0\08004\0\08A141D\0".., 16384, 0x01200000) = 16384

oracle@testdb $ pfiles 4326
  257: S_IFREG mode:0640 dev:181,65553 ino:4300 uid:100 gid:101 size:24264704
       O_RDWR|O_DSYNC|O_LARGEFILE FD_CLOEXEC
       advisory write lock set by process 16900
       /oratestdb/oradata/testdb/control01.ctl
  
-- where 4326 is pid of Oracle sid 35, 257 is fd of first control file.

Monitoring the same query by dtrace:

oracle@testdb $ sudo dtrace -n 'pid$target::_pread:entry {@[arg0, ustack(12, 0)] = count();}' -p 4326
  257
libc.so.1`_pread               libc.so.1`_pread                 libc.so.1`_pread                 
libc.so.1`pread+0x85           libc.so.1`pread+0x85             libc.so.1`pread+0x85          
oracle`skgfqio+0x284           oracle`skgfqio+0x284             oracle`skgfqio+0x284          
oracle`ksfd_skgfqio+0x195      oracle`ksfd_skgfqio+0x195        oracle`ksfd_skgfqio+0x195     
oracle`ksfd_io+0x2e79          oracle`ksfd_io+0x2e79            oracle`ksfd_io+0x2e79         
oracle`ksfdread+0x746          oracle`ksfdread+0x746            oracle`ksfdread+0x746         
a.out`kccrhd+0x208             a.out`kccrbp+0x279               a.out`kccrbp+0x279            
a.out`kccgft_refresh_hdr+0x68  a.out`kccsed_rbl+0x1dc           a.out`kccsed_rbl+0xfc         
a.out`kccgftcs+0x2a2           a.out`kccgft_refresh_hdr+0x141   a.out`kccgft_refresh_hdr+0x141
a.out`kccxdi+0x8d              a.out`kccgftcs+0x2a2             a.out`kccgftcs+0x2a2          
a.out`qerfxFetch+0x5df         a.out`kccxdi+0x8d                a.out`kccxdi+0x8d             
a.out`rwsfcd+0x6f              a.out`qerfxFetch+0x5df           a.out`qerfxFetch+0x5df        

libc.so.1`_pread               libc.so.1`_pread                  
libc.so.1`pread+0x85           libc.so.1`pread+0x85           
oracle`skgfqio+0x284           oracle`skgfqio+0x284           
oracle`ksfd_skgfqio+0x195      oracle`ksfd_skgfqio+0x195      
oracle`ksfd_io+0x2e79          oracle`ksfd_io+0x2e79          
oracle`ksfdread+0x746          oracle`ksfdread+0x746          
a.out`kccrhd+0x208             a.out`kccrbp+0x279             
a.out`kccgft_refresh_hdr+0x68  a.out`kccrec_rbl+0x1c2         
a.out`kccgftcs+0x2a2           a.out`kccrec_read_write+0x19b  
a.out`kccxdi2+0x8c             a.out`kccgftcs+0x36a           
a.out`qerfxFetch+0x5df         a.out`kccxdi2+0x8c             
a.out`qersoProcessULS+0x26f    a.out`qerfxFetch+0x5df         

libc.so.1`_pread               libc.so.1`_pread
libc.so.1`pread+0x85           libc.so.1`pread+0x85
oracle`skgfqio+0x284           oracle`skgfqio+0x284
oracle`ksfd_skgfqio+0x195      oracle`ksfd_skgfqio+0x195
oracle`ksfd_io+0x2e79          oracle`ksfd_io+0x2e79
oracle`ksfdread+0x746          oracle`ksfdread+0x746
a.out`kccrbp+0x279             a.out`kccrbp+0x279
a.out`kccsed_rbl+0x1dc         a.out`kccsed_rbl+0xfc
a.out`kccgft_refresh_hdr+0x141 a.out`kccgft_refresh_hdr+0x141
a.out`kccgftcs+0x2a2           a.out`kccgftcs+0x2a2
a.out`kccxdi2+0x8c             a.out`kccxdi2+0x8c
a.out`qerfxFetch+0x5df         a.out`qerfxFetch+0x5df     

The above output shows all 7 I/O reads of first control file (fd: 257), among which, there are 2 Calls of subroutine "kccrhd", and 5 Calls of subroutine"kccrbp".

The xplan in Event 10046 trace contains two different row sources: "X$KCCDI" and "X$KCCDI2", Dtrace shows the respective Calls; 3 "kccxdi", and 4 "kccxdi2".

All are finalized by function "ksfdread", which probably denotes file direct read.

Since each select on v$database is implemented by a few disk I/O Reads (7 in above example, 14 if select all columns), concurrently accesses can entail severe wait event on control file sequential read, which often appears as one of AWR Top Wait Events.


2. Other control file related Objects


There are a few control files based views, which can be listed by:

select * from v$fixed_view_definition where lower(view_definition) like '%x$kcc%'; 

for example, gv$archive, v$block_change_tracking, gv$deleted_object, v$tablespace. Any access to them will lead to similar effect as v$database.

As a test, run query below, the session event shows "control file sequential read" since v$tablespace is defined on X$KCCTS and xplan rowsource accesses X$KCCTS by FIXED TABLE FULL:

with sq as (select level from dual connect by level <= 1e6)
select /*+ leading(s) use_nl(tbs) */ count(*) from sq s, v$tablespace tbs;

-------------------------------------------------------------------------------------------
| Id  | Operation                       | Name    | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                |         |     1 |     7 |     2   (0)| 00:00:01 |
|   1 |  SORT AGGREGATE                 |         |     1 |     7 |            |          |
|   2 |   NESTED LOOPS                  |         |  1557 | 10899 |     2   (0)| 00:00:01 |
|   3 |    VIEW                         |         |     1 |       |     2   (0)| 00:00:01 |
|*  4 |     CONNECT BY WITHOUT FILTERING|         |       |       |            |          |
|   5 |      FAST DUAL                  |         |     1 |       |     2   (0)| 00:00:01 |
|*  6 |    FIXED TABLE FULL             | X$KCCTS |  1557 | 10899 |     0   (0)| 00:00:01 |
-------------------------------------------------------------------------------------------
There are also indirect control file dependent objects, for example,
  dba_scheduler_jobs
  dba_scheduler_running_jobs
whose definitions containing v$database. They can be listed by:

  select * from dba_dependencies where referenced_name = 'V$DATABASE';

Further more, there are also Oracle applications, which is using v$database, for example, MMON Slave Process.


3. Control File Size


Two queries can be used to display Control File size, and details per section.

  select v.*, round(block_size*file_size_blks/1024/1024, 2) MB from v$controlfile v;
  select v.*, round(record_size*records_total/1024/1024, 2) MB from v$controlfile_record_section v order by MB desc;
  
  select * from v$parameter where name = 'control_file_record_keep_time';
The size depends on the retention days, specified by 'control_file_record_keep_time', which is 7 in default.

Monday, July 10, 2017

Getting Oracle Transaction Commit SCN

This Blog demonstrates one approach to get exact Commit SCN and compare it with other methods. It has not only (Oracle) academic interest, but also practical demand, for example, data replication (The COMMIT SCN - an undocumented feature).

Note: all tests are done in Oracle 12.1.0.2.0.


1. Setup



drop table test_tab;
drop table commitscn_gtt;
create table test_tab(id number, sid number);

create global temporary table commitscn_gtt(dummy)
on commit preserve rows
as select -1 from dual;

create or replace procedure push_commitscn as
begin
  delete from commitscn_gtt;
  insert into commitscn_gtt (dummy) values (-1);
end;
/

create or replace function get_commitscn return number as
 l_commitscn number;
begin
  select ora_rowscn into l_commitscn from commitscn_gtt where rownum=1;
  return l_commitscn;
end;
/


2. Test



insert into test_tab (id, sid) values (1, sys.dbms_support.mysid);

-- run immediately before commit
exec push_commitscn;

commit;

set numformat 999,999,999,999,999

-- get exact commitscn after commit
select get_commitscn from dual;

       GET_COMMITSCN
--------------------
   9,183,757,165,446


3. Comparing with Other Approaches


Test below comprises 5 different commit scn getting methods.

drop table test_tab2;
create table test_tab2(id number, sid number, scn number) rowdependencies;
insert into test_tab2 (id, sid, scn) values (1, sys.dbms_support.mysid, userenv('commitscn'));
exec push_commitscn;
commit;

set numformat 999,999,999,999,999

select scn from test_tab2 where id = 1;
                 SCN
--------------------
   9,183,757,165,468
   
select ora_rowscn from test_tab2 where id = 1;
          ORA_ROWSCN
--------------------
   9,183,757,165,469
   
select get_commitscn from dual;
       GET_COMMITSCN
--------------------
   9,183,757,165,469

select dbms_flashback.get_system_change_number from dual;
GET_SYSTEM_CHANGE_NUMBER
------------------------
   9,183,757,165,471
       
select current_scn from v$database;
         CURRENT_SCN
--------------------
   9,183,757,165,472

Let's look their differences.


Method 1. USERENV('COMMITSCN')

select scn from test_tab2 where id = 1;
→ USERENV('COMMITSCN') is the actual COMMIT SCN minus 1, i.e immediately scn before commit.
    Each commit creates 1 new number (for commit Record).
→ Undocumented
→ 12c USERENV deprecated


Method 2. ORA_ROWSCN

select ora_rowscn from test_tab2 where id = 1;
→ Oracle Database SQL Language Reference - ORA_ROWSCN Pseudocolumn said:
    Whether at the block level or at the row level, the ORA_ROWSCN should not be considered to be an exact SCN.
    If a block is queried twice, then it is possible for the value of ORA_ROWSCN to change between the queries
    even though rows have not been updated in the time between the queries. The only guarantee is that the value of
    ORA_ROWSCN in both queries is greater than the commit SCN of the transaction that last modified that row.
   (Note: "greater than" seems an Oracle Document error. It should be "not less than")

    So ORA_ROWSCN is not deterministic because returned scn also depends on query start scn
    due to preious discussed Delayed Block Cleanout.
    Hence it can decrease even there are not any user updates on the selected table.

    It can increase if there are any committed updates between two queries as demonstrated in
    How can ORA_ROWSCN change between queries when no update? at Jul 8, 2017 9:20 PM.
→ For each row, ORA_ROWSCN returns the conservative upper bound SCN of the most recent change to the row.
    For example, "delayed block cleanout".
→ It increases the size of each row by 6 bytes.
→ Oracle BUG: INSERT to a Table With ROWDEPENDENCIES Failed With ORA-00600 [kdtgsph-row] (Doc ID 2210391.1)


Method 3. Commit SCN of this Blog

select get_commitscn from dual;
→ Exact commit SCN.
    Once a commit is executed, this single row (single block) is stamped with that commit SCN.
    Since the one-row GTT is session local, it can never be selected by other sessions
    and is hardly to imagine a "delayed block cleanout". Therefore it never be changed.


Method 4. System functions

select dbms_flashback.get_system_change_number from dual;

select current_scn from v$database;
→ Upper bound system change number (SCN), not precise.


4. Commit SCN exposed


Blog: PL/SQL Function Result Cache Invalidation observed that commit accomplishes invalidating Result Cache before returns, and interpreted:

    The above Stack Trace shows that when a transaction user session calls commit command,
    commit takes a detour to visit Result Cache along its code path in order to perform
    the invalidation before publishing the confirmed and consistent news to the world.

The following test will demonstrate that Commit SCN is exposed into V$RESULT_CACHE_OBJECTS.SCN during Result Cache Invalidation.

drop table rc_tab;
create table rc_tab (id number, val number);
insert into rc_tab select level, level*10 from dual connect by level <= 3;
commit;

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 .. 3 loop
    l_val := get_val(i);
  end loop;
end;
/

exec dbms_result_cache.flush;

exec run_test;

column name format a13

select id, type, status, name, namespace, creation_timestamp, scn
  from v$result_cache_objects ro
order by scn desc, type, id;

ID TYPE       STATUS    NAME          NAMESPACE  CREATION_TIMESTAMP                    SCN
-- ---------- --------- ------------- ---------- -------------------- --------------------
 0 Dependency Published K.GET_VAL                2017*JUL*12 07:06:43    9,198,309,753,651
 2 Dependency Published K.RC_TAB                 2017*JUL*12 07:06:43    9,198,309,753,651
 1 Result     Published "K"."GET_VAL" PLSQL      2017*JUL*12 07:06:43    9,198,309,753,651
 3 Result     Published "K"."GET_VAL" PLSQL      2017*JUL*12 07:06:43    9,198,309,753,651
 4 Result     Published "K"."GET_VAL" PLSQL      2017*JUL*12 07:06:43    9,198,309,753,651

update rc_tab set val = -2 where id = 2;

exec push_commitscn;

commit;

select get_commitscn from dual;

     GET_COMMITSCN
------------------
 9,198,309,753,654

select id, type, status, name, namespace, creation_timestamp, scn
  from v$result_cache_objects ro
order by scn desc, type, id;

ID TYPE       STATUS    NAME          NAMESPACE  CREATION_TIMESTAMP                    SCN
-- ---------- --------- ------------- ---------- -------------------- --------------------
 2 Dependency Published K.RC_TAB                 2017*JUL*12 07:06:43    9,198,309,753,654
 0 Dependency Published K.GET_VAL                2017*JUL*12 07:06:43    9,198,309,753,651
 1 Result     Invalid   "K"."GET_VAL" PLSQL      2017*JUL*12 07:06:43    9,198,309,753,651
 3 Result     Invalid   "K"."GET_VAL" PLSQL      2017*JUL*12 07:06:43    9,198,309,753,651
 4 Result     Invalid   "K"."GET_VAL" PLSQL      2017*JUL*12 07:06:43    9,198,309,753,651

The above test shows that Commit SCN:
    9,198,309,753,654
is exposed in V$RESULT_CACHE_OBJECTS.SCN as invalidation SCN.

Oracle 12c Database Reference said about V$RESULT_CACHE_OBJECTS.SCN:
    Build SCN (TYPE = Result) or invalidation SCN (TYPE = Dependency)

There are also a few Oracle Tables/Views containing "commitscn" or "commit_scn" columns, which could point to its usage.