- 일단 추적 기능이 활성화되면 오라클은 모든 SQL과 애플리케이션이 만든 최상위 수준의 PL/SQL호출을 서버의 추적파일에 기록한다.
- 이 추적파일 자체를 읽기란 매우 어렵다. 우리가 원하는것은 이 추적 파일로부터 사용자에게 친숙한 포멧의 보고서를 생성하는 것이다.
- 추적 파일을 이용하기 쉬운 무언가로 바꾸는 것이 바로 TKPROF의 유일한 목적이다.
TKPROF 활성화
- TKPROF활성화 방법(SQL_TRACE를 켜는 방법)
alter session set timed_statistics=true;
alter session set events '10046 trace name context forever, level 12';
절차
- 1.최소한 세션수준에서 ALTER SESSION SET TIMED_STATISTICS=TRUE 를 활성화 되어야한다.(CPU시간이 보이지 않는다면 경과된 시간이 보이지 않으므로 어디가 병목인지를 알수 없음)
- 2.ALTER SESSION SET SQL_TRACE=TRUE 또는 ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT FOREVER, LEVEL <N>';
<N>은 다음 수들 중의 하나임
1 - 표준 SQL_TRACE 기능을 활성화한다(SQL_TRACE=TRUE와 동일)
4 - SQL_TRACE을 활성화하고 바인드 변수의 값을 추적 파일에 기록한다.
8 - SQL_TRACE을 활성화하고 대기이벤트를 추적 파일에 기록한다.
12 - 표준 SQL_TRACE을 활성화하고 바인드변수와 대기이벤트를 기록한다.
- TKPROF는 바인드 변수 값을 보고 하지 않기 때문에 추적파일 자체가 필요함
- 추적파일에 대기 이벤트가 포함되면 추적파일이 상당히 커질수 있으므로 max_dump_file_size init.ora매개변수가 이들 정보를 수용할 수 있을 만큼 충분히 큰지를 확인
PROD9i > show parameter max_dump
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
max_dump_file_size string UNLIMITED
TKPROF 실행
- TKPROF가 무엇을 제공하고 서버의 추적 파일을 어떻게 액세스하는지를 보여주기 위하여 간단한 테스트, 즉 추적을 활성화하는 스크립트를 실행
주석파일의 생성
- 이 예에서는 ALL_OBJECTS로 부터 생성되어 많은 수의 행을 포함하도록 여러 차례 복사된 BIG_TABLE을 사용할 예정
tkyte@PROD9I> alter session set timed_statistics=true;
세션이 변경되었습니다.
tkyte@PROD9I> alter session set events '10046 trace name context forever, level 12';
세션이 변경되었습니다.
tkyte@PROD9I> select count(*) from big_table
2 /
COUNT(*)
----------
25131
tkyte@PROD9I> select *
2 from big_table
3 where owner = 'SYS'
4 and object_type = 'PACKAGE'
5 and object_name like 'F%'
6 /
선택된 레코드가 없습니다.
주석파일 이름의 획득
- Windows용으로서 Oracle8i와 그이전 버전에서 사용된 표준 8.3파일 이름 규칙을 이용하는 곳에서 사용
select c.value || '\ora' || to_char(a.spid,'fm00000') || '.trc'
from v$process a, v$session b, v$parameter c
where a.addr = b.PADDR
and b.audsid = sys_context('userenv','sessionid')
and c.name = 'user_dump_dest'
/
- 유닉스와 Windows용으로서 Oralce 9i 이상(플랫폼에 종속된 파일 이름 문제를 해결하였다)에서 사용
select rtrim(c.value,'/') || '/'|| d.instance_name ||
'_ora_' || ltrim(to_char(a.spid)) || '.trc'
from v$process a, v$session b, v$parameter c, v$instance d
where a.addr = b.PADDR
and b.audsid = sys_context('userenv','sessionid')
and c.name = 'user_dump_dest'
/
tkyte@PROD9I> select rtrim(c.value,'/') || '/'|| d.instance_name ||
2 '_ora_' || ltrim(to_char(a.spid)) || '.trc'
3 from v$process a, v$session b, v$parameter c, v$instance d
4 where a.addr = b.PADDR
5 and b.audsid = sys_context('userenv','sessionid')
6 and c.name = 'user_dump_dest'
7 /
RTRIM(C.VALUE,'/')||'/'||D.INSTANCE_NAME||'_ORA_'||LTRIM(TO_CHAR(A.SPID))||'.TRC'
--------------------------------------------------------------------------------------------
C:\oracle\admin\PROD9i\udump/prod9i_ora_2196.trc
tkyte@PROD9I>
tkyte@PROD9I> exit
Oracle9i Enterprise Edition Release 9.2.0.8.0 - Production
With the Partitioning, OLAP and Oracle Data Mining options
JServer Release 9.2.0.8.0 - Production에서 분리되었습니다.
C:\Documents and Settings\root\My Documents\Workspace>
- 이를 쿼리를 실행한 후에 SQL*Plus(사용중인 툴)를 빠져나오면서 추적파일을 완전히 닫아서 추적파일의 정보를 이용할 수 있도록함
TKPROF 보고서 생성
C:\oracle\admin\PROD9i\udump>tkprof prod9i_ora_2196.trc tk.prf
TKPROF: Release 9.2.0.8.0 - Production on 금 Aug 22 23:42:07 2008
Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved.
- 이 명령은 현재 작업 디렉토리에 tk.prf라는 텍스트 파일을 만듬
TKPROF 보고서 읽기
select count(*)
from
big_table
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.10 0.08 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 4 0.07 0.38 1100 2544 0 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 8 0.18 0.47 1100 2544 0 2
Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 39
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE
25131 TABLE ACCESS FULL BIG_TABLE
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 4 0.00 0.00
SQL*Net message from client 3 114.51 114.51
db file scattered read 70 0.05 0.32
********************************************************************************
쿼리와 실행 통계
- 보고서는 데이터베이스에 의해 처리된 쿼리의 텍스트로 시작된다.
select count(*) from big_table
- 다음에는 쿼리 자체의 주요 단계별 실행 통계가 테이블 형태로 나타난다.
| 분석(Parse) | 오라클이 공유 풀에서 쿼리를 찾거나(소프트 파스) 새로운 쿼리 계획을 작성하는 단계(하드 파스)이다. |
| 실행(Execute) | 쿼리에 나타난 OPEN또는 EXECUTE문을 보고 오라클이 작업을 수행하는 단계이다. |
| SELECT문의 경우 대부분 공백으로 나타나며 UPDATE문의 경우에는 모든 작업이 수행되는 곳이다. |
| 인출(Fetch) | SELECT 문의 경우에는 대부분의 작업이 수행되어 나타나는 단계이다. |
| UPDATE 문의 경우에는 아무것도 나타나지 않는다(갱신 작업 시에는 인출하지 않아도 된다). |
처리된 모든 문은 이들 세 단계를 거치며 보고서의 맨 위에는 다음과 같은 제목이 나타난다.
| 횟수(Count) | 이 단계가 몇번 수행되었는가를 나타낸다. 적절하게 애플리케이션에서는 모든 SQL에 대해 분석 회수와 실행 횟수가 1또는 2 이상으로 나타난다. |
| CPU | 이 단계에서 소비된 총 CPU 시간으로 1/1000초 단위로 기술된다. |
| 경과(Elapsed) | 이 단계에서 소된 총 벽시계 시간, 경과 시간이 CPU 시간보다 훨씬 큰 경우에는 대기 시간이 존재하였음을 의미한다. |
| 디스크(Disk) | 이 단계에서 수행된 물리적인 I/O의 수를 나타낸다. |
| 쿼리(Query) | 일관된 모드 블록을 인출하기 위하여 수행된 논리적인 I/O의 수를 나타낸다. |
| 이들 블록을 롤백 세그먼트로부터 재구성되었을지도 모르기 때문에 쿼리가 시작될 당시에 이미 존재했을 수도 있다. |
| 일반적으로 모든 물리적인 I/O는 논리적인 I/O를 동반하여 논리적인 I/O의 수가 물리적인 I/O의 수를 능가한다. |
| 그러나 앞쪽의 AUTOTRACE절에서 보았듯이 임시공간에 대한 직접읽기 및 쓰기에는 이 규칙이 적용되지 않는다. |
| 다시 말하면 논리적인 I/O로 변역되지 않는 물리적인 I/O가 존재할 수도 있다. |
| 현재(Cureent) | 지금 현재 블록을 인출하기 위하여 수행된 논리적인 I/O의 수를 나타낸다. 갱신과 삭제같은 수정DML 작업중에는 이들을 흔히 볼수 있다. |
| 테이블에 쿼리를 던질때는 오라클이 쿼리가 시작된 시점을 기준으로 블록을 인출해 오는 것과 달리 수정을 처리하기 위해서는 현재 모드로 블록을 인출하여야 한다. |
| 행(Rows) | 이 과정에서 처리되거나 영향을 받은 행의 수를 나타낸다. 수정중일 때는 실행 과정에 행 값이 나타나며 SELECT 쿼리중에는 인출 과정에 이 값이 나타난다 |
쿼리 환경
- TKPROF 보고서의 다음 절은 쿼리가 실행된 환경을 말해준다.
Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 39
- Misses in library cache during parse: 0은 소프트 파스 수행
- Optimizer goal: CHOOSE는 최적화기 목표가 RBO또는 CBO로 사용될수 있음을 의미
- Parsing user id : 이 쿼리가 파싱될 때 적용된 스키마
tkyte@PROD9I> select * from all_users where user_id = 39;
USERNAME USER_ID CREATED
------------------------------ ---------- --------
TKYTE 39 08/01/14
쿼리 계획
- TKPROF 보고서의 다음절은 이 쿼리가 실행될 때 실제로 이용되었던 쿼리 계획이다.
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=2300 r=2209 w=0 time=2077 us)
1000 TABLE ACCESS FULL OBJ#(30635) (cr=2300 r=2209 w=0 time=1054 us)
| cr | 일관된 모드 읽기로서 일관된 입수(논리적인 I/O)를 보여준다. |
| r | 물리적인 읽기를 나타낸다 |
| w | 물리적인 쓰기를 나타낸다 |
| time | 경과된 시간을 1/1,000,000초 단위로 나타낸다. us는 마이크로초를 나타낸다 |
대기 이벤트
- TKPROF 보고서의 마지막 부분에는 대기 이번트가 온다 (Oracle 9iR1 이상에서 SET EVENT 구문 사용시)
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 4 0.00 0.00
SQL*Net message from client 3 114.51 114.51
db file scattered read 70 0.05 0.32