꿈꾸는 개발자, DBA 커뮤니티 구루비

09. ASH(Active Session History)

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

POOL NAME BYTES

--

---

shared pool ASH buffers 16252928

오라클은 현재 접속해서 활동 중인 Active 세션 정보를 1초에 한번씩 샘플링해서 ASH 버퍼에 저장한다.
SGA Shared Pool에서 CPU당 2MB의 버퍼를 할당 받아 세션 정보를 기록하며, 1시간 혹은 버퍼의 2/3가 찰 때마다 디스크로 기록한다. 즉, AWR에 저장하는 것이다.
v$active_session_history 뷰를 이용해 ASH 버퍼에 저장된 세션 히스토리 정보를 조회할 수 있다.

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# 컬럼을 가져온 것임
⑩ 애플리케이션 정보

⑦과 ⑧번 '대기 이벤트' 정보는 두말할 것도 없고, ⑥번 '블로킹 세션' 정보와 ⑨번 '현재 액세스 중인 오브젝트' 정보도 매우 유용하다. 블로킹 세션 정보를 통해 현재 Lock을 발생시킨 세션을 빨리 찾아 해소 할 수 있게 도와준다
오브젝트 정보도 더할 나위 없이 유용하지만 현재 발생 중인 대기 이벤트의 Wait Class가 Application, Concurrency, Cluster, User I/O 일 때만 의미 있는 값임을 알아야 한다.
예를 들어, ITL 슬롯 부족 때문에 발생하는 enq:TX - allocate ITL entry 대기 이벤트는 Configuration에 속하므로, v$active_session_history 뷰를 조회할 때 함께 출력되는 오브젝트에 Lock이 걸렸다고 판단해서는 안된다. 대개 그럴 때는 오브젝트번호가 -1로 출력되지만 직전에 발생한 이벤트의 오브젝트 정보가 계속 남아서 보이는 경우가 있으므로 잘못 해석하지 않도록 주의해야 한다.
아래 예시에도 파일 번호와 블록 번호가 그대로 남아있는 것을 알 수 있다.

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	476

초단위로 쓰기가 발생하는 ASH 버퍼를 읽을 때 래치를 사용한다면 경합이 생길 수 있다. 따라서 오라클은 ASH 버퍼를 읽는 세션에 대해서는 래치를 요구하지 않으며 그 때문에 간혹 일관성 없는 잘못된 정보가 나타날 수도 있다.
ASH 기능을 이용하면 현재뿐 아니라 과거시점에 발생한 장애 및 성능 저하 원인까지 세션 레벨로 분석할 수 있게 도와준다. 오라클 10g부터는 v$active_session_history 정보를 AWR 내에 보관하므로 과거치에 대한 세션 레벨 분석이 가능해 졌다.(SGA를 DMA방식으로 억세스)
1/10만 샘플링해서 저장.(문제가 되는 대기 이벤트는 일정간격을 두고 지속적으로 발생하기 때문에 샘플링 된 자료만으로도 원인을 찾는데 큰 지장이 없다)
v$active_session_history를 조회했을 때 정보가 찾아지지 않는다면 이미 AWR에 쓰여진 것으로 dba_hist_active_sess_history뷰를 조회하면 된다.

1. AWR 뷰를 이용해 하루 동안의 이벤트 발생현황을 조회해 본다.
그래프는 dba_hist_system_event를 이용해 그린 것인데, 08:15~09:15 구간에서 enq: TM - contention 이벤트가 다량 발생한 것이 확인 되었다.
2. dba_hist_active_sess_history를 조회해서 해당 이벤트를 많이 대기한 세션을 확인 한다.
3. 블로킹 세션 정보를 통해 dba_hist_active_sess_history를 다시 조회한다. 블로킹 세션이 찾아지면 해당 세션이 그 시점에 어떤 작업을 수행 중이었는지 확인한다. sql_id를 이용해 그 당시 SQL과 실행계획까지 확인 할 수 있다. v$sql과 v$sql_plan까지 AWR에 저장되기 때문이다. 위 사례에서는 브로킹 세션이 Append Mode Insert를 수행하면서 Exclusive 모드 TM Lock에 의한 경합이 발생하고 있었다.
4. program, module, action, client_id 등 애플리케이션 정보를 이용해 관련 프로그램을 찾아 Append 힌트를 제거한다. 그러고 나서, 다른 트랜잭션과 동시 DML이 발생할 수 있는 상황에서는 insert문에 Append 힌트를 사용해서는 안 된다는 사실을 개발팀 전체에 공지한다.

ASH(Active Session History,. (by sesesejoa) [2014.04.11]