2021-02-20

[20210219]全表扫描逻辑读问题.txt

[20210219]全表扫描逻辑读问题.txt

--//一般探究逻辑读设置_trace_pin_time,或者设置10200事件.
--//设置_trace_pin_time有一个明显的缺点就是在系统级设置,而且要重启,这样每个进程产生大量跟踪信息.
--//还有的一个因素就是对于唯一索引的执行计划,一些pin会捕捉到.自己没什么事情测试看看,
--//主要出现一些小问题,自己无法理解.

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.测试:
--//测试前在别的会话执行select * from emp;多次,避免一些递归语句的执行.不然跟踪输出太乱.

SCOTT@book> @ 10046on 12
Session altered.

SCOTT@book> select * from emp;
     EMPNO ENAME      JOB              MGR HIREDATE                   SAL       COMM     DEPTNO
---------- ---------- --------- ---------- ------------------- ---------- ---------- ----------
      7369 SMITH      CLERK           7902 1980-12-17 00:00:00        800                    20
...
      7934 MILLER     CLERK           7782 1982-01-23 00:00:00       1300                    10
14 rows selected.

SCOTT@book> @ 10046off
Session altered.

3.检查跟踪文件:
=====================
PARSING IN CURSOR #139634694966072 len=17 dep=0 uid=83 oct=3 lid=83 tim=1613695908737267 hv=1745700775 ad='7c3dc5f0' sqlid='a2dk8bdn0ujx7'
select * from emp
END OF STMT
PARSE #139634694966072:c=3000,e=2654,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3956160932,tim=1613695908737263
EXEC #139634694966072:c=0,e=41,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3956160932,tim=1613695908737408
WAIT #139634694966072: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=407 tim=1613695908737476
pin ktewh26: kteinpscan dba 0x1000092:4 time 3681186314
pin kdswh11: kdst_fetch dba 0x1000093:1 time 3681186358
pin kdswh11: kdst_fetch dba 0x1000094:1 time 3681186382
pin kdswh11: kdst_fetch dba 0x1000095:1 time 3681186398
pin kdswh11: kdst_fetch dba 0x1000096:1 time 3681186413
pin kdswh11: kdst_fetch dba 0x1000097:1 time 3681186429
FETCH #139634694966072:c=0,e=161,p=0,cr=6,cu=0,mis=0,r=1,dep=0,og=1,plh=3956160932,tim=1613695908737681
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
WAIT #139634694966072: nam='SQL*Net message from client' ela= 557 driver id=1650815232 #bytes=1 p3=0 obj#=407 tim=1613695908738283
pin kdswh11: kdst_fetch dba 0x1000097:1 time 3681187130
WAIT #139634694966072: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=407 tim=1613695908738391
FETCH #139634694966072:c=0,e=89,p=0,cr=1,cu=0,mis=0,r=13,dep=0,og=1,plh=3956160932,tim=1613695908738440
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
STAT #139634694966072 id=1 cnt=14 pid=0 pos=1 obj=87108 op='TABLE ACCESS FULL EMP (cr=7 pr=0 pw=0 time=144 us cost=3 size=532 card=14)'

*** 2021-02-19 08:51:51.614
WAIT #139634694966072: nam='SQL*Net message from client' ela= 2876023 driver id=1650815232 #bytes=1 p3=0 obj#=407 tim=1613695911614606
CLOSE #139634694966072:c=0,e=10,dep=0,type=0,tim=1613695911614709
=====================
PARSING IN CURSOR #139634694966072 len=55 dep=0 uid=83 oct=42 lid=83 tim=1613695911614965 hv=2217940283 ad='0' sqlid='06nvwn223659v'
alter session set events '10046 trace name context off'
END OF STMT
PARSE #139634694966072:c=999,e=194,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1613695911614964
EXEC #139634694966072:c=0,e=373,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1613695911615415

$ grep ^pin /tmp/aa.txt
pin ktewh26: kteinpscan dba 0x1000092:4 time 3681186314
pin kdswh11: kdst_fetch dba 0x1000093:1 time 3681186358
pin kdswh11: kdst_fetch dba 0x1000094:1 time 3681186382
pin kdswh11: kdst_fetch dba 0x1000095:1 time 3681186398
pin kdswh11: kdst_fetch dba 0x1000096:1 time 3681186413
pin kdswh11: kdst_fetch dba 0x1000097:1 time 3681186429
pin kdswh11: kdst_fetch dba 0x1000097:1 time 3681187130

--//0x1000092 = set dba 4,146 = alter system dump datafile 4 block 146 = 16777362
--//0x1000097 = set dba 4,151 = alter system dump datafile 4 block 151 = 16777367
--//0x1000097 读2次,注意看前面fetch存在2次,第1次fetch1条,第2次fetch 13次.共14条记录返回.
--//中间4块是空块.

SCOTT@book> alter session set statistics_level = all;
Session altered.

SCOTT@book> select * from emp;
...
SCOTT@book> @ dpc '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID  a2dk8bdn0ujx7, child number 2
-------------------------------------
select * from emp
Plan hash value: 3956160932
--------------------------------------------------------------------------------------------------------------------
| Id  | Operation         | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
--------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |      1 |        |       |     3 (100)|          |     14 |00:00:00.01 |       7 |
|   1 |  TABLE ACCESS FULL| EMP  |      1 |     14 |   532 |     3   (0)| 00:00:01 |     14 |00:00:00.01 |       7 |
--------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
   1 - SEL$1 / EMP@SEL$1
--//与前面的测试逻辑读正好7个一致.有点奇怪的是与vaga书提到的不同,按照他的介绍段头要读2次.而实际上仅仅1次.这是我的疑问.

SCOTT@book> select rowid from emp where rownum=1;
ROWID
------------------
AAAVREAAEAAAACXAAA

SCOTT@book> @ rowid AAAVREAAEAAAACXAAA
    OBJECT       FILE      BLOCK        ROW ROWID_DBA            DBA                  TEXT
---------- ---------- ---------- ---------- -------------------- -------------------- ----------------------------------------
     87108          4        151          0  0x1000097           4,151                alter system dump datafile 4 block 151 ;

SCOTT@book> select * from dba_segments where owner=user and segment_name='EMP'
  2  @ prxx
==============================
OWNER                         : SCOTT
SEGMENT_NAME                  : EMP
PARTITION_NAME                :
SEGMENT_TYPE                  : TABLE
SEGMENT_SUBTYPE               : ASSM
TABLESPACE_NAME               : USERS
HEADER_FILE                   : 4
HEADER_BLOCK                  : 146
BYTES                         : 65536
BLOCKS                        : 8
EXTENTS                       : 1
INITIAL_EXTENT                : 65536
NEXT_EXTENT                   : 1048576
MIN_EXTENTS                   : 1
MAX_EXTENTS                   : 2147483645
MAX_SIZE                      : 2147483645
RETENTION                     :
MINRETENTION                  :
PCT_INCREASE                  :
FREELISTS                     :
FREELIST_GROUPS               :
RELATIVE_FNO                  : 4
BUFFER_POOL                   : DEFAULT
FLASH_CACHE                   : DEFAULT
CELL_FLASH_CACHE              : DEFAULT
PL/SQL procedure successfully completed.
--//段头dba=4,146.与跟踪看到的dba地址一致.

4.建立另外的表测试看看:
SCOTT@book> create table empx as select * from emp;
Table created.

SCOTT@book> @ 10046on 12
Session altered.

SCOTT@book> select /*+ full(empx) */ count(*) from empx;
  COUNT(*)
----------
        14

SCOTT@book> @ 10046off
Session altered.

=====================
PARSING IN CURSOR #139940786742280 len=43 dep=0 uid=83 oct=3 lid=83 tim=1613696616211174 hv=4266967087 ad='7e10b110' sqlid='36gz0zrz59h1g'
select /*+ full(empx) */ count(*) from empx
END OF STMT
PARSE #139940786742280:c=1999,e=1151,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=36332186,tim=1613696616211169
EXEC #139940786742280:c=0,e=37,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=36332186,tim=1613696616211315
WAIT #139940786742280: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1613696616211379
pin ktewh26: kteinpscan dba 0x1000222:4 time 93692910
pin kdswh11: kdst_fetch dba 0x1000223:1 time 93692951
FETCH #139940786742280:c=0,e=100,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=1,plh=36332186,tim=1613696616211516
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
STAT #139940786742280 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=2 pr=0 pw=0 time=97 us)'
STAT #139940786742280 id=2 cnt=14 pid=1 pos=1 obj=90510 op='TABLE ACCESS FULL EMPX (cr=2 pr=0 pw=0 time=79 us cost=3 size=0 card=14)'
WAIT #139940786742280: nam='SQL*Net message from client' ela= 332 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1613696616212000
FETCH #139940786742280:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=36332186,tim=1613696616212063
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
WAIT #139940786742280: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1613696616212101

*** 2021-02-19 09:03:39.314
WAIT #139940786742280: nam='SQL*Net message from client' ela= 3102263 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1613696619314389
CLOSE #139940786742280:c=0,e=10,dep=0,type=0,tim=1613696619314489
=====================
--//0x1000222 = set dba 4,546 = alter system dump datefile 4 block 546 = 16777762

SCOTT@book> @ dpc '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID  36gz0zrz59h1g, child number 2
-------------------------------------
select /*+ full(empx) */ count(*) from empx
Plan hash value: 36332186
-------------------------------------------------------------------------------------------------------------
| Id  | Operation          | Name | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
-------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |      1 |        |     3 (100)|          |      1 |00:00:00.01 |       2 |
|   1 |  SORT AGGREGATE    |      |      1 |      1 |            |          |      1 |00:00:00.01 |       2 |
|   2 |   TABLE ACCESS FULL| EMPX |      1 |     14 |     3   (0)| 00:00:01 |     14 |00:00:00.01 |       2 |
-------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
   1 - SEL$1
   2 - SEL$1 / EMPX@SEL$1
--//2个逻辑读.也就是不像vage测试那样,读段头2次在全表扫描的情况下.为什么呢?
--//如果你看链 ktewh26: kteinpscan dba 0x10a6202:4 time 1039048805
pin ktewh27: kteinmap dba 0x10a6202:4 time 1039048847
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

5.我使用gdb跟踪进程,发现实际上还是调用kteinmap.
SCOTT@book> select * from emp;

(gdb) b kteinmap
Breakpoint 1 at 0xfc97f0
(gdb) c
Continuing.

Breakpoint 1, 0x0000000000fc97f0 in kteinmap ()

(gdb) info register
rax            0x0      0
rbx            0x0      0
rcx            0x0      0
rdx            0x0      0
rsi            0x85f7a080       2247598208
rdi            0x7f44073a92f0   139930155782896
rbp            0x7fff1225b300   0x7fff1225b300
rsp            0x7fff1225b300   0x7fff1225b300
r8             0x85f7a080       2247598208
r9             0x0      0
r10            0x85f7a020       2247598112
r11            0x10     16
r12            0x7f44073a92f0   139930155782896
r13            0x7f44073a95c0   139930155783616
r14            0x0      0
r15            0x0      0
rip            0xfc97f0 0xfc97f0 <kteinmap+4>
eflags         0x246    [ PF ZF IF ]
cs             0x33     51
ss             0x2b     43
ds             0x0      0
es             0x0      0
fs             0x0      0
gs             0x0      0
fctrl          0x27f    639
fstat          0x4020   16416
ftag           0xffff   65535
fiseg          0x0      0
fioff          0x5f47add        99908317
foseg          0x7fff   32767
fooff          0x1225bb28       304462632
fop            0x0      0
mxcsr          0x1fa0   [ PE IM DM ZM OM UM PM ]

(gdb) x /32x $rdi
0x7f44073a92f0: 0x00000004      0x01000092      0x00015444      0x00015444
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
0x7f44073a9300: 0x003f0008      0x00001fe8      0x00000000      0x00000000
0x7f44073a9310: 0x00000000      0x00000000      0x00000000      0x00000000
0x7f44073a9320: 0x0000000a      0x00000000      0x0747b6d0      0x00007f44
0x7f44073a9330: 0x0747b690      0x00007f44      0x00000000      0x00000000
0x7f44073a9340: 0x00000000      0x00000000      0x00000000      0x00000000
0x7f44073a9350: 0x00000033      0x01000092      0x00000004      0x00000004
0x7f44073a9360: 0x01000093      0x00000005      0x01000090      0x00000008
--//$rdi记录的地址偏移4个字节记录的是dba地址. 我尝试建立大表发现还是可以跟踪到kteinmap.继续...

6.继续测试:
SCOTT@book> create table t1 as select * from dba_objects where rownum<=600;
Table created.

SCOTT@book> select count(*),DBMS_ROWID.ROWID_BLOCK_NUMBER(rowid) from t1 group by DBMS_ROWID.ROWID_BLOCK_NUMBER(rowid) order by 2;
  COUNT(*) DBMS_ROWID.ROWID_BLOCK_NUMBER(ROWID)
---------- ------------------------------------
        88                                 3483
        83                                 3484
        80                                 3485
        78                                 3486
        78                                 3487
        80                                 3488
        81                                 3489
        32                                 3490
8 rows selected.
--//88+83+80+78+78 = 407,这样仅仅使用1个extent.

SCOTT@book> create table t2 as select * from dba_objects where rownum<=407;
Table created.

SCOTT@book> create table t3 as select * from dba_objects where rownum<=408;
Table created.

--//分析表略.
> select count(*) from t2;
Plan hash value: 3321871023
-------------------------------------------------------------------------------------------------------------
| Id  | Operation          | Name | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
-------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |      1 |        |     4 (100)|          |      1 |00:00:00.01 |       6 |
|   1 |  SORT AGGREGATE    |      |      1 |      1 |            |          |      1 |00:00:00.01 |       6 |
|   2 |   TABLE ACCESS FULL| T2   |      1 |    407 |     4   (0)| 00:00:01 |    407 |00:00:00.01 |       6 |
-------------------------------------------------------------------------------------------------------------
*** 2021-02-19 16:03:37.760
pin ktewh26: kteinpscan dba 0x1000daa:4 time 3820405730
pin kdswh11: kdst_fetch dba 0x1000dab:1 time 3820405818
pin kdswh11: kdst_fetch dba 0x1000dac:1 time 3820405880
pin kdswh11: kdst_fetch dba 0x1000dad:1 time 3820405919
pin kdswh11: kdst_fetch dba 0x1000dae:1 time 3820405953
pin kdswh11: kdst_fetch dba 0x1000daf:1 time 3820405988

SCOTT@book> select count(*) from t3;
Plan hash value: 463314188
-------------------------------------------------------------------------------------------------------------
| Id  | Operation          | Name | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
-------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |      1 |        |     4 (100)|          |      1 |00:00:00.01 |       8 |
|   1 |  SORT AGGREGATE    |      |      1 |      1 |            |          |      1 |00:00:00.01 |       8 |
|   2 |   TABLE ACCESS FULL| T3   |      1 |    408 |     4   (0)| 00:00:01 |    408 |00:00:00.01 |       8 |
-------------------------------------------------------------------------------------------------------------

*** 2021-02-19 16:05:05.952
pin ktewh26: kteinpscan dba 0x1000db2:4 time 3908597185
pin ktewh27: kteinmap dba 0x1000db2:4 time 3908597257
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
pin kdswh11: kdst_fetch dba 0x1000db3:1 time 3908597290
pin kdswh11: kdst_fetch dba 0x1000db4:1 time 3908597334
pin kdswh11: kdst_fetch dba 0x1000db5:1 time 3908597372
pin kdswh11: kdst_fetch dba 0x1000db6:1 time 3908597412
pin kdswh11: kdst_fetch dba 0x1000db7:1 time 3908597456
pin kdswh11: kdst_fetch dba 0x1000db8:1 time 3908597505

--//你可以发现我仅仅增加1条记录,逻辑读增加2个.
--//0x1000db2 = set dba 4,3506 = alter system dump datafile 4 block 3506 = 16780722

SCOTT@book> alter system dump datafile 4 block 3506;
System altered.

Block dump from disk:
buffer tsn: 4 rdba: 0x01000db2 (4/3506)
scn: 0x0003.176c4279 seq: 0x01 flg: 0x04 tail: 0x42792301
frmt: 0x02 chkval: 0xd1dd type: 0x23=PAGETABLE SEGMENT HEADER
Hex dump of block: st=0, typ_found=1
Dump of memory from 0x00007F7083993200 to 0x00007F7083995200
7F7083993200 0000A223 01000DB2 176C4279 04010003  [#.......yBl.....]
7F7083993210 0000D1DD 00000000 00000000 00000000  [................]
7F7083993220 00000000 00000002 00000010 00000A9C  [................]
7F7083993230 00000001 00000001 00000008 01000DB9  [................]
7F7083993240 00000000 00000001 00000000 00000009  [................]
7F7083993250 00000000 00000000 00000000 00000001  [................]
7F7083993260 00000001 00000008 01000DB9 00000000  [................]
7F7083993270 00000001 00000000 00000009 01000DB0  [................]
7F7083993280 01000DB0 00000000 00000000 00000000  [................]
7F7083993290 00000000 00000000 00000000 00000000  [................]
        Repeat 3 times
7F70839932D0 00000001 00002000 00000000 00001434  [..... ......4...]
7F70839932E0 00000000 01000DB1 00000001 01000DB0  [................]
7F70839932F0 01000DB1 00000000 00000000 00000000  [................]
7F7083993300 00000000 00000000 00000002 00000000  [................]
7F7083993310 00016198 10000000 01000DB0 00000008  [.a..............]
7F7083993320 01000DB8 00000008 00000000 00000000  [................]
7F7083993330 00000000 00000000 00000000 00000000  [................]
        Repeat 151 times
7F7083993CB0 01000DB0 01000DB3 01000DB0 01000DB8  [................]
7F7083993CC0 00000000 00000000 00000000 00000000  [................]
        Repeat 151 times
7F7083994640 00000000 00000000 01000DB1 00000000  [................]
7F7083994650 00000000 00000000 00000000 00000000  [................]
        Repeat 185 times
7F70839951F0 00000000 00000000 00000000 42792301  [.............#yB]
  Extent Control Header
  -----------------------------------------------------------------
  Extent Header:: spare1: 0      spare2: 0      #extents: 2      #blocks: 16
                  last map  0x00000000  #maps: 0      offset: 2716
      Highwater::  0x01000db9  ext#: 1      blk#: 1      ext size: 8
      ~~~~~~~~~~~~~~~~~~~~~~~~高水位标识.
  #blocks in seg. hdr's freelists: 0
  #blocks below: 9
  mapblk  0x00000000  offset: 1
                   Unlocked
  --------------------------------------------------------
  Low HighWater Mark :
      Highwater::  0x01000db9  ext#: 1      blk#: 1      ext size: 8
  #blocks in seg. hdr's freelists: 0
  #blocks below: 9
  mapblk  0x00000000  offset: 1
  Level 1 BMB for High HWM block: 0x01000db0
  Level 1 BMB for Low HWM block: 0x01000db0
  --------------------------------------------------------
  Segment Type: 1 nl2: 1      blksz: 8192   fbsz: 0
  L2 Array start offset:  0x00001434
  First Level 3 BMB:  0x00000000
  L2 Hint for inserts:  0x01000db1
  Last Level 1 BMB:  0x01000db0
  Last Level II BMB:  0x01000db1
  Last Level III BMB:  0x00000000
     Map Header:: next  0x00000000  #extents: 2    obj#: 90520  flag: 0x10000000
  Inc # 0
  Extent Map
  -----------------------------------------------------------------
   0x01000db0  length: 8
   0x01000db8  length: 8

  Auxillary Map
  --------------------------------------------------------
   Extent 0     :  L1 dba:  0x01000db0 Data dba:  0x01000db3
   Extent 1     :  L1 dba:  0x01000db0 Data dba:  0x01000db8
  --------------------------------------------------------
   Second Level Bitmap block DBAs
   --------------------------------------------------------
   DBA 1:   0x01000db1
End dump data blocks tsn: 4 file#: 4 minblk 3506 maxblk 3506
--//存在2个extent.
--//你可以发现在Auxillary Map仅仅1条Extent的情况下就不会将kteinmap计入逻辑读的现象.

7.继续测试调用kteinmap的情况:
create table t1 as select * from dba_objects ;
--//分析略.不然逻辑读有一些增加.

SCOTT@book> alter session set "_serial_direct_read"=never;
Session altered.
--//注:主要我的表有点大,出现直接路径读,需要关闭直接路径读.不然仅仅看到仅仅2个逻辑读.
*** 2021-02-19 16:16:43.303
pin ktewh26: kteinpscan dba 0x1000d9a:4 time 310980860
pin ktewh27: kteinmap dba 0x1000d9a:4 time 310980967

SCOTT@book> select count(*) from t1;
  COUNT(*)
----------
     87003

$ grep -C1 kteinmap /tmp/a1.txt
pin ktewh26: kteinpscan dba 0x1000d9a:4 time 436002887
pin ktewh27: kteinmap dba 0x1000d9a:4 time 436002967
pin kdswh11: kdst_fetch dba 0x1000d9b:1 time 436003159
--
pin kdswh11: kdst_fetch dba 0x1000dff:1 time 436006353
pin ktewh27: kteinmap dba 0x1000d9a:4 time 436006383
pin kdswh11: kdst_fetch dba 0x1000781:1 time 436006478
--
pin kdswh11: kdst_fetch dba 0x1000a7f:1 time 436028085
pin ktewh27: kteinmap dba 0x1000d9a:4 time 436028114
pin kdswh11: kdst_fetch dba 0x1000a82:1 time 436029189
--//出现3次.
--//0x1000d9a = set dba 4,3482 = alter system dump datafile 4 block 3482 = 16780698;

$ grep "^pin" /tmp/a1.txt |wc
   1246    8722   68524
Plan hash value: 3724264953
-------------------------------------------------------------------------------------------------------------
| Id  | Operation          | Name | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
-------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |      1 |        |   347 (100)|          |      1 |00:00:00.04 |    1246 |
|   1 |  SORT AGGREGATE    |      |      1 |      1 |            |          |      1 |00:00:00.04 |    1246 |
|   2 |   TABLE ACCESS FULL| T1   |      1 |  87003 |   347   (1)| 00:00:05 |  87003 |00:00:00.03 |    1246 |
-------------------------------------------------------------------------------------------------------------   
--//逻辑读的数量1246一致.

SCOTT@book> alter system checkpoint;
System altered.

SCOTT@book> alter system dump datafile 4 block 3482;
System altered.

--//转储  Auxillary Map部分如下:
  Auxillary Map
  --------------------------------------------------------
   Extent 0     :  L1 dba:  0x01000d98 Data dba:  0x01000d9b
   Extent 1     :  L1 dba:  0x01000d98 Data dba:  0x01000da0
   Extent 2     :  L1 dba:  0x01000dc0 Data dba:  0x01000dc1
   Extent 3     :  L1 dba:  0x01000dc0 Data dba:  0x01000dc8
   Extent 4     :  L1 dba:  0x01000dd0 Data dba:  0x01000dd1
   Extent 5     :  L1 dba:  0x01000dd0 Data dba:  0x01000dd8
   Extent 6     :  L1 dba:  0x01000de0 Data dba:  0x01000de1
   Extent 7     :  L1 dba:  0x01000de0 Data dba:  0x01000de8
   Extent 8     :  L1 dba:  0x01000df0 Data dba:  0x01000df1
   Extent 9     :  L1 dba:  0x01000df0 Data dba:  0x01000df8
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~=>读到0x1000dff后出现kteinmap.
   Extent 10    :  L1 dba:  0x01000780 Data dba:  0x01000781
   Extent 11    :  L1 dba:  0x01000780 Data dba:  0x01000788
   Extent 12    :  L1 dba:  0x01000790 Data dba:  0x01000791
   Extent 13    :  L1 dba:  0x01000790 Data dba:  0x01000798
   Extent 14    :  L1 dba:  0x010007a0 Data dba:  0x010007a1
   Extent 15    :  L1 dba:  0x010007a0 Data dba:  0x010007a8
   Extent 16    :  L1 dba:  0x01000800 Data dba:  0x01000802
   Extent 17    :  L1 dba:  0x01000880 Data dba:  0x01000882
   Extent 18    :  L1 dba:  0x01000900 Data dba:  0x01000902
   Extent 19    :  L1 dba:  0x01000a00 Data dba:  0x01000a02
-------------------------------------------------=>读到0x1000a7f后出现kteinmap.
   Extent 20    :  L1 dba:  0x01000a80 Data dba:  0x01000a82
   Extent 21    :  L1 dba:  0x01000b00 Data dba:  0x01000b02
   Extent 22    :  L1 dba:  0x01000b80 Data dba:  0x01000b82
   Extent 23    :  L1 dba:  0x01000c00 Data dba:  0x01000c02
   Extent 24    :  L1 dba:  0x01000c80 Data dba:  0x01000c82
  --------------------------------------------------------
--//你可以简单发现一个规律,1次调用kteinmap读10个Extent.

总结:
1.当段头的 Auxillary Map仅仅1个Extent时,全表扫描不会将出现kteinmap计入逻辑读的情况.
2.如果段头的 Auxillary Map 记录的extent很多,每次调用kteinmap读10个Extent.
3.我没有测试索引全扫描以及索引快速全扫描的情况,有机会测试看看.
4.注意执行计划存在INDEX UNIQUE SCAN,是检测不到pin的情况的.











原文转载:http://www.shaoqun.com/a/570608.html

跨境电商:https://www.ikjzd.com/

韩国naver:https://www.ikjzd.com/w/1727

米兰网:https://www.ikjzd.com/w/1304.html


[20210219]全表扫描逻辑读问题.txt--//一般探究逻辑读设置_trace_pin_time,或者设置10200事件.--//设置_trace_pin_time有一个明显的缺点就是在系统级设置,而且要重启,这样每个进程产生大量跟踪信息.--//还有的一个因素就是对于唯一索引的执行计划,一些pin会捕捉到.自己没什么事情测试看看,--//主要出现一些小问题,自己无法理解.1.环境:SYS@
马士基集团:https://www.ikjzd.com/w/1296
yiqu:https://www.ikjzd.com/w/210
飞书互动:https://www.ikjzd.com/w/1319
亚马逊政策更新!两个改动让卖家抓狂:https://www.ikjzd.com/home/130151
这周,多项跨境贸易促进措施出炉,各平台相继发布财报!:https://www.ikjzd.com/home/109300
6月30日开放入口!美国2000亿关税清单排除申请启动!:https://www.ikjzd.com/home/98919

No comments:

Post a Comment