[20210220]全索引扫描快速索引扫描的逻辑读.txt
[20210220]全索引扫描快速索引扫描的逻辑读.txt
--//昨天测试了表扫描逻辑读问题,今天测试看看全索引扫描快速索引扫描的逻辑读.
1.环境:
SYS@book> @ver1
PORT_STRING VERSION BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx 11.2.0.4.0 Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
SYS@book> alter system set "_trace_pin_time"=1 scope=spfile;
System altered.
--//重启数据库.
SYS@book> @ hide _trace_pin
NAME DESCRIPTION DEFAULT_VALUE SESSION_VALUE SYSTEM_VALUE ISSES ISSYS_MOD
--------------- ------------------------------------ ------------- ------------- ------------ ----- ---------
_trace_pin_time trace how long a current pin is held FALSE 1 1 FALSE FALSE
2.测试INDEX FULL SCAN:
SCOTT@book> alter session set "_serial_direct_read"=never;
Session altered.
SCOTT@book> alter session set statistics_level = all;
Session altered.
SCOTT@book> select count(*) from emp;
COUNT(*)
----------
14
Plan hash value: 2937609675
-------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
-------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 1 (100)| | 1 |00:00:00.01 | 1 |
| 1 | SORT AGGREGATE | | 1 | 1 | | | 1 |00:00:00.01 | 1 |
| 2 | INDEX FULL SCAN| PK_EMP | 1 | 14 | 1 (0)| 00:00:01 | 14 |00:00:00.01 | 1 |
-------------------------------------------------------------------------------------------------------------
--//跟踪发现如下:
*** 2021-02-20 08:27:27.735
pin qeilwhrp: qeilbk dba 0x100009b:1 time 2720838425
3.测试INDEX FAST FULL SCAN:
SCOTT@book> select /*+ index_ffs(emp) */count(*) from emp;
COUNT(*)
----------
14
Plan hash value: 1006289799
------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 2 (100)| | 1 |00:00:00.01 | 3 |
| 1 | SORT AGGREGATE | | 1 | 1 | | | 1 |00:00:00.01 | 3 |
| 2 | INDEX FAST FULL SCAN| PK_EMP | 1 | 14 | 2 (0)| 00:00:01 | 14 |00:00:00.01 | 3 |
------------------------------------------------------------------------------------------------------------------
--//跟踪发现如下:
*** 2021-02-20 08:28:53.366
pin ktewh26: kteinpscan dba 0x100009a:4 time 2806469226
pin ktewh26: kteinpscan dba 0x100009a:4 time 2806469311
pin kdiwh100: kdircys dba 0x100009b:1 time 2806469343
4.gdb无法跟踪的问题:
(gdb) b kdircys
Function "kdircys" not defined.
Make breakpoint pending on future shared library load? (y or [n]) y
Breakpoint 1 (kdircys) pending.
(gdb) b qeilbk
Function "qeilbk" not defined.
Make breakpoint pending on future shared library load? (y or [n]) y
Breakpoint 2 (qeilbk) pending.
--//出现Make breakpoint pending on future shared library load?,如果选择Y.也无法跟踪到断点.
5.看看唯一索引的情况:
SCOTT@book> select * from emp where empno=7369;
EMPNO ENAME JOB MGR HIREDATE SAL COMM DEPTNO
---------- ---------- --------- ---------- ------------------- ---------- ---------- ----------
7369 SMITH CLERK 7902 1980-12-17 00:00:00 800 20
Plan hash value: 2949544139
--------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 1 (100)| | 1 |00:00:00.01 | 2 |
| 1 | TABLE ACCESS BY INDEX ROWID| EMP | 1 | 1 | 38 | 1 (0)| 00:00:01 | 1 |00:00:00.01 | 2 |
|* 2 | INDEX UNIQUE SCAN | PK_EMP | 1 | 1 | | 0 (0)| | 1 |00:00:00.01 | 1 |
--------------------------------------------------------------------------------------------------------------------------------
--//跟踪没有任何信息.
6.看看rowid探查的情况:
SCOTT@book> select * from emp where rowid='AAAVREAAEAAAACXAAA';
EMPNO ENAME JOB MGR HIREDATE SAL COMM DEPTNO
---------- ---------- --------- ---------- ------------------- ---------- ---------- ----------
7369 SMITH CLERK 7902 1980-12-17 00:00:00 800 20
Plan hash value: 1116584662
-----------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
-----------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 1 (100)| | 1 |00:00:00.01 | 1 |
| 1 | TABLE ACCESS BY USER ROWID| EMP | 1 | 1 | 38 | 1 (0)| 00:00:01 | 1 |00:00:00.01 | 1 |
-----------------------------------------------------------------------------------------------------------------------------
*** 2021-02-20 08:37:31.503
pin kdswh05: kdsgrp dba 0x1000097:1 time 3324606823
7.最后看看快速索引扫描的情况.
SCOTT@book> create table t as select * from all_objects;
Table created.
SCOTT@book> create index i_t_owner_obj_name on t (owner,object_name) ;
Index created.
SCOTT@book> @ seg i_t_owner_obj_name
SCOTT@book> @prxx
==============================
SEG_MB : 4
SEG_OWNER : SCOTT
SEG_SEGMENT_NAME : I_T_OWNER_OBJ_NAME
SEG_PARTITION_NAME :
SEG_SEGMENT_TYPE : INDEX
SEG_TABLESPACE_NAME : USERS
BLOCKS : 512
HDRFIL : 4
HDRBLK : 1986
PL/SQL procedure successfully completed.
--//分析略.
SCOTT@book> select count(*) from t;
COUNT(*)
----------
84774
Plan hash value: 1196567590
------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 135 (100)| | 1 |00:00:00.06 | 501 |
| 1 | SORT AGGREGATE | | 1 | 1 | | | 1 |00:00:00.06 | 501 |
| 2 | INDEX FAST FULL SCAN| I_T_OWNER_OBJ_NAME | 1 | 84774 | 135 (0)| 00:00:02 | 84774 |00:00:00.06 | 501 |
------------------------------------------------------------------------------------------------------------------------------
$ grep ^pin /tmp/ab.txt |wc
501 3507 26557
$ grep -n -C1 kteinmap /tmp/ab.txt
2-pin ktewh26: kteinpscan dba 0x10007c2:4 time 148494304
3:pin ktewh27: kteinmap dba 0x10007c2:4 time 148499972
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
4-pin ktewh26: kteinpscan dba 0x10007c2:4 time 148505557
5:pin ktewh27: kteinmap dba 0x10007c2:4 time 148511168
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
6:pin ktewh27: kteinmap dba 0x10007c2:4 time 148516498
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
7-pin kdiwh100: kdircys dba 0x10007c3:1 time 148516571
--
79-pin kdiwh100: kdircys dba 0x1000d97:1 time 148520913
80:pin ktewh27: kteinmap dba 0x10007c2:4 time 148526353
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
81-pin kdiwh100: kdircys dba 0x1000d01:1 time 148526407
--//一共4次,有点与全表扫描不同的是集中在开始要调用2次kteinpscan.kteinmap.
--//另外你查看select /*+ index_ffs(emp) */count(*) from emp;
*** 2021-02-20 08:28:53.366
pin ktewh26: kteinpscan dba 0x100009a:4 time 2806469226
pin ktewh26: kteinpscan dba 0x100009a:4 time 2806469311
pin kdiwh100: kdircys dba 0x100009b:1 time 2806469343
--//猜测这个跟全表扫描类似,如果Auxillary Map仅仅1个Extent时,全索引快速扫描不会将出现kteinmap计入逻辑读.
--//0x10007c2 = set dba 4,1986 = alter system dump datafile 4 block 1986 = 16779202
SCOTT@book> alter system dump datafile 4 block 1986 ;
System altered.
--//INDEX FAST FULL SCAN类似将索引当作表的全扫描.开始连续2次kteinpscan,kteinmap.
--//转储 Auxillary Map部分如下:
Auxillary Map
--------------------------------------------------------
Extent 0 : L1 dba: 0x010007c0 Data dba: 0x010007c3
Extent 1 : L1 dba: 0x010007c0 Data dba: 0x010007c8
Extent 2 : L1 dba: 0x010007d0 Data dba: 0x010007d1
Extent 3 : L1 dba: 0x010007d0 Data dba: 0x010007d8
Extent 4 : L1 dba: 0x010007e0 Data dba: 0x010007e1
Extent 5 : L1 dba: 0x010007e0 Data dba: 0x010007e8
Extent 6 : L1 dba: 0x010007f0 Data dba: 0x010007f1
Extent 7 : L1 dba: 0x010007f0 Data dba: 0x010007f8
Extent 8 : L1 dba: 0x01000d88 Data dba: 0x01000d89
Extent 9 : L1 dba: 0x01000d88 Data dba: 0x01000d90
------------------------------------------------->读到0x1000d97后出现kteinmap.
Extent 10 : L1 dba: 0x01000d00 Data dba: 0x01000d01
Extent 11 : L1 dba: 0x01000d00 Data dba: 0x01000d08
Extent 12 : L1 dba: 0x01000d10 Data dba: 0x01000d11
Extent 13 : L1 dba: 0x01000d10 Data dba: 0x01000d18
Extent 14 : L1 dba: 0x01000d20 Data dba: 0x01000d21
Extent 15 : L1 dba: 0x01000d20 Data dba: 0x01000d28
Extent 16 : L1 dba: 0x01000e00 Data dba: 0x01000e02
Extent 17 : L1 dba: 0x01000e80 Data dba: 0x01000e82
Extent 18 : L1 dba: 0x01000f00 Data dba: 0x01000f02
--------------------------------------------------------
--//1次调用kteinmap读10个Extent.
8.最后看看索引全扫描的情况.
SCOTT@book> select /*+ INDEX_ASC(t) */ count(*) from t;
COUNT(*)
----------
84774
Plan hash value: 2053645701
-------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
-------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 495 (100)| | 1 |00:00:00.03 | 494 |
| 1 | SORT AGGREGATE | | 1 | 1 | | | 1 |00:00:00.03 | 494 |
| 2 | INDEX FULL SCAN| I_T_OWNER_OBJ_NAME | 1 | 84774 | 495 (1)| 00:00:06 | 84774 |00:00:00.03 | 494 |
-------------------------------------------------------------------------------------------------------------------------
$ grep ^pin /tmp/ac.txt |wc
492 3444 25585
--//奇怪存在2个差距.索引全扫描是单块读,cost有点高.
--//后记:我估计跟索引root节点以及叶子节点cbc采用共享拴锁模式有关.
$ head /tmp/ac.txt ; echo ;tail /tmp/ac.txt
*** 2021-02-20 09:13:46.572
pin qeilwhnp: qeilbk dba 0x10007c4:1 time 1204708362
pin kdiwh15: kdifxs dba 0x10007c5:1 time 1204708513
pin kdiwh15: kdifxs dba 0x10007c6:1 time 1204708586
pin kdiwh15: kdifxs dba 0x10007c7:1 time 1204708650
pin kdiwh15: kdifxs dba 0x10007c8:1 time 1204708720
pin kdiwh15: kdifxs dba 0x10007c9:1 time 1204708785
pin kdiwh15: kdifxs dba 0x10007ca:1 time 1204708849
pin kdiwh15: kdifxs dba 0x10007cb:1 time 1204708956
pin kdiwh15: kdifxs dba 0x10007cc:1 time 1204709022
pin kdiwh15: kdifxs dba 0x1000f74:1 time 1204741750
pin kdiwh15: kdifxs dba 0x1000f75:1 time 1204741818
pin kdiwh15: kdifxs dba 0x1000f76:1 time 1204741885
pin kdiwh15: kdifxs dba 0x1000f77:1 time 1204741959
pin kdiwh15: kdifxs dba 0x1000f78:1 time 1204742031
pin kdiwh15: kdifxs dba 0x1000f79:1 time 1204742105
pin kdiwh15: kdifxs dba 0x1000f7a:1 time 1204742178
pin kdiwh15: kdifxs dba 0x1000f7b:1 time 1204742250
pin kdiwh15: kdifxs dba 0x1000f7c:1 time 1204742331
pin kdiwh15: kdifxs dba 0x1000f7d:1 time 1204742422
--//扫描叶子节点使用的函数是kdifxs,与快速全索引扫描的函数kdircys不同.
9.gdb跟踪kdifxs的问题:
--//有点奇怪的是如果跟踪kdifxs,会发现每取一条记录调用1次kdifxs.
break kdifxs
set pagination off
commands
silent
shell echo -n $( date +"%Y/%m/%d %T.%N : ")
printf "kdifxs 0x%x\n", *($rdi+28)
continue
end
SCOTT@book> select /*+ INDEX_ASC(t) */ count(*) from emp;
COUNT(*)
----------
14
--//跟踪文件:
*** 2021-02-20 09:35:56.279
pin qeilwhrp: qeilbk dba 0x100009b:1 time 2534414893
--//gdb
2021/02/20 09:35:56.283527260 :kdifxs 0x100009b
2021/02/20 09:35:56.288943445 :kdifxs 0x100009b
2021/02/20 09:35:56.294140527 :kdifxs 0x100009b
2021/02/20 09:35:56.299311991 :kdifxs 0x100009b
2021/02/20 09:35:56.304559641 :kdifxs 0x100009b
2021/02/20 09:35:56.309751711 :kdifxs 0x100009b
2021/02/20 09:35:56.315070138 :kdifxs 0x100009b
2021/02/20 09:35:56.320309307 :kdifxs 0x100009b
2021/02/20 09:35:56.325567607 :kdifxs 0x100009b
2021/02/20 09:35:56.330755128 :kdifxs 0x100009b
2021/02/20 09:35:56.336053584 :kdifxs 0x100009b
2021/02/20 09:35:56.341249687 :kdifxs 0x100009b
2021/02/20 09:35:56.346460461 :kdifxs 0x100009b
2021/02/20 09:35:56.351713932 :kdifxs 0x100009b
2021/02/20 09:35:56.356859085 :kdifxs 0x100009b
--//一共15行.
--//我修改如下:
set var a=0x0
break kdifxs if *($rdi+28) != a
set pagination off
commands
silent
shell echo -n $( date +"%Y/%m/%d %T.%N : ")
printf " kdifxs 0x%x\n", *($rdi+28)
set var a= *($rdi+28)
continue
end
--//注意这样不能作为逻辑读统计.注我不熟悉gdb的调式.
SCOTT@book> set arraysize 2
SCOTT@book> select /*+ INDEX_ASC(t) */ empno from emp;
*** 2021-02-20 10:01:02.141
pin qeilwhrp: qeilbk dba 0x100009b:1 time 4040276637
pin kdiwh16: kdifxs dba 0x100009b:1 time 4040278254
pin kdiwh16: kdifxs dba 0x100009b:1 time 4040279670
pin kdiwh16: kdifxs dba 0x100009b:1 time 4040280965
pin kdiwh16: kdifxs dba 0x100009b:1 time 4040282210
pin kdiwh16: kdifxs dba 0x100009b:1 time 4040283446
pin kdiwh16: kdifxs dba 0x100009b:1 time 4040284689
pin kdiwh16: kdifxs dba 0x100009b:1 time 4040285942
--//逻辑读8.
--//gdb下仅仅看到1行.
(gdb) c
Continuing.
2021/02/20 10:04:23.791914398 :kdifxs 0x100009b
10.最后看看索引范围扫描:
SCOTT@book> set arraysize 400
SCOTT@book> select /*+ index(t) */ CREATED from t where owner='SCOTT';
CREATED
-------------------
2013-08-24 12:04:21
...
2017-01-03 11:41:11
22 rows selected.
Plan hash value: 3696261165
--------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 2237 (100)| | 22 |00:00:00.01 | 18 |
| 1 | TABLE ACCESS BY INDEX ROWID| T | 1 | 2923 | 40922 | 2237 (0)| 00:00:27 | 22 |00:00:00.01 | 18 |
|* 2 | INDEX RANGE SCAN | I_T_OWNER_OBJ_NAME | 1 | 2923 | | 19 (0)| 00:00:01 | 22 |00:00:00.01 | 4 |
--------------------------------------------------------------------------------------------------------------------------------------------
*** 2021-02-20 10:08:47.319
pin qeilwhnp: qeilbk dba 0x1000e8f:1 time 210487381
pin kdswh05: kdsgrp dba 0x100074c:1 time 210487471
pin kdiwh16: kdifxs dba 0x1000e8f:1 time 210487812
pin kdswh05: kdsgrp dba 0x1000755:1 time 210487858
pin kdswh05: kdsgrp dba 0x100074c:1 time 210487892
pin kdswh05: kdsgrp dba 0x1000755:1 time 210487914
pin kdswh05: kdsgrp dba 0x100074c:1 time 210487932
pin kdswh05: kdsgrp dba 0x1000755:1 time 210487951
pin kdswh05: kdsgrp dba 0x100074d:1 time 210487971
pin kdswh05: kdsgrp dba 0x1000755:1 time 210487988
pin kdswh05: kdsgrp dba 0x100074c:1 time 210488006
pin kdswh05: kdsgrp dba 0x1000755:1 time 210488026
pin kdswh05: kdsgrp dba 0x100074c:1 time 210488044
pin kdswh05: kdsgrp dba 0x100074d:1 time 210488069
pin kdswh05: kdsgrp dba 0x100074c:1 time 210488089
pin kdswh05: kdsgrp dba 0x1000755:1 time 210488107
--//逻辑读16.还是少2个.
--//后记:我估计跟索引root节点以及叶子节点cbc采用共享拴锁模式有关.
SCOTT@book> alter system reset "_trace_pin_time";
System altered.
--//重启,不然下面的跟踪信息太乱了.
SCOTT@book> @ treedump i_t_owner_obj_name
old 1: select object_id from user_objects where object_name = upper('&&1') and object_type = 'INDEX'
new 1: select object_id from user_objects where object_name = upper('i_t_owner_obj_name') and object_type = 'INDEX'
OBJECT_ID
----------
90544
old 1: alter session set events 'immediate trace name treedump level &m_index_id'
new 1: alter session set events 'immediate trace name treedump level 90544'
Session altered.
----- begin tree dump
branch: 0x10007c3 16779203 (0: nrow: 2, level: 2)
branch: 0x1000efb 16781051 (-1: nrow: 363, level: 1)
--//应该是漏掉这2个块的逻辑读.检索找不到这两块的读操作.
leaf: 0x10007c4 16779204 (-1: nrow: 157 rrow: 157)
leaf: 0x10007c5 16779205 (0: nrow: 159 rrow: 159)
leaf: 0x10007c6 16779206 (1: nrow: 148 rrow: 148)
leaf: 0x10007c7 16779207 (2: nrow: 157 rrow: 157)
leaf: 0x10007c8 16779208 (3: nrow: 154 rrow: 154)
leaf: 0x10007c9 16779209 (4: nrow: 158 rrow: 158)
...
leaf: 0x1000f78 16781176 (122: nrow: 187 rrow: 187)
leaf: 0x1000f79 16781177 (123: nrow: 195 rrow: 195)
leaf: 0x1000f7a 16781178 (124: nrow: 185 rrow: 185)
leaf: 0x1000f7b 16781179 (125: nrow: 227 rrow: 227)
leaf: 0x1000f7c 16781180 (126: nrow: 221 rrow: 221)
leaf: 0x1000f7d 16781181 (127: nrow: 61 rrow: 61)
----- end tree dump
11.总结:
--//测试有点乱,基本想到哪里做到哪里.
--//使用"_trace_pin_time"=1探究全表扫描以及快速全索引扫描逻辑读还是很准确的,索引一些逻辑读存在一些误差.
--//kteinmap 调用实际上跟全表扫描类似.不知道是为什么快速全扫描开始出现2次kteinpscan,extents多的话还会出现2次kteinmap.
--//gdb无法跟踪qeilbk,kdircys, 不知道是为什么快速全扫描开始出现2次.
