Optimized index maintenance in DML
This post is about how amount and type of work during DML can depends on child steps in an execution plan.
Introduction
Oracle has optimized (this is just my term) index maintenance mechanism used in some kind of DMLs. I call it “optimized” because in this case Oracle applies each change to an index as array of keys. It is also the reason why you may encounter that a session executing the simplest statement like this
delete from t where col = :val
can wait “direct path write temp” / “direct path read temp” because the statement has active workareas not fit into the memory.
Details are below in section “How it works”.
Described optimized index maintenance is performed in:
1. Direct-path insert.
2. Delete / Update / Merge if access path to the data is via b-tree Index Range Scan or Index Full Scan.
The first point is better known. When data inserting is finished durnig direct-path insert index maintenance is peformed. But there is no (or almost no) information about the same process during Update/Delete and conditions when it can be performed.
Read more…
Dynamic tracing of Oracle logical I/O
I would like to provide one more option to investigate Oracle logical I/O with DTrace.
This method allows to see each consistent/current gets with details about block, object and location from which function is called.
This is the DTrace script: dtracelio.d
Short description:
This tool allows to see:
– details of each call (consistent/current get)
– details of blocks been read
– function from which call been performed without investigating of call stack (“where”)
– aggregation of performed calls
The tool can be especially helpful in 11g because x$kcbuwhy (x$kcbsw in 10g) is not populated properly there.
Note: Examples of using views x$kcbsw/x$kcbuwhy:
- Investigating Logical I/O by Jonathan Lewis
- Finding the reasons for excessive logical IOs by Tanel Poder
Current version of the script monitors execution of two Kernel Cache Layer functions:
kcbgtcr – Kernel Cache Buffer Get Consistent Read. Number of calls of this function we can see as statistic “consistent gets” and in 10046 trace as “cr=”.
kcbgcur – Kernel Cache Buffer Get Current Read. Number of calls of this function we can see as statistic “db block gets” in 10046 trace as “cu=”.
upd:
statistic “db block gets” is incremented not only by kcbgcur, but also by kcbget (included in current version of dtracelio.d), kcbnew (coming soon), and some others. But kcbgcur is most often used.
In the both functions:
- the first argument is a pointer on the structure which describes a block;
- the second argument is unknown, but I could suggest that this is lock_mode (from MOS bug 7109078);
- the third argument (the least significant bits) is “where” (x$kcbwh), that is a module where the function is called.
Usage:
dtracelio.d PID [show_each_call]
PID – unix process ID
show_each_call – if 0 then output of each call will be disabled, else details of each call will be shown
A little example of usage. Let’s try to see what is going on during select on very small table:
SQL> @spid
SID ORACLE_DEDICATED_PROCESS CLIENTPID
---------- ------------------------ ------------------------
41 18949 900:408
SQL> create table dualcopy as select * from dual;
Table created
SQL> select * from dualcopy;
DUMMY
-----
X
Notice, that I have executed “select * from dualcopy” to avoid hard parsing in consequences executions.
Let’s execute dtracelio
dtracelio.d 18949
I have executed the script with default parameter show_each_call, it means that details of each calls will be shown.
Now I am executing our query:
SQL> select * from dualcopy; DUMMY ----- X
And this is an output of dtracelio
kcbgtcr(0xFFFFFD7FFFDFB0F0,0,742,0) [tsn: 4 rdba: 0x100060a (4/1546) obj: 79218 dobj: 79218] where: 742 kcbgtcr(0xFFFFFD7FFFDFAED0,0,743,0) [tsn: 4 rdba: 0x100060a (4/1546) obj: 79218 dobj: 79218] where: 743 kcbgtcr(0xFFFFFD7FFDC3B2E0,0,860,0) [tsn: 4 rdba: 0x100060b (4/1547) obj: 79218 dobj: 79218] where: 860
You can see here:
kcbgtcr(0xFFFFFD7FFFDFB0F0,0,742,0) – it is function call with 3 arguments,
tsn: 4 – a tablespace number, ts# from v$tablespace
rdba: 0x100060a – a relative dba (data block address)
(4/1546) – file 4 block 1546
obj: 79218 – dictionary object number, object_id from dba_objects
dobj: 79218 – data object number, data_object_id from dba_objects
where: 742 – location from function (kcbgtcr in this case) was executed. This is INDX from x$kcbwf.
SQL> select indx, kcbwhdes from x$kcbwh where indx in (742, 743, 860);
INDX KCBWHDES
---------- ----------------------------------------------------------------
742 ktewh25: kteinicnt
743 ktewh26: kteinpscan
860 kdswh01: kdstgr
It is functions from which our function kcbgtcr was executed. It is exactly parent function which you will see if will print call stack during the call of kcbgtcr.
If you would print call stack you will see (I’ve just added ustack() in the script):
kcbgtcr(0xFFFFFD7FFFDFB0F0,0,742,0) [tsn: 4 rdba: 0x100060a (4/1546) obj: 79218 dobj: 79218] where: 742
oracle`kcbgtcr
oracle`ktecgshx+0x3f6
oracle`kteinicnt1+0x1cf
oracle`qertbFetch+0xc2a
oracle`opifch2+0xaa2
oracle`opifch+0x3a
oracle`opiodr+0x433
oracle`ttcpip+0x599
oracle`opitsk+0x600
oracle`opiino+0x675
oracle`opiodr+0x433
oracle`opidrv+0x32e
oracle`sou2o+0x57
oracle`opimai_real+0x219
oracle`ssthrdmain+0x14e
oracle`main+0xcb
oracle`0x159e67c
kcbgtcr(0xFFFFFD7FFFDFAED0,0,743,0) [tsn: 4 rdba: 0x100060a (4/1546) obj: 79218 dobj: 79218] where: 743
oracle`kcbgtcr
oracle`ktecgshx+0x3f6
oracle`kteinpscan+0x1b6
oracle`kteiniscan+0x2c
oracle`kdselini+0x2f
oracle`kdsirs1+0x792
oracle`kdsirs+0x2b
oracle`qertbFetch+0xbb0
oracle`opifch2+0xaa2
oracle`opifch+0x3a
oracle`opiodr+0x433
oracle`ttcpip+0x599
oracle`opitsk+0x600
oracle`opiino+0x675
oracle`opiodr+0x433
oracle`opidrv+0x32e
oracle`sou2o+0x57
oracle`opimai_real+0x219
oracle`ssthrdmain+0x14e
oracle`main+0xcb
kcbgtcr(0xFFFFFD7FFDC3B2E0,0,860,0) [tsn: 4 rdba: 0x100060b (4/1547) obj: 79218 dobj: 79218] where: 860
oracle`kcbgtcr
oracle`ktrget2+0x27d
oracle`kdstgr+0x46b
oracle`qertbFetch+0x466
oracle`opifch2+0xaa2
oracle`opifch+0x3a
oracle`opiodr+0x433
oracle`ttcpip+0x599
oracle`opitsk+0x600
oracle`opiino+0x675
oracle`opiodr+0x433
oracle`opidrv+0x32e
oracle`sou2o+0x57
oracle`opimai_real+0x219
oracle`ssthrdmain+0x14e
oracle`main+0xcb
oracle`0x159e67c
So, 3 consistent gets, 3 logical reads were performed.
Two times block (4/1546) – this is segment header – has been read. The first time from function kteinicnt and the second time from function kteinpscan.
And the third get is block (4/1547) – this is data block – was read from function kdstgr.
After that, if you push Ctrl+C, dtracelio script will be finished, and you will see Summary section:
^C ========================= Summary ========================== object_id data_object_id function where count 79218 79218 kcbgtcr 742 1 79218 79218 kcbgtcr 743 1 79218 79218 kcbgtcr 860 1
Summary section is aggregation of all calls grouped by object_id, data_object_id, function, where.
example 2
There was question on sql.ru. The author asked “why number of current gets (db block gets) during update in distributed transaction is more then in usual, non-distributed transaction?”.
In his case it were:
3070178 current gets in non-distributed transaction
6070211 current gets in distributed transaction
So, let’s find out what exactly is read during distributed transaction and is not read in usual, non-distributed transaction.
SQL> select * from v$version;
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
PL/SQL Release 11.2.0.2.0 - Production
CORE 11.2.0.2.0 Production
TNS for Solaris: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production
SQL> @spid
SID ORACLE_DEDICATED_PROCESS CLIENTPID
---------- ------------------------ ------------------------
1 16727 900:408
SQL> create table test as select * from all_objects;
Table created
SQL> alter session set optimizer_dynamic_sampling=0;
Session altered
SQL> @10046
Session altered
Here we are executing dtracelio.d:
dtracelio.d 16727 0Here I have asked to show me only summary section of executions of functions performing logical I/O by process 16727.
1st update, without distributed transaction
SQL> begin 2 update test set owner = owner; 3 commit; 4 end; 5 / PL/SQL procedure successfully completed
After the update has been completed we can push Ctrl+C to finish the DTrace and see the Summary section:
^C ========================= Summary ========================== object_id data_object_id function where count ... 0 -1 kcbgcur 48 16 0 -1 kcbgcur 156 16 17 17 kcbgtcr 869 18 0 -1 kcbgcur 51 253 0 -1 kcbgcur 79 1365 79204 79204 kcbgcur 878 1656 0 -1 kcbgcur 50 2357 -1 79204 kcbgcur 859 2357 79204 79204 kcbgtcr 869 2726 79204 79204 kcbgcur 1053 75105
An excerpt from raw 10046 trace:
=====================
PARSING IN CURSOR #18446741324891442008 len=60 dep=0 uid=0 oct=47 lid=0 tim=229288260276 hv=2516922591 ad='88f557c0' sqlid='6sj578yb0ac6z'
begin
update test set owner = owner;
commit;
end;
END OF STMT
....
EXEC #18446741324891442008:c=2780000,e=4884618,p=0,cr=2776,cu=84545,mis=0,r=1,dep=0,og=1,plh=0,tim=229293144944
Pay attention, cu=84545.
Now let’s execute the same update within distributed transaction
SQL> declare 2 i integer; 3 begin 4 5 select count(*) into i from dual@dblink; 6 update test set owner = owner; 7 commit; 8 9 end; 10 /
PARSING IN CURSOR #18446741324891442008 len=122 dep=0 uid=0 oct=47 lid=0 tim=229346672450 hv=1954107067 ad='88f04bc0' sqlid='arss8t9u7kmpv' declare i integer; begin select count(*) into i from dual@dblink; update test set owner = owner; commit; end; END OF STMT ... EXEC #18446741324891442008:c=2950000,e=3432722,p=0,cr=2298,cu=159479,mis=0,r=1,dep=0,og=1,plh=0,tim=229350105247
As we can see cu=159479, about in two times more then in previous execution.
dtracelio.d output:
========================= Summary ========================== object_id data_object_id function where count ... 0 -1 kcbgcur 48 16 0 -1 kcbgcur 156 16 17 17 kcbgtcr 869 18 0 -1 kcbgcur 51 49 0 -1 kcbgcur 50 442 -1 79204 kcbgcur 859 442 0 -1 kcbgcur 79 1161 79204 79204 kcbgcur 878 1177 79204 79204 kcbgtcr 869 2248 79204 79204 kcbgcur 1053 75105 0 -1 kcbgcur 109 79853
Pay attention on the last row
0 -1 kcbgcur 109 79853
79853 additional db block gets of some undo block which does not exist in previous output.
If we take a look at the output of dtracelio.d with enabled output of each call we will see something like this:
... kcbgcur(0xFFFFFD7FFDC42D68,2,1053,0) [tsn: 0 rdba: 0x4186e6 (1/100070) obj: 79204 dobj: 79204] where: 1053 kcbgcur(0xFFFFFD7FFFDF46A0,1,109,0) [tsn: 2 rdba: 0xc000f0 (3/240) obj: 0 dobj: -1] where: 109 kcbgcur(0xFFFFFD7FFDC42D68,2,1053,0) [tsn: 0 rdba: 0x4186e6 (1/100070) obj: 79204 dobj: 79204] where: 1053 kcbgcur(0xFFFFFD7FFFDF46A0,1,109,0) [tsn: 2 rdba: 0xc000f0 (3/240) obj: 0 dobj: -1] where: 109 kcbgcur(0xFFFFFD7FFDC42D68,2,1053,0) [tsn: 0 rdba: 0x4186e6 (1/100070) obj: 79204 dobj: 79204] where: 1053 kcbgcur(0xFFFFFD7FFFDF46A0,1,109,0) [tsn: 2 rdba: 0xc000f0 (3/240) obj: 0 dobj: -1] where: 109 kcbgcur(0xFFFFFD7FFDC42D68,2,1053,0) [tsn: 0 rdba: 0x4186e6 (1/100070) obj: 79204 dobj: 79204] where: 1053 kcbgcur(0xFFFFFD7FFFDF46A0,1,109,0) [tsn: 2 rdba: 0xc000f0 (3/240) obj: 0 dobj: -1] where: 109 kcbgcur(0xFFFFFD7FFDC42D68,2,1053,0) [tsn: 0 rdba: 0x4186e6 (1/100070) obj: 79204 dobj: 79204] where: 1053 kcbgcur(0xFFFFFD7FFFDF46A0,1,109,0) [tsn: 2 rdba: 0xc000f0 (3/240) obj: 0 dobj: -1] where: 109 kcbgcur(0xFFFFFD7FFDC42D68,2,1053,0) [tsn: 0 rdba: 0x4186e6 (1/100070) obj: 79204 dobj: 79204] where: 1053 ...
Here we can see these additional calls “where: 109″ and that the same block (3/240) is read during these calls.
Here is only excerpt, but I checked, all 79853 calls for the same block from the same “where” (109 in this case).
Update: updated version of dtracelio.d allows to see that these current gets were performed in shared mode, so content of the block is not changed.
Let’s try to look at inside the block.
alter system dump datafile 3 block 240;
An excerpt from block dump:
... Block dump from disk: buffer tsn: 2 rdba: 0x00c000f0 (3/240) scn: 0x0000.0015240d seq: 0x02 flg: 0x04 tail: 0x240d2602 frmt: 0x02 chkval: 0x54dc type: 0x26=KTU SMU HEADER BLOCK ...So, this is the undo header.
What is “where: 109″? “Where” means location in code, let’s try to find function name with indx 109
SQL> select indx, kcbwhdes from x$kcbwh where indx = 109;
INDX KCBWHDES
---------- ----------------------------------------------------------------
109 ktuwh87: ktugus:ktuGetExtTxnInfo
It is exactly what you will see if print call stack during call with “where: 109″ (the second row, function from kcbgcur was called is ktuGetExtTxnInfo):
0000000002c63d01 kcbgcur () + 1 00000000029272d4 ktuGetExtTxnInfo () + 174 00000000028f5193 ktugti () + 13 00000000028e2561 ktuchg2 () + 1971 0000000002944d2f ktbchg2 () + 12f 0000000001b04809 kdu_array_flush_retry () + c69 0000000001b01f42 kdu_array_buf () + 522 0000000001af5390 kduurp () + 460 0000000001adea00 kdusru () + 13e0 0000000001ac6c12 kauupd () + 1b2 0000000005a3370c updrow () + a5c 0000000007b8bd27 qerupFetch () + 397 000000000367cfdc qerstFetch () + 58c 0000000005a3f2fe updaul () + 4ce 0000000005a4469d updThreePhaseExe () + 1cd 0000000005a43abd updexe () + 1ed 000000000447b2c5 opiexe () + 2455 ...
It were for 11.2.0.2. In my 10.2.0.5 all these additional calls are with “where: 383″, “ktuwh02: ktugus” which Jonathan Lewis called “Get Undo Segment header for commit” (Seems it is not correct descriptoin).
And following call stack is during these calls
oracle`kcbgcur
oracle`ktugusc+0x321
oracle`ktugti+0xf2
oracle`ktuchg+0x139a
oracle`ktbchg2+0x115
oracle`kddchg+0x2c2
oracle`kddlok+0x7da
oracle`kddlkr+0x16a
oracle`updrow+0x2417
oracle`qerupRowProcedure+0x4f
oracle`qerupFetch+0x339
oracle`updaul+0x481
oracle`updThreePhaseExe+0xc72
oracle`updexe+0x171
oracle`opiexe+0xf1b
oracle`opipls+0x98e
oracle`opiodr+0x433
oracle`rpidrus+0xde
oracle`skgmstack+0x80
oracle`rpidru+0x86
Conclusion
We have determined what exactly are extra current gets within distributed transaction.
Why Oracle 79853 times reads undo header is a topic for further research. I would prefer to write another post about it.
Little oftopic, but interesting point is that Oracle opens distributed transaction (binds undo header, transaction appears in v$transaction, v$global_transaction) for PLSQL block with dblinks during hard parsing. If hard parsing is not performed then during parsing/execution of statement with dblink.
It follows that if you will execute a statement like this
declare
i integer;
begin
DML;
DML;
DML;
if 1=0 then
select count(*) into i from dual@dblink;
end if;
end;
then either it will be executed within dustributed transaction (with extra current gets) or not depends on will hard parsing be performed or not.
p.s.
Attention!
I am still looking for additional information about
* structure kcbds,
* argments of functions kcbgtcr
* argments of functions kcbgcur
If you have this information please let me know.
row_number < n
It’s about feature of WINDOW NOSORT STOPKEY and difference between row_number() = 1 and row_number() < 2. Read more…
Evolution of INDEX RANGE/FULL SCAN (MIN/MAX)
This post is about some little difference in CBO estimations of INDEX FULL SCAN (MIN/MAX) between versions 10.2, 11.1 and 11.2.
Read more…
Non-determinisitic PLSQL function and Index Range Scan
Yesterday I met a funny issue.
Checked in versions 10.2.0.4, 10.2.0.5 – reproduced. 11.1.0.7 – not (partially, see update below. For IOT reproduced in 11.1, 11.2).
Thus, this bug could be considered as not actual, but may shed light on internals of IRS.
Read more…
SQL_TRACE event in 11g
There is one new excellent and powerful diagnostic event in 11g. Which is still not sufficiently known and popular.
Just a couple links with good explanation of this event from Miladin Modrakovic and Tanel Poder.
http://oraclue.com/2009/03/24/oracle-event-sql_trace-in-11g/
http://blog.tanelpoder.com/2010/06/23/the-full-power-of-oracles-diagnostic-events-part-2-oradebug-doc-and-11g-improvements
When indexes degrade
Is there needed to regular rebuild of indexes?
Sometimes it is necesarry. Read more…
Jokes of the CBO with local indexes.
It may seem strange, but in some cases estimation of cardinality can depends on size (in blocks) of a segment. Read more…
CBO defaults
Somtime ago I was need to determine how selectivity is calculated in a simple query:
SQL> create table all_obj as
2 select rownum id,
3 rownum n
4 from all_objects
5 where rownum <= 10000;
Table created
SQL> create index idx on all_obj(n);
Index created
SQL> explain plan for
2 select *
3 from all_obj
4 where n = :1;
Explained
SQL> select * from table(dbms_xplan.display);
PLAN_TABLE_OUTPUT
-------------------------------------------------------
| Id | Operation | Name | Rows |
-------------------------------------------------------
| 0 | SELECT STATEMENT | | 100 |
| 1 | TABLE ACCESS BY INDEX ROWID| ALL_OBJ | 100 |
|* 2 | INDEX RANGE SCAN | IDX | 40 |
-------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("N"=TO_NUMBER(:1))
Note
-----
- dynamic sampling used for this statement
There are two questions:
1. Cardinality of INDEX RANGE SCAN less(!) than TABLE ACCESS BY INDEX ROWID
2. How cardinality of INDEX RANGE SCAN is calculated
The answer and other usefull CBO defaults were found here:
http://www.mail-archive.com/oracle-l@fatcity.com/msg24731.html
========================================================= /* defaults */ /* Default selectivities are set low to 1. keep cost values low for future resource limiter use 2. keep cost values low for permutation cutoff in kko Defaults are used for bind variables, general expressions and unanalyzed tables, except for equality where defaults are not needed for bind variables. */ #define KKEDSREL 0.05 /* default selectivity for < <= > >= */ #define KKEDSEQ 0.01 /* default selectivity for = */ #define KKEDSNE 0.05 /* default selectivity for != */ #define KKEDSDF 0.05 /* default selectivity for all other ops */ #define KKEDSIRL 0.009 /* default selectivity for relation on indexed col */ #define KKEDSBRL 0.009 /* def sel for relation with bind var on index col*/ #define KKEDSIEQ 0.004 /* default selectivity for = on indexed col */ #define KKEDMBR 8 /* default multiblock read factor */ #define KKEDMBW 8 /* default multiblock write factor */ #define KKEDFNR 100.0 /* default - fixed table cardinality */ #define KKEDFRL 20 /* default - fixed table row length */ #define KKEDDNR 2000.0 /* default - remote table cardinality */ #define KKEDDRL 100 /* default - remote table avg row length */ #define KKEDDNB 100 /* default - default # of blocks */ #define KKEDDSC 13.0 /* default - default scan cost */ #define KKEDILV 1 /* default - default index levels */ #define KKEDILB 25 /* default - number of index leaf blocks */ #define KKEDLBK 1 /* default - number leaf blocks/key */ #define KKEDDBK 1 /* default - number of data blocks/key */ #define KKEDKEY 100 /* default - number of distinct keys */ #define KKEDCLF (KKEDDNB*8) /* default - clustering factor */ #define KKECRI 1.5 /* remote table access cost increase factor */ #define KKECFSC 1.0 /* fixed table scan cost */ #define KKECFNB 0 /* fixed table number of blocks */ #define KKECMXB 15 /* maximum byte length for normalization */ #define KKECBBS 256.0 /* base for byte sequence normalization */ #define KKECSPC ' ' /* space byte value */ #define KKECSPD 86400.0 /* seconds per day */ #define KKESROH 10.0 /* sort per row overhead in bytes */ #define KKESAUT 0.75 /* sort area utilization */ #define KKESROP 0.10 /* sort row overhead percent */ #define KKESRML 2.0 /* sort run multiple */ #define KKESTP 0x01 /* single table predicate */ #define KKETEQ 0x02 /* equi join */ #define KKETBCPJ 0x04 /* Cartesian product join */ #define KKESOK 0x08 /* input swap ok */ #define KKESWP 0x10 /* inputs swapped */ #define KKEEQP 0x20 /* equipartitioned */ #define KKELKNWC 0x01 /* LIKE no wild card */ #define KKELKTWC 0x02 /* LIKE trailing wild card */ #define KKELKEWC 0x04 /* LIKE embedded wild card */ #define KKELKLWC 0x08 /* LIKE leading wild card */ #define KKELKOWC 0x10 /* LIKE only wild card */ ==================================================================
Oracle uses different constants for estimation of default selectivity of a table and an index range scan:
#define KKEDSEQ 0.01 /* default selectivity for = */ #define KKEDSIEQ 0.004 /* default selectivity for = on indexed col */
So, for the execution plan above
-------------------------------------------------------
| Id | Operation | Name | Rows |
-------------------------------------------------------
| 0 | SELECT STATEMENT | | 100 |
| 1 | TABLE ACCESS BY INDEX ROWID| ALL_OBJ | 100 |
|* 2 | INDEX RANGE SCAN | IDX | 40 |
-------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("N"=TO_NUMBER(:1))
cardinality of TABLE ACCESS BY INDEX ROWID = 10000 * 0.01 = 100
cardinality of INDEX RANGE SCAN = 10000 * 0.004 = 40
10000 is number of rows in the table getting during dynamic sampling.
