구분 | 환자 치료 | SQL 튜닝 |
---|---|---|
진단 1단계 | X-Ray 촬영 | Explain Plan을 통해 실행계획 확인 |
진단 2단계 | CT 촬영 | AutoTrace를 걸어 수행 시 실제 일량 측정 |
진단 3단계 | MRI 촬영 | SQL 트레이스를 걸어 내부 수행 단계별 부하 확인 |
치료 1단계 | 외용약 또는 내복약 처방 | 쿼리를 변환하거나 옵티마이저 힌트를 사용하여 튜닝 |
치료 2단계 | 칼을 대지 않는 시술 | 인덱스 조정 |
치료 3단계 | 칼을 대는 절개수술 | 반정규화를 실시하거나 집계 테이블 생성 |
구분 | 내용 |
---|---|
10g 이전 | 스크립트 실행: $ORACLE_HOME/rdbms/admin/utlxplan.sql |
10g 이후 | 설치 시 기본적으로 테이블(sys.plan_table$)과 public synoym(plan_table) 생성 |
SQL> SELECT owner, synonym_name, table_owner, table_name
2 FROM all_synonyms
3 WHERE synonym_name = 'PLAN_TABLE'
4 ;
OWNER SYNONYM_NAME TABLE_OWNER TABLE_NAME
------------------------------ ------------------------------ ------------------------------ ------------------------------
PUBLIC PLAN_TABLE SYS PLAN_TABLE$
SQL> explain plan set statement_id='query1' for
2 select * from emp where empno=7900;
SQL> SELECT lpad(id, 4, ' ') || NVL(LPAD(parent_id, 6, ' '), ' ')
2 || ' ' || lpad(' ', (LEVEL - 1) * 2, ' ')
3 || operation || NVL2(options, ' ( ' || options || ' ) ', '')
4 || NVL2(object_name, ' OF '''
5 || object_owner || '.' || object_name, NULL)
6 || NVL2(object_name, '''', '')
7 || decode(parent_id, NULL, ' Optimizer=' || optimizer)
8 || (CASE
9 WHEN cost IS NULL AND cardinality IS NULL AND bytes IS NULL
10 THEN ''
11 ELSE '(' || NVL2(cost, 'Cost=' || cost, '')
12 || NVL2(cardinality, 'Card=' || cardinality, '')
13 || NVL2(bytes, 'Bytes=' || bytes, '')
14 || ')' END) "Execution Plan"
15 FROM plan_table p
16 START WITH statement_id = 'query1' AND id = 0
17 CONNECT BY PRIOR id = parent_id AND PRIOR statement_id = statement_id
18 ORDER BY id;
Execution Plan
--------------------------------------------------------------------------------
0 SELECT STATEMENT Optimizer=ALL_ROWS(Cost=2Card=1Bytes=87)
1 0 TABLE ACCESS ( BY INDEX ROWID ) OF 'SCOTT.EMP'(Cost=2Card=1Bytes=87)
2 1 INDEX ( UNIQUE SCAN ) OF 'SCOTT.PK_EMP'(Cost=1Card=1)
SQL> SET LINESIZE 200
SQL> @ORACLE_HOME\rdbms\admin\utlxpls
PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------------
Plan hash value: 2949544139
--------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 87 | 2 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| EMP | 1 | 87 | 2 (0)| 00:00:01 |
|* 2 | INDEX UNIQUE SCAN | PK_EMP | 1 | | 1 (0)| 00:00:01 |
--------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------------
2 - access("EMPNO"=7900)
CREATE TABLE SQL repository(SQL id VARCHAR2(30), SQL text VARCHAR2(4000));
BEGIN
FOR c IN (SELECT sql_id, sql_text frαn sql_repository)
LOOP
EXECUTE IMMEDIATE 'explain plan set statement_id = ''' || c.sql_id
|| ''' into sql_plan_repository'
|| ' for ' || c.sql_text;
COMMIT;
END LOOP;
END;
/
위 스크립트는 예시로, 실제 운영 환경에서는 SQL 문장을 테이블에 담아두고 수행할때마다 "매번 실시간으로" 읽어오는 방식을 사용하는 것은 금물.
SQL> set autotrace on
SQL> select * from scott.emp where empno=7900;
EMPNO ENAME JOB MGR HIREDATE SAL COMM DEPTNO <<< 쿼리수행결과
---------- ---------- --------- ---------- -------- ---------- ---------- ----------
7900 JAMES CLERK 7698 81/12/03 950 30
Execution Plan
----------------------------------------------------------
Plan hash value: 2949544139
--------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | <<< 실행계획
--------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 87 | 2 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| EMP | 1 | 87 | 2 (0)| 00:00:01 |
|* 2 | INDEX UNIQUE SCAN | PK_EMP | 1 | | 1 (0)| 00:00:01 |
--------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("EMPNO"=7900)
Statistics <<< 실행통계
----------------------------------------------------------
1 recursive calls
0 db block gets
2 consistent gets
6 physical reads
0 redo size
782 bytes sent via SQL*Net to client
405 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
1 rows processed
옵션 | 출력 내용 | 쿼리실행 |
---|---|---|
set autotrace on | 쿼리결과, 실행계획, 실행통계 | O |
set autotrace on explain | 쿼리결과, 실행계획 | O |
set autotrace on statistics | 쿼리결과, 실행통계 | O |
set autotrace traceonly | 실행계획, 실행통계 | O |
set autotrace traceonly explain | 실행계획 | X |
set autotrace traceonly statistics | 실행통계 | O |
구분 | 내용 |
---|---|
Role | dba, select_catalog |
일반사용자 | 실행계획: plan_table 실행통계: v$sesstat, v$statname, v$mystat |
※ AutoTrace 권한 관리 Tip: 일반사용자를 위한 AutoTrace 권한을 별도 Role로 생성에서 부여
USERNAME OSUSER TERMINAL PROGRAM STATUS LOGON_TI SID SERIAL# PROCESS
---------- --------------- ---------------- -------------------- -------- -------- ---------- ---------- ---------
SCOTT KODB-PC\KODB KODB-PC sqlplus.exe ACTIVE 16/03/29 5 5 2480:4576
SQL> SET AUTOTRACE ON STATISTICS
USERNAME OSUSER TERMINAL PROGRAM STATUS LOGON_TI SID SERIAL# PROCESS
---------- --------------- ---------------- -------------------- -------- -------- ---------- ---------- ---------
SCOTT KODB-PC\KODB KODB-PC sqlplus.exe ACTIVE 16/03/29 5 5 2480:4576
SCOTT KODB-PC\KODB KODB-PC sqlplus.exe INACTIVE 16/03/29 10 24 2480:4576
SQL> SET AUTOTRACE ON EXPLAIN
USERNAME OSUSER TERMINAL PROGRAM STATUS LOGON_TI SID SERIAL# PROCESS
---------- --------------- ---------------- -------------------- -------- -------- ---------- ---------- ---------
SCOTT KODB-PC\KODB KODB-PC sqlplus.exe ACTIVE 16/03/29 5 5 2480:4576
SQL> alter session set sql_trace=true;
SQL> select * from emp where empno=7900;
SQL> select * from dual;
SQL> alter session set sql_trace=false;
SQL> SELECT r.value || '/' || LOWER(t.instance_name) || '_ora_'
2 || ltrim(to_char(p.spid)) || '.trc' trace_file
3 FROM v$process p, v$session s, v$parameter r, v$instance t
4 WHERE p.addr = s.paddr
5 AND r.name = 'user_dump_dest'
6 AND s.sid = (SELECT sid FROM v$mystat WHERE rownum = 1)
7 ;
TRACE_FILE
------------------------------------------------------------------
c:\app\kodb\diag\rdbms\orcl\orcl\trace/orcl_ora_5964.trc
SQL> alter session set tracefile_identifier ='scott';
PS C:\app\kodb\diag\rdbms\orcl\orcl\trace> ls *scott.trc
Mode LastWriteTime Length Name
---- ------------- ------ ----
-a--- 2016-03-29 오후 3:32 3053 orcl_ora_5964_scott.trc
Trace file c:\app\kodb\diag\rdbms\orcl\orcl\trace\orcl_ora_5964_scott.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
Windows NT Version V6.1 Service Pack 1
CPU : 4 - type 586, 4 Physical Cores
Process Affinity : 0x0x00000000
Memory (Avail/Total): Ph:1677M/3318M, Ph+PgF:4093M/6635M, VA:952M/2047M
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 42
Windows thread id: 5964, image: ORACLE.EXE (SHAD)
*** 2016-03-29 15:32:05.263
*** SESSION ID:(135.981) 2016-03-29 15:32:05.263
*** CLIENT ID:() 2016-03-29 15:32:05.263
*** SERVICE NAME:(SYS$USERS) 2016-03-29 15:32:05.263
*** MODULE NAME:(SQL*Plus) 2016-03-29 15:32:05.263
*** ACTION NAME:() 2016-03-29 15:32:05.263
*** TRACE CONTINUED FROM FILE c:\app\kodb\diag\rdbms\orcl\orcl\trace\orcl_ora_5964.trc ***
=====================
PARSING IN CURSOR #4 len=32 dep=0 uid=93 oct=42 lid=93 tim=2972724228 hv=1569151342 ad='4165fed0' sqlid='4tk6t8tfsfqbf'
alter session set sql_trace=true
END OF STMT
EXEC #4:c=0,e=171,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=2972724224
*** 2016-03-29 15:32:08.944
CLOSE #4:c=0,e=14,dep=0,type=0,tim=2976410836
=====================
PARSING IN CURSOR #2 len=34 dep=0 uid=93 oct=3 lid=93 tim=2976411110 hv=2098490199 ad='37a5a404' sqlid='a2ntx1jyj8uur'
select * from emp where empno=7900
END OF STMT
PARSE #2:c=0,e=96,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3956160932,tim=2976411109
EXEC #2:c=0,e=41,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3956160932,tim=2976411242
FETCH #2:c=0,e=99,p=0,cr=7,cu=0,mis=0,r=1,dep=0,og=1,plh=3956160932,tim=2976411437
FETCH #2:c=0,e=21,p=0,cr=1,cu=0,mis=0,r=0,dep=0,og=1,plh=3956160932,tim=2976411877
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=74610 op='TABLE ACCESS FULL EMP (cr=8 pr=0 pw=0 time=0 us cost=3 size=87 card=1)'
*** 2016-03-29 15:32:12.283
CLOSE #2:c=0,e=28,dep=0,type=0,tim=2979746839
=====================
PARSING IN CURSOR #3 len=18 dep=0 uid=93 oct=3 lid=93 tim=2979747123 hv=942515969 ad='37a12304' sqlid='a5ks9fhw2v9s1'
select * from dual
END OF STMT
PARSE #3:c=0,e=103,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=272002086,tim=2979747122
EXEC #3:c=0,e=34,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=272002086,tim=2979747245
FETCH #3:c=0,e=82,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=1,plh=272002086,tim=2979747401
STAT #3 id=1 cnt=1 pid=0 pos=1 obj=116 op='TABLE ACCESS FULL DUAL (cr=3 pr=0 pw=0 time=0 us cost=2 size=2 card=1)'
FETCH #3:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=272002086,tim=2979747736
*** 2016-03-29 15:32:15.886
CLOSE #3:c=0,e=30,dep=0,type=0,tim=2983354744
=====================
PARSING IN CURSOR #4 len=33 dep=0 uid=93 oct=42 lid=93 tim=2983355377 hv=525901419 ad='4165fed0' sqlid='aam2chsgpj7mb'
alter session set sql_trace=false
END OF STMT
PARSE #4:c=0,e=455,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=2983355375
EXEC #4:c=0,e=73,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=2983355538
PS C:\app\kodb\diag\rdbms\orcl\orcl\trace> tkprof orcl_ora_5964_scott.trc report.prf sys=no
TKPROF: Release 11.2.0.1.0 - Development on 화 3월 29 15:52:42 2016
Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.
Trace file: orcl_ora_5964_scott.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
********************************************************************************
SQL ID: 4tk6t8tfsfqbf
Plan Hash: 0
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 1 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 93
********************************************************************************
SQL ID: a2ntx1jyj8uur
Plan Hash: 3956160932
select *
from
emp where empno=7900
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 8 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 0 8 0 1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 93
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL EMP (cr=8 pr=0 pw=0 time=0 us cost=3 size=87 card=1)
********************************************************************************
SQL ID: a5ks9fhw2v9s1
Plan Hash: 272002086
select *
from
dual
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 3 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 0 3 0 1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 93
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL DUAL (cr=3 pr=0 pw=0 time=0 us cost=2 size=2 card=1)
********************************************************************************
SQL ID: aam2chsgpj7mb
Plan Hash: 0
alter session set sql_trace=false
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 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: 1
Optimizer mode: ALL_ROWS
Parsing user id: 93
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0
Execute 4 0.00 0.00 0 0 0 0
Fetch 4 0.00 0.00 0 11 0 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 11 0.00 0.00 0 11 0 2
Misses in library cache during parse: 1
Misses in library cache during execute: 1
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 0 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
4 user SQL statements in session.
0 internal SQL statements in session.
4 SQL statements in session.
********************************************************************************
Trace file: orcl_ora_5964_scott.trc
Trace file compatibility: 11.1.0.7
Sort options: default
1 session in tracefile.
4 user SQL statements in trace file.
0 internal SQL statements in trace file.
4 SQL statements in trace file.
4 unique SQL statements in trace file.
61 lines in trace file.
10 elapsed seconds in trace file.
********************************************************************************
SQL ID: a2ntx1jyj8uur
Plan Hash: 3956160932
select *
from
emp where empno=7900
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 8 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 0 8 0 1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 93
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL EMP (cr=8 pr=0 pw=0 time=0 us cost=3 size=87 card=1)
********************************************************************************
항목 | 설명 |
---|---|
call | 커서 상태에 따라 Parse, Execute, Fetch 세 개의 Call로 나누어 각각에 대한 통계정보 \- Parse : 커서를 파싱하고 실행계획을 생성하는 데 대한 통계 \- Execute : 커서의 실행 단계에 대한 통계 \- Fetch : 레코드를 실제로 Fetch하는 데 대한 통계 |
count | Parse, Execute, Fetch 각 단계가 수행된 횟수 |
cpu | 현재 커서가 각 단계에서 사용한 cpu time |
elapsed | 현재 커서가 각 단계를 수행하는 데 소요된 시간 |
disk | 디스크로부터 읽은 블록 수 |
query | Consistent 모드에서 읽은 버퍼 블록 수 |
current | Current모드에서 읽은 버퍼 블록수 |
rows | 각 단계에서 읽거나 갱신한 처리건수 |
실행 통계 | Call |
---|---|
db block gets | current |
consistent gets | query |
physical reads | disk |
SQL*Net roundtrips to/from client | fetch count |
rows processed | fetch rows |
exec dbms_system.set_ev(145,3,10046,12,'');
레벨 | 내용 |
---|---|
레벨1 | Default |
레벨4 | Bind Values |
레벨8 | Waits |
레벨12 | Bind Values & Waits |
dbms_monitor.session_trace_enable(
session_id => 145,
serial_num => 3,
waits => true,
binds => true);
end;
/
dbms_monitor.session_trace_disable(
session_id => 145,
serial_num => 3);
end;
/
SQL> begin
2 dbms_monitor.serv_mod_act_trace_enable (
3 service_name => 'eCRM' -- 대소문자 구분함
4 ,module_name => dbms_monitor.all_module
5 ,action_name => dbms_monitor.all_actions
6 ,waits => true
7 ,binds => true
8);
SQL> begin
2 dbms_monitor.serv_mod_act_trace_disable (
3 service_name => 'eCRM'
4 ,module_name => dbms_monitor.all_module
5 ,action_name => dbms_monitor.all_actions
8);
SQL> select plan_table_output
from table (dbms_xplan.display('plan_table' <<< 실행 계획이 저장된 Plan_Table 명
,null <<< NULL일 경우 가장 마지막 explain_plan 출력
,'all' <<< 포맷 옵션:Basic, Typical, All, Outline, Advanced
));
SQL> set serveroutput off
SQL> select *
2 from emp e, dept d
3 where d.deptno = e.deptno
4 and e.sal >= 1000;
SQL> column prev_sql_id new_value sql_id
SQL> column prev_chi1d_number new_value child_no
SQL> select prev_sql_id, prev_child_number
2 from v$session
3 where sid=userenv('sid')
4 and username is not null
5 and prev_hash_value <> 0;
PREV_SQL_ID PREV_CHILD_NUMBER
------------- -----------------
gjk03d9kmmmhu 0
SQL> select *
2 from table (dbms_xplan.display_cursor('gjk03d9kmmmhu' <<< SQL_ID
,0 <<< Child_No
,'ALLSTATS LAST') <<< Format
);
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------
SQL_ID gjk03d9kmmmhu, child number 0
-------------------------------------
select * from emp e, dept d where d.deptno = e.deptno and e.sal >= 1000
Plan hash value: 844388907
------------------------------------------------------------------------------------
| Id | Operation | Name | E-Rows | OMem | 1Mem | Used-Mem |
------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | | |
| 1 | MERGE JOIN | | 14 | | | |
| 2 | TABLE ACCESS BY INDEX ROWID| DEPT | 4 | | | |
| 3 | INDEX FULL SCAN | PK_DEPT | 4 | | | |
|* 4 | SORT JOIN | | 14 | 2048 | 2048 | 2048 (0)|
|* 5 | TABLE ACCESS FULL | EMP | 14 | | | |
------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
4 - access("D"."DEPTNO"="E"."DEPTNO")
filter("D"."DEPTNO"="E"."DEPTNO")
5 - filter("E"."SAL">=1000)
Note
-----
- Warning: basic plan statistics not available. These are only collected when:
* hint 'gather_plan_statistics' is used for the statement or
* parameter 'statistics_level' is set to 'ALL', at session or system level
SQL> set serveroutput off
SQL> select /*+ gather_plan_statistics */ *
2 from emp e, dept d
3 where d.deptno = e.deptno
4 and e.sal >= 1000;
SQL> column prev_sql_id new_value sql_id
SQL> column prev_chi1d_number new_value child_no
SQL> select prev_sql_id, prev_child_number
2 from v$session
3 where sid=userenv('sid')
4 and username is not null
5 and prev_hash_value <> 0;
PREV_SQL_ID PREV_CHILD_NUMBER
------------- -----------------
gshst92z7qbt1 0
SQL> select *
2 from table (dbms_xplan.display_cursor('gshst92z7qbt1'
,0
,'ALLSTATS LAST'));
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------
SQL_ID gshst92z7qbt1, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ * from emp e, dept d where
d.deptno = e.deptno and e.sal >= 1000
Plan hash value: 844388907
-----------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | OMem | 1Mem | Used-Mem |
-----------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 12 |00:00:00.01 | 13 | | | |
| 1 | MERGE JOIN | | 1 | 14 | 12 |00:00:00.01 | 13 | | | |
| 2 | TABLE ACCESS BY INDEX ROWID| DEPT | 1 | 4 | 4 |00:00:00.01 | 4 | | | |
| 3 | INDEX FULL SCAN | PK_DEPT | 1 | 4 | 4 |00:00:00.01 | 2 | | | |
|* 4 | SORT JOIN | | 4 | 14 | 12 |00:00:00.01 | 9 | 2048 | 2048 | 2048 (0) |
|* 5 | TABLE ACCESS FULL | EMP | 1 | 14 | 12 |00:00:00.01 | 9 | | | |
-----------------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
4 - access("D"."DEPTNO"="E"."DEPTNO")
filter("D"."DEPTNO"="E"."DEPTNO")
5 - filter("E"."SAL">=1000)
구분 | 뷰 |
시스템 레벨 | V$SYSSTAT |
개별 세션별 | V$SESSTAT |
본인 세션 | V$MYSTAT |
SQL> SELECT NAME, VALUE FROM V$SYSSTAT
2 WHERE STATISTIC# IN (7, 47, 50, 54, 134, 335, 336, 337, 341, 342);
NAME VALUE
---------------------------------------------------------------- ----------
user calls 53079
physical read total bytes 473201664
physical write total bytes 287825920
spare statistic 3 0
commit cleanout failures: cannot pin 0
TBS Extension: bytes extended 10485760
total number of times SMON posted 18
SMON posted for undo segment recovery 0
SMON posted for dropping temp segment 0
segment prealloc tasks 0
Buffer NoWait % | 버퍼블록을 읽으려 할 때, buffer busy waits대기 없이 곧바로 읽기에 성공한 비율 |
Redo NoWait % | Redo로그를 기록할 공간을 요청하지 않고 곧바로 Redo 엔트리를 기록한 비율 이 비율이 낮으면 로그 스위칭이 느리거나 너무 자주 발생함을 의미 |
Buffer Hit % | 디스크 읽기를 수반하지 않고 버퍼캐시에서 블록찾기에 성공한 비율 |
Latch Hit % | 래치 경합없이 첫번째 시도에서 곧바로 래치를 획득한 비율 |
Library Hit % | 라이브러리 캐시에 이미 적재된 SQL커서를 생행하거나 오브젝트정보를 읽으려할 때 커서 또는 오브젝트정보가 Heap영역에서 찾아진다면 Hit에 성공 비율 Get hit율과 Pin hit율로 나누어짐 Get hit율은 Parse 단계와 관련이 있으며 이 수치가 낮다면 하드파싱 또는 최초 로드가 발생한 경우임 |
Soft Parse % | 실행계획이 라이브러리 캐시에서 찾아져 하드파싱을 일으키지 않고 SQL을 수행한 비율 |
Execute to Parse % | Parse Call없이 곧바로 SQL을 수행한 비율. 즉, 커서를 애플리케이션에서 캐싱한 채 반복 수행한 비율 n-Tier에서 이 값이 일반적으로 값이 낮게 나타남 |
Parse CPU to Parse Elapsd % | 파싱 총 소요 시간 중 CPU time이 차지한 비율. 파싱에 소요된 시간 중 실제 일을 수행한 시간비율 이값이 낮으면 대기시간이 많았다는 의미로서 Shared Pool과 라이브러리 캐시 경합이 많았다는 것을 의미하며 대개 하드파싱 부하때문임 초당 하드파싱 횟수가 거의 나타나지 않는데 이 Ratio가 낮은 수치를 기록한다면 Parse Call 자체가 많아 발생한는 경합임 |
% Non-Parse CPU | SQL을 수행하면서 사용한 전체 CPU time중 파싱 이외의 작업이 차지한 비율. 이 비율이 낮으면 파싱에 소비되는 CPU Time이 많은거며, 파싱부하를 줄이도록 애플리케이션을 개선해야함 |
In-memory Sort % | 전체 소트 수행횟수에서 In-Memory방식으로 소트한 비율 |
Memory Usage % | Shared Pool내에서 현재 사용중인 메모리 비중 |
% SQL with executions>1 | 전체 SQL 개수에서 두번이상 수행된 SQL이 차지하는 비중. 이 비율이 낮으면 Literal 상수값을 이용하는 쿼리수행빈도가 높다는 것을 의미 |
% Memory for SQL w/exec>1 | 전체 SQL이 차지하는 메모리 중 두번이상 수행된 SQL이 차지하는 메모리 비중. 이 비율이 낮으면 Literal 상수값을 사용하는 쿼리에 의해 Shared Pool이 낭비되고 있음을 의미 |
v$system_event | 인스턴스 기동 후 현재까지 누적된 이벤트 발생 현황을 시스템 레벨로 확인하고자 할 때 사용 |
v$session_event | 개별 세션별로 누적치 확인 |
v$session_wait | 세션별로 현재 진행 중이거나 바로 직전에 발생했던 이벤트 정보 |
SQL> column wait_time heading 'WAIT|TIME'
SQL> column seconds_in_wait heading 'SECONDS|IN WAIT'
SQL> SELECT event
2 , wait_time
3 , seconds_in_wait
4 , state
5 , p1text || '->' || p1 || ',' || p2text || '->' || p2 || ',' || p3text || '->' || p3 param
6 from v$session_wait
7 where sid = 70
8 ;
WAIT SECONDS
EVENT TIME IN WAIT STATE PARAM
------------------------------ ---------- ---------- ---------- -----------------------------------
enq: TX - row lock contention 0 304 WAITING name|mode->1415053318,usn<<16 | slo
t->458760,sequence->663
구분 | 내용 |
---|---|
WAIT_TIME > 0 | 마지막 대기이벤트를 대기한 시간 |
WAIT_TIME = 0 | 이 이벤트를 현재 대기 중 |
WAIT_TIME = \-1 | 마지막 대기 이벤트를 대기한 시간이 10ms 미만 |
WAIT_TIME = \-2 | 타이밍이 활성화되지 않음 |
Response Time = Servic Time + Wait Time
= CPU Time + Queue Time
구분 | 내용 |
---|---|
서비스 시간(Servic Time ) | 프로세스가 정상적으로 동작하며 일을 수행한 시간(=CPU time) |
대기 시간(Wait Time) | 대기 이벤트가 발생해 수행을 잠시 멈추고 대기한 시간(=Queue Time) |
1 | 아래 쿼리를 수행하는 20개 프로세스가 동시에 떠서 작업을 수행 {code:sql} INSERT INTO t1 SELECT /*+ ordered use_nl(t3) / seq.nextbal, t2., t3.* FROM t2, t3 WHERE t2.key = t3.key and t2.col between :range1 and :range2;{code} |
2 | 분석: db file scattered read 대기 이벤트가 Wait time의 대부부분을 차지 → Full Table Scan 원인: t2 테이블 기준으로 NL 조인을 수행하면서 반복 액세스가 일어나는 t3 테이블 조인 컬럼에 인덱스가 없어 매번 Full Table Scan으로 처리 조치: 인덱스를 추가해 정상적인 Index Scan으로 처리 |
3 | 분석: buffer busy waits과 latch: cache buffers chains 이벤트가 새롭게 발생 원인: 서버 프로세스의 처리 속도가 크게 향상되면서 버퍼 블록에 대한 동시 액세스가 증가하면서 메모리 경합이 발생 조치: 캐싱된 버퍼 블록에 대한 읽기 요청이 많아 생기는 문제이므로 블록 요청 횟수를 줄여야 한다. → NL조인을 해시 조인 방식으로 변경 |
4 | 분석: log buffer space와 enq:SQ-contention 이벤트가 새롭게 발생 원인: select 경합이 해소되면서 insert에 의한 Redo 레코드 생성 속도가 증가하니까 Redo 로그 버퍼 공간이 부족하고 Sequence 테이블에 대한 경합 발생 조치: Redo 로그 버퍼 크기를 약간 늘려주고, Sequence 캐시 사이즈를 10에서 20으로 늘림 |
구분 | 오라클 제공 버전 |
---|---|
Statspack | 8i |
AWR | 10g |
Statspack | SQL을 이용한 딕셔너리 조회 방식 |
AWR | DMA(Direct Memory Access)방식으로 SGA를 직접 액세스 |
Statspack | @$ORACLE_HOME/rdbms/admin/spreport |
AWR | @$ORACLE_HOME/rdbms/admin/awrrpt |
매일 시스템의 Load Profile 비교 |
---|
하루 업무 시간을 기분으로 추출 |
문제점을 찾아 성능 이슈를 해결할 목적 |
peak 시간대 또는 장애가 발생한 시점을 전후해 가능한 한 짧은 구간을 선택 OS모니터링 도구를 이용해 CPU, 메모리, I/O사용량을 정보를 먼저 수집하고 이를 통해 peak 시간대를 파악 |
Load Profile Per Second Per Transaction Per Exec Per Call
~~~~~~~~~~~~ --------------- --------------- ---------- ----------
DB Time(s): 0.0 0.0 0.00 0.00
DB CPU(s): 0.0 0.0 0.00 0.00
Redo size: 4,316.6 13,706.9
Logical reads: 252.4 801.4
Block changes: 27.9 88.5
Physical reads: 0.5 1.7
Physical writes: 0.4 1.2
User calls: 2.5 8.1
Parses: 7.0 22.3
Hard parses: 0.5 1.5
W/A MB processed: 0.1 0.2
Logons: 0.1 0.3
Executes: 26.9 85.4
Rollbacks: 0.0 0.0
Transactions: 0.3
Per Second | 각 측정 지표 값을 측정 시간(Snapshot Interval, 초)으로 나눈 것, 초당 부하 발생량을 의미 |
Per Transaction | 각 측정 지표 값들을 트랜잭션 개수로 나눈 것 트랜잭션 개수는 commit 또는 rollback 수행 횟수를 단순히 더한 값 |
Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 100.00 Redo NoWait %: 100.00
Buffer Hit %: 99.79 In-memory Sort %: 100.00
Library Hit %: 96.27 Soft Parse %: 93.51
Execute to Parse %: 73.91 Latch Hit %: 99.95
Parse CPU to Parse Elapsd %: 104.10 % Non-Parse CPU: 96.51
Shared Pool Statistics Begin End
------ ------
Memory Usage %: 62.73 74.90
% SQL with executions>1: 91.42 64.29
% Memory for SQL w/exec>1: 90.66 67.30
Top 5 Timed Foreground Events
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Avg
wait % DB
Event Waits Time(s) (ms) time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
DB CPU 36 102.2
control file sequential read 1,624 0 0 .9 System I/O
db file sequential read 1,382 0 0 .6 User I/O
log file sync 314 0 0 .3 Commit
SQL*Net break/reset to client 240 0 0 .1 Applicatio
SQL> select * from v$sgastat where name = 'ASH buffers';
POOL NAME BYTES
------------ -------------------------- ----------
shared pool ASH buffers 8388608
select
sample_id, sample_time --①
, session_id, session_serial#, user_id, xid --②
, sql_id, sql_child_number, sql_plan_hash_value --③
, session_state --④
, qc_instance_id, gc_session_id --⑤
, blocking_session, blocking_session_serial#, blocking_session_status --⑥
, event, event#, seq#, wait_class, wait_time, time_waited --⑦
, p1text, p1, p2text, p2, p3text, p3 --⑧
, current_obj#, current_file#, current_block# --⑨
, program, module, action, client_id --⑩
from V$ACTIVE_SESSION_HISTORY
① | 샘플링이 일어난 시간과 샘플 ID |
② | 세션정보, User명, 트랜잭션ID |
③ | 수행 중 SQL 정보 |
④ | 현재 세션의 상태 정보. 'ON CPU' 또는 'WAITING' |
⑤ | 병렬 Slave 세션일 때, 쿼리 코디네이터(QC) 정보를 찾을 수 있게 함 |
⑥ | 현재 세션의 진행을 막고 있는(=블로킹) 세션 정보 |
⑦ | 현재 발생 중인 대기 이벤트 정보 |
⑧ | 현재 발생 중인 대기 이벤트의 파라미터 정보 |
⑨ | 해당 세션이 현재 참조하고 있는 오브젝트 정보 V$session 뷰에 있는 row_wait_obj#, row_wait_file#, row_wait_block# 컬럼을 가져온 것 |
⑩ | 애플리케이션 정보 |
column current_obj# format 99999 heading 'CUR_OBJ#'
column current_file# format 999 heading 'CUR_FIL#'
column current_block# format 999 heading 'CUR_BLK#'
select to_char(sample_time, 'hh24:mi:ss') sample_tm, session_state
, event, wait_class, current_obj#, current_file#, current_block#
from v$active_session_history
where session_id = 143
and session_serial# = 9
order by sample_time;
SAMPLE_T SESSION EVENT WAIT_CLASS CUR_OBJ# EUR_FIL# CUR_CLK#
-------- ------- ----------------------------- ------------- -------- -------- --------
15:00:44 WATING enq: TX - row lock contention Application 55765 4 476
15:00:45 WATING enq: TX - row lock contention Application 55765 4 476
15:00:46 WATING enq: TX - row lock contention Application 55765 4 476
15:00:47 WATING enq: TX - row lock contention Application 55765 4 476
15:01:36 WATING enq: TX - allocate ITL entry Conficuration -1 4 476
15:01:37 WATING enq: TX - allocate ITL entry Conficuration -1 4 476
15:01:38 WATING enq: TX - allocate ITL entry Conficuration -1 4 476
15:01:39 WATING enq: TX - allocate ITL entry Conficuration -1 4
dba_hist_system_event를 이용해 그린 그래프 |
1 | AWR 뷰를 이용해 하루 동안의 이벤트 발생현황을 조회 08:15~09:15 구간에서 enq: TM - contention 이벤트가 다량 발생 |
2 | dba_hist_active_sess_history를 조회해서 해당 이벤트를 많이 대기한 세션을 확인 |
3 | 블로킹 세션 정보를 통해 dba_hist_active_sess_history를 다시 조회 블로킹 세션이 찾아지면 해당 세션이 그 시점에 어떤 작업을 수행 중이었는지 확인 sql_id를 이용해 그 당시 SQL과 실행계획까지 확인(AWR) 위 교재 예재에서는 브로킹 세션이 Append Mode Insert를 수행하면서 Exclusive 모드 TM Lock에 의한 경합이 발생 |
4 | program, module, action, client_id 등 애플리케이션 정보를 이용해 관련 프로그램을 찾아 Append 힌트를 제거 다른 트랜잭션과 동시 DML이 발생할 수 있는 상황에서는 insert문에 Append 힌트를 사용해서는 안 된다는 사실을 개발팀 전체에 공지 |
select sql_id, child_number, sql_text, sql_fulltext, parsing_schema_name --①
, sharable_mem, persistent_mem ,runtime_mem --②
, loads, invalidations, parse_calls, executions, fetches, rows_processed --③
, cpu_time, elapsed_time --④
, buffer_gets, disk_reads, sorts --⑤
, application_wait_time, concurrency_wait_time --⑥
, cluster_wait_time, user_io_waait_time --⑥
, first_load_time, last_active_time --⑦
from v$sql
① | 라이브러리 캐시에 적재된 SQL 커서 자체에 대한 정보 |
② | SQL 커서에 의해 사용되는 메모리 사용량 |
③ | 하드파싱 및 무효화 발생횟수, Parse, Execute, Fetch Call 발생 횟수, Execute, Fetch Call 발생 횟수, Execute 또는 Fetch Call 시점에 처리한 로우 건수 등 |
④ | SQL을 수행하면서 사용된CPU time과 소요시간(microsecond) |
⑤ | SQL을 수행하면서 발생한 논리적 블럭 읽기와 디스크 읽기, 그리고 소트 발생 횟수 |
⑥ | SQL 수행 도중 대기 이벤트 때문에 지연이 발생한 시간(microsecond) |
⑦ | 커서가 라이브러리 캐시에 처음 적재된 시점, 가장 마지막에 수행된 시점 |
select parsing_schema_name
, count(*) sql_cnt
, count(distinct substr(SQL_TEXT, 1, 100)) sql_cnt2
, sum(executions)
, round(avg(buffer_gets/executions)) bugger_gets
, round(avg(DISK_READS/executions)) disk_reads
, round(avg(ROWS_PROCESSED/executions)) rows_processed
, round(avg(elapsed_time/executions/1000000),2) "ELAPSED TIME(AVG)"
, count(case when elapsed_time/executions/1000000 >= 10 then 1 end) "BAD SQL"
, round(max(elapsed_time/executions/1000000),2) "ELAPSED_TIME(MAX)"
from v$sql
where parsing_schema_name in ('원무', '공통', '진료', '사업/행정', '진료지원')
and last_active_time >= to_date('20090315','yyyymmdd')
group by parsing_schema_name;
뷰 | 내 용 |
---|---|
v$sql_plan | 실행계획 |
v$sql_plan_statistics | 각 Row Source별 수행 통계 |
v$sql_bind_capture | 샘플링한 바인드 변수 값 |
-- 지정
SQL> begin
2 dbms_workload_repository.add_colored_sql(sql_id => 'abr8dkhpuh3gx');
3 end;
4 /
-- 조회
SQL> select * from dba_hist_colored_sql;
DBID SQL_ID CREATE_T
---------- ------------- --------
2822792603 abr8dkhpuh3gx 16/04/02
-- 해제
SQL> begin
2 dbms_workload_repository.remove_colored_sql('abr8dkhpuh3gx');
3 end;
4 /
SQL> select * from dba_hist_colored_sql;
선택된 레코드가 없습니다.
1 | 라이브러리 캐시 최적화 |
2 | 데이터베이스 Call 최소화 |
3 | I/O 효율화 및 버퍼캐시 최적화 |