태터데스크 관리자

도움말
닫기
적용하기   첫페이지 만들기

태터데스크 메시지

저장하였습니다.

Oracle 성능 모니터링 툴이 성능 문제를 일으키다

오라클 2008.10.17 11:04
실제로 이런 경우가 많다.

Oracle 성능 문제를 모니터링을 위해 수행하는 Query들이 성능 문제를 일으키는 경우가 종종 목격된다. 이런 Query들은 대부분 v$ 뷰나 x$ 뷰들을 과도하게 조회하는 경향이 있다.

만일 이런 Query들이 실행 계획 이상이나 버그와의 치명적인 키스를 통해 과도하게 일을 수행하면 어떤 현상이 발생할까?

- v$ 뷰나 x$ 뷰들을 조회하기 위해 과도하게 latch를 획득한다. 이 과정에서 치명적인 latch 경합이 유발된다.
- 문제는 이런 Query들은 Logical Reads가 "0"으로 관찰된다는 것이다. 일을 하는지 안하는지 바로 파악이 안되기 때문에 원인을 재빨리 분석할 때 상당한 혼란을 가져 온다.
- 확인가능한 지표 하나는 CPU 사용량이다. 비록 Logical Reads는 증가하지 않지만 실제로는 일을 하기 때문에 CPU 사용량이 증가하기 때문이다.

실제로 얼마전 한 고객사에서 이런 일이 발생했다.

- 성능 모니터링 툴에서 수행한 Session 모니터링 Query가 v$ 뷰들을 과도하게 조회하면서
- CPU 사용률은 100%, Logical Reads는 0를 기록하고 있다.
- 이 Query가 v$sort_usage 뷰를 과도하게 조회하면서 sort extent pool latch 경합이 발생하고
- Temp Segment를 사용해야 하는 모든 Query들이 latch free 대기에 빠지게 되었다.
- 아마 이 정도의 문제는 버그와 연관이 있을 확률이 상당히 높다.

간단한 테스트를 통해 과도한 v$ 뷰 조회가 어떻게 관찰되는지 알아 보자.

@capture_on

@ukja102

@trace_on 10046 1

@mysid
@mon_on &v_sid

select count(*)
from
  v$sql, v$sql
where
  rownum <= 5000000
;

@mon_off
@mon_show

@trace_off
@trace_file
@tkprof trc1.out
@ed trc1.out

@capture_off


Trace 결과는 다음과 같다.

select count(*)
from
  v$sql, v$sql
where
  rownum <= 5000000

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      3.04       3.13          0          0          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      3.06       3.14          0          0          0           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61 

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SORT AGGREGATE (cr=0 pr=0 pw=0 time=3135108 us)
 156816   COUNT STOPKEY (cr=0 pr=0 pw=0 time=2677328 us)
 156816    MERGE JOIN CARTESIAN (cr=0 pr=0 pw=0 time=1736405 us)
    396     FIXED TABLE FULL X$KGLCURSOR_CHILD (cr=0 pr=0 pw=0 time=19832 us)
 156816     BUFFER SORT (cr=0 pr=0 pw=0 time=642605 us)
    396      FIXED TABLE FULL X$KGLCURSOR_CHILD (cr=0 pr=0 pw=0 time=10315 us)

많은 수의 Row를 Fetch하지만 Logical Reads는 "0"이다.

Time Model 정보는 다음과 같다. 실제로 대부분의 수행 시간을 SQL을 수행하는데 소비한 것을 알 수 있다.

STAT_NAME                                    DIFF
-------------------------------------------------
DB time                                 3,233,086
sql execute elapsed time                3,212,915
DB CPU                                  3,146,838
parse time elapsed                         10,377
hard parse elapsed time                     9,897


성능 모니터링 툴을 사용할 때는 이런 잠재적인 위험성이 있다는 것을 항상 유념해야 할 것이다.
Trackback 0 : Comment 1
  1. 탐구자 2011.08.05 15:52 Modify/Delete Reply

    관리자의 승인을 기다리고 있는 댓글입니다

Write a comment

티스토리 툴바