- 이 문서는 구루비에서 작성하였습니다.
- 이 문서를 다른 블로그나 홈페이지에 게재하실 경우에는 출처를 꼭 밝혀 주시면 고맙겠습니다.~^^
- 출처 : http://wiki.gurubee.net/pages/viewpage.action?pageId=20742150&
- 구루비 지식창고의 모든 문서는 크리에이티브 커먼즈의 저작자표시-비영리-동일조건변경허락(BY-NC-SA) 라이선스에 따라 자유롭게 사용할 수 있습니다.
 | 성능 트러블슈팅의 기본: 시스템과 세션의 전반적인 성능 문제를 효과적으로 파악하는 것 세가지 방법
|
액티브 세션 히스토리
- 현재 오라클 성능 문제를 분석하는데 있어서 가장 기본적이고 중요한 데이터
- 액티브 세션: 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 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 -------------------------------------------------------------
- 가장 기본적인 성능 정보(SGA 크기, 샘플수, 액티브 세션 수)
| DBMS_WORKLOAD_REPOSITORY.ASH_REPORT_XXX함수 파라미터 특정 sql, 세션, 서비스, 모듈에 대해 타겟을 지정할때 활용
|
ASH 덤프
- 시스템 성능 문제가 심각하여 V$ACTIVE_SESSION_HISTORY 뷰 조회나 ASH 리포트 생성 쿼리도 실행이 되지 않을때 ASH 덤프 이용
예비 접속 사용 정상적인 접속이 불가능한 비상상황에서 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) 에서 출간한 '오라클 성능 트러블슈팅의 기초'를 참고하였습니다.
문서정보
- 이 문서는 구루비에서 작성하였습니다.
- 이 문서를 다른 블로그나 홈페이지에 게재하실 경우에는 출처를 꼭 밝혀 주시면 고맙겠습니다.~^^
- 출처 : http://wiki.gurubee.net/pages/viewpage.action?pageId=20742150&
- 구루비 지식창고의 모든 문서는 크리에이티브 커먼즈의 저작자표시-비영리-동일조건변경허락(BY-NC-SA) 라이선스에 따라 자유롭게 사용할 수 있습니다.