튜닝 - SQL 실행 계획 확인하기 : SQL Trace 및 TKPROF

SQL Trace 파일 생성 및 TKPROF 사용
 - 모든 SQL 문장에 대한 추적 파일 생성
   : 인스턴스 레벨 추적(많은 부하 발생 - 비추천)
   : 세션 레벨 추적 (추천)
 - 구문분석, 실행 및 인출 단게에 대한 크기 및 시간 통계 정보
 - 시스템의 전체적인 분석에 필요
 - TKPROF로 추적 파일의 내용 분석
 - 실제 튜닝에서 가장 많이 활용

 - 관련 초기화 파일
   : USER_DUMP_DEST 에 추적 파일 생성 됨
     → 확인하기 SQL> show parameter USER_DUMP_DEST
   : TIMED_STATISTICS = true   → 시간 정보 보기

1. 세션 레벨 추적하기 위해 scott사용자에게 권한 주고 추적하기

SQL> grant alter session to scott;
SQL> conn scott/tiger
SQL> alter session set tracefile_identifier='AAA';
    ▶ 트레이스를 뜰 경우에 파일이름을 찾기 어려우므로 지금부터 뜰 파일에 확장자는 AAA로 줘라

SQL> alter session set sql_trace=true;
SQL> alter session set timed_statistics=true;
 
SQL> select * from emp where empno=790;
    ▶ 따로 화면에 추적된 정보가 나오지 않지만, 초기화 파라메터로 지정한 위치에 저장된다.

 
 
2. 저장되는 경로 확인하기

SQL> show parameter user_dump_dest;
경로나오면 그곳으로 가서 파일 확인해 보기
 
$ cd admin/testdb/udump/
$ ls
파일이름 testdb_ora_2669_AAA.trc
 
$ vi testdb_ora_2669_AAA.trc
내용나오면 분석하면 된다.

하지만, 내용을 확인해보면 알아보기 힘들다.
- 복잡한 내용을 보기 좋게 바꿔주는 프로그램 제공됨 = TKPROF

3. TKPROF 사용하여 확인 할수 있는 형식으로 바꾸기

$ tkprof 원본이름 abc.txt(출력이름아무거나주면됨) explain=scott/tiger sys=no(파싱할때 썼던 recursive calls는 빼라)
 
$ vi abc.txt
결과 분석하면 됨.

 
 

---

위의 내용 실습 :

 

SQL> conn / as sysdba
Connected.
SQL> grant alter session to scott;
 
Grant succeeded.
 
SQL> conn scott/tiger
Connected.
 
SQL> alter session set tracefile_identifier='AAA';
 
Session altered.
 
SQL> alter session set sql_trace = true;
 
Session altered.
 
 
SQL> alter session set timed_statistics=true;
 
Session altered.
 
 
 
 
SQL> select * from student where deptno=101;
 
    STUDNO NAME       USERID     G IDNUM         BIRTHDATE    TEL
---------- ---------- ---------- - ------------- ------------ -------------
    HEIGHT     WEIGHT     DEPTNO     PROFNO
---------- ---------- ---------- ----------
     10101 전인하     jun123     4 7907021369824 02-JUL-79    051)781-2158
       176         72        101       9903
 
     10102 박미경     ansel414   1 8405162123648 16-MAY-84    055)261-8947
       168         52        101
 
     10103 김영균     mandu      3 8103211063421 11-JAN-81    051)824-9637
       170         88        101       9906
 
 
    STUDNO NAME       USERID     G IDNUM         BIRTHDATE    TEL
---------- ---------- ---------- - ------------- ------------ -------------
    HEIGHT     WEIGHT     DEPTNO     PROFNO
---------- ---------- ---------- ----------
     10104 지은경     Gomo00     2 8004122298371 12-APR-80    055)418-9627
       161         42        101       9907
 
     10105 임유진     YouJin12   2 8301212196482 21-JAN-83    02)312-9838
       171         54        101       9907
 
     10106 서재진     seolly     1 8511291186273 29-NOV-85    051)239-4861
       186         72        101
 
 
    STUDNO NAME       USERID     G IDNUM         BIRTHDATE    TEL
---------- ---------- ---------- - ------------- ------------ -------------
    HEIGHT     WEIGHT     DEPTNO     PROFNO
---------- ---------- ---------- ----------
     10107 이광훈     huriky     4 8109131276431 13-OCT-81    055)736-4981
       175         92        101       9903
 
     10108 류민정     cleanSky   2 8108192157498 19-AUG-81    055)248-3679
       162         72        101       9907
 
 
8 rows selected.

 
 

[oracle@rac1 udump]$ pwd
/home/oracle/admin/rac/udump
[oracle@rac1 udump]$ ls
rac1_ora_11500.trc      rac1_ora_17372.trc  rac1_ora_18490.trc  rac1_ora_23934.trc  rac1_ora_27853.trc  rac1_ora_9643.trc
rac1_ora_11918.trc      rac1_ora_1787.trc   rac1_ora_19019.trc  rac1_ora_24014.trc  rac1_ora_3131.trc   rac1_ora_9936.trc
rac1_ora_12316.trc      rac1_ora_18024.trc  rac1_ora_21232.trc  rac1_ora_24791.trc  rac1_ora_664.trc
rac1_ora_15574_AAA.trc  rac1_ora_18466.trc  rac1_ora_22017.trc  rac1_ora_24928.trc  rac1_ora_7893.trc
rac1_ora_16098.trc      rac1_ora_18467.trc  rac1_ora_23593.trc  rac1_ora_24934.trc  rac1_ora_9010.trc

 
 
 

[oracle@rac1 udump]$ tkprof rac1_ora_15574_AAA.trc abc.txt explain=scott/tiger sys=no
 
TKPROF: Release 10.2.0.5.0 - Production on Tue Mar 13 17:28:50 2012
 
Copyright (c) 1982, 2007, Oracle.  All rights reserved.

[oracle@rac1 udump]$ vi abc.txt 
TKPROF: Release 10.2.0.5.0 - Production on Tue Mar 13 17:28:50 2012
 
Copyright (c) 1982, 2007, Oracle.  All rights reserved.
 
Trace file: rac1_ora_15574_AAA.trc
Sort options: default
 
********************************************************************************
count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
********************************************************************************
 
The following statements encountered a error during parse:
 
alter sesion set tim ...
*** 2012-03-13 17:21:48.464
Error encountered: ORA-00940
--------------------------------------------------------------------------------
select * from emp where empno=790
 
Error encountered: ORA-00942
********************************************************************************
 
alter session set sql_trace = true
 
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        0      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        1      0.00       0.00          0          0          0           0
 
Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 29  (SCOTT)
********************************************************************************
 
alter session set timed_statistics=true
 
 
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        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          0           0
 
Misses in library cache during parse: 0
Parsing user id: 29  (SCOTT)
********************************************************************************
 
SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE
  NO_PARALLEL(SAMPLESUB) opt_param('parallel_execution_enabled', 'false')
  NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"),
  NVL(SUM(C2),:"SYS_B_1")
FROM
 (SELECT /*+ IGNORE_WHERE_CLAUSE NO_PARALLEL("STUDENT") FULL("STUDENT")
  NO_PARALLEL_INDEX("STUDENT") */ :"SYS_B_2" AS C1, CASE WHEN
  "STUDENT"."DEPTNO"=:"SYS_B_3" THEN :"SYS_B_4" ELSE :"SYS_B_5" END AS C2
  FROM "STUDENT" "STUDENT") SAMPLESUB
 
 
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        1      0.00       0.00          0          7          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          0          7          0           1
 
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 29  (SCOTT)   (recursive depth: 1)
 
Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SORT AGGREGATE (cr=7 pr=0 pw=0 time=84 us)
     16   TABLE ACCESS FULL STUDENT (cr=7 pr=0 pw=0 time=79 us)
 
 
Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   MODE: HINT: ALL_ROWS
      1   SORT (AGGREGATE)
     16    TABLE ACCESS (FULL) OF 'STUDENT' (TABLE)
 
********************************************************************************
 
select *
from
 student where deptno=101
 
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.02          0         77          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0          8          0           8
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.01       0.02          0         85          0           8
 
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 29  (SCOTT)
 
Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   MODE: ALL_ROWS
      0   TABLE ACCESS (FULL) OF 'STUDENT' (TABLE)
 
 
 
 
********************************************************************************
 
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.01       0.02          0         77          0           0
Execute      3      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0          8          0           8
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        7      0.01       0.03          0         85          0           8
 
Misses in library cache during parse: 1
Misses in library cache during execute: 1
 
 
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse       15      0.00       0.00          0          0          0           0
Execute    165      0.03       0.22          0          0          0           0
Fetch      176      0.01       0.00          0        424          0        1281
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total      356      0.05       0.23          0        424          0        1281
 
Misses in library cache during parse: 11
Misses in library cache during execute: 11
 
    4  user  SQL statements in session.
  164  internal SQL statements in session.
  168  SQL statements in session.
    2  statements EXPLAINed in this session.
********************************************************************************
Trace file: rac1_ora_15574_AAA.trc
Trace file compatibility: 10.01.00
Sort options: default
 
       1  session in tracefile.
       4  user  SQL statements in trace file.
     164  internal SQL statements in trace file.
     168  SQL statements in trace file.
      14  unique SQL statements in trace file.
       2  SQL statements EXPLAINed using schema:
           SCOTT.prof$plan_table
             Default table was used.
             Table was created.
             Table was dropped.
    1456  lines in trace file.
     221  elapsed seconds in trace file.

 
 
===================================================================================================================
 
 

※ 설명 : TKPROF
 
select *
from
 student where deptno=101
 
 
call     count       cpu      elapsed       disk          query     current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.02            0                77          0               0
Execute     1      0.00       0.00            0                0           0               0
Fetch        2      0.00       0.00            0                8            0               8
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total         4       0.01       0.02            0               85           0               8
 
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 29  (SCOTT)
 
Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   MODE: ALL_ROWS
      0   TABLE ACCESS (FULL) OF 'STUDENT' (TABLE)
 
 

call          각단계
count       작업을 한 횟수
cpu          걸린시간(순수한 작업시간)
elapsed    걸린시간(총 소요시간)
              : 둘의 차이가 많이나면 문제있다.(보통 2배이상 차이나면 무조건 기다리는 시간 많다는것을 알수있다.)
    ex) 은행업무 : 가서 기다리고 돈뽑는 총시간 = elapsed, 돈뽑은 시간 = cpu
  ▶ 총 읽은 블락은 query와 current에서 읽은 블락의 합인데, 그중 몇개는 disk에서 읽었다.
disk         블락을 읽은 갯수(disk에서) = query + current중에 disk에서 읽은 블락수
query       블락을 읽은 갯수(DB buffer cache - CR블락에서 읽은 블락)
current     블락을 읽은 갯수(DB buffer cache - 나만 읽을수 있는 블락)
   ex) 홍 update 일 로했을때..
         → 만약 disk 가 0이라면? 디스크에서는 하나도 읽어오지 않았다.
rows        각 처리 단계 별 읽은 총 행수