h1.02.AutoTrace
h3.준비

  • AutoTrace를 실행계획 확인용으로만 사용한다면 plan_table만 생성되어있으면 된다.
  • 실행통계까지 함께 확인하려면 v_$sesstat, v_$statname, v_$mystat 뷰에 대한 읽기 권한이 필요하다. 읽기 권한이 없다면 다음을 실행

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.사용

  • AutoTrace 사용법은 다음과 같다.

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 항목 설명

  • acess predicate : block을 읽기 전 어떠한 방법으로 block을 읽을 것인가 결정하는 데 쓰인 조건
  • filter predicate : block을 읽은 후 data를 filtering 하기 위해 사용된 조건

테스트를 해보자.

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 : 해당 쿼리를 수행하기 위해 추가적으로 수행되는 SQL 건수
  • db block gets : cache에서 current mode(블럭의 제일 마지막 버전, SCN 미확인)로 읽은 block의 수
  • consistent gets : cache에서 consistent mode(쿼리가 수행된 시점의 버전, SCN 확인)로 읽은 block의 수
  • physical reads : disk에서 읽어온 block의 수
  • redo size : 해당 쿼리를 수행하면서 생성된 redo의 byte 크기
  • bytes sent via SQL*Net to client : 백그라운드 프로세스에서 client에게 보낸 byte 크기
  • bytes received via SQL*Net from client : Oracle Net을 통해 client에서 보낸 byte 크기
  • SQL*Net roundtrips to/from client : client에게로 보내지거나 client에서 보낸 Oracle Net 메시지수
  • sorts (memory) : disk를 쓰지 않고 메모리상에서만 수행된 sort수
  • sorts (disk) : 최소 하나 이상의 disk 쓰기를 요청해서 처리한 sort수
  • rows processed : 수행된 row 수

--------------------------------------------------------------------------------------------------------------------
* 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.옵션

  • AutoTrace 옵션은 다음과 같다.
옵션실제수행여부수행결과표시실행계획표시실행통계표시
set autotrace onOOOO
set autotrace on explainOOO
set autotrace on statisticsOOO
set autotrace traceonlyOOO
set autotrace traceonly explainO
set autotrace traceonly statisticsOO