[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次.