9. ASH(Active Session History)

조회 수 12506 추천 수 0 2010.06.16 21:05:01
실천하자 *.51.205.73

ASH 등장배경


- 문제 원인을 찾기 위한 여러 분석방법이 있음

- 구조적 문제가 흔히 발생하지 않기 때문에 시스템 레벨에서 분석보다

   일반적으로 세션 레벨의 성능 분석을 요함


▶ 기존 제공 세션 레벨 동적 성능 뷰만으로 해결하지 못하는 문제가 대부분


SQL 트레이스를 통한 상세한 세션 레벨 분석이 가능

→ 시스템 부하 큼

→ 파일단위 정보 수집으로 통계적 접근 어려움

→ 분석 완료까지 긴 시간 필요


☞ 오라클 10g 부터 ASH 기능 등장



ASH(Active Session History)


- 별도의 Third Party 모니터링 도구 없이 오라클 내 세션 레벨 실시간 모니터링 가능케함

   ☞ OWI 활용성 극대화


- Active 세션 정보를 1초에 한번씩 샘플링 하여 ASH 버퍼에 저장 ☞ AWR에 저장

SQL> select * from v$sgastat where name = 'ASH buffers';


POOL           NAME                               BYTES
------------ -------------------------- ----------
shared pool   ASH buffers                       4194304


- ASH 버퍼 저장된 세션 히스토리 정보 (v$active_session_history)

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, qc_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

  • line  2     샘플링이 일어난 시간과 샘플 ID
  • line  3     세션정보, User 명, 트랜잭션 ID
  • line  4     수행중 SQL 정보
  • line  5     현재 세션의 상태 정보, 'ON CPU' 또는 'WAITING'
  • line  6     병렬 Slave 세션일 때, 쿼리 코디네이터(QC) 정보를 찾을 수 있게 함
  • line  7, 8  현재 세션의 진행을 막고 있는(blocking) 세션 정보
  • line  9     현재 발생 중인 대기 이벤트 정보
  • line 10     현재 발생 중인 대기 이벤트의 파라미터 정보
  • line 11     해당 세션이 현재 참조하고 있는 오브젝트 정보. v$session 뷰의 컬럼
  • line 12     애플리케이션 정보
☞ line 7~11의 정보가 매용 유용, 블로킹 세션 정보를 통해 현재 Lock 발생 시킨 세션을 찾음


- 오브젝트 정보의 의미 있는 값

   → 현재 발생 중인 대기 이벤트의 Wait Class가 Application, Concurrency, Cluster, User I/O 일 때

SQL> SELECT  to_char(sample_time, 'hh24:mi:ss') sample_tm, session_state

  2        , event, wait_class, current_obj#, current_file#, current_block#
  3  FROM   V$ACTIVE_SESSION_HISTORY
  4  --WHERE session_id = 143              -- p.223
  5  --AND   session_serial# = 9           -- p.223
  6  WHERE  session_state = 'WAITING'

  7  ORDER BY sample_time;


p.223 예시

                                                                                         CUR_   CUR_ CUR_

SAMPLE_T SESSION EVENT                                                   WAIT_CLASS      OBJ#   FIL# BLK#

-------- ------- ------------------------------------------------------- --------------- ------ ---- ------

15:00:46 WAITING enq : TX - row lock contention                           Application     55765   4     476

15:00:47 WAITING enq : TX - row lock contention                           Application     55765   4     476

15:01:36 WAITING enq : TX - allocate ITL entry                            Configuration      -1   4     476

15:01:37 WAITING enq : TX - allocate ITL entry                            Configuration      -1   4     476


※ 함께 출력 된 오브젝트에 Lock이 걸렸다고 판단해서 안됨. 오브젝트 번호 "-1" 해당

   직전에 발생한 이벤트의 오브젝트 정보(파일번호, 블럭번호)가 계속 남아서 보이는 현상을 예로 보여줌.



TEST 결과 : 우분투9 오라클 10gR2

                                                                                         CUR_   CUR_ CUR_

SAMPLE_T SESSION EVENT                                                   WAIT_CLASS      OBJ#   FIL# BLK#

-------- ------- ------------------------------------------------------- --------------- ------ ---- ------

01:10:06 WAITING db file sequential read                                  User I/O          -1    0       0

01:10:06 WAITING db file scattered read                                   User I/O        4586    1    9666

01:10:07 WAITING db file sequential read                                  User I/O          -1    0       0

01:10:08 WAITING control file parallel write                              System I/O      4586    1    9666

01:10:09 WAITING db file sequential read                                  User I/O        4586    1    9666

01:10:10 WAITING db file sequential read                                  User I/O          -1    0       0
01:10:11 WAITING db file sequential read                                  User I/O          90    1     674
01:10:11 WAITING db file sequential read                                  User I/O        8803    3    2772
01:10:11 WAITING os thread startup                                        Concurrency     5055    1   10905
01:10:12 WAITING db file scattered read                                   User I/O        8781    3    2677
01:10:12 WAITING os thread startup                                        Concurrency     5055    1   10905
01:10:13 WAITING os thread startup                                        Concurrency     5055    1   10905
01:10:13 WAITING latch: library cache                                     Concurrency     8782    3    2684
01:10:13 WAITING latch: library cache                                     Concurrency      105    1     796
01:10:13 WAITING db file sequential read                                  User I/O        5106    1   11114
01:10:14 WAITING library cache load lock                                  Concurrency       -1    0       0
01:10:14 WAITING enq: PR - contention                                     Other           5055    1   10905
01:10:14 WAITING latch: shared pool                                       Concurrency      335    1   56099
01:10:14 WAITING os thread startup                                        Concurrency       -1    0       0
01:10:14 WAITING db file sequential read                                  User I/O          -1    0       0
01:10:15 WAITING db file sequential read                                  User I/O         335    1   48347
01:10:15 WAITING db file sequential read                                  User I/O        8789    3    2716
01:10:15 WAITING enq: PR - contention                                     Othe             5055   1   10905
01:10:15 WAITING library cache load lock                                  Concurrency       -1    0       0
01:10:15 WAITING os thread startup                                        Concurrency       -1    0       0
01:10:16 WAITING db file sequential read                                  User I/O         335    1   48347
01:10:16 WAITING latch: shared pool                                       Concurrency       -1    0       0
01:10:16 WAITING Streams AQ: qmn coordinator waiting for slave to start   Other             -1    0       0
01:10:16 WAITING latch free                                               Other          49860    3    3161
01:10:16 WAITING os thread startup                                        Concurrency     5055    1   10905
01:10:17 WAITING latch: row cache objects                                 Concurrency      345    1   15455
01:10:17 WAITING Streams AQ: qmn coordinator waiting for slave to start   Other             -1    0       0
01:10:17 WAITING db file scattered read                                   User I/O       49860    3    3722
01:10:17 WAITING os thread startup                                        Concurrency     5055    1   10905
01:10:17 WAITING latch: shared pool                                       Concurrency     8789    3    2716
01:10:18 WAITING latch: shared pool                                       Concurrency      335    1    2660
01:10:18 WAITING Streams AQ: qmn coordinator waiting for slave to start   Other             -1    0       0
01:10:18 WAITING latch: shared pool                                       Concurrency       -1    0       0
01:10:18 WAITING latch: shared pool                                       Concurrency    42483    3   13764
01:10:18 WAITING db file sequential read                                  User I/O         335    1   10921
01:10:18 WAITING latch: shared pool                                       Concurrency       -1    0       0
01:10:18 WAITING enq: JS - queue lock                                     Other           5055    1   10905
01:10:19 WAITING db file sequential read                                  User I/O        5127    3    1482
01:10:19 WAITING db file sequential read                                  User I/O          -1    0       0
01:10:19 WAITING Streams AQ: qmn coordinator waiting for slave to start   Other             -1    0       0
01:10:19 WAITING db file sequential read                                  User I/O         355    1   53203
01:10:19 WAITING db file sequential read                                  User I/O        8798    3    2748
01:10:19 WAITING enq: JS - queue lock                                     Other            5055   1   10905
01:10:20 WAITING db file sequential read                                  User I/O          -1    0       0
01:10:20 WAITING os thread startup                                        Concurrency       -1    0       0
01:10:20 WAITING db file sequential read                                  User I/O         335    1   10921
01:10:21 WAITING log file sync                                            Commit            -1    0       0
01:10:21 WAITING Streams AQ: qmn coordinator waiting for slave to start   Other             -1    0       0
01:10:21 WAITING os thread startup                                        Concurrency       -1    0       0
01:10:21 WAITING log file parallel write                                  System I/O        -1    0       0
01:10:21 WAITING db file sequential read                                  User I/O         335    1   56104
01:10:22 WAITING Streams AQ: qmn coordinator waiting for slave to start   Other             -1    0       0
01:10:22 WAITING db file scattered read                                   User I/O       50291    3   26190
01:10:23 WAITING db file sequential read                                  User I/O          -1    0       0
01:10:23 WAITING Streams AQ: qmn coordinator waiting for slave to start   Other             -1    0       0
01:10:24 WAITING Streams AQ: qmn coordinator waiting for slave to start   Other             -1    0       0
01:10:25 WAITING db file sequential read                                  User I/O       50364    3    3172
01:10:25 WAITING Streams AQ: qmn coordinator waiting for slave to start   Other             -1    0       0
01:10:26 WAITING db file sequential read                                  User I/O       50364    3    3172
01:10:27 WAITING db file scattered read                                   User I/O          70    1   46657
01:10:30 WAITING db file sequential read                                  User I/O       50364    3    3366
01:10:32 WAITING db file scattered read                                   User I/O       50309    3   26324
01:11:25 WAITING control file parallel write                              System I/O        -1    0       0
01:15:04 WAITING db file sequential read                                  User I/O           1    5       2
01:15:05 WAITING db file sequential read                                  User I/O           1    5       2
01:15:06 WAITING db file sequential read                                  User I/O           1    5       2
01:15:07 WAITING db file sequential read                                  User I/O           1    5       2
01:15:08 WAITING db file sequential read                                  User I/O           1    5       2
01:15:09 WAITING db file sequential read                                  User I/O           1    5       2
01:18:48 WAITING null event                                               Other             -1    0       0
01:20:28 WAITING db file sequential read                                  User I/O          -1    0       0
01:20:30 WAITING db file sequential read                                  User I/O          -1    0       0
01:20:31 WAITING db file scattered read                                   User I/O          -1    0       0
01:20:31 WAITING log file parallel write                                  System I/O        -1    0       0
01:21:06 WAITING control file parallel write                              System I/O        -1    0       0
01:25:10 WAITING log file parallel write                                  System I/O        -1    0       0
01:28:34 WAITING os thread startup                                        Concurrency     5055    1   10905
01:28:34 WAITING null event                                               Other             -1    0       0

01:30:40 WAITING control file parallel write                              System I/O        -1    0       0

01:30:52 WAITING db file sequential read                                  User I/O          -1    0       0
01:31:26 WAITING control file parallel write                              System I/O        -1    0       0
01:31:39 WAITING log file parallel write                                  System I/O        -1    0       0
01:33:00 WAITING control file parallel write                              System I/O        -1    0       0
01:33:53 WAITING control file parallel write                              System I/O        -1    0       0
01:34:00 WAITING null event                                               Other             -1    0       0
01:34:39 WAITING control file parallel write                              System I/O        -1    0       0
01:35:53 WAITING control file parallel write                              System I/O        -1    0       0
01:37:12 WAITING os thread startup                                        Concurrency     5055    1   10905



- 오라클 ASH 버퍼를 읽는 세션에 대해서 래치를 요구하지 않음
     이유 : 초단위로 쓰기가 발생하는 ASH 버퍼를 읽을 시 래치를 사용할 경우 경합이 발생 할 수 있음.
     문제 : 간혹 일관성 없는 잘못된 정보가 나타날 수 있음

- ASH 기능 이용 시 현재뿐이 아닌 과거시점 발생한 장애 및 성능 저하 원인까지 세션 레벨로 분석하도록 도움
   ☞ 오라클 10g 부터 v$active_session_history 정보를 AWR내 보관
       SGA를 DMA 방식으로 액세스
       단, 정보가 크기때문에 1/10만 샘플링 저장

- v$active_session_history 조회에 정보가 없을 시 이미 AWR에 쓰여짐
   ☞ dba_hist_active_sess_history 뷰 조회
 

※ AWR과 ASH 활용 시 전문 성능관리 툴 없이 효과적 성능 분석 가능 !