세션 수행을 트레이싱 하는것은 애플리케이션 튜닝 방법중 가장 강력한 방법이다. 오라클의 SQL tracing 기능은 세션이나 세션그룹으로 부터 수행된 모든 활동을 캡쳐하도록 지원하고 있고, 튜닝 시점의 확인 및 보틀넥 지점을 식별할수 있도록 해준다. 이러한 기능은 당연히 TOAD DBA 슈트에 포함되어 있다.
오라클의 트레이싱 기능은 다음 2가지 컴포넌트로 구성되어 있다.
- 현재 작업하고 있는 세션 혹은 다른 세션상에서 초기 트레이싱 작업 수행 가능하도록 설정
- tkprof 툴 : 트레이싱된 파일을 의미있는 방법으로 읽기 할 수 있도록 포매팅 생성
SQL 트레이스 기능과 tkprof 기능은 강력한 튜닝 조합이다. 그러나 미숙하게 사용하거나, 해석을 하는데 어려움을 겪는 이가 있다. 그래서 아마도 이 툴을 널리 사용하지 못하고 있는듯 하다. 어쨌든 SQL 트레이싱 기능은, SQL 구문 튜닝을 위한 가장 강력하고, 광범위하게 사용되는 튜닝 도구이다.
SQL 트레이스 시작하기
SQL 트레이스를 시작하는 방법은 다야한 방법이 있다.
- 애플리케이션 코드에 명령어로 실행하는 방법
- 다른 세션에서 트레이싱을 위한 커맨드를 내리는 방법
- DBMS_MONITOR 패키지 호출을 통해 틀정 세션으로 트레이싱 하기
- 개인적인 이용을 위해 로그인 트리거를 생성하여 트레이싱 실행하기
현재 세션에서 트레이싱 하기
가장 간단한 방법으로, 다음 명령어를 통해서 당신의 세션에서 트레이싱을 수행할 수 있다.
ALTER SESSION SET SQL_TRACE TRUE;
이것은 "basic"트레이싱을 생성하는 것으로 SQL구문을 수행하고 통계치와 실행 계획을 레코딩하도록 한다. 그러나 바인드 변수의 값은 수집하지 않는다. 또한 다양한 이벤트를 통해서 대기 시간을 소비한 항목에 대해서도 수집하지 않는다. 좀더 admvanced 한 트레잇를 위해서는 DBMS_SESSION 패키지를 이용할 수 있다.
DBMS_SESSION.session_trace_enable (
waits IN BOOLEAN DEFAULT TRUE,
binds IN BOOLEAN DEFAULT FALSE,
plan_stat IN VARCHAR2 DEFAULT NULL –-11g Only
);
DBMS_SESSION.SESSION_TRACE_ENABLE 을 위한 파라미터에 대한 설명은 다음과 같다.
| WAITS |
TRUE 로 설정하면 대기 정보를 수집한다. FALSE를 하면 수집하지 않는다. |
| BINDS |
TRUE 로 설정하면 바인드 정보를 수집한다. FALSE는 수집하지 않는다. |
| PLAN_STAT |
11g에서, 개별적인 플랜 단계를 위한 로 카운트를 수집한다. 여기에 들어올 수 있는 변수값은 "never", "first_execution", "all_execution"값 들이다. |
다음 인스턴스는 트레이싱을 시작할때, 대기정보 포함, 바인드정보 미 포함, 모든 실행을 위한 통합된 로 카운트 정보 포함하기 설정으로 트레이싱을 시작한다.
For instance, the following command will commence tracing, will include wait information, will not include bind information and will include step row counts aggregated for all executions:
BEGIN
DBMS_SESSION.session_trace_enable (waits => TRUE,
binds => FALSE,
plan_stat => 'all_executions'
);
END;
트레이싱 상태값 수집
V$SESSION 에서는 SQL_TRACE, SQL_TRACE_WAIT, SQL_TRACE_BINDS 칼럼이 있으며, 세션의 트레이싱 상태를 보여준다. V$SESSION 에서 TRACEID와 TRACEFILE 칼럼은 트레이싱 파일의 이름을 보여준다. 그리고 주어진 서버 프로세스의 RACEFILE_IDENTIFIER 정보를 알려준다.
다음 쿼리(11g only)는 현재 세션의 이러한 칼럼 값을 보여준다.
SQL> SELECT s.sql_trace, s.sql_trace_waits, s.sql_trace_binds,
2 traceid, tracefile
3 FROM v$session s JOIN v$process p ON (p.addr = s.paddr)
4 WHERE audsid = USERENV ('SESSIONID')
5 /
SQL_TRACE SQL_TRACE_WAITS SQL_TRACE_BINDS TRACEID
---------- ---------------- ---------------- ----------
TRACEFILE
----------------------------------------------------------------------
ENABLED TRUE FALSE GUY
/oracle/diag/rdbms/gh11r1ga/gh11R1GA/trace/gh11R1GA_ora_32200_GUY.trc
Tkprof를 통한 트레이스 포맷하기
일단 트레이스 파일이 만들어지면 tkprof 유틸리티는 이용가능한 형태로 렌더링 해준다. 기본적인 문법은 다음과 같다.
tkprof trace_file output_file
explain=connection waits=yes|no sort=(sort options)
Where:
| trace_file |
SQL_TRACE 기능을 이용하여 생성된 RAW 트레이스 파일 |
| output_file |
포맷 결과가 쓰여질 대상 파일 |
| Explain=connection |
커넥션 파라미터를 이용하여 오라클에 접속하기 위한 정보와 각 구문을 위한 실행계획 생성을
수행하도록 한다. 이것은 트레이스 파일이 실행 계획을 포함하고 있지 않을때만 필요하다. |
| Waits=yes/no |
각 SQL의 대기 정보의 요약정보를 제공한다. |
| sort=(sort keys) |
표현할 SQL구문을 소트 키에 따라서 소팅을 수행한다. 소트 키는 (prsela, exeela, fchela)가 온다. |
일반적인 tkprof 는 다음 처럼 호출할 수 있다.
$ tkprof mysid_ora_31429.trc tkprof_out1.prf explain=guy/guy
sort='(prsela,fchela,exeela)'
대상 raw 파일은 mysid_ora_31429.trc라는 파일이며, 출력 파일은 tkprof_out1.prf 이다. 이것은 guy라는 계졍으로 수행된 실행계획을 표현하고, 처리된 시간에 따라 각각 항목이 소팅된다. 이 예제는 리눅스에서 수행된 내용이며, 괄호값은 단일 쿼테이션 마크 ' 로 쌓였음을 확인하자. 윈도우에서는 이렇게 적을 필요가 없다.
Tkprof 출력
Tkprof는 각 SQL 구문을 위한 실행 통계정보를 포함하고, 몇가지 요약정보를 생성한다.
Tkprof 출력은 처음부터 조금 어렵게 보인다. 그렇지만 다음 예제를 통해서 하나하나 살펴보자. 그림 1은 tkprof 출력의 샘플을 보여준다.
Figure 1 Sample tkprof output
이제 tkprof 출력 부분을 상세하게 알아보자. 각 항목에는 위 첨자를 붙여 두었고 이것을 이용해서 각각을 설명하도록 한다.
i) SQL 텍스트는 (1)에 표시된다.
ii) 다음에 보이는 테이블 항목은 실행된 통계정보를 보여준다.
- 각 카테고리에서 수행된 회수를 나타낸다. (2).
- 요청된 CPU 시간을 나타낸다. (3).
- 요청된 사항이 수행된 시간 (4).
- 물리적 디스크 읽기 회수 (5)
- (6) query(consistent 모드 : 읽기 일관성 모드로, select에서 주로 읽는 영역)에서 버퍼 read 회수,
(7) current(dirty block : 즉, 값이 변경되었지만(update, delete 등) 아직 물리적인 쓰기가 이루어 지지 않은 블록 버퍼 읽기를 나타낸다.
## (이 아티클의 저자는 이 2가지 query, current 모드 읽기를 특별하게 구분짓지 않는다. 이 두개의 모드가 SQL 튜닝에서는 중요한 팩터로 작용하지 않는다고 말하고 있다. 이러한 두가지 읽기를 "logical read"라고 한다.)
- 처리된 row수 (8).
iii) 아래 테이블은 오라클이 쿼리를 수행할때 처리되는 각각의 부분을 카테고리로 나누어 측정하는 부분들이다. 3개의 카테고리가 있으며 다음과 같다.
- Parse (a) : 각 SQL구문의 문법을 체크하고, 적절한 object를 이용하는지, 보안은 적절한지, 그리고 옵티마이저에 의해서 선택되어진 실행 계획을 결정하도록 하는 처리를 한다.
- Execute (b) : SQL 구문이 수행된 결과이며, 첫번째 페치를 위해 준비 수행정보를 나타낸다. FOR UPDATE를 수행한 쿼리나, 실제적으로 각 로 추출을 위한 소트 수행 등이 이 지점에서 처리된다.
- Fetch (c) : 퀴리 수행결과로 부터 실제 데이터를 반환하는 작업
우리는 SQL 구문의 효율성을 지금 보이는 출력에 나타난 ratio 정보를 통해서 다루게 된다. 이러한 중요한 ratio들은 다음과 같다.
- Blocks read : (f와 g) 이 두값과 처리된 row를 나타내는 (h). 이 값들은 쿼리를 수행하기 위한 비용과 연관이 있다. 해당 로를 반환하기 위해서 많은 블록을 읽었다고 한다면 각 로는 "expensive:비싸다" 라는 의미이다. 이와 유사한 ratio 값은 block read를 (f와 g)수행하기 위해서 execution 값인 (e) 항목과 연관을 고려해 보면 된다.
- Parse count : (d) 는 이론상 parse count는 1에 가까운 것이좋다. 만약 execution count 와 비교해 봤을때 높은값이 나온다면 이것은 불필요한 재 파싱이 이루어 지고 있다는 것이다.
- Rows fetched : 패치된 로 수(i) 는 패치를 (j) 수행한 결과 로수를 의미한다. 이것은 array fetch 수행 레벨을 가리키며, 수행된 패치값을 기준으로 나타낼 수 있다. (here 에서 array processing 에 대해서 확인할 수 있다.).
- Disk reads : 디스크 읽기(k) 는 논리적 읽기를 (f g) 수행한 결과로 부터 나온다. 이 값은 "miss rate"의 측정값으로 데이터 버퍼캐시 적중과 관련되어 있다.
TkProf 실행 계획
이 예제에서 보는것과 같이 실행 계획이 2번 보이는것을 알 수 있다. 첫번째 실행계획(o)은 구문이 닫힐때 트레이스 파일에 저장된 정보를 바탕으로 생성된 것이다. 이 실행계획은 EXPLAIN PLAN 구문의 출력을 이용해서 생성된 것이 아니며, 실행 시간에 실제 수행된 계획을 나타낸 것이다. 이것은 EXPLAIN PLAN을 통해서 생성된 가능성 있는 계획보다 더 정확한 플랜이다.
- 실행계획은 OPTIMIZER_GOAL, PARALLEL MDS ENABLED, SORT_AREA_SIZE등과 같은 파라미터 값에 따라 영향을 받게 된다. Tkprof는 EXPLAIN PLAN을 수행할때 각 계졍으로 이러한 설정값을 받을 수 없다.
- tkprof를 수행이 너무 오래 걸리면, 테이블 통계는 다른 실행계획이 충분히 수행될 수 있도록 변경되어야 하며, 다른 EXPLAIN PLAN이 생성될 것이다.
가끔 "REAL" 실행계획은 보여주지 않을때도 있다. 왜냐하면 SQL 구문이 종료되기 전에 Tkprof가 닫혀버릴 때도 있기 때문이다.양쪽의 실행계획은 스텝 (m)과 각 스텝이 실행될때 row수를 나타내는 (l)에서 나타난다. 로 카운트(l)은 스텝에서 가장큰 작업을 의미하고, 향후 가장 효과적인 튜닝을 위한 자료로 사용될 수 있다.
tkprof에서 보여지는 각 스텝의 상세한 통계정보는 다소 이해하기 어려운 형식으로 되어 있다. 각 스텝에서 나타나는 정보는 다음과 같이 해석할 수 있다.
(cr=49754 pr=49749 time=296110 us cost=13766 size=10458 card=747)
각 통계치는 단축된 용어를 이용하여 표시하는데 그 단축된 표현의 의미는 다음과 같다.
| cr: |
consistent 데이터 블록 읽기 처리 수행횟수 (논리적 읽기) |
| pr: |
물리적 읽기 처리 회수 |
| time: |
microseconds 단위로 한 스텝이 처리되기까지 소모된 시간 |
| cost: |
현재 스텝에서 옵티마이저 비용 |
| size: |
현재 스텝에서 처리된 바이트 수 |
| card: |
현재 스텝에서 처리된 row 수
Number of rows processed by the step |
11g에서 DBMS_SESSION.SESSION_TRACE_ENABLE혹은 DBMS_MONITOR.SESSION_TRACE_ENABLE의 PLAN_STAT 옵션은 첫번째 실행에서의 통계값으로 할지 모든 SQL 구문으로 할지를 결졍하는 옵션이다.
SQL_TRACE / tkprof에 의해서 제공되는 로 카운트는 sql 튜닝에서 매우 귀한 자료이다. 처리된 로의 수, 요구된 컴퓨터 자원과 같이 매우 중요한 정보이므로, 각 스텝에서 높은 수행 카운트는 보통 최적화를 위한 가장 중요한 자료정보가 된다. Tkprof는 각 스텝 단위로 처리된 카운트를 제공한다. DBMS_XPLAN.DISPLAY_CURSOR() 도 이러한 유사한 정보를 보여주지만 서버 파라미터에서 STATISTICS_LEVEL 을 ALL로 설정해야 한다.
Tkprof의 wait 통계
오라클 세션은 lock와 같은 CPU 웨이트 시간처럼 버려진 정보를 필요로 한다. 이 소비된 시간을 수집하기 위해서는 WAITS=YES로 설정하면 된다.
그림 1에서와 같이 (p)로 마킹된 정보가 wait 정보이다. 우리의 SQL 구문에서는 네트워크 대기시간이 5.3초 걸렸고, IO 대기시간이 17.6초 걸린것을 알 수 있다. 이론적으로 CPU와 대기시간은 서로 총 수행시간의 지표가 된다.
총 수행시간 = cpu시간 + 대기시간
