액티브 세션 히스토리 (by tlswofl) [2012.03.13]
*성능 트러블슈팅의 기본: 시스템과 세션의 전반적인 성능 문제를 효과적으로 파악하는 것*
세가지 방법
1. 액티브 세션 히스토리
2. AWR 리포트
3. 시스템과 세션 스냅샷 리포트
액티브 세션 히스토리
- 현재 오라클 성능 문제를 분석하는데 있어서 가장 기본적이고 중요한 데이터
- 액티브 세션: CPU 점유/락, 래치, 파일, 네트워크와 같은 자원을 획득하기 위해 대기하는 세션
- 1초마다 액티브 세션의 정보를 수집하여 Shared Pool의 ASH 버퍼 영역에 저장
액티브 세션 히스토리를 사용하는 간단한 예제
***** 테이블 생성후 1 row 추가한다.
SQL> create table t1(c1 number);
SQL> insert into t1 values(1);
SQL> commit;
***** TEMP.SQL을 작성한다.
begin
for idx in 1..10 loop
update t1 set c1 = 1;
dbms_lock.sleep(1);
commit;
for r in (select * from user_objects) loop
null;
end loop;
end loop;
end;
/
***** 10개의 세션에서 동시에 TEMP.SQL 파일을 실행한다.
- 10개의 세션이 동시에 T1의 동일한 로우를 업데이트하기 때문에 Row Level Lock 경합이 발생
- 아래 4가지 방법을 이용하여 액티브 세션 히스토리가 제공하는 데이터를 확인
- V$ACTIVE_SESSION_HISTROY 뷰
- ASH 리포트
- ASH 덤프
- DBA_HIST_ACTIVE_SESS_HISTORY 뷰
- Enterprise Manager의 성능탭 GUI 화면
V$ACTIVE_SESSION_HISTROY 뷰
- 컬럼 하나 하나가 성능 문제를 분석하는데 있어 유용한 정보를 제공(자세한 컬럼 설명은 매뉴얼 참고)
가장 최근에 캡처된 액티브 세션의 목록을 추출
select
to_char(h.sample_time,'mi:ss') as sample_time,
h.session_id as sid,
h.session_state as st,
h.sql_id,
(select sql_text from v$sqlarea a where a.sql_id=h.sql_id) as sql_text,
event,
blocking_session as blocker
from
v$active_session_history h
where
sample_id = (select max(sample_id) from v$active_session_history)
and session_id <> userenv{'sid')
;
***** 결과
SAMPLE_TIME SID ST SQL_ID SQL_TEXT EVENT BLOCKER
--------------- ----- --------------------- --------------------------------------- -------------------- ---------- ----------
29:58 1341 WAITING 38w2yh616xkw3 UPDATE T1 SET C1 = 1 enq: TX - 1151
row lock c
ontention
- enq: TX - row lock contention 이벤트를 대기
- 1151 세션에 의해 모든 세션들이 대기 상태에 빠져 있는 것을 확인
- 액티브 세션 히스토리를 이용하여 현재 시스템이 겪고 있는 문제를 가장 직관적으로 확인 가능
특정 세션이 시간 순으로 어떤 변화를 겪고 있는지 분석
select *
from (
select
h.session_id as sid,
to_char(h.sample_time,'mi:ss') as sample_time,
h.sql_id,
(select sql_text from v$sqlarea a where a.sql_id = h.sql_id) as sql_text,
event,
blocking_session as blocker
from
v$active_session_history h
where
h.session_id = &sid
order by h.sample_time desc
) where rownum <= 20
;
***** 결과
SID SAMPLE_TIME SQL_ID SQL_TEXT EVENT BLOCKER
----- --------------- -------------------- -------------------- ---------- ----------
1341 29:58 38w2yh616xkw3 UPDATE T1 SET C1 = 1 enq: TX - 1151
row lock c
ontention
1341 29:56 38w2yh616xkw3 UPDATE T1 SET C1 = 1 enq: TX - 1151
row lock c
ontention
1341 29:54 38w2yh616xkw3 UPDATE T1 SET C1 = 1 enq: TX - 1151
row lock c
ontention
1341 29:52 38w2yh616xkw3 UPDATE T1 SET C1 = 1 enq: TX - 1151
row lock c
ontention
1341 29:50 38w2yh616xkw3 UPDATE T1 SET C1 = 1 enq: TX - 1151
row lock c
ontention
- 1341 세션은 계속적으로 enq:TX-row lock contention 이벤트를 대기
- blocker는 위에서는 같게 나오지만(2개의 세션만으로 테스트했기 때문) 여러개의 세션을 사용시 계속적으로 변경됨(번갈아 가면서 로우 레벨 락을 획득하기 위해 경쟁하기 때문)
- 특정시간의 액티브 세션의 목록 분석/특정 세션이 시간 순으로 어떤 상태에 있는지 분석하는 것만으로 시스템 성능 문제의 대부분 파악 가능
ASH 리포트
- DBMS_WORKLOAD_REPOSITORY패키지의 ASH_REPORT_XXX 함수를 이용하여 특정 구간동안의 ASH 요약 리포트 생성
- 오라클이 제공하는 @?/rdbms/admin/ashrpt.sql 파일 이용하여 ASH 요약 리포트 생성'
- ASH 리포트는 V$ACTIVE_SESSION_HISTORY 뷰나 DBA_HIST_ACTIVE_SESS_HISTORY 뷰를 기반으로 필요한 데이터를 만들어낸다.
10초전~현재까지의 ASH 리포트 생성 예제
col db_id new_value db_id;
col inst_num new_value inst_num;
select dbid as db_id from v$database;
DB_ID
----------
3588319577
select instance_number as inst_num from v$instance;
INST_NUM
----------
1
select * from table(
dbms_workload_repository.ash_report_text(
&db_id,
&inst_num,
sysdate - 10/24/60/60,
sysdate
));
- ASH 리포트 분석 정보
- 가장 기본적인 성능 정보(SGA 크기, 샘플수, 액티브 세션 수)
DB Name DB Id Instance Inst Num Release RAC Host
------------ ----------- ------------ -------- ----------- --- ------------
ELEVEN 3588319577 ELEVEN 1 11.2.0.1.0 NO oranewdb
CPUs SGA Size Buffer Cache Shared Pool ASH Buffer Size
---- ------------------ ------------------ ------------------ ------------------
8 2,039M (100%) 448M (22.0%) 816M (40.0%) 15.5M (0.8%)
Analysis Begin Time: 13-Mar-12 16:29:58
Analysis End Time: 13-Mar-12 16:30:58
Elapsed Time: 1.0 (mins)
Begin Data Source: V$ACTIVE_SESSION_HISTORY
End Data Source: V$ACTIVE_SESSION_HISTORY
Sample Count: 4
Average Active Sessions: 0.07
Avg. Active Session per CPU: 0.01
Report Target: None specified
Top User Events DB/Inst: ELEVEN/ELEVEN (Mar 13 16:29 to 16:30)
Avg Active
Event Event Class % Event Sessions
----------------------------------- --------------- ---------- ----------
CPU + Wait for CPU CPU 25.00 0.02
enq: TX - row lock contention Application 25.00 0.02
-------------------------------------------------------------
Top Background Events DB/Inst: ELEVEN/ELEVEN (Mar 13 16:29 to 16:30)
- 대기 이벤트 정보(대기이벤트, 대기클래스, 대기시간정보)
Event Event Class % Event Sessions
----------------------------------- --------------- ---------- ----------
CPU + Wait for CPU CPU 25.00 0.02
enq: TX - row lock contention Application 25.00 0.02
-------------------------------------------------------------
Top Background Events DB/Inst: ELEVEN/ELEVEN (Mar 13 16:29 to 16:30)
Avg Active
Event Event Class % Activity Sessions
----------------------------------- --------------- ---------- ----------
CPU + Wait for CPU CPU 50.00 0.03
- 대기 이벤트의 파라미터를 알 수 있어 어떤 자원에서 경합이 발생하는지 구체적 정보 파악 가능
Top Event P1/P2/P3 Values DB/Inst: ELEVEN/ELEVEN (Mar 13 16:29 to 16:30)
Event % Event P1 Value, P2 Value, P3 Value % Activity
------------------------------ ------- ----------------------------- ----------
Parameter 1 Parameter 2 Parameter 3
-------------------------- -------------------------- --------------------------
enq: TX - row lock contention 25.00 "1415053318","655365","27706" 25.00
name|mode usn<<16 | slot sequence
-------------------------------------------------------------
- Top SQL에 대한 정보(명령 유형, 실행단계, 대기이벤트, Row Source등 정보 제공)를 제공
Top SQL Command Types DB/Inst: ELEVEN/ELEVEN (Mar 13 16:29 to 16:30)
-> 'Distinct SQLIDs' is the count of the distinct number of SQLIDs with the given SQL Command Type found over all the ASH samplesctive
SQL Coin the analysis period SQLIDs % Activity Sessions
---------------------------------------- --
Distinct Avg Active
SQL Command Type SQLIDs % Activity Sessions
---------------------------------------- ---------- ---------- ----------
SELECT
UPDATE 1 25.00 0.026:30) -------------------------------------------------------------
Top Phases of Execution DB/Inst: ELEVEN/ELEVEN (Mar 13 16:29 to 16:30)
------------------------------ ----------
Avg Active
Phase of Execution % Activity Sessions-------------------
------------------------------ ---------- ----------
SQL Execution 50.00 0.03 -------------------------------------------------------------^LTop SQL with Top Events DB/Inst: ELEVEN/ELEVEN (Mar 13 16:29 to 16:30)y
----------------------- -------------------- -----------
Event % Eve ow Sourc Sampled #
SQL ID Planhash of Executions % Activity
----------------------- -------------------- -------------------- --------------
Event % Event Top Row Source % RwSrc
------------------------------ ------- --------------------------------- -------
38w2yh616xkw3 2927627013 1
enq: TX - row lock contention 25.00 UPDATE 1 25.00
UPDATE T1 SET C1 = 1 25.00 FIXED TABLE - FIXED INDEX 25.00
select to_
9fuz3z6xhya28 h.sql_id, 672577666 1 a where a.
CPU + Wait for CPU 25.00 FIXED TABLE - FIXED INDEX 25.00
select to_char(h.sample_time,'mi:ss') as sample_time, h.session_id as sid, h.session_state as st, h.sql_id, (select sql_text from v$sqlarea a where a.
sql_id=h.sql_id) as sql_text, event, blocking_session as blocker from v$ac
tive_session_history h where sample_id = (select max(sample_id) from v$active_
Top SQL wi -------------------------------------------------------------Top SQL with Top Row Sources DB/Inst: ELEVEN/ELEVEN (Mar 13 16:29 to 16:30)ty
----------------------- -------------------- -----------
Row Source wSrc Top Sampled #
SQL ID PlanHash of Executions % Activity
----------------------- -------------------- -------------------- --------------
Row Source % RwSrc Top Event % Event
---------------------------------------- ------- ----------------------- -------
38w2yh616xkw3 2927627013 1 a28 6725776625.00 enq: TX - row lock cont 25.00
UPDATE T1 SET C1 = 1INDEX 25.00 CPU + Wait for CPU 25.00
select to_
....
- Top Session 정보
- Samples Active: 특정 이벤트에 대해 대기하는 세션이 발견된 ASH 샘플수
- XIDs: 샘플링된 ASH에서 어떤 세션이 특정이벤트에 대해 대기할때의 transaction ID 수
- 병렬 쿼리를 실행하는 세션의 경우, 각각의 PQ Slave에서 실행되는 것을 통합해서 보여주지 않으므로 'Top Sessions running PQs'을 참고해서 확인이 필요하다.
- Top Session 정보
Top Sessions DB/Inst: ELEVEN/ELEVEN (Mar 13 16:29 to 16:30)
Sid, Serial# % Activity Event % Event--------------- ---------- ------------------------------ ----------User Program # Samples Active XIDs-------------------- ------------------------------ ------------------ -------- 1, 1 50.00 CPU + Wait for CPU 50.00SYS oracle@oranewdb (DIA0) 2/60 [ 3%] 0
7,56035 25.00 CPU + Wait for CPU 25.00
SYS sqlplus@oranewdb (TNS V1-V3) 1/60 [ 2%] 0
1341,41838 25.00 enq: TX - row lock contention 25.00
SYS sqlplus@oranewdb (TNS V1-V3) 1/60 [ 2%] 0
-------------------------------------------------------------
Top Blocking Sessions DB/Inst: ELEVEN/ELEVEN (Mar 13 16:29 to 16:30)
Blocking Sid (Inst) % Activity Event Caused % Event
-------------------- ---------- ------------------------------ ----------
User Program # Samples Active XIDs
-------------------- ------------------------------ ------------------ --------
1151,60462( 1) 25.00 enq: TX - row lock contention 25.00
** NOT FOUND ** BLOCKING SESSION NOT FOUND 0/60 [ 0%] N/A
-------------------------------------------------------------
DBMS_WORKLOAD_REPOSITORY.ASH_REPORT_XXX함수 파라미터
특정 sql, 세션, 서비스, 모듈에 대해 타겟을 지정할때 활용
| Prameter | Description |
|---|---|
| l_dbid | The database identifier |
| l_inst_num | The instance number |
| l_btime | The 'begin time' |
| l_etime | The 'end time' |
| l_options | Report level (currently not used) |
| l_slot_width | Specifies (in seconds) how wide the slots used in the "Top Activity" section of the report should be. This argument is optional, and if it is not specified the time interval between l_btime and l_etime is appropriately split into not more than 10 slots. |
| l_sid | The session ID (for example, V$SESSION.SID) |
| l_sql_id | The SQL ID (for example, V$SQL.SQL_ID) |
| l_wait_class | The wait class name (for example, V$EVENT_NAME.WAIT_CLASS) |
| l_service_hash | The service name hash (for example, V$ACTIVE_SERVICES.NAME_HASH) |
| l_module | The module name (for example, V$SESSION.MODULE) |
| l_action | The action name (for example, V$SESSION.ACTION) |
| l_client_id | The client ID for end-to-end backtracing (for example, V$SESSION.CLIENT_IDENTIFIER) |
ASH 덤프
- 시스템 성능 문제가 심각하여 V$ACTIVE_SESSION_HISTORY 뷰 조회나 ASH 리포트 생성 쿼리도 실행이 되지 않을때 ASH 덤프 이용
{tip:title=예비 접속 사용}
정상적인 접속이 불가능한 비상상황에서 systemstate 덤프와 같은 데이터를 수집하기 위한 용도로 제공
- "-prelim" 옵션 사용*
sqlplus -prelim / as sysdba
- 또는 set_prelim on 명령 사용*
sqlplus /nolog
set _prelim on
conn /as sysdba
- 그 후 oradebug dump ashdump 명령 호출*
oradebug setmypid
oradebug dump ashdump 10
oradebug tracefile_name
- 특정 시간 동안의 ASH 메모리를 텍스트 형태로 트레이스 파일에 기록하는 기능
- oradebug 덤프 명령 사용
ASH 덤프 사용 예제
SQL> oradebug setmypid
Statement processed.
SQL> oradebug dump ashdump 3 -- 지난 3분간의 액티브 세션 히스토리를 기록
Statement processed.
SQL> oradebug tracefile_name
/oracle/eleven/diag/rdbms/eleven/ELEVEN/trace/ELEVEN_ora_20606.trc
-- 트레이스 파일을 열어 보면 덤프 내용을 테이블에 로드할 수 있는 SQL *Loader 정보들이 기록(사용 편의성을 높이기 위해)
------------------------------------------
Step 1: Create destination table <ashdump>
------------------------------------------
CREATE TABLE ashdump AS
SELECT * FROM SYS.WRH$_ACTIVE_SESSION_HISTORY WHERE rownum < 0
----------------------------------------------------------------
Step 2: Create the SQL*Loader control file <ashldr.ctl> as below
----------------------------------------------------------------
load data
infile * "str '\n####\n'"
append
into table ashdump
fields terminated by ',' optionally enclosed by '"'
(
SNAP_ID CONSTANT 0 ,
DBID ,
INSTANCE_NUMBER ,
SAMPLE_ID ,
SAMPLE_TIME TIMESTAMP ENCLOSED BY '"' AND '"' "TO_TIMESTAMP(:SAMPLE_TIME ,'MM-DD-YYYY HH24:MI:SSXFF')" ,
SESSION_ID ,
SESSION_SERIAL# ,
SESSION_TYPE ,
....
MACHINE ,
PORT ,
ECID
)
---------------------------------------------------
Step 3: Load the ash rows dumped in this trace file
---------------------------------------------------
sqlldr userid/password control=ashldr.ctl data=<this_trace_filename> errors=1000000
---------------------------------------------------
<<<ACTIVE SESSION HISTORY - PROCESS TRACE DUMP HEADER END>>>
<<<ACTIVE SESSION HISTORY - PROCESS TRACE DUMP BEGIN>>>
####3588319577,1,52954001,"03-14-2012 14:02:04.246443000",384,1,2,0,"",0,0,0,"",0,0,0,0,0,0,"",0,0,0,0,0,0,0,133155944,7570,1,0,0,0,29729,4294967292,0,1,4294967295,0,0,0,0,0,,0,0,165959219,"oracle@oranewdb (DBW0)","","","","oranewdb",0,""
####3588319577,1,52954000,"03-14-2012 14:02:03.246443000",384,1,2,0,"",0,0,0,"",0,0,0,0,0,0,"",0,0,0,0,0,0,0,133155944,7526,1,0,0,0,20386,4294967292,0,1,4294967295,0,0,0,0,0,,0,0,165959219,"oracle@oranewdb (DBW0)","","","","oranewdb",0,""
####3588319577,1,52953975,"03-14-2012 14:01:38.196443000",1341,41838,1,0,"7dazh7hup4yq3",2,3,9594626248704926389,"cjb5pdyrsjmyr",47,2733724707,2,51,0,16777255,"03/14/2012 14:01:37",0,0,0,0,0,0,0,818280116,88,100,0,0,1000641,0,4294967291,0,1,4294967295,1,83585,0,94,12166,,0,1024,3427055676,"sqlplus@oranewdb (TNS V1-V3)","sqlplus@oranewdb (TNS V1-V3)","","","oranewdb",0,""
....
DBA_HIST_ACTIVE_SESS_HISTORY 뷰
- V$ACTIVE_SESSION_HISTORY 뷰의 AWR 버전이며 기본적인 사용법은 동일
- 제약사항은 실제 액티브 세션의 10%에 해당하는 데이터만 저장하는 것(V$ 뷰와는 달리 10초 단위로 샘플링)
- ASH 리포트를 이용하면 보다 간편하게 이 뷰를 사용할 수 있으며 ASH 리포트는 선택적으로 V$ACTIVE_SESSION_HISTORY 뷰와 DBA_HIST_ACTIVE_SESS_HISTORY 뷰를 선택적으로 사용하며 어느 뷰를 사용할지 직접 지정할 수 도 있음
Enterprise Manager의 성능탭 GUI 화면
문서에 대하여
- 최초작성일 : 2012년 03월 03일
- 이 문서는 오라클클럽 오라클 성능 트러블슈팅의 기초 스터디 모임에서 작성하였습니다.
- {*}이 문서의 내용은 엑셈(EXEM) 에서 출간한 '오라클 성능 트러블슈팅의 기초'를 참고하였습니다.*