[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
韩国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