제 4 장 시스템 진단과 튜닝

2.SQL_TRACE(Trace 파일 생성)

SQL_TRACE 는 실행되는 SQL문의 실행통계를 세션(Session)별로 모아서 트레이스(Trace) 파일을 만는다.

{section}{column:width=33%}

SQL_TRACE 에는 다음과 같은 사항들이 포함되어 있다.

■ SQL 파싱(Parsing), 실행(Execute), 페치(Fetch)를 수행한 횟수
■ 수행한 CPU 시간과 경과한(Elapsed) 시간들
■ 물리적(Disk), 논리적(Memory)인 읽기를 수행한 횟수
■ 추출된 로우의 수

{column}{section}

SQL_TRACE에 의해 생성되는 트레이스 파일의 이름은 시스템에 따라서 다르지만 보통 filename.TRC 의 형태를 가진다. 이 파일은 직접 읽을 수가 없으므로 읽을수 있는 상태로 만들기 위해 TKPROF 유틸리티를 실행시켜야 한다.

SQL_TRACE를 수행하는 방법은 각각의 오라클 툴과 사용자 세션들에 따라 다르며 오라클 툴이 아닌 경우에는 조금씩 다를 수 있다.

3.TKPROF(trace 파일 출력)

TKPROF 유틸리티는 SQL_TRACE를 통해 생성된 트레이스 파일을 분석이 가능한 형식으로 전환하여 출력한다.
SQL 문에 대한 실행(Explan Plan) 뿐만 아니라 다양한 옵션(Options)을 이용하여 분석하기 쉬운 형태로 추출시킬 수도 있다.

TKPROF 는 다음의 실행문으로 실행한다.

{section}{column:width=33%}

 
[syntax]

TKPROF tracefile listfile [SORT = parameters]  [PRINT = number]
       [EXPLAN = username/password]

tracefile     : SQL_TRACE 기능에 의해 생성된 통계정보를 가진 트레이스 파일이름
listfile      : TKPROF 가 출력시킬 파일의 이름
                    모든 SQL_TRACE로 모아진 통계값에 대해 파라메터를 지정할 수 있다. 
                 TKPROF는 지정한 파라메터의 통계값에 대한 역순으로 통계를 출력한다. 예)SORT=EXECPU
                 TKPROF는 가장 나쁜 EXECPU 값을 가진 통계값을 먼저 (여기서는 실행 CPU 시간이 많은 SQL 부터)출려해준다.
                 하나 이상의 파라메터를 지정하려면 다음과같이 부여한다.
                 SORT=(FCHDSK, PRSCPU)
PRINT = number : 트레이스 파일별로 출력시킬 sql 문의수. 나쁜 수행속도를 가지는 sql문의 개수를 예상하여 제한하는 것이 좋다.
EXPLAIN = username/password
                해당 트레이스 파일이 수행된 세션의 사용자그룹 및 패스워드를 지정하여야 하며 트레이스 
                   파일내에 있는 각 sql 문에대한 실행계획이 수립되고 저장된다.
                저장된 실행계획에는 각 수행 단계별로 수행된 로우수가 같이 표시되므로 비효율이 발생한 
                   이유 및 그 개선방법을 찾기가 아주 쉬워진다ㅣ.

예:  TKPROF ora_12343.trc trc1.txt  SORT=(EXECPU)  [EXPLAIN = scott/tiger]

{column}{section}

***********************************************************************************************************

tkprof유틸을 이용하여 trace 보려고할때 정렬방법

{section}{column:width=33%}

 

튜닝을 하기 위해서는 먼저 통계정보를 확인한다.

{column}{section}

{section}{column:width=33%}

 

통계정보를 보니 table, index 부분에 distinct 가 100만건이 있는걸 확인할수 있다.

index 를 만드는 목적은 빨리 실행되야하는 이유도 있지만 전체 table에 분포도가 얼마나 차지 하고있는지를 확인하여야한다.

실행계획을 한번 보고 sql_trace를 하는것이 좋다
여기서는 바로 tkprof를 이용하여 sql_trace를 하겠다.

먼저 튜닝해야할 부분 쿼리를 날려본다.

{column}{section}

{section}{column:width=33%}

 
*********************************************************************************************************
11.스크립트 기록.txt

SQL*Plus: Release 10.2.0.1.0 - Production on Thu Nov 8 19:51:30 2007

Copyright (c) 1982, 2005, Oracle.  All rights reserved.


Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.2.0 - 64bit Production
With the Partitioning, Real Application Clusters, OLAP and Data Mining options

SQL> CREATE TABLE XSOFT_TEMP(ORDER_DATE   VARCHAR2(8),
  2                          ORDER_NUMBER NUMBER);

Table created.

SQL> INSERT INTO XSOFT_TEMP
  2  SELECT TO_CHAR(TO_DATE('10000101', 'YYYYMMDD') + LEVEL - 1, 'YYYYMMDD') ORDER_DATE
  3       , TRUNC(LEVEL / 10) + 100                                          ORDER_NUMBER
  4  FROM   DUAL
  5  CONNECT BY LEVEL <= 1000000;

1000000 rows created.

SQL> CREATE INDEX APPS.XSOFT_TEMP_N1 ON APPS.XSOFT_TEMP (ORDER_DATE, ORDER_NUMBER)
  2  TABLESPACE APPS_TS_TX_DATA COMPUTE STATISTICS PARALLEL 6;

Index created.

SQL> ALTER INDEX APPS.XSOFT_TEMP_N1 NOPARALLEL;

Index altered.

SQL> CREATE INDEX APPS.XSOFT_TEMP_N2 ON APPS.XSOFT_TEMP (ORDER_NUMBER, ORDER_DATE)
  2  TABLESPACE APPS_TS_TX_DATA COMPUTE STATISTICS PARALLEL 6;

Index created.

SQL> ALTER INDEX APPS.XSOFT_TEMP_N2 NOPARALLEL;

Index altered.

SQL> BEGIN
  2      DBMS_STATS.GATHER_TABLE_STATS('APPS',           -- OWNER
  3                                    'XSOFT_TEMP',     -- TABLE_NAME
  4                                    CASCADE => TRUE);
  5  END;
  6  /

PL/SQL procedure successfully completed.

SQL> SELECT P.SPID SERVER
  2  FROM   V$PROCESS P,
  3         V$SESSION S
  4  WHERE  P.ADDR = S.PADDR
  5  AND    S.AUDSID = USERENV('SESSIONID');

SERVER
------------------------
435616

SQL> ALTER SESSION SET MAX_DUMP_FILE_SIZE=UNLIMITED;

Session altered.

SQL> 
SQL> ALTER SESSION SET SQL_TRACE=TRUE;

Session altered.

SQL> 
SQL> SET TERMOUT OFF;
SQL> /

Session altered.

SQL> SELECT /*+ INDEX(XSOFT_TEMP XSOFT_TEMP_N1) */
  2         *
  3  FROM   XSOFT_TEMP
  4  WHERE  ORDER_DATE BETWEEN '20000101' AND '30000101'
  5  AND    ORDER_NUMBER = 50000;

ORDER_DATE       ORDER_NUMBER
---------------- ------------
23660325                50000
23660326                50000
23660327                50000
23660328                50000
23660329                50000
23660330                50000
23660331                50000
23660401                50000
23660402                50000
23660403                50000

10 rows selected.

SQL> ALTER SESSION SET SQL_TRACE=FALSE;

Session altered.

SQL > EXIT;
*********************************************************************************************************

{column}{section}

{section}{column:width=33%}

 


*$ORACLE_HOME\admin\kdohee\udump* 에 TRC파일이 있는걸 확인할수있다.
가장 처음에 기록된걸 TKPROF를 이용하여 실행한다.

!tkprof_trans.jpg!

이때 여기서 명령어를 칠때 맨 마지막에 sort=fchela 를 하였는데 이는 패치를 하는데 걸린 실제 소요시간을 말한다 
이렇게 옵션을 준다.


|TKPROF: Release 10.2.0.1.0 - Production on Thu Nov 8 20:11:01 2007

Copyright (c) 1982, 2005, Oracle.  All rights reserved.

Trace file: intg41_ora_435616.trc
Sort options: fchela  
********************************************************************************
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
********************************************************************************

SELECT /*+ INDEX(XSOFT_TEMP XSOFT_TEMP_N1) */
       *
FROM   XSOFT_TEMP
WHERE  ORDER_DATE BETWEEN '20000101' AND '30000101'
AND    ORDER_NUMBER = 50000

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.63       1276       1277          0          10
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.26       0.64       1276       1277          0          10

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 44  

Rows     Row Source Operation
-------  ---------------------------------------------------
     10  INDEX RANGE SCAN XSOFT_TEMP_N1 (cr=1277 pr=1276 pw=0 time=242396 us)(object id 844722)

********************************************************************************|

Row Source Operation을 보니 INDEX RANGE SCAN을 탄것을 볼수있다.
10건을 추출하는데 걸리는 시간은 0.26초걸리고 실제로 쿼리문이 돌면서 걸린시간은 0.64초가 걸렸다.
한번 PARSE하고 Fetch는 2번 했다 이는 운반단위가 두번 움직였다는걸 볼수있다.

{column}{section}

참고자료

• 오라클클럽
• 대용량 데이터베이스 솔루션1 제4장 시스템 진단과 튜닝
• 4조 강정식 오빠 조장

문서에 대하여

• 최초작성자 : 김도희
• 최초작성일 : 2007년 11월 9일
• 이 문서는 오라클클럽 대용량 데이터베이스 솔루션1 제4장 시스템 진단과 튜닝 모임에서 작성하였습니다.