call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.26 0.26 64 69 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.26 0.26 64 69 0 1
읽고자 하는 블록을 버퍼 캐시에서 찾지 못했을 때, I/O Call을 통해 데이터파일로부터 버퍼 캐시에 적재하는 방식에는 크게 두 가지가 있다.
인덱스는 리프블록끼리 Double Linked List 구조로 연결되어 있어, 물리적으로 한 Extent에 속한 블록들을 I/O Call발생 시점에 같이 적재하여 올렸을 때
그 블록들이 논리적 순서로는 한참 뒤쪽에 위치할 수 있으므로, 실제 사용되지 못한 채 버퍼상에서 밀려 날 수도 있으므로 Singl Block I/O방식이 효율적
Index Range Scan 뿐 아니라 Index Full Scan시에도 논리적인 순서에 따라 Single Block I/O방식으로 읽음
Index Fast Full Scan은 Multiblock I/O 방식을 사용
서버 프로세스는 Disk에서 블록을 읽어야 하는 시점마다 I/O 서브시스템에 I/O 요청을 하고 대기 상태에 빠지는데 대표적인 대기 이벤트는 다음과 같다.
sequential, scattered 평균 대기 시간
SQL> SELECT a.average_wait "SEQ READ", b.average_wait "SCAT READ"
2 FROM sys.v_$system_event a, sys.v_$system_event b
3 WHERE a.event = 'db file sequential read'
4 AND b.event = 'db file scattered read';
SEQ READ SCAT READ
---------- ----------
.05 .14
SQL> CREATE TABLE t2
2 AS
3 SELECT * FROM all_objects;
테이블이 생성되었습니다.
SQL> ALTER TABLE t2 ADD
2 CONSTRAINT t_pk PRIMARY KEY(object_id);
테이블이 변경되었습니다.
SQL> SELECT /*+ index(t) */ COUNT(*)
2 FROM t2
3 WHERE object_id > 0;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.01 0 3 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.02 0.01 84 90 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.03 0.03 84 93 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=90 pr=84 pw=0 time=17665 us)
42672 INDEX RANGE SCAN T_PK (cr=90 pr=84 pw=0 time=42702 us)(object id 109394)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
db file sequential read 84 0.00 0.00
SQL*Net message from client 2 12.00 12.00
위 트레이스 결과를 보면, 논리적으로 93개 블록을 읽는 동안 84개의 디스크 블록을 읽었다.
이벤트 발생 현황을 보면 db file sequential read 대기 이벤트가 84번 발생했다.
즉, 84개 인덱스 블록을 Disk에서 읽으면서 84번의 I/O Call이 발생한 것이다.
SQL> show parameter db_block_size
NAME TYPE VALUE
------------------------------------ ---------------------- ---------------------
db_block_size integer 8192
SQL> show parameter db_file_multiblock_read_count
NAME TYPE VALUE
------------------------------------ ---------------------- ---------------------
db_file_multiblock_read_count integer 16
SQL> SELECT /*+ index_ffs(t) */ COUNT(*)
2 FROM t2
3 WHERE object_id > 0;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.01 0 3 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.02 0.01 84 96 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.03 0.02 84 99 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 54
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=96 pr=84 pw=0 time=13522 us)
42672 INDEX FAST FULL SCAN T_PK (cr=96 pr=84 pw=0 time=42786 us)(object id 109396)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
db file scattered read 12 0.00 0.00
SQL*Net message from client 2 13.12 13.12
똑같이 84개 블록을 디스크에서 읽었는데, I/O Call이 12번에 그쳤다.
Single Block I/O 할 때보다는 크게 줄었지만 예상했던 5보다는 두 배 많은 수치다.
84/12 = 7 이므로 평균 7~8개씩 읽은 셈이다.
OS에서 I/O 단위가 65,536(=8,192X8) 바이트인 것일까? 트레이스 파일을 열어 확인해 보자.
EXEC #19:c=0,e=89,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=5312766948262
WAIT #19: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=109394 tim=5312766948334
-------------------------------------------------p1------p2-----------p3----------------------------------
WAIT #19: nam='db file scattered read' ela= 74 file#=4 block#=1090 blocks=7 obj#=109396 tim=5312766949324
WAIT #19: nam='db file scattered read' ela= 99 file#=4 block#=1098 blocks=7 obj#=109396 tim=5312766950465
WAIT #19: nam='db file scattered read' ela= 56 file#=4 block#=1105 blocks=8 obj#=109396 tim=5312766951503
WAIT #19: nam='db file scattered read' ela= 80 file#=4 block#=1114 blocks=7 obj#=109396 tim=5312766952696
WAIT #19: nam='db file scattered read' ela= 70 file#=4 block#=1121 blocks=8 obj#=109396 tim=5312766953776
WAIT #19: nam='db file scattered read' ela= 89 file#=4 block#=1130 blocks=7 obj#=109396 tim=5312766954983
WAIT #19: nam='db file scattered read' ela= 66 file#=4 block#=1137 blocks=8 obj#=109396 tim=5312766956031
WAIT #19: nam='db file scattered read' ela= 103 file#=4 block#=1146 blocks=7 obj#=109396 tim=5312766957243
WAIT #19: nam='db file scattered read' ela= 71 file#=4 block#=1153 blocks=8 obj#=109396 tim=5312766958293
WAIT #19: nam='db file scattered read' ela= 74 file#=4 block#=1674 blocks=7 obj#=109396 tim=5312766959489
WAIT #19: nam='db file scattered read' ela= 78 file#=4 block#=1681 blocks=8 obj#=109396 tim=5312766960565
WAIT #19: nam='db file scattered read' ela= 28 file#=4 block#=1690 blocks=2 obj#=109396 tim=5312766961684
----------------------------------------------------------------------------------------------------------
FETCH #19:c=20000,e=13521,p=84,cr=96,cu=0,mis=0,r=1,dep=0,og=1,tim=5312766961918
WAIT #19: nam='SQL*Net message from client' ela= 585 driver id=1413697536 #bytes=1 p3=0 obj#=109396 tim=5312766962645
FETCH #19:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=5312766962722
WAIT #19: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=109396 tim=5312766962782
*** 2012-07-10 10:52:27.291
WAIT #19: nam='SQL*Net message from client' ela= 13126184 driver id=1413697536 #bytes=1 p3=0 obj#=109396 tim=5312780089022
STAT #19 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=96 pr=84 pw=0 time=13522 us)'
STAT #19 id=2 cnt=42672 pid=1 pos=1 obj=109396 op='INDEX FAST FULL SCAN T_PK (cr=96 pr=84 pw=0 time=42786 us)'
=====================
db file scattered read 대기 이벤트가 실제 12번 발생한 것을 볼 수 있고, 세 번째 파라미터(p3)를 보면 마지막 것만 빼고 매번 7개 또는 8개씩을 읽었다.
테이블스페이스에 할당된 익스텐트 크기를 확인해 보면 그 이유를 쉽게 찾을 수 있다.
Extent Size 확인
SQL> select extent_id, block_id, bytes, blocks
2 from dba_extents
3 where owner = USER
4 and segment_name = 'T_PK'
5 and tablespace_name = 'USERS'
6 order by extent_id ;
EXTENT_ID BLOCK_ID BYTES BLOCKS
---------- ---------- ---------- ----------
0 1081 65536 8
1 1089 65536 8
2 1097 65536 8
3 1105 65536 8
4 1113 65536 8
5 1121 65536 8
6 1129 65536 8
7 1137 65536 8
8 1145 65536 8
9 1153 65536 8
10 1673 65536 8
11 1681 65536 8
12 1689 65536 8
13 개의 행이 선택되었습니다.
모든 익스텐트가 8개 블록으로 구성돼 있는 것이 원인이었다.
Multiblock I/O 방식으로 읽더라도 익스텐트 범위를 넘지는 못한다
예를 들어, 모든 익스텐트에 20개 블록이 있고 db_file_multiblock_read_count가 8이면, 익스텐트마다 8, 8, 4개씩 세 번에 걸쳐 읽는다.
익스텐트 크기 때문에 예상보다 조금 더 많은 I/O Call이 발생하긴 했지만, Single Block I/O 때보다 훨씬 적은 양의 I/O Call이 발생하는 것을 알 수 있었다.