오라클 성능 트러블슈팅의 기초 (2012년)
액티브 세션 히스토리 0 0 74,808

by 구루비스터디 ASH ACTIVE SESSION HISTROY [2018.09.27]


  1. 액티브 세션 히스토리
  2. V$ACTIVE_SESSION_HISTROY 뷰
    1. ASH 리포트
    2. ASH 덤프
    3. DBA_HIST_ACTIVE_SESS_HISTORY 뷰
    4. Enterprise Manager의 성능탭 GUI 화면


*성능 트러블슈팅의 기본: 시스템과 세션의 전반적인 성능 문제를 효과적으로 파악하는 것*

세가지 방법

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 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, 세션, 서비스, 모듈에 대해 타겟을 지정할때 활용

PrameterDescription
l_dbidThe database identifier
l_inst_numThe instance number
l_btimeThe 'begin time'
l_etimeThe 'end time'
l_optionsReport level (currently not used)
l_slot_widthSpecifies (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_sidThe session ID (for example, V$SESSION.SID)
l_sql_idThe SQL ID (for example, V$SQL.SQL_ID)
l_wait_classThe wait class name (for example, V$EVENT_NAME.WAIT_CLASS)
l_service_hashThe service name hash (for example, V$ACTIVE_SERVICES.NAME_HASH)
l_moduleThe module name (for example, V$SESSION.MODULE)
l_actionThe action name (for example, V$SESSION.ACTION)
l_client_idThe client ID for end-to-end backtracing (for example, V$SESSION.CLIENT_IDENTIFIER)


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년에 "오라클 성능 트러블슈팅의 기초 " 도서를 스터디하면서 정리한 내용 입니다.

- 강좌 URL : http://www.gurubee.net/lecture/4105

- 구루비 강좌는 개인의 학습용으로만 사용 할 수 있으며, 다른 웹 페이지에 게재할 경우에는 출처를 꼭 밝혀 주시면 고맙겠습니다.~^^

- 구루비 강좌는 서비스 제공을 위한 목적이나, 학원 홍보, 수익을 얻기 위한 용도로 사용 할 수 없습니다.

댓글등록
SQL문을 포맷에 맞게(깔끔하게) 등록하려면 code() 버튼을 클릭하여 작성 하시면 됩니다.
로그인 사용자만 댓글을 작성 할 수 있습니다. 로그인, 회원가입