트러블슈팅 오라클 퍼포먼스 2판 (2017년)
TVD$XTAT
- Trivadis 확장 트레이스 파일 분석 도구
tvdxtat -i DBM11106_ora_6334.trc -o DBM11106_ora_6334.html
TKPROF로 충분하지 않은 이유
TVD$XTAT 에서 해결된 TKPROF 의 다섯 가지 문제
- sort 인수 지정 시 SQL 간 관계 손실
- 집계 데이터 제공 (유용한 정보 손실)
- 바인드 변수 정보 미제공
- 경과 시간에 Idle 대기 이벤트가 제외 됨 (예: SQL*Net message from client)
- 트레이스 파일에 SQL 구문 텍스트가 없으면 상세 정보 미제공, 요약 정보 합산 제공 됨
- SQL 실행 시작 이후 트레이스 활성화 시
설치
- http://top.antognini.ch 에서 다운로드
- 디렉터리 생성 후 압축 풀기
- tvdxtat.sh 내 JAVA_HOME, TVDXTAT_HOME 설정
- 인수 설정 변경 (config/tvdxtat.properties)
- 로깅 설정 변경 (config/logging.properties)
TVD$XTAT 인수 (p.113)
| 인수 | 설명 | 비고 |
|---|---|---|
| input | 입력 파일 - .trc 혹은 압축 파일(.gz, .zip) | .zip 에서는 하나만 추출 됨 |
| output | 출력 파일 | 임시 파일(xml) 생성/삭제 됨 |
| cleanup | 임시 파일(xml) 제거 여부 | |
| feedback | 진행 상황 표시 여부 | |
| help | 도움말 표시 | |
| limit | 출력 파일내 목록에서 제공되는 항목의 최대 개수 | 0:무제한 |
| release | 트레이스 파일 생성 DB 메이저 버전 지정 | 7,8,9,10,11,12 |
| sys | sys 유저 재귀 SQL 출력 여부 | |
| template | 출력 파일 생성에 사용될 XSL 템플릿 지정 | html.xsl, text.xsl |
| version | TVD$XTAT 버전 표시 | |
| wait | 대기 이벤트 상세 정보 출력 여부 | 부하가 크므로 필요시 적용 |
| logging | 로깅 레벨 제어(severe, warning, info, fine, finer) | TVD$XTAT 디버깅용 |
TVD$XTAT 출력 해석
tvdxtat -i DBM11203_ora_28030.trc -o DBM11203_ora_28030.txt -s no -w yes -t text
주요 정보 : Interval, Transactions
Database Version
****************
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, Automatic Storage Management, Oracle Label Security, OLAP,
Data Mining and Real Application Testing options
Analyzed Trace File
*******************
/u00/app/oracle/diag/rdbms/dbm11203/DBM11203/trace/DBM11203_ora_28030.trc
Interval
********
Beginning 30 Nov 2012 23:21:45.691
End 30 Nov 2012 23:21:58.097
Duration 12.407 [s]
Transactions
************
Committed 0
Rollbacked 0
리소스 사용률 프로파일 - 개괄 적인 정보
- 처리시간 : 12.407초 (CPU: 56%, 임시파일 24%, 파일읽기 23%, 계측되지 않은 시간...)
- TVD$XTAT 는 항상 응답시간 기준으로 리스트
Resource Usage Profile
**********************
Total Number of Duration per
Component Duration [s] % Events Events [s]
--------------------------------------------- ----------------- ------- ------------- -----------------
CPU 6.969 56.171 n/a n/a
db file scattered read 2.792 22.502 530 0.005
direct path read temp 2.417 19.479 24,015 0.000
direct path write temp 0.513 4.136 11,002 0.000
db file sequential read 0.041 0.326 72 0.001
SQL*Net message from client 0.001 0.008 2 0.001
SQL*Net message to client 0.000 0.000 2 0.000
unaccounted-for -0.325 -2.623 n/a n/a
--------------------------------------------- ----------------- -------
Total 12.407 100.000
- 비재귀 SQL 구문 목록 - SQL 별 정보
Statement ID Type Duration [s] % Executions Execution [s]
------------- -------------------------------- ----------------- ------- ------------- -----------------
#1 PL/SQL 12.724 102.561 1 12.724
#5 PL/SQL 0.006 0.045 1 0.006
#9 PL/SQL 0.002 0.016 1 0.002
------------- -------------------------------- ----------------- -------
Total 12.732 102.623
처리 시간을 가장 많이 차지한 SQL 세부 정보 확인(Statement ID #1)
****************************************** STATEMENT #1 ******************************************
Session ID 156.29
Service Name SYS$USERS
Module Name SQL*Plus
Parsing User 34
Hash Value 166910891
-- 11.1 버전 이상 SQL ID 지원
SQL ID 15p0p084z5qxb
DECLARE
l_count INTEGER;
BEGIN
FOR c IN (SELECT extract(YEAR FROM d), id, pad
FROM t
ORDER BY extract(YEAR FROM d), id)
LOOP
NULL;
END LOOP;
FOR i IN 1..10
LOOP
SELECT count(n) INTO l_count
FROM t
WHERE id < i*123;
END LOOP;
END;
-- Misses : 하드 파싱 횟수
-- LIO : Consisitent + Current
Database Call Statistics with Recursive Statements
**************************************************
Call Count Misses CPU [s] Elapsed [s] PIO [b] LIO [b] Consistent [b] Current [b] Rows
----------------------- ------------- ------------- ----------------- ----------------- ------------- ------------- ----------------- ------------- -------------
Parse 1 1 0.005 0.006 7 20 20 0 0
Execute 1 0 6.957 12.387 71,562 38,820 38,812 8 1
Fetch 0 0 0.000 0.000 0 0 0 0 0
----------------------- ------------- ------------- ----------------- ----------------- ------------- ------------- ----------------- ------------- -------------
Total 2 1 6.962 12.393 71,569 38,840 38,832 8 1
Database Call Statistics without Recursive Statements
*****************************************************
Call Count Misses CPU [s] Elapsed [s] PIO [b] LIO [b] Consistent [b] Current [b] Rows
----------------------- ------------- ------------- ----------------- ----------------- ------------- ------------- ----------------- ------------- -------------
Parse 1 1 0.005 0.004 0 0 0 0 0
Execute 1 0 0.448 0.410 0 0 0 0 1
Fetch 0 0 0.000 0.000 0 0 0 0 0
----------------------- ------------- ------------- ----------------- ----------------- ------------- ------------- ----------------- ------------- -------------
Total 2 1 0.453 0.414 0 0 0 0 1
Resource Usage Profile
**********************
Total Number of Duration per
Component Duration [s] % Events Events [s]
--------------------------------------------- ----------------- ------- ------------- -----------------
recursive statements 12.271 96.437 n/a n/a
CPU 0.453 3.560 n/a n/a
SQL*Net message from client 0.000 0.003 1 0.000
SQL*Net message to client 0.000 0.000 1 0.000
--------------------------------------------- ----------------- -------
Total 12.724 100.000
-- 재귀 SQL 목록 중 Statement ID #2 드릴 다운 필요
7 recursive statements were executed.
Total
Statement ID Type Duration [s] %
------------- -------------------------------- ----------------- -------
#2 SELECT 12.234 96.150
#3 SELECT 0.033 0.263
#7 SELECT (SYS recursive) 0.003 0.022
#11 SELECT (SYS recursive) 0.000 0.001
#12 SELECT (SYS recursive) 0.000 0.001
#14 SELECT (SYS recursive) 0.000 0.001
#16 SELECT (SYS recursive) 0.000 0.000
------------- -------------------------------- ----------------- -------
Total 12.252 96.286
Statement ID #2
- 재귀 레벨, 부모 SQL Statement ID 정보 추가 (SQL 구문 사이의 관계)
****************************************** STATEMENT #2 ******************************************
Session ID 156.29
Service Name SYS$USERS
Module Name SQL*Plus
Parsing User 34
Recursive Level 1 <<<
Parent Statement ID 1 <<<
Hash Value 955957303
SQL ID 7wd0gdwwgph1r
SELECT EXTRACT(YEAR FROM D), ID, PAD FROM T ORDER BY EXTRACT(YEAR FROM D), ID
Execution Plan
**************
Optimizer Mode ALL_ROWS
Hash Value 961378228
Rows Operation
------------- --------------------------------------------------------------------------------------
1,000,000 SORT ORDER BY (cr=38474 pr=71499 pw=33035 time=11123996 us cost=216750 size=264000000 card=1000000)
1,000,000 TABLE ACCESS FULL T (cr=38474 pr=38463 pw=0 time=5674541 us cost=21 size=264000000 card=1000000)
Database Call Statistics with Recursive Statements
**************************************************
Call Count Misses CPU [s] Elapsed [s] PIO [b] LIO [b] Consistent [b] Current [b] Rows
----------------------- ------------- ------------- ----------------- ----------------- ------------- ------------- ----------------- ------------- -------------
Parse 1 1 0.004 0.010 7 32 32 0 0
Execute 1 1 0.000 0.000 0 0 0 0 0
Fetch 10,001 0 6.492 11.926 71,499 38,482 38,474 8 1,000,000
----------------------- ------------- ------------- ----------------- ----------------- ------------- ------------- ----------------- ------------- -------------
Total 10,003 2 6.496 11.936 71,506 38,514 38,506 8 1,000,000
Average (per row) 0 0 0.000 0.000 0 0 0 0 1
Database Call Statistics without Recursive Statements
*****************************************************
Call Count Misses CPU [s] Elapsed [s] PIO [b] LIO [b] Consistent [b] Current [b] Rows
----------------------- ------------- ------------- ----------------- ----------------- ------------- ------------- ----------------- ------------- -------------
Parse 1 1 0.001 0.001 0 9 9 0 0
Execute 1 1 0.000 0.000 0 0 0 0 0
Fetch 10,001 0 6.492 11.926 71,499 38,482 38,474 8 1,000,000
----------------------- ------------- ------------- ----------------- ----------------- ------------- ------------- ----------------- ------------- -------------
Total 10,003 2 6.493 11.927 71,499 38,491 38,483 8 1,000,000
Average (per row) 0 0 0.000 0.000 0 0 0 0 1
Resource Usage Profile
**********************
Total Number of Duration per
Component Duration [s] % Events Events [s]
--------------------------------------------- ----------------- ------- ------------- -----------------
CPU 6.493 53.071 n/a n/a
db file scattered read 2.792 22.818 530 0.005
direct path read temp 2.417 19.753 24,015 0.000
direct path write temp 0.513 4.194 11,002 0.000
recursive statements 0.020 0.161 n/a n/a
db file sequential read 0.000 0.002 2 0.000
--------------------------------------------- ----------------- -------
Total 12.234 100.000
6 recursive statements were executed.
Total
Statement ID Type Duration [s] %
------------- -------------------------------- ----------------- -------
#4 SELECT (SYS recursive) 0.015 0.121
#6 SELECT (SYS recursive) 0.004 0.032
#10 SELECT (SYS recursive) 0.001 0.008
#13 SELECT (SYS recursive) 0.000 0.001
#17 SELECT (SYS recursive) 0.000 0.000
#18 SELECT (SYS recursive) 0.000 0.000
------------- -------------------------------- ----------------- -------
Total 0.006 0.050
-- 대기 이벤트 히스토그램 (db file scattered read : 멀티블록 읽기 → Blocks per Event[b])
db file scattered read
**********************
Total Number of Duration per Blocks per
Range [us] Duration [s] % Events % Event [us] Blocks [b] Event [b]
---------------------------------- ----------------- ------- ------------- ------- ------------- ------------- -------------
256 ≥ duration < 512 0.003 0.111 7 1 443 56 8
512 ≥ duration < 1024 0.008 0.288 9 2 892 72 8
1024 ≥ duration < 2048 0.033 1.191 18 3 1,847 826 46
2048 ≥ duration < 4096 0.517 18.525 166 31 3,115 11,627 70
4096 ≥ duration < 8192 1.465 52.459 264 50 5,547 20,742 79
8192 ≥ duration < 16384 0.579 20.736 60 11 9,648 4,722 79
16384 ≥ duration < 32768 0.126 4.496 5 1 25,101 336 67
32768 ≥ duration < 65536 0.061 2.195 1 0 61,274 81 81
---------------------------------- ----------------- ------- ------------- ------- ------------- ------------- -------------
Total 2.792 100.000 530 100.000 5,267 38,462 73
-- 디스크 I/O 관련 대기 이벤트 추가 정보
File Total Number of Duration per
Number Duration [s] % Events % Blocks [b] % Event [us]
------------- ----------------- ------- ------------- ------- ------------- ------- -------------
4 2.792 100.000 530 100.000 38,462 100.000 5,267
direct path read temp
*********************
Total Number of Duration per Blocks per
Range [us] Duration [s] % Events % Event [us] Blocks [b] Event [b]
---------------------------------- ----------------- ------- ------------- ------- ------------- ------------- -------------
4 ≥ duration < 8 0.002 0.078 264 1 7 264 1
8 ≥ duration < 16 0.086 3.559 6,576 27 13 6,576 1
16 ≥ duration < 32 0.073 3.003 3,065 13 24 3,065 1
32 ≥ duration < 64 0.080 3.301 1,585 7 50 1,585 1
64 ≥ duration < 128 0.799 33.046 7,724 32 103 7,724 1
128 ≥ duration < 256 0.688 28.485 4,276 18 161 4,276 1
256 ≥ duration < 512 0.115 4.770 356 1 324 356 1
512 ≥ duration < 1024 0.004 0.167 5 0 809 5 1
1024 ≥ duration < 2048 0.035 1.438 23 0 1,511 23 1
2048 ≥ duration < 4096 0.430 17.797 119 0 3,614 119 1
4096 ≥ duration < 8192 0.097 3.997 21 0 4,599 21 1
8192 ≥ duration < 16384 0.009 0.359 1 0 8,673 1 1
---------------------------------- ----------------- ------- ------------- ------- ------------- ------------- -------------
Total 2.417 100.000 24,015 100.000 101 24,015 1
File Total Number of Duration per
Number Duration [s] % Events % Blocks [b] % Event [us]
------------- ----------------- ------- ------------- ------- ------------- ------- -------------
201 2.417 100.000 24,015 100.000 24,015 100.000 101
direct path write temp
**********************
Total Number of Duration per Blocks per
Range [us] Duration [s] % Events % Event [us] Blocks [b] Event [b]
---------------------------------- ----------------- ------- ------------- ------- ------------- ------------- -------------
4 ≥ duration < 8 0.001 0.141 91 1 8 91 1
8 ≥ duration < 16 0.007 1.283 520 5 13 520 1
16 ≥ duration < 32 0.004 0.844 169 2 26 169 1
32 ≥ duration < 64 0.423 82.467 9,340 85 45 9,340 1
64 ≥ duration < 128 0.068 13.263 865 8 79 865 1
128 ≥ duration < 256 0.001 0.189 6 0 162 6 1
256 ≥ duration < 512 0.001 0.193 3 0 330 3 1
512 ≥ duration < 1024 0.003 0.633 4 0 812 4 1
1024 ≥ duration < 2048 0.005 0.987 4 0 1,266 4 1
---------------------------------- ----------------- ------- ------------- ------- ------------- ------------- -------------
Total 0.513 100.000 11,002 100.000 47 11,002 1
File Total Number of Duration per
Number Duration [s] % Events % Blocks [b] % Event [us]
------------- ----------------- ------- ------------- ------- ------------- ------- -------------
201 0.513 100.000 11,002 100.000 11,002 100.000 47
db file sequential read
***********************
Total Number of Duration per Blocks per
Range [us] Duration [s] % Events % Event [us] Blocks [b] Event [b]
---------------------------------- ----------------- ------- ------------- ------- ------------- ------------- -------------
64 ≥ duration < 128 0.000 100.000 2 100 106 2 1
File Total Number of Duration per
Number Duration [s] % Events % Blocks [b] % Event [us]
------------- ----------------- ------- ------------- ------- ------------- ------- -------------
4 0.000 54.460 1 50.000 1 50.000 116
201 0.000 45.540 1 50.000 1 50.000 97
------------- ----------------- ------- ------------- ------- ------------- ------- -------------
Total 0.000 100.000 2 100.000 2 100.000 106
- SQL Statement ID #3 - 바인드 변수 있을 때
****************************************** STATEMENT #3 ******************************************
Session ID 156.29
Service Name SYS$USERS
Module Name SQL*Plus
Parsing User 34
Recursive Level 1
Parent Statement ID 1
Hash Value 1035370675
SQL ID 7fjjjf0yvd05m
SELECT COUNT(N) FROM T WHERE ID < :B1 *123
Bind Variables
**************
10 bind variable sets were used to execute this statement.
Number of
Execution Bind Datatype Value
------------- ------------- --------------------------------- ----------------------------------------
1 1 NUMBER "1"
2 1 NUMBER "2"
3 1 NUMBER "3"
4 1 NUMBER "4"
5 1 NUMBER "5"
6 1 NUMBER "6"
7 1 NUMBER "7"
8 1 NUMBER "8"
9 1 NUMBER "9"
10 1 NUMBER "10"
"데이터베이스 스터디모임" 에서 2017년에 "전문가를 위한 트러블슈팅 오라클 퍼포먼스(Second Edition)
" 도서를 스터디하면서 정리한 내용 입니다.
- 강좌 URL : http://www.gurubee.net/lecture/4324
- 구루비 강좌는 개인의 학습용으로만 사용 할 수 있으며, 다른 웹 페이지에 게재할 경우에는 출처를 꼭 밝혀 주시면 고맙겠습니다.~^^
- 구루비 강좌는 서비스 제공을 위한 목적이나, 학원 홍보, 수익을 얻기 위한 용도로 사용 할 수 없습니다.
) 버튼을 클릭하여 작성 하시면 됩니다.