h1.02.AutoTrace
h3.준비
SQL> @?/sqlplus/admin/plustrce.sql
SQL> grant plustrace to 스키마명;
plustrce.sql 내용은 다음과 같다.
drop role plustrace;
create role plustrace;
grant select on v_$sesstat to plustrace;
grant select on v_$statname to plustrace;
grant select on v_$mystat to plustrace;
grant plustrace to dba with admin option;
h3.사용
SQL> set autotrace on
SQL> select col1 from test_table1 where col1 = '20161172280234001';
COL1
------------------------------------
20161172280234001
Execution Plan
----------------------------------------------------------
Plan hash value: 11495898
------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 18 | 1 (0)| 00:00:01 |
|* 1 | INDEX UNIQUE SCAN| TEST_TABLE1_PK | 1 | 18 | 1 (0)| 00:00:01 |
------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - access("COL1"='20161172280234001')
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
2 consistent gets
0 physical reads
0 redo size
253 bytes sent via SQL*Net to client
252 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
1 rows processed
SQL> set autotrace off
Predicate Information 항목 설명
테스트를 해보자.
test_table1 테이블의 pk => col1
test_table2 테이블의 pk => col1, col2
SQL> select a.col1, b.col2
2 from test_table1 a
3 , test_table2 b
4 where a.col1 = b.col1
5 and a.col1 = '20150500603904001'
6 and b.col3 = 38;
COL1 COL2
------------------------------------ ----------
20150500603904001 39
Execution Plan
----------------------------------------------------------
Plan hash value: 4128140013
-----------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-----------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 44 | 6 (0)| 00:00:01 |
| 1 | NESTED LOOPS | | 1 | 44 | 6 (0)| 00:00:01 |
|* 2 | INDEX UNIQUE SCAN | TEST_TABLE1_PK | 1 | 18 | 1 (0)| 00:00:01 |
|* 3 | TABLE ACCESS BY INDEX ROWID| TEST_TABLE2 | 1 | 26 | 5 (0)| 00:00:01 |
|* 4 | INDEX RANGE SCAN | TEST_TABLE2_PK | 40 | | 1 (0)| 00:00:01 |
-----------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("A"."COL1"='20150500603904001')
3 - filter("B"."COL3"=38)
4 - access("B"."COL1"='20150500603904001')
분석)
실행순서 2->4->3->1->0
2.TEST_TABLE1_PK index를 INDEX UNIQUE SCAN 한다.
이때 Predicate Information 을 보면
access("A"."COL1"='20150500603904001')
즉, TEST_TABLE1_PK index 블럭을 접근하기 위한 조건으로 col1 = '20150500603904001'이 사용되었다.
4.TEST_TABLE1이 driving 테이블이 되고 해당 블럭을 찾기 위해
TEST_TABLE2_PK index를 INDEX RANGE SCAN 한다.
이때 Predicate Information 을 보면
access("A"."COL1"='20150500603904001')
TEST_TABLE2_PK index 블럭을 접근하기 위한 조건으로 co1 = '20150500603904001'이 사용되었다.
3.col3은 index 항목이 아니므로 TEST_TABLE2로 접근한다.
이때 Predicate Information 을 보면
filter("B"."COL3"=38)
해당 테이블 블럭을 모두 읽은 후 col3 = 38 조건으로 데이터를 필터링한다.
Statistics 항목 설명
--------------------------------------------------------------------------------------------------------------------
* recursive calls TEST
--------------------------------------------------------------------------------------------------------------------
recursive calls 는 사용자가 수행한 SQL 이외에 시스템에서 자동적으로 수행한 SQL로
수행하려고 하는 SQL을 파싱하기 위해 딕셔너리에 해당 SQL이 존재하는지 등을 체크할 때 발생하기도 하며
사용자가 정의한 트리거 등에 의해서도 발생하기도 한다.
테스트를 해보자.
SQL> SET AUTOTRACE TRACEONLY STATISTICS
SQL> UPDATE TEST_TABLE1
2 SET COL3 = '1'
3 WHERE COL1 = '20160718578354013';
1 행이 갱신되었습니다.
Statistics
----------------------------------------------------------
0 recursive calls
1 db block gets
2 consistent gets
0 physical reads
280 redo size
399 bytes sent via SQL*Net to client
363 bytes received via SQL*Net from client
3 SQL*Net roundtrips to/from client
1 sorts (memory)
0 sorts (disk)
1 rows processed
SQL> COMMIT;
커밋이 완료되었습니다.
트리거 생성
CREATE OR REPLACE TRIGGER TEST_TABLE1
AFTER UPDATE OF COL3 ON TEST_TABLE1
FOR EACH ROW
BEGIN
UPDATE TEST_TABLE2
SET COL4 = :NEW.COL3
WHERE COL1 = :NEW.COL1;
UPDATE TEST_TABLE2
SET COL5 = :NEW.COL3
WHERE COL1 = :NEW.COL1;
UPDATE TEST_TABLE2
SET COL6 = :NEW.COL3
WHERE COL1 = :NEW.COL1;
END;
SQL> UPDATE TEST_TABLE1
2 SET COL3 = '1'
3 WHERE COL1 = '20160718578354013';
1 행이 갱신되었습니다.
Statistics
----------------------------------------------------------
7 recursive calls
51 db block gets
20 consistent gets
0 physical reads
50984 redo size
399 bytes sent via SQL*Net to client
363 bytes received via SQL*Net from client
3 SQL*Net roundtrips to/from client
2 sorts (memory)
0 sorts (disk)
1 rows processed
SQL> COMMIT;
커밋이 완료되었습니다.
7 recursive calls이 되었다. 트리거 이외에 뭔가 더 수행된 것 같다.
다시 한번 수행해보자.
SQL> UPDATE TEST_TABLE1
2 SET COL3 = '1'
3 WHERE COL1 = '20160718578354013';
1 행이 갱신되었습니다.
Statistics
----------------------------------------------------------
3 recursive calls
51 db block gets
9 consistent gets
0 physical reads
50936 redo size
399 bytes sent via SQL*Net to client
363 bytes received via SQL*Net from client
3 SQL*Net roundtrips to/from client
1 sorts (memory)
0 sorts (disk)
1 rows processed
SQL> COMMIT;
커밋이 완료되었습니다.
TRIGGER에 의해 발생된 것으로 보이는 3 recursive calls 가 발생하였다.
몇 차례 더 수행해보니 상황에 따라 recursive calls가 올라가기도 했으나
3 recursive calls 이하로는 줄어들지 않는다.
--------------------------------------------------------------------------------------------------------------------
* db block gets && consistent gets TEST
--------------------------------------------------------------------------------------------------------------------
* 스칼라서브쿼리는 특별한 이유가 없는 한 항상 consistent 모드로 읽기를 수행한다.
다만 update 문에서 update해야할 컬럼값을 스칼라서브쿼리에서 참조하게 되면
스칼라서브쿼리도 current 모드로 수행된다.
-- consistent모드로 update문을 수행해본다.
SQL> update test_table2 a
2 set a.col2 = a.col2 + (select sum(b.col17) from test_table1 b where b.col1 = a.col1)
3 where a.col1 = '20150500603904001';
52 행이 갱신되었습니다.
Statistics
----------------------------------------------------------
0 recursive calls
154 db block gets
6 consistent gets
0 physical reads
26776 redo size
399 bytes sent via SQL*Net to client
455 bytes received via SQL*Net from client
3 SQL*Net roundtrips to/from client
2 sorts (memory)
0 sorts (disk)
52 rows processed
SQL> commit;
-- current 모드로 update문을 수행해본다.
SQL> update test_table2 a
2 set a.col2 = (select a.col2 + sum(b.col17) from test_table1 b where b.col1 = a.col1)
3 where a.col1 = '20150500603904001';
52 행이 갱신되었습니다.
Statistics
----------------------------------------------------------
0 recursive calls
208 db block gets
112 consistent gets
0 physical reads
38488 redo size
398 bytes sent via SQL*Net to client
456 bytes received via SQL*Net from client
3 SQL*Net roundtrips to/from client
2 sorts (memory)
0 sorts (disk)
52 rows processed
SQL> commit;
current 모드로 update할 때 평균적으로 높은 db block gets 을 볼 수 있었다.
col2를 update해야하는 시점에 test_table1의 col17 컬럼도 current 모드로 읽었음을 알 수 있다.
그런데 current 모드에서 consistent gets는 왜 같이 올라간 걸까?
consistent 모드일 때 실행계획을 보면
Rows Row Source Operation
------- ---------------------------------------------------
0 UPDATE TEST_TABLE2 (cr=6 pr=0 pw=0 time=1424 us)
52 INDEX RANGE SCAN TEST_TABLE2_PK (cr=3 pr=0 pw=0 time=102 us cost=2 size=198 card=9)(object id 353490)
1 SORT AGGREGATE (cr=3 pr=0 pw=0 time=25 us)
1 TABLE ACCESS BY INDEX ROWID TEST_TABLE1 (cr=3 pr=0 pw=0 time=20 us cost=2 size=21 card=1)
1 INDEX UNIQUE SCAN TEST_TABLE1_PK (cr=2 pr=0 pw=0 time=12 us cost=1 size=0 card=1)(object id 353488)
current 모드일 때 실행계획을 보면
Rows Row Source Operation
------- ---------------------------------------------------
0 UPDATE TEST_TABLE2 (cr=112 pr=0 pw=0 time=2151 us)
52 INDEX RANGE SCAN TEST_TABLE2_PK (cr=3 pr=0 pw=0 time=93 us cost=2 size=198 card=9)(object id 353490)
52 SORT AGGREGATE (cr=109 pr=0 pw=0 time=379 us)
52 TABLE ACCESS BY INDEX ROWID TEST_TABLE1 (cr=109 pr=0 pw=0 time=265 us cost=2 size=21 card=1)
52 INDEX UNIQUE SCAN TEST_TABLE1_PK (cr=57 pr=0 pw=0 time=141 us cost=1 size=0 card=1)(object id 353488)
current 모드에서 INDEX UNIQUE SCAN TEST_TABLE1_PK 에서 가지고온 row 수가 52인 반면
consistent 모드일 때는 1이다.
위 상황으로 유추하여 볼 때
consistent 모드일 때는 쿼리가 수행하는 시점에 1회에 한하여 test_table1의 col17 sum한 값을
가지고 왔고 test_table2의 각 row를 업데이트할 때 해당 값을 재사용했다는 것을 알 수 있다.
test_tabl1에 1회만 접근하였으므로 consistent gets는 6에서 멈춘다.
반면 current 모드일 때는 test_table2의 각 row를 update하는 매 순간 test_table1의 col17값을
가지고 온 것을 알 수 있다. 여러회 반복하여 test_table1에 접근하였으므로 consistent 값도
같이 올라간 것이다.
--------------------------------------------------------------------------------------------------------------------
* physical reads TEST
--------------------------------------------------------------------------------------------------------------------
SQL> select count(1) from aibakort201310;
Statistics
----------------------------------------------------------
1 recursive calls
0 db block gets
3889 consistent gets
3883 physical reads
0 redo size
243 bytes sent via SQL*Net to client
251 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
1 rows processed
SQL> select count(1) from aibakort201310;
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
3889 consistent gets
0 physical reads
0 redo size
243 bytes sent via SQL*Net to client
251 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
1 rows processed
--동일한 데이터에 대해 2번째 요청을 할 때는 디스크가 아닌 메모리로부터 불러오는 것을 알 수 있다.
h3.옵션
옵션 | 실제수행여부 | 수행결과표시 | 실행계획표시 | 실행통계표시 |
---|---|---|---|---|
set autotrace on | O | O | O | O |
set autotrace on explain | O | O | O | |
set autotrace on statistics | O | O | O | |
set autotrace traceonly | O | O | O | |
set autotrace traceonly explain | O | |||
set autotrace traceonly statistics | O | O |