쉽게 설명한 Wait 인터페이스

Wait 인터페이스

 

10g의 wait 인터페이스는 ADDM에 의해 아직 캡처 되지 않은 현 시점의 성능 문제를 진단하고 해결하기 위한 유용한 정보를 제공합니다.

 

"데이타베이스가 너무 느리네요!"

 

성능에 불만을 가진 사용자들은 이렇게 말하곤 합니다. 여러분들도 필자와 같다면, DBA로 근무하면서 이런 이야기를 수없이 들어왔을 것입니다.

 

그렇다면 성능 문제를 해결하기 위해 어떻게 대처하십니까? 사용자의 불만을 무시하는 방법도 있겠지만(대부분의 DBA에게 이런 사치는 허용되지 않으므로), 데이타베이스 내부 또는 외부에 세션 wait 이벤트가 발생했는지 확인하는 것이 첫 번째로 하는 일이 될 것입니다.

 

오라클은 이를 위해 단순하면서도 강력한 메커니즘을 제공합니다. V$SESSION_WAIT 뷰가 바로 그것입니다. V$SESSION_WAIT 뷰를 통해 세션이 대기 중인 이벤트가 무엇이고 얼마나 자주, 얼마나 오랫동안 대기했는지 등의 정보를 확인할 수 있습니다. 예를 들어 특정 세션이 “db file sequential read” 이벤트를 대기하고 있는 경우, 컬럼 P1과 P2는 세션이 대기 중인 블록의 file_id와 block_id를 각각 표시하게 됩니다. 대부분의 경우, V$SESSION_WAIT 뷰만으로 wait 이벤트에 관련한 충분한 정보를 확인할 수 있습니다. 하지만 다음과 같은 두 가지 약점이 있습니다:

 

For most wait events this view is sufficient, but it is hardly a robust tuning tool for at least two important reasons:

- V$SESSION_WAIT 뷰는 현 시점의 상태만을 표시합니다. wait 이벤트가 종료되면, 그 히스토리 정보 역시 소실되어 버립니다. 또 V$SESSION_EVENT 뷰는 세션이 시작된 이후의 누적된 정보를 제공하지만 그 정보가 상세하지 않습니다.

- V$SESSION_WAIT 뷰는 wait 이벤트에 대한 정보만을 포함하고 있습니다. 그 밖의 다른 정보(userid, terminal 등)를 확인하려면 V$SESSION 뷰와 조인해야 합니다.

 

Oracle Database 10g는 최소한의 작업으로 보다 많은 정보를 얻을 수 있도록 wait 인터페이스를 혁신적으로 개선하였습니다. 이번 연재에서는, wait 인터페이스와 관련하여 Oracle Database 10g가 제공하는 새로운 기능을 소개하고 성능 문제 해결을 위한 활용 방안을 설명합니다. 대부분의 경우 ADDM(Automatic Database Diagnostic Manager)이 성능 분석 툴로 활용되겠지만, ADDM에 의해 아직 수집되지 않은 현 시점의 성능 문제를 분석하는 데에는 wait 인터페이스가 유용합니다.

 

Session Wait 뷰의 기능 향상

 

먼저 V$SESSION_WAIT의 개선된 기능에 대해 예를 통해 설명하도록 하겠습니다.

 

사용자의 세션이 갑자기 느려졌다는 불만이 제기된 경우를 가정해 봅시다. 먼저 사용자 세션의 SID를 확인하고, 해당 SID에 대해 V$SESSION_WAIT 뷰를 조회합니다. 그 결과가 아래와 같습니다:

 

 

SID                      : 269

SEQ#                     : 56

EVENT                    : enq: TX - row lock contention

P1TEXT                   : name|mode

P1                       : 1415053318

P1RAW                    : 54580006

P2TEXT                   : usn<<16 | slot

P2                       : 327681

P2RAW                    : 00050001

P3TEXT                   : sequence

P3                       : 43

P3RAW                    : 0000002B

WAIT_CLASS_ID            : 4217450380

WAIT_CLASS#              : 1

WAIT_CLASS               : Application

WAIT_TIME                : -2

SECONDS_IN_WAIT          : 0

STATE                    : WAITED UNKNOWN TIME

 

굵은 글씨체로 표시된 컬럼을 주목하시기 바랍니다. WAIT_CLASS_ID, WAIT_CLASS#, WAIT_CLASS 등은 모두 10g에서 새로 추가된 컬럼들입니다. WAIT_CLASS는 wait의 유형을 구분해 주는 컬럼으로, idle한 wait이므로 무시해도 되는지 또는 유효한 wait인지를 판단하는 중요한 기준으로 활용됩니다. 위의 예에서는 wait class가 “Application”으로 표시되고 있으며, 따라서 주목할 만한 이유가 충분한 것으로 판단할 수 있습니다.

 

이러한 컬럼들은 튜닝 과정에서 매우 요긴하게 활용됩니다. 예를 들어 다음과 같은 쿼리를 작성하여 세션 wait에 관련한 정보를 얻을 수 있습니다.

 

select wait_class, event, sid, state, wait_time, seconds_in_wait

from v$session_wait

order by wait_class, event, sid

/

 

쿼리 실행 결과의 예가 다음과 같습니다:

 

 

WAIT_CLASS  EVENT                       SID STATE                WAIT_TIME SECONDS_IN_WAIT

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

Application enq: TX -                   269 WAITING                      0              73

            row lock contention       

Idle        Queue Monitor Wait          270 WAITING                      0              40

Idle        SQL*Net message from client 265 WAITING                      0              73

Idle        jobq slave wait             259 WAITING                      0            8485

Idle        pmon timer                  280 WAITING                      0              73

Idle        rdbms ipc message           267 WAITING                      0          184770

Idle        wakeup time manager         268 WAITING                      0              40

Network     SQL*Net message to client   272 WAITED SHORT TIME           -1               0

 

여기 몇 가지 이벤트(Queue Monitor Wait, JobQueue Slave등)가 “Idle” 이벤트로 표시되고 있음을 확인할 수 있습니다. 이러한 항목들은 nonblocking wait로 간주하고 고려 대상에서 제외할 수도 있습니다. 하지만 “idle” 이벤트가 다른 문제를 암시하는 경우도 있습니다. 예를 들어, “idle”로 표시되는 SQL*Net 관련 이벤트는 네트워크 지연율이 높음을 나타낼 수도 있습니다.

 

WAIT_TIME이 -2의 값을 갖는 경우도 참고할 필요가 있습니다. Windows와 같은 일부 플랫폼은 fast timing mechanism을 지원하지 않습니다. 해당 플랫폼에 초기화 매개변수 TIMED_STATISTICS 가 설정되어 있지 않은 경우, 정확한 시간 통계를 얻을 수 없습니다. 이 경우 Oracle9i에서는 관련된 컬럼에 비정상적으로 높은 숫자가 표시되며, 이로 인해 성능 문제의 진단이 더욱 어려워질 수 있습니다. 10g에서는 이러한 경우 일률적으로 -2의 값을 표시합니다. 즉, -2는 플랫폼이 fast timing mechanism을 지원하지 않으며 TIMED_STATISTICS 매개변수가 설정되어 있지 않음을 의미합니다. (이 문서의 뒷부분에서는 fast timing mechanism이 사용 가능한 것으로 가정하고 설명을 진행합니다.)

 

Session 뷰와 Session Wait 뷰의 통합

 

세션에 대한 자세한 정보를 얻기 위해서 V$SESSION_WAIT를 V$SESSION과 조인해야만 했던 사실을 기억하고 계실 겁니다. 10g에서는 V$SESSION 뷰 안에 V$SESSION_WAIT의 정보가 기본적으로 포함됩니다. V$SESSION이 wait 이벤트에 관련하여 추가로 제공하는 컬럼이 아래와 같습니다:

 

 

EVENT#                     NUMBER

EVENT                      VARCHAR2(64)

P1TEXT                     VARCHAR2(64)

P1                         NUMBER

P1RAW                      RAW(4)

P2TEXT                     VARCHAR2(64)

P2                         NUMBER

P2RAW                      RAW(4)

P3TEXT                     VARCHAR2(64)

P3                         NUMBER

P3RAW                      RAW(4)

WAIT_CLASS_ID              NUMBER

WAIT_CLASS#                NUMBER

WAIT_CLASS                 VARCHAR2(64)

WAIT_TIME                  NUMBER

SECONDS_IN_WAIT            NUMBER

STATE                      VARCHAR2(19)

 

이 컬럼들은 V$SESSION_WAIT에서 제공되는 것들과 동일한 이름을 가지며 동일한 정보를 제공합니다. 결국 이벤트에 대한 세션 wait 정보를 확인하기 위해 V$SESSION_WAIT를 따로 조회할 필요가 없게 된 것입니다.

 

그럼 다시 처음에 설명한 예로 돌아가 봅시다. SID 269의 세션이 “enq: TX - row lock contention”이벤트를 대기 중이며, 이는 이 세션이 다른 세션이 점유하고 있는 락(lock)을 대기 중임을 의미합니다. 문제를 진단하기 위해서는 “다른” 세션이 무엇인지 확인해야 합니다. 그렇다면 어떤 방법을 써야 할까요?

 

Oracle9i와 이전 버전에서는 매우 복잡한 쿼리를 실행해야만 락을 소유한 세션의 SID를 알아낼 수 있었습니다. 10g에서는 다음과 같은 간단한 쿼리로 해결 가능합니다:

 

 

select BLOCKING_SESSION_STATUS, BLOCKING_SESSION

from v$session

where sid = 269

 

BLOCKING_SE BLOCKING_SESSION

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

VALID                    265

 

이렇게 간단한 작업만으로 SID 265 세션이 세션 269를 블로킹하고 있음이 확인되었습니다.

 

얼마나 많은 Wait가 발생했는가?

 

아직도 사용자를 만족시키기에는 이릅니다. 사용자의 세션이 느려진 이유는 도대체 무엇일까요? 다음과 같은 쿼리를 먼저 실행해 봅시다:

 

select * from v$session_wait_class where sid = 269;

 

결과는 다음과 같이 표시됩니다:

 

 

SID SERIAL# WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS    TOTAL_WAITS TIME_WAITED

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

 269    1106    4217450380           1 Application           873      261537

 269    1106    3290255840           2 Configuration           4           4

 269    1106    3386400367           5 Commit                  1           0

 269    1106    2723168908           6 Idle                   15      148408

 269    1106    2000153315           7 Network                15           0

 269    1106    1740759767           8 User I/O               26           1

 

위 결과는 세션 wait에 대한 매우 상세한 정보를 제공하고 있습니다. 위 결과를 통해 애플리케이션에 관련한 세션 wait 이벤트가 873회, 총 261,537 centi-second에 걸쳐 발생되었으며, 네트워크 관련한 wait 이벤트가 15회 발생되었음을 확인할 수 있습니다.

 

이 방법을 응용하여, wait class에 관련한 시스템의 전반적인 통계를 확인할 수도 있습니다. (여기에서도 시간은 centi-second 단위로 표시됩니다.)

 

 

select * from v$system_wait_class;

 

WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS    TOTAL_WAITS TIME_WAITED

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

   1893977003           0 Other                2483       18108

   4217450380           1 Application          1352      386101

   3290255840           2 Configuration          82         230

   3875070507           4 Concurrency            80         395

   3386400367           5 Commit               2625        1925

   2723168908           6 Idle               645527   219397953

   2000153315           7 Network              2125           2

   1740759767           8 User I/O             5085        3006

   4108307767           9 System I/O         127979       18623

 

대부분의 성능 문제는 독립적으로 존재하지 않으며, 문제의 패턴을 암시하는 단서로서 해석되는 것이 일반적입니다. 이러한 패턴을 확인하려면 wait class의 히스토리 뷰를 조회해야 합니다:

 

select * from v$waitclassmetric;

 

V$WAITCLASSMETRIC 뷰는 지난 1분 동안의 wait class 통계를 제공합니다.

 

 

select wait_class#, wait_class_id,

average_waiter_count "awc", dbtime_in_wait,

time_waited,  wait_count

from v$waitclassmetric

/

 

WAIT_CLASS# WAIT_CLASS_ID  AWC DBTIME_IN_WAIT TIME_WAITED WAIT_COUNT

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

          0    1893977003    0              0           0          1

          1    4217450380    2             90        1499          5

          2    3290255840    0              0           4          3

          3    4166625743    0              0           0          0

          4    3875070507    0              0           0          1

          5    3386400367    0              0           0          0

          6    2723168908   59              0      351541        264

          7    2000153315    0              0           0         25

          8    1740759767    0              0           0          0

          9    4108307767    0              0           8        100

         10    2396326234    0              0           0          0

         11    3871361733    0              0           0          0

 

WAIT_CLASS_ID 컬럼을 주목하시기 바랍니다. 지난 1분 동안 4217450380의 WAIT_CLASS_ID 값을 갖는 wait class를 2개의 세션이 총 5회, 1,499 centi-second에 걸쳐 대기하였음을 알 수 있습니다. 그렇다면 이 wait class는 무엇일까요? V$SYSTEM_WAIT_CLASS를 조회하면 이 wait class가 바로 "Application” class임을 확인할 수 있습니다.

 

DBTIME_IN_WAIT 컬럼도 매우 유용하게 활용됩니다. Automatic Workload Repository(AWR)를 주제로 한 제 6번째 연재에서, 10g가 한층 세분화된 시간 통계를 제공하며, 데이타베이스 내부에서 실제로 사용된 시간을 정확하게 확인할 수 있음을 설명한 바 있습니다. DBTIME_IN_WAIT가 바로 데이타베이스 내부에서 사용된 시간을 표시하는 컬럼입니다.

 

단서는 항상 남는다

 

해당 사용자의 세션이 종료되자 DBA는 안도의 한숨을 내쉽니다. 하지만 도대체 어떤 wait 때문에 세션에 성능 문제가 발생했는지에 대한 궁금증이 가시지 않습니다. V$SESSION_WAIT를 조회하면 쉽게 해답을 얻을 수 있겠지만, 이제 wait 이벤트가 종료된 상황이므로 이 뷰에는 더 이상 기록이 남아있지 않을 것입니다. 이런 경우 어떻게 하시겠습니까?

 

10g는 액티브 세션의 마지막 10개 이벤트에 관련한 session wait 히스토리 정보를 자동 저장하고 관리하며, 이 결과는 V$SESSION_WAIT_HISTORY 뷰를 통해 조회할 수 있습니다:

 

 

select event, wait_time, wait_count

from v$session_wait_history

where sid = 265

/

 

EVENT                           WAIT_TIME WAIT_COUNT

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

log file switch completion              2          1

log file switch completion              1          1

log file switch completion              0          1

SQL*Net message from client         49852          1

SQL*Net message to client               0          1

enq: TX - row lock contention          28          1

SQL*Net message from client           131          1

SQL*Net message to client               0          1

log file sync                           2          1

log buffer space                        1          1

 

세션이 inactive 상태가 되거나 연결이 끊어진 경우, 관련된 기록도 뷰에서 삭제됩니다. 하지만 히스토리 정보는 AWR 테이블에 별도로 저장됩니다. AWR의 V$ACTIVE_SESSION_HISTORY 뷰는 session wait에 관련한 정보를 제공합니다. (AWR에 관련한 자세한 정보는 본 시리즈의 제 6번째 연재를 참고하시기 바랍니다.)

 

결론

 

Oracle Database 10g의 향상된 wait 모델을 사용하여 한층 쉽게 성능 분석 작업을 진행할 수 있습니다. 세션 히스토리 정보를 이용하면 문제의 징후가 사라진 이후에도 문제 원인을 진단할 수 있습니다. 또 wait를 wait class로 구분함으로써, 각 wait 유형별 영향을 이해하고 효율적으로 대처할 수 있게 됩니다.