의 
블로그
Parallel Query와 direct path read, 그리고 LOB
오라클 2009.09.24 16:20 Parallel하게 Table을 읽으면 direct path I/O를 사용합니다. 이것이 일반적인 진실입니다.
하지만, 테이블의 크기가 _small_table_threshold 파라미터 값보다 클 때만 그렇습니다.
NAME VALUE IS_DEFAUL SES_MODIFI ------------------------------ -------------------- --------- ---------- SYS_MODIFI ---------- DESCRIPTION -------------------------------------------------------------------------------- _small_table_threshold 1027 TRUE true deferred threshold level of table size for direct reads즉, 이 시스템에서는 테이블의 크기가 1027 블록보다 클 때만 direct path I/O를 사용합니다. 하지만 테이블의 크기가 그보다 작을 때는 conventional path I/O를 사용합니다. _small_table_threshold 파라미터의 기본값은 Buffer Cache 크기의 5% 정도입니다. 즉 Buffer Cache의 5%보다 큰 테이블에 대해서만 Parallel Query에서 direct path I/O를 사용합니다. Direct path I/O와 관련해서 또 하나의 숨겨진 사실이 있습니다. Out-Of-Row로 저장된 LOB 데이터를 Parallel Query로 읽고자 합니다. 이 LOB 데이터는 Slave Process가 읽을까요, Coordinator Process가 읽을까요? 놀랍게도 정답은 Coordinator Process가 읽는다는 것입니다. 이런 복합적인 사실들을 명확하게 이해하지 못하면 Parallel Query에 대한 10046 트레이스 분석시 치명적인 실수를 하게 됩니다. 아래의 간단한 테스트 결과를 볼까요. 1. _small_table_threshold 파라미터 값이 1027입니다.
UKJA@ukja1021> col value new_value stt UKJA@ukja1021> @para small_table_threshold UKJA@ukja1021> set echo off old 9: and i.ksppinm like '%&1%' new 9: and i.ksppinm like '%small_table_threshold%' NAME VALUE IS_DEFAUL SES_MODIFI ------------------------------ -------------------- --------- ---------- SYS_MODIFI ---------- DESCRIPTION -------------------------------------------------------------------------------- _small_table_threshold 1027 TRUE true deferred threshold level of table size for direct reads2. 테이블의 크기가 1027보다 조금 작게끔 생성합니다.
UKJA@ukja1021> create table t1(c1 int, c2 char(2000), c3 char(2000), c4 char(1000), c5 clob)
2 lob(c5) store as (nocache nologging disable storage in row)
3 ;
Table created.
Elapsed: 00:00:00.15
UKJA@ukja1021>
UKJA@ukja1021> insert into t1
2 select level, 'x', 'x', 'x', rpad('x',4000)
3 from dual
4 connect by level <= &stt - 100
5 ;
old 4: connect by level <= &stt - 100
new 4: connect by level <= 1027 - 100
927 rows created.
Elapsed: 00:00:09.20
UKJA@ukja1021> @gather t1
UKJA@ukja1021> exec dbms_stats.gather_table_stats(user, '&1', no_invalidate=>false);
PL/SQL procedure successfully completed.
Elapsed: 00:00:00.09
UKJA@ukja1021> select table_name, blocks
2 from user_tables
3 where table_name = 'T1';
TABLE_NAME BLOCKS
-------------------- ----------
T1 938
3. 이 테이블에 대해 Parallel Query를 수행합니다. Coordinator Process에서는 Physical I/O가 전혀 발생하지 않습니다.
UKJA@ukja1021> alter system flush buffer_cache;
UKJA@ukja1021> select /*+ parallel(t1 2) small */ * from t1;
select /*+ parallel(t1 2) small */ *
from
t1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.45 1 2 0 0
Fetch 928 0.12 0.27 0 0 0 927
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 930 0.12 0.72 1 2 0 927
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61
Rows Row Source Operation
------- ---------------------------------------------------
927 PX COORDINATOR (cr=2 pr=1 pw=0 time=518856 us)
0 PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
0 PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)
0 TABLE ACCESS FULL T1 (cr=0 pr=0 pw=0 time=0 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 1 0.01 0.01
PX Deq: Parse Reply 3 0.43 0.43
SQL*Net message to client 929 0.00 0.00
SQL*Net message from client 929 0.00 0.13
PX Deq: Execute Reply 271 0.01 0.07
SQL*Net more data to client 2 0.00 0.00
PX qref latch 13 0.00 0.00
PX Deq: Signal ACK 3 0.09 0.10
enq: PS - contention 2 0.00 0.00
********************************************************************************
4. Physical I/O는 Slave Process에서 발생합니다. 하지만 direct path I/O가 아닌 conventional path I/O(db file scattered read 대기이벤트)가 사용된 것을 알 수 있습니다.
select /*+ parallel(t1 2) small */ *
from
t1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.07 27.00 481 507 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.07 27.00 481 507 0 0
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 61 (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
0 PX COORDINATOR (cr=0 pr=0 pw=0 time=0 us)
0 PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
470 PX BLOCK ITERATOR (cr=507 pr=481 pw=0 time=17523 us)
470 TABLE ACCESS FULL T1 (cr=507 pr=481 pw=0 time=166734 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
PX Deq: Execution Msg 15 0.12 0.14
db file scattered read 39 0.02 0.19
PX Deq Credit: send blkd 845 0.19 26.32
PX qref latch 10 0.00 0.00
PX Deq Credit: need buffer 6 0.11 0.24
********************************************************************************
5. 테이블에 데이터를 더 추가해서 _small_table_threshold 값을 살짝 넘게 만듭니다.
UKJA@ukja1021> insert into t1
2 select level, 'x', 'x', 'x', rpad('x',4000)
3 from dual
4 connect by level <= 200
5 ;
200 rows created.
Elapsed: 00:00:01.23
UKJA@ukja1021> @gather t1
UKJA@ukja1021> exec dbms_stats.gather_table_stats(user, '&1', no_invalidate=>false);
PL/SQL procedure successfully completed.
Elapsed: 00:00:00.57
UKJA@ukja1021> select table_name, blocks
2 from user_tables
3 where table_name = 'T1';
TABLE_NAME BLOCKS
-------------------- ----------
T1 1130
6. 다음과 같이 Parallel Query를 수행합니다. 여전히 Coordinator Process에서는 Physical I/O가 관찰되지 않습니다.
select /*+ parallel(t1 2) big */ *
from
t1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.13 1 2 0 0
Fetch 1128 0.09 0.25 0 0 0 1127
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1130 0.09 0.38 1 2 0 1127
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61
Rows Row Source Operation
------- ---------------------------------------------------
1127 PX COORDINATOR (cr=2 pr=1 pw=0 time=222619 us)
0 PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
0 PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)
0 TABLE ACCESS FULL T1 (cr=0 pr=0 pw=0 time=0 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 1 0.00 0.00
PX Deq: Join ACK 2 0.00 0.00
PX Deq: Parse Reply 2 0.12 0.12
SQL*Net message to client 1129 0.00 0.00
SQL*Net message from client 1129 0.00 0.15
PX Deq: Execute Reply 311 0.01 0.02
SQL*Net more data to client 2 0.00 0.00
PX qref latch 12 0.00 0.00
PX Deq: Signal ACK 3 0.10 0.10
enq: PS - contention 2 0.00 0.00
7. 이번에도 Slave Process에서 Physical I/O가 이루어집니다. 단, conventional path I/O가 아닌 direct path I/O(direct path read 대기이벤트)가 이루어진 것을 알 수 있습니다.
select /*+ parallel(t1 2) big */ *
from
t1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.07 28.93 572 585 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.07 28.93 572 585 0 0
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 61 (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
0 PX COORDINATOR (cr=0 pr=0 pw=0 time=0 us)
0 PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
569 PX BLOCK ITERATOR (cr=585 pr=572 pw=0 time=447086 us)
569 TABLE ACCESS FULL T1 (cr=585 pr=572 pw=0 time=327324 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
PX Deq: Execution Msg 15 0.04 0.32
direct path read 51 0.01 0.05
PX Deq Credit: need buffer 7 0.02 0.07
PX Deq Credit: send blkd 1025 0.08 28.38
PX qref latch 27 0.00 0.00
8. 여기서 한가지 더 의문이 있습니다. 테이블을 정의할 때 Out-Of-Row로 LOB을 생성했습니다. 이 LOB에 대한 Physical I/O는 어디로 갔을까요? LOB을 실제로 Fetch하는 것은 Slave Process가 아닌 Coordinator Process입니다. 더불어서 LOB에 대한 Fetch는 #0번의 Internal Cursor를 사용하기 때문에 Coordinator Process가 수행한 Query에 대한 TKPROF 결과에는 보고되지 않습니다. 이 문제는 여기에서 보고한 바 있죠.
따라서 LOB에 대한 direct path I/O에서 발생하는 direct path read 대기이벤트는 Coordinator Process가 남긴 트레이스 파일에 대한 TKPROF 리포트의 요약정보에서만 관찰됩니다.
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 4 0.00 0.00 0 0 0 0 Execute 6 0.00 0.58 2 4 0 0 Fetch 2056 0.21 0.52 0 0 0 2054 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 2066 0.21 1.11 2 4 0 2054 Misses in library cache during parse: 2 Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 6168 0.00 0.02 SQL*Net message from client 6168 0.14 49.16 db file sequential read 20 0.02 0.17 PX Deq: Parse Reply 5 0.43 0.55 PX Deq: Execute Reply 582 0.01 0.10 SQL*Net more data to client 4 0.00 0.00 direct path read 8216 0.04 4.43 PX qref latch 25 0.00 0.00 PX Deq: Signal ACK 6 0.10 0.20 enq: PS - contention 4 0.00 0.00 PX Deq: Join ACK 2 0.00 0.00그 이유는 Coordinator Process에 대한 트레이스 파일 원본을 보면 알 수 있습니다. direct path read가 WAIT #0으로 보고되는 것에 유의해야 합니다.
WAIT #2: nam='PX Deq: Execute Reply' ela= 5 sleeptime/senderid=200 passes=1 p3=0 WAIT #2: nam='PX Deq: Execute Reply' ela= 6 sleeptime/senderid=200 passes=2 p3=0 WAIT #2: nam='PX Deq: Execute Reply' ela= 206 sleeptime/senderid=200 passes=3 p3 WAIT #2: nam='SQL*Net message to client' ela= 4 driver id=1413697536 #bytes=1 p3 FETCH #2:c=0,e=501,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,tim=511204438360 WAIT #2: nam='SQL*Net message from client' ela= 245 driver id=1413697536 #bytes= WAIT #0: nam='direct path read' ela= 5019 file number=9 first dba=23243 block cn WAIT #0: nam='direct path read' ela= 443 file number=9 first dba=23243 block cnt WAIT #0: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3 *** 2009-09-24 15:42:07.328 WAIT #0: nam='SQL*Net message from client' ela= 14753 driver id=1413697536 #byte WAIT #0: nam='direct path read' ela= 253 file number=9 first dba=23243 block cnt WAIT #0: nam='direct path read' ela= 188 file number=9 first dba=23243 block cnt WAIT #0: nam='SQL*Net message to client' ela= 4 driver id=1413697536 #bytes=1 p3 WAIT #0: nam='SQL*Net message from client' ela= 609 driver id=1413697536 #bytes= WAIT #2: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3Parallel Query와 LOB이 같이 사용되면 문제가 상당히 복잡해진다는 것을 알 수 있죠. 대기이벤트를 분석할 때는 언제나 정신을 바짝 차려야 합니다.
'오라클' 카테고리의 다른 글
| Extended Describe (6) | 2009.10.01 |
|---|---|
| Fixed Table에 대한 Query 튜닝하기 (0) | 2009.09.29 |
| Parallel Query와 direct path read, 그리고 LOB (1) | 2009.09.24 |
| SQL*Net message from dblink 이벤트는 Idle인가, Network 문제인가? (1) | 2009.09.18 |
| TKPROF 결과 해석시 조심해야할 함정 - CURSOR #0 (3) | 2009.09.17 |