SQL Trace / TKPROF 의 사용

SQL Trace / TKPROF 의 사용

 

작성일  : 2002-03-09
수정일  : 2004-01-10
작성자  : 강명규
OS      : LINUX kernel 2.4.10(x86)
ORACLE  : 9.0.1 EE
참조문서: Oracle8i Designing and Tuning for Performance

수정내용
3가지 패러미터에 대한 세션내의 설정을 모두 timed_statistics 로 한 것을 각각에 맞게 수정.

[SQL Trace]
실행되는 SQL문장에 대해 분석정보를 제공하므로 사용자(프로그래머,..)가 특정 SQL문장을 
어떻게 사용해야겠다는 가이드라인을 제공해준다. EXPLAIN PLAN과 병행하여 사용하는 것이 좋다.

다음과 같은 분석정보를 제공한다.

parse,execute,fetch수
CPU시간/경과된 시간
물리적/논리적 reads
처리된 로우수
라이브러리 캐쉬 misses
파싱이 발생할 때의 사용자
커밋/롤백



SQL_TRACE와 관련된 패러미터는 3가지가 있고, 모두 동적패러미터(dynamic parameter)이다.

timed_statistics   : CPU시간, 실행시간등 시간에 관련된 정보를 표시하기 위해 사용된다.
                     지속적인 설정을 위해 패러미터파일(init.ora)에 설정하거나 
                     세션에서만 임시로 설정하기 위해 alter session set timed_statistics=true
                  로 사용할 수 있다.

max_dump_file_size : 트레이스파일의 최대 크기(단위: OS블럭수), 문서에는 500이 디폴트라고 했지만
                    실제로는 unlimited였다.
                     지속적인 설정을 위해 패러미터파일(init.ora)에 설정하거나 
                     세션에서만 임시로 설정하기 위해 alter session set max_dump_file_size=500
                  로 사용할 수 있다.

user_dump_dest     : 트레이스파일이 생성될 디렉토리
                     여기서는 /u01/app/oracle/admin/dev/udump라고 가정한다.
                     지속적인 설정을 위해 패러미터파일(init.ora)에 설정하거나 
                     인스턴스에서만 임시로 설정하기 위해 alter system set user_dump_dest=/tmp 로
                 사용할 수 있다.


SQL Trace는 세션레벨 혹은 인스턴스레벨에서 enable될 수 있다.
인스턴스레벨에서 모든 SQL을 트레이스하는 경우는 거의 없으므로
DB응용프로그램에서 사용되는 특정 SQL에 대해서만 트레이스하는 것이 일반적이다.
그리고 트레이스를 enable하는것은 당연히 DB의 부하를 발생하는 것이라 필요할때만
사용하고 평상시의 production환경에서는 disable하는 것이 좋다.

enable : alter session set sql_trace=true 혹은 
         exec dbms_session.set_sql_trace(true)

disable: alter session set sql_trace=false 혹은
         exec dbms_session.set_sql_trace(false)


[TKPROF]
오라클 유틸리티 프로그램으로 OS상에 실행파일로 존재한다.
TKPROF은 SQL Trace가 생성한 트레이스파일을 분석하여 우리가 알아보기 쉬운 출력파일을 생성한다.
SQL문장이 실행될때마다 사용된 리소스량, 시간, 로우수등에 대해 보고한다.


출력예

SQL Trace 사용예제 우선 USER_DUMP_DEST로 지정된 디렉토리내 모든 TRACE파일들을 삭제한다. 삭제하지 않아도 되지만, 이렇게 하는 이유는 SQL_TRACE를 TRUE로 변경시 생성되는 트레이스파일명이 명확하지 않아서이다. 즉, 파일은 USER_DUMP_DEST에 지정된 디렉토리에 생성되지만, 어떤 파일명을 가지는지는 오라클이 지맘대로 알아서 정한다. SQL> create table t 2 as 3 select decode(mod(rownum,2),0,'M','F') gender, all_objects.* 4 from all_objects; 테이블이 생성되었습니다. SQL> create index t_idx on t(gender, object_id); 인덱스가 생성되었습니다. SQL> select count(1) from t; COUNT(1) ---------- 26878 SQL> analyze table t compute statistics 2 for table 3 for all indexes 4 for all indexed columns; 테이블이 분석되었습니다. SQL> alter session set timed_statistics=true; 세션이 변경되었습니다. SQL> alter session set sql_trace=true; 세션이 변경되었습니다. SQL> select * from t t1 where object_id=55; 선택된 레코드가 없습니다. SQL> alter session set sql_trace=false; 세션이 변경되었습니다. SQL> drop table t; 테이블이 삭제되었습니다. SQL> create table t 2 as 3 select chr(mod(rownum,256)) gender, all_objects.* 4 from all_objects; 테이블이 생성되었습니다. SQL> create index t_idx on t(gender, object_id); 인덱스가 생성되었습니다. SQL> analyze table t compute statistics 2 for table 3 for all indexes 4 for all indexed columns; 테이블이 분석되었습니다. SQL> alter session set sql_trace=true; 세션이 변경되었습니다. SQL> select * from t t2 where object_id=55; 선택된 레코드가 없습니다. SQL> alter session set sql_trace=false; 세션이 변경되었습니다. TKPROF 사용예제 위에서 질의했던 것들은 ora_17994.trc라는 트레이스파일에 기록되어 있다. 트레이스파일명은 앞서 말했듯이 파악하기 힘드므로 자~알 찾아야 한다. [oracle@dev2 udump]$ tkprof ora_17994.trc skip_scan_query_report.txt [oracle@dev2 udump]$ cat skip_scan_query_report.txt TKPROF: Release 9.0.1.0.0 - Production on Fri Mar 8 20:39:22 2002 (c) Copyright 2001 Oracle Corporation. All rights reserved. Trace file: ora_17994.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 ******************************************************************************** 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 2 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 Optimizer goal: CHOOSE Parsing user id: 49 ******************************************************************************** select /*+ rule */ bucket_cnt, row_cnt, cache_cnt, null_cnt, timestamp#, sample_size, minimum, maximum, distcnt, lowval, hival, density, col#, spare1, spare2, avgcln from hist_head$ where obj#=:1 and intcol#=:2 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 2 0.00 0.00 0 0 0 0 Execute 24 0.00 0.00 0 0 0 0 Fetch 24 0.00 0.00 0 48 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 50 0.00 0.00 0 48 0 0 Misses in library cache during parse: 0 Optimizer goal: RULE Parsing user id: SYS (recursive depth: 1) ******************************************************************************** ******************************************************************************** alter session set sql_trace=false call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 2 0.00 0.00 0 0 0 0 Execute 2 0.00 0.00 0 0 0 0 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 4 0.00 0.00 0 0 0 0 Misses in library cache during parse: 0 Optimizer goal: CHOOSE Parsing user id: 49 ******************************************************************************** ******************************************************************************** OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 4 0.03 0.02 0 0 0 0 Execute 6 0.00 0.00 0 0 0 0 Fetch 2 0.07 0.06 0 393 18 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 12 0.10 0.09 0 393 18 0 Misses in library cache during parse: 2 OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 2 0.00 0.00 0 0 0 0 Execute 24 0.00 0.00 0 0 0 0 Fetch 24 0.00 0.00 0 48 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 50 0.00 0.00 0 48 0 0 Misses in library cache during parse: 0 6 user SQL statements in session. 2 internal SQL statements in session. 8 SQL statements in session. ******************************************************************************** Trace file: ora_17994.trc Trace file compatibility: 9.00.01 Sort options: default 1 session in tracefile. 6 user SQL statements in trace file. 2 internal SQL statements in trace file. 8 SQL statements in trace file. 5 unique SQL statements in trace file. 118 lines in trace file. Copyleft(C) 명규의 DBAKOREA All rights free