0. 소개
1. MOATS
2. Runstats
3. OraSRP
4. XPLAN
5. TPT
유틸리티들이 제공하는 기능들을 통해 거꾸로 오라클 성능 문제를 분석하기 위해 어떤 기법이 필요한지 배울 수 있다.
MOATS : 세션/시스템 스냅샷, 액티브 세션 히스토리, 대기 이벤트 등에 기반한 시스템 모니터링 유틸리티
Runstats : 세션 스냅샷 리포트
OraSRP : Extended SQL 트레이스 파일에 대한 상세한 분석을 제공
XPLAN : SQL 성능 분석에 대한 상세한 리포트
TPT : 세션 프로파일링, 래치 플파일링, 힙 덤프 분석 등의 기능을 제공
유틸리티들이 제공하는 기능들을 통해 거꾸로 오라클 성능 문제를 분석하기 위해 어떤 기법이 필요한지 배울 수 있다.
Download :http://www.oracle-developer.net/content/utilities/moats_v1.04.zip
MOATS(Mother Of All Tunig scripts)
성능 튜닝 작업을 하기 전에 어떤 부분에 문제가 있는지를 직관적으로 파악하기 위한 모니터링 기능을 제공
고가의 모니터링 툴을 구입할 여유가 없는 경우에 비용 대비 최고의 효과
SQL> SELECT * FROM TABLE (moats . top(5));
MOATS: The Mother Of All Tuning Scripts v1.0 by Adrian Billington & Tanel Poder
http://www.oracle-developer.net & http://www.e2sn.com
+ INSTANCE SUMMARY ------------------------------------------------------------------------------------------+
OUTPUT
--------------------------------------------------------------------------------------------------------------
| Instance: PRD | Execs/s: 925.2 | sParse/s: 24.9 | LIOs/s: 303783.8 | Read MB/s: 42.8 |
| Cur Time: 12-May 01:26:20 | Calls/s: 941.6 | hParse/s: 0.0 | PhyRD/s: 5472.7 | Write MB/s: 0.1 |
| History: 0h 0m 7s | Commits/s: 5.8 | ccHits/s: 65.6 | PhyWR/s: 16.2 | Redo MB/s: 0.0 |
+------------------------------------------------------------------------------------------------------------+
+ TOP SQL_ID (child#) -----+ TOP SESSIONS ---------+ + TOP WAITS -------------------------+ WAIT CLASS -+
| 89% | 0szdu5xyt628h (1) | 93,103,104,111,112 | | 81% | read by other session | User I/O |
| 3% | any10yyapacp5 (3) | 197,502,375,219 | | 12% | db file sequential read | User I/O |
| 1% | 33sr04320nk79 (0) | 322 | | 5% | latch: cache buffers chains | Concurrency |
| 1% | 4jgvbz1z484wk (0) | 398 | | 1% | db file parallel read | User I/O |
| 1% | 6y9n7a20n7mrd (0) | 99 | | 1% | ON CPU | ON CPU |
OUTPUT
--------------------------------------------------------------------------------------------------------------
+--------------------------------------------------+ +--------------------------------------------------+
+ TOP SQL_ID ----+ PLAN_HASH_VALUE + SQL TEXT ---------------------------------------------------------------+
| 0szdu5xyt628h | 2111011212 | SELECT "VBELN" , "TUTOR" , "ERDAT" , "AUDAT" , "KVGR2" , "WKDAY" , "AUG |
| | | RU" , "VGBEL" FROM "VBAK" WHERE "MANDT" = :A0 AND "VBELN" BETWEEN :A1 A |
+ ---------------------------------------------------------------------------------------------------------- +
| any10yyapacp5 | 570089534 | SELECT T_00 . "VBELN" , COUNT(*) "ZCNT" FROM "ZBW_TEMP11" T_00 INNER JO |
| | | IN "VBUP" T_01 ON T_01 . "MANDT" = :A0 AND T_00 . "VBELN" = T_01 . "VBE |
+ ---------------------------------------------------------------------------------------------------------- +
| 33sr04320nk79 | 2315334320 | SELECT T_01 . "TUTOR" , T_03 . "MATNR" , T_04 . "ZMVGR" FROM "ZSDT0078" |
| | | T_00 INNER JOIN "ZSDT0085" T_01 ON T_01 . "MANDT" = :A0 AND T_00 . "VB |
OUTPUT
--------------------------------------------------------------------------------------------------------------
+ ---------------------------------------------------------------------------------------------------------- +
| 4jgvbz1z484wk | 2605360516 | SELECT "VBELN" , "POSNR" , "VBELV" , "ERDAT" FROM "VBAP" WHERE "MANDT" |
| | | = :A0 AND "EDUFL" = :A1 AND "MVGR1" IN ( :A2 , :A3 ) |
+ ---------------------------------------------------------------------------------------------------------- +
| 6y9n7a20n7mrd | 1492336331 | insert /*+ append */ into sys.ora_temp_1_ds_40535 select /*+ no_paralle |
| | | l(t) no_parallel_index(t) dbms_stats cursor_sharing_exact use_weak_name |
+ ---------------------------------------------------------------------------------------------------------- +
시스템 전반의 스냅샷 리포트와 Top SQL, Top Wait, 액티브 세션 히스토리 등이 일목요연하게 출력되어 매우 간편하게 시스템 전반의 성능문제를 파악 할 수있다.
액티브 세션 히스토리를 V$ACTIVE_SESSION_HISTORY 뷰에서 읽기 때문에 최소한의 부하로 데이터를 가져온다.
Download :http://asktom.oracle.com/pls/asktom/ASKTOM.download_file?p_file=6551378329289980701
Runstats 패키지는 톰 카이트(Tom Kyte)가 공개한 성능 비교 라이브러리.
2장에서 설명한 [세션 스냅샷 리포트|http://wiki.gurubee.net/pages/viewpage.action?pageId=22052874|]와 동일한 기능을 제공한다.
예제)
SQL>exec runStats_pkg.rs_start;
--soft parse only
declare
v_cnt number;
begin
for idx in 1 .. 10000 loop
execute immediate
'select min(1) from dual where 1 = :b1'
into v_cnt
using idx;
end loop;
end;
/
SQL>exec runstats_pkg.rs_middle;
declare
v_cnt number;
begin
for idx in 1 .. 10000 loop
execute immediate
'select min(1) from dual where 1 = ' || idx into v_cnt;
end loop;
end;
/
--총 세개의 스냅샷이 만들어진다. 스냅샷간의 차이(Delta)는 두개가 존재하게된다.
--Runstats 패키지는 이 두개의 차이를 잘 정리해서 보여주는 것을 목적으로 한다.
-- STAT 지수와 LATCH 지수의 차이를 통해 두 작업간의 성능 차이를 명확하게 이해 할 수 있다.
SQL> set serveroutput on
SQL> exec runstats_pkg.rs_stop(100);
Run1 ran in 1713 hsecs
Run2 ran in 3416 hsecs
run 1 ran in 50.15% of the time
Name Run1 Run2 Diff
LATCH.messages 128 248 120
LATCH.checkpoint queue latch 324 642 318
LATCH.SQL memory manager worka 404 739 335
STAT...parse time cpu 0 492 492
STAT...recursive cpu usage 72 602 530
STAT...CPU used when call star 80 614 534
STAT...CPU used by this sessio 79 615 536
STAT...bytes received via SQL* 673 1,238 565
LATCH.shared pool sim alloc 0 711 711
STAT...bytes sent via SQL*Net 725 1,453 728
STAT...Elapsed Time 1,788 3,518 1,730
STAT...parse time elapsed 3 2,193 2,190
STAT...DB time 166 2,413 2,247
LATCH.simulator hash latch 13,625 8,950 -4,675
STAT...enqueue requests 11 10,004 9,993
STAT...enqueue releases 10 10,004 9,994
STAT...parse count (hard) 4 10,003 9,999
STAT...parse count (total) 5 10,006 10,001
STAT...recursive calls 10,015 20,020 10,005
LATCH.kks stats 8 20,012 20,004
LATCH.enqueue hash chains 280 20,477 20,197
LATCH.enqueues 276 20,498 20,222
LATCH.row cache objects 126 30,231 30,105
LATCH.shared pool simulator 55 35,644 35,589
LATCH.library cache pin 117 60,147 60,030
LATCH.library cache lock 120 60,160 60,040
STAT...session uga memory 0 65,408 65,408
STAT...session uga memory max 0 65,408 65,408
STAT...session pga memory 131,072 65,536 -65,536
STAT...session pga memory max 131,072 65,536 -65,536
LATCH.cache buffers chains 433,615 294,577 -139,038
LATCH.library cache 300 217,551 217,251
LATCH.shared pool 218 341,028 340,810
Run1 latches total versus runs -- difference and pct
Run1 Run2 Diff Pct
450,058 1,112,470 662,412 40.46%
PL/SQL procedure successfully completed.
– 10.2.0.4에서는 Livrary Cache Latch의 획득 수 차이가 217,251번
– 11.2.0.1에서는 LATCH 지수에서 Library Cache Latch 의 차이가 보이지 않음
– Oracle 11g에서 Library Cache Latch가 없어지고 Mutex가 사용하기 때문(자세한내용은 3장대기이벤트 분석 )
– Runstats 패키지와 같은 세션 스냅샷 리포트를 이용하면 이러한 차이를 손쉽게 확인 할 수 있다.
Download :http://www.oracledba.ru/orasrp/
※ Linux,Windows,Mac 버전만 제공
OraSRP는 Extended SQL *Trace, 즉 10046 Event에 의해 생성된 트레이스 정보에 대한 상세한 리포트를 제공하는 역할을 한다.
OraSRP는 TKPROF의 단점을 보완한 보다 완전한 형태의 리포트를 제공한다.
※ TKPROF 단점
예제)
--orasrp_temp.sql
declare
v_cnt number;
begin
for idx in 1 .. 10000 loop
execute immediate
'select count(*) from user_objects where ' || mod(idx,100) ||' = ' ||mod(idx,10) into v_cnt;
end loop;
end;
/
ho sqlplus system/manager @orasrp_temp &
ho sqlplus system/manager @orasrp_temp &
ho sqlplus system/manager @orasrp_temp &
ho sqlplus system/manager @orasrp_temp &
ho sqlplus system/manager @orasrp_temp &
-- ※ho : 임시로 dos 모드로 변경
alter session set events '10046 trace name context forever , level 8';
@orasrp_temp
alter session set events '10046 trace name context off';
총 6개의 세션이 동일한 패턴의 sql문장을 동시 다발적으로 실행하기 때문에 라이브러리 캐시 영역에서 상당한 경합이 발생할 것으로 예상할수 있다.
@trace_file -- 현재세션의 트레이스 파일 확인
select r.value || case when d.platform_name like 'M%' then'\'else '/' END||
lower(t.instance_name) || '_ora_'
||ltrim(to_char(p.spid)) || '.trc' trace_file
from v$process p,v$session s, v$parameter r, v$instance t, v$database d
where p.addr =s.paddr
and r.name ='user_dump_dest'
and s.sid =(select sid from v$mystat where rownum = 1) ;
TRACE_FILE
--------------------------------------------------------------------------------
/oracle/app/oracle/admin/SCTEST/udump/sctest_ora_26959.trc
※ OraSRP에 대한 도움말
[oracle@sctest orasrp]$ ./orasrp -h
usage: orasrp [options] trcfile [outfile]
options:
-h, --help show this help message and exit
--version show program's version number and exit
-t, --text output in text format
--aggregate=YES/no aggregate similar statements
-bn, --binds=n how many unique bind-sets to display (1 by defaut)
-c, --config specify config file
--maxbinds=n how many unique bind-sets to analyze (all by default)
--recognize-idle-events=YES/no
recognize or not idle wait events
--sys=YES/no print sys statements
--sort how to sort statements in output (values like in tkprof)
-s, --server run httpd mode
-p, --port listen on alternate port (in httpd mode)
-r, --remote connect to remote machine:port
--display-sections what sections of report to display (all by default)
--skip-sections what sections of report to skip
--sessionid analyze data only for the specified session id
--threshold omit statements which spend less than threshold % from total time (not used by defaut)
--google-charts display charts using Google Chart API
SQL> ho ./orasrp --sys=no &trace_file orasrp.html
Enter value for trace_file: /oracle/app/oracle/admin/SCTEST/udump/sctest_ora_26959.trc
-- <결과>
다음과같이 요약정보가 출력된다.
그리고 DPU사용 및 대기 이벤트에 대한 프로파일 정보를 볼 수 있다.
TKPROF가 제공한느 정보에 비해 훨씬 입체적이고 다양한 정보가 제공된다.
위에서 제시한 CPU 자원과 대기 이벤트별로 어떤 SQL문장이 어느정도의 비중을 차지하는지 일복 요연하게 볼 수 있다. 이 역시 TKPROF 리포트에는 없는 매우 유용한 정보이다.
library cache : mutex x => 11g에서 나옴
그리고 각 SQL 별로 재귀 SQL 의 분포를 보여준다.
레벨 8에 의하 대기 이벤트 정보가 기록되었기 때문에, 각 대기 이벤트별로 히스토그램정보를 보여준다. 이역시 너무나 유용한 정보이다.
library cache : mutex X
그리고 각 SQL별로 상세한 프로파일링 정보를 보여준다. TKPROF 리포트와 거의 유사한 정보이지만, 훨씬 더 입체적이고 다양한 방식으로 데이터를 보여준다.
Download : http://www.adellera.it/scripts_etcetera/xplan/index.html
XPLAN 유틸리티는 DBMS_XPLAN 패키지의 확장판이라고 보시면 된다.
SQL 문장의 실행 계획과 관련된 모든 정보를 일목 요연하게 리포팅 해 줌
예제 )
create table t1(c1 number, c2 char(100));
insert into t1
select level, level from dual connect by level < = 100000;
create index t1_n1 on t1(c1);
exec dbms_stats.gather_table_stats(user, 't1');
var b1 number;
exec :b1 :=1;
alter sesson set optimizer_index_cost_adj = 50;
alter system flush buffer_cache;
select /*+ gather_plan_statistics index(t1) opt_parm('_hash_join_enabled', 'false') */ count (c2)
from t1
where c1>= :b1 ;
/
/
/
/
...
select
prev_sql_id
from v$session
where sid = userenv('sid');
@xplan "" "sql_id=&prev_sql_id"
<결과>
--기본요약 정보가 출력
xplan version 2.4.2 01-May-2011 (C) Copyright 2008-2009 Alberto Dell'Era, www.adellera.it
db_name=BWD instance_name=BWD version=10.2.0.4.0 (compatible = 10.2.0)
--시스템 레벨의 옵티마이저 파라미터값( V$SYS_OPTIMIZER_ENV 뷰 )
optimizer parameters instance(sys) settings:
------------------------------------------ ------------------------------------------ ------------------------------------------
|optimizer param name |value | |optimizer param name |value | |optimizer param name |value |
------------------------------------------ ------------------------------------------ ------------------------------------------
|_B_TREE_BITMAP_PLANS | false | |optimizer_features_enable |10.2.0.4 | |pga_aggregate_target |1481038 KB |
|_OPTIM_PEEK_USER_BINDS | false | |optimizer_index_caching | 0 | |QUERY_REWRITE_ENABLED | false |
|_PGA_MAX_SIZE |296200 KB | |optimizer_index_cost_adj | 100 | |query_rewrite_integrity | enforced |
|_SORT_ELIMINATION_COST_RATIO | 10 | |OPTIMIZER_MODE | choose | |skip_unusable_indexes | true |
|active_instance_count | 1 | |optimizer_secure_view_merging | true | |sort_area_retained_size | 0 |
|BITMAP_MERGE_AREA_SIZE | 33554432 | |parallel_ddl_mode | enabled | |SORT_AREA_SIZE | 45485760 |
|cpu_count | 6 | |parallel_dml_mode |disabled | |STAR_TRANSFORMATION_ENABLED | true |
|cursor_sharing | exact | |parallel_execution_enabled | true | |statistics_level | typical |
|HASH_AREA_SIZE | 20971520 | |parallel_query_mode | enabled | |workarea_size_policy | auto |
|optimizer_dynamic_sampling | 2 | |PARALLEL_THREADS_PER_CPU | 1 | ------------------------------------------
--시스템 통계정보를 보여준다. ( SYS.AUX_STATS$ 테이블 )
optimizer system statistics:
---------------------------------------- -------------------------- --------------------------
|system statistic |value | |system statistic |value | |system statistic |value |
---------------------------------------- -------------------------- --------------------------
|status | completed | |cpuspeednw | 827 | |ioseektim | 10 |
|gathering start |2011-01-08/13:25:00 | |sreadtim | null | |iotfrspeed | 4096 |
|gathering stop |2011-01-08/13:25:00 | |mreadtim | null | |maxthr | null |
|cpuspeed | null | |mbrc | null | |slavethr | null |
---------------------------------------- -------------------------- --------------------------
--SQL레벨의 기본 실행 정보들, 즉 실행 횟수, Logical Reads, Physical Reads, 수행시간등의 정도( V$SQL 뷰 )
sql_id=dwm98gygzfk9b hash=2683783467 child_number=0 plan_hash=3892869488 module=sqlplus@r3dev (TNS V1-V3)
first_load: 2012/05/11 17:10:38 last_load: 2012/05/11 17:10:38 last_active: 2012/05/11 17:10:44
parsed_by=SYS inst_id=1
------------------------------------ -------------------------------- -----------------------------------------
|gv$sql statname |total |/exec | |gv$sql statname |total |/exec | |gv$sql statname |total |/exec |
------------------------------------ -------------------------------- -----------------------------------------
|executions | 6 | | |sorts | 0 | .0 | |users_executing | 0 | .0 |
|rows_processed | 6 | 1.0 | |fetches | 6 | 1.0 | |application wait (usec) | 0 | .0 |
|buffer_gets | 10560 | 1760.0 | |end_of_fetch_c | 6 | 1.0 | |concurrency wait (usec) | 0 | .0 |
|disk_reads | 1760 | 293.3 | |parse_calls | 6 | 1.0 | |cluster wait (usec) | 0 | .0 |
|direct_writes | 0 | .0 | |sharable_mem |18769 | | |user io wait (usec) |15969 |2661.5 |
|elapsed (usec) |702820 |117136.7 | |persistent_mem | 4736 | | |plsql exec wait (usec) | 0 | .0 |
|cpu_time (usec) |695806 |115967.7 | |runtime_mem | 3552 | | |java exec wait (usec) | 0 | .0 |
------------------------------------ -------------------------------- -----------------------------------------
--SQL 실행 계획 정보( V$SQL_PLAN_STATISTICS 뷰)
select /*+ gather_plan_statistics index(t1) opt_parm('_hash_join_enabled', 'false') */ count (c2)
from t1
where c1>=:b1
-------------------------------------------------------------------------
|Id|Operation |Name |TabName|Erows|Arows |Cost|IoCost|
------------------------------------------------------last---------------
| 0|SELECT STATEMENT | | | | | 17| |
| 1| SORT AGGREGATE | | | 1| 1| | |
| 2| TABLE ACCESS BY INDEX ROWID|T1 |T1 | 4999|100000| 17| 17|
| 3| INDEX RANGE SCAN |T1_N1|T1 | 900|100000| 3| 3|
-------------------------------------------------------------------------
. 3 - access[ "C1">=:B1 ]
--각 실행 단계별 Consistent Read, Current Read, Direct Read, Direct Write, Elapsed Time 의 정보
--------------------------------------
|Id|Starts|CR |CU |DR |DW |Ela |
----last---last-last-last-last-last---
| 0| | | | | | |
| 1| 1|1760| 0| 0| 0|110395|
| 2| 1|1760| 0| 0| 0|100057|
| 3| 1| 223| 0| 0| 0| 43|
-------------------------------usec---
note: stats Aram, A01M, 0/1/M, ActTim do not seem to be always accurate.
all params in gv$sql_optimizer_env are the same as instance ones.
--대기 이벤트 정보(V$ACTIVE_SESSION_HISTORY)
--액티브 세션 히스토리 기능을 이용하면 SQL 트레이스를 수행하지 않아도 대기 이벤트 정보를 어느 정도 분석할 수 있다.(앞에서 설명)
-------------------
|ash event|cnt|% |
-------------------
|cpu | 1|100|
-------------------
--현재 SQL 문장에서 변경된 옵티마이저 파라미터가 있는 경우, 해당 파라미터의 값을 보여준다.(V$SQL_OPTIMIZER_ENV 뷰)
--쿼리에서 사용되는 테이블과 인덱스의 정의와 통계 정보( DBA_TAB_STATISTICS뷰, DBA_TAB_COL_STATISTICS 뷰, DBA_IND_STATISTICS 뷰 )
############################################# table SYS.T1 ###
-----------------------------------------
|Id|IId|V|ColName|Type |Null|1|
-----------------------------------------
| 1| 1|N|C1 |NUMBER |yes |1|
| 2| 2|N|C2 |CHAR (100 byte)|yes | |
-----------------------------------------
-------------------------------------------------------------------------------------
|num_rows|blocks|empty_blocks|avg_row_len|sample_size|last_analyzed |parallel |
-------------------------------------------------------------------------------------
| 99984| 1541| 0| 105| 24996|2012/05/11 15:34:39| 1|
-------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------
|ColName|ndv |dens*#rows|num_nulls|#bkts|avg_col_len|sample_size|last_analyzed |
--------------------------------------------------------------------------------------
|C1 |99984| 1| 0| 1| 5| 24996|2012/05/11 15:34:39|
|C2 |99984| 1| 0| 1| 101| 24996|2012/05/11 15:34:39|
--------------------------------------------------------------------------------------
### index #1: SYS.T1_N1
on SYS.T1 ( C1 )
NONUNIQUE B+TREE
-----------------------------------------------------------------------------------------
|distinct_keys|num_rows|blevel|leaf_blocks|cluf|sample_size|last_analyzed |parallel|
-----------------------------------------------------------------------------------------
| 100000| 100000| 1| 222|1537| 100000|2012/05/11 15:34:40|1 |
-----------------------------------------------------------------------------------------
OPTIONS: inst_id=1 plan_stats=last access_predicates=Y lines=200 ash_profile_mins=15 module= action= hash= sql_id=dwm98gygzfk9b parsed_by= child_number= dbms_xplan=N dbms_metadata=N plan_details=N
plan_env=Y tabinfos=Y objinfos=Y partinfos=Y order_by= spool_name=xplan_dwm98gygzfk9b_i1.lst spool_files=single
SQL_LIKE=""
-- Warning: since ash_profile_mins > 0, you are using ASH/AWR; make sure you are licensed to use it.
위에서 제공된 정보를 보면 SQL 문장의 실행 계획 분석에 있어서 필수적인 데이터들을 매우 일목요연하게 보여주는 것을 알 수 있다.
위의 정보들을 미리 입수한 후에 SQL 문장의 최적화 작업을 수행한다면 보다 체계적인 작업이 가능할 것이다.
Download : http://tech.e2sn.com/oracle-scripts-and-tools
TPT 스크립트는 Tanel Poder 가 공개한 오라클 성능 트러블슈팅 라이브러리이다.
Tanel Poder Troubleshooting Scripts의 약자.
TPT 스크립트의 특징은 데이터베이스에 별도의 오브젝트를 만들지 않고, 순수 PL/SQL 블록만으로 구현되어 사용하기가 매우 편리하다.
가능한 V$뷰나 X$테이블만을 참조하도록 구현되어 성능면에서도 최적화 되어 있다.
예제)
-- 접속만해도 아래와같이 세션 정보등이 나옴
SQL*Plus: Release 10.2.0.4.0 - Production on Fri May 11 18:04:26 2012
Copyright (c) 1982, 2007, Oracle. All Rights Reserved.
Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, Data Mining and Real Application Testing options
USERNAME INST_NAME HOST_NAME SID SERIAL# VERSION STARTED SPID OPID CPID SADDR PADDR
-------------------- ------------ ------------------------- ----- -------- ---------- -------- --------------- ----- --------------- ---------------- ----------------
SYS BWD r3dev 586 12 10.2.0.4.0 20120511 1040800 13 1290836 0700000188BA37C8 07000001887FC5A0
-ne
SQL> @snapper ash 5 1 474 -- V$ACTIVE_SESSION_HISTORY로부터 데이터를 읽되, 5초 동안 1번의 스냅샷을 통해 474번 세션의 성능 정보 리포트
Sampling SID 474 with interval 5 seconds, taking 1 snapshots...
-- Session Snapper v3.52 by Tanel Poder @ E2SN ( http://tech.e2sn.com)
---------------------------------------------------------------------------------
Active% | SQL_ID | EVENT | WAIT_CLASS
---------------------------------------------------------------------------------
52% | gy5xm0s9qsupc | read by other session | User I/O
35% | gy5xm0s9qsupc | db file sequential read | User I/O
13% | gy5xm0s9qsupc | ON CPU | ON CPU
-- End of ASH snap 1, end=2012-05-11 18:18:24, seconds=5, samples_taken=46
PL/SQL procedure successfully completed.
SQL>@snapperash=sid+event+wait_class,ash1=plsql_object_id+plsql_subprogram_id+sql_id,ash2=program+module+action 5 1 all
Sampling SID all with interval 5 seconds, taking 1 snapshots...
-- Session Snapper v3.52 by Tanel Poder @ E2SN ( http://tech.e2sn.com)
------------------------------------------------------------------------
Active% | SID | EVENT | WAIT_CLASS
------------------------------------------------------------------------
100% | 221 | db file sequential read | User I/O
100% | 250 | db file sequential read | User I/O
98% | 94 | db file sequential read | User I/O
98% | 472 | db file sequential read | User I/O
95% | 372 | db file sequential read | User I/O
90% | 231 | db file sequential read | User I/O
68% | 392 | db file sequential read | User I/O
63% | 398 | db file sequential read | User I/O
18% | 256 | db file sequential read | User I/O
15% | 321 | db file sequential read | User I/O
---------------------------------------------------
Active% | PLSQL_OBJE | PLSQL_SUBP | SQL_ID
---------------------------------------------------
268% | | | 1n0qp2ppx4xb6
100% | | | 4r2z4grh7z216
100% | | | 9bkwsu6h2h054
65% | | | 1ajy753y74q4r
63% | | | 78dx9cvwzk9nq
25% | | | 1rtxjds0zcugz
23% | | | bzwp1br33tuhn
18% | | | 57gb6v1btkf06
15% | | | 376qq9b4g5jtk
15% | | | 4jgqmk2fs974h
-------------------------------------------------------------------------------------------
Active% | PROGRAM | MODULE | ACTION
-------------------------------------------------------------------------------------------
168% | dw.sapPRD_D00@r3prdap2 (T | SAPLZSD_CLOSING_TUTOR_N | 1608
100% | dw.sapPRD_D00@r3prdap1 (T | SAPLXRSA | 7530
100% | dw.sapPRD_D00@r3prdap1 (T | ZSDC0506_DAILY | 512
100% | dw.sapPRD_D00@r3prdap3 (T | SAPLZSD_CLOSING_TUTOR_N | 1608
98% | dw.sapPRD_D00@r3prdap3 (T | SAPLZFI_DUTY_AMOUNT | 638
95% | dw.sapPRD_D00@r3prdap2 (T | ZSDSINFO | 2917
63% | dw.sapPRD_D00@r3prdap3 (T | SAPLXRSA | 7602
20% | dw.sapPRD_D00@r3prdap1 (T | RSM13000 | 11698
20% | dw.sapPRD_D00@r3prdap2 (T | SAPMV45A | 31173
13% | dw.sapPRD_D00@r3prdap3 (T | ZSDA0012 | 2000
-- End of ASH snap 1, end=2012-05-11 18:31:48, seconds=5, samples_taken=40
PL/SQL procedure successfully completed
TINCLUDE, SINCLUDE 파라미터를 이용하면 타임모델(V$SESS_TIME_MODEL 뷰)과 통계정보(V$SESSTAT뷰)에 대한 프로파일링 결과도 볼 수 있다.
Latch Profiler
Latch Profiler는 래치프로파일링기법[3장 대기 이벤트 분석]을 구현한 것.
PL/SQL블록으로 되어 있어 간편하게 사용가능
예제)
SQL> @latchprof name % % 100000
-- LatchProf 2.00 by Tanel Poder ( http://www.tanelpoder.com )
NAME Held Gets Held % Held ms Avg hold ms
----------------------------------- ---------- ---------- ------- ----------- -----------
cache buffers chains 311 287 .31 9.112 .032
simulator lru latch 7 7 .01 .205 .029
cache buffers lru chain 6 6 .01 .176 .029
row cache objects 5 5 .01 .147 .029
SQL memory manager latch 4 1 .00 .117 .117
undo global data 2 2 .00 .059 .029
enqueue hash chains 1 1 .00 .029 .029
active checkpoint queue latch 1 1 .00 .029 .029
8 rows selected.
-- Parameter 1 specifies which columns from V$LATCHHOLDER to report and group by. In the case below I just want to report latch holds by latch name (and not even break it down by SID for starters)
-- Parameter 2 specifies which SIDs to monitor. In the case below, I am interested in any SID which holds a latch (%)
-- Parameter 3 specifies which latches to monitor. This can be set either to latch name or latch address in memory. In the case below, I monitor all latches (%)
-- Parameter 4 specifies how many times to sample V$LATCHHOLDER. I use 100000 samples below, which completed in a couple of seconds on my test database. The sampling speed depends on your server CPU/memory bus speed and the value of processes parameter. You should start from lower number like 1000 and adjust it so that LatchProf would complete its sampling in a couple of seconds, and that is usually enough for diagnosing ongoing latch contention problems. You shouldn't keep sampling for long periods since LatchProf runs constantly on the CPU
-- Name -Latch name
-- Held - During how many samples out of total samples (100000) the particular latch was held by somebody
-- Gets -How many latch gets against that latch were detected during LatchProf sampling
-- Held % -How much % of time was the latch held by somebody during the sampling. This is the main column you want to be looking at in order to see who/what holds the latch the most (the latchprof output is reverse-ordered by that column)
-- Held ms -How many milliseconds in total was the latch held during the sampling
-- Avg hold ms -Average latch hold time in milliseconds (normally latches are held from a few to few hundred microseconds
데이터베이스에 어떤 오브젝트도 만들지 않고 SQL*Plus 와 PL/SQL 블록만으로 이정도의 기능을 구현한 것은 정말대단.
또한 세션의 성능 문제를 파악하는데 있어 V$SESSION 뷰나 V$ACTIVE_SESSION_HISTORY 뷰가 얼마나 다양한 정보를 제공하는지도 알 수 있다.