태터데스크 관리자

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

태터데스크 메시지

저장하였습니다.

SQL*Net message from dblink 이벤트는 Idle인가, Network 문제인가?

오라클 2009.09.18 14:40
아래 두 대기이벤트는 이름이 너무 비슷해서 많은 오해를 불러 일으킵니다.
  • SQL*Net message from client
  • SQL*Net message from dblink
SQL*Net message from client대기이벤트는 대표적인 Idle 이벤트죠. 그렇다면 SQL*Net message from dblink이벤트는 어떨까요?
UKJA@ukja1106> @event 'SQL*Net message from'
UKJA@ukja1106> set serveroutput on
UKJA@ukja1106>
UKJA@ukja1106> exec print_table('select * from v$event_name where name like ''%&
1%''');
EVENT#                        : 289
EVENT_ID                      : 1421975091
NAME                          : SQL*Net message from client
PARAMETER1                    : driver id
PARAMETER2                    : #bytes
PARAMETER3                    :
WAIT_CLASS_ID                 : 2723168908
WAIT_CLASS#                   : 6
WAIT_CLASS                    : Idle
-----------------
EVENT#                        : 291
EVENT_ID                      : 4093028837
NAME                          : SQL*Net message from dblink
PARAMETER1                    : driver id
PARAMETER2                    : #bytes
PARAMETER3                    :
WAIT_CLASS_ID                 : 2000153315
WAIT_CLASS#                   : 7
WAIT_CLASS                    : Network
-----------------
SQL*Net message from client 이벤트는 Idle로 분류되지만, SQL*Net message from dblink 이벤트는 Network로 분류됩니다. 그렇다면 SQL*Net message from dblink 이벤트를 대기한다는 것은 Network의 성능에 문제가 있다는 의미일까요?

SQL*Net message from dblink 이벤트를 대기한다는 것은 달리 말하면 다음과 같습니다.

  1. 로컬 데이터베이스가 Remote SQL을 리모트 데이터베이스에 전송 요청합니다.
  2. 이때 로컬 데이터베이스는 OS의 API를 호출해서 해당 SQL 문장을 네트워크 전송 버퍼에 담습니다. 이 짧은 시간 동안 SQL*Net message to dblink 이벤트를 대기합니다. 실제 네트워크 전송과 무관하게 전송 버퍼에 담는 것만으로 대기이벤트는 종료됩니다.
  3. 로컬 데이터베이스는 이제 OS의 API를 호출해서 네트워크 수신 버퍼에서 데이터를 꺼내고자 합니다. 아직 원격 데이터베이스에서 데이터를 보내지 않은 상태이므로 SQL*Net message from dblink 이벤트를 대기합니다.
  4. 원격 데이터베이스가 데이터를 전송하고 로컬 OS가 그 데이터를 받아서 네트워크 수신 버퍼에 넣으면 그제서야 로컬 데이터베이스의 SQL*Net message from dblink 이벤트가 종료됩니다.
위의 내용을 잘 이해하면 SQL*Net message from dblink 이벤트를 대기한다고 하서 네트워크 전송이 느리다고 판단할 수 없다는 것을 잘 알 수 있습니다.

장시간의 SQL*Net message from dblink 이벤트가 네트워크 성능과 전혀 무관한 간단한 예를 만들어 보겠습니다.

1. UKJA1021 데이터베이스에서 다음과 같이 10,000건의 로우수를 가진 테이블을 만듭니다.

-- UKJA1021
drop table t1 purge;

create table t1
as
select level as c1 
from dual connect by level <= 10000
;
2. 다음과 같이 UKJA1106 --> UKJA1021 데이터베이스 링크를 만듭니다.
create database link UKJA1021
connect to ukja identified by ukja
using 'UKJA1021'
;
3. 실행 계획을 보면 원격 데이터베이스에서 100% 실행됨을 알 수 있습니다.
explain plan for
select count(*) 
from t1@ukja1021, t1@ukja1021
;

@plan
--------------------------------------------------------------------------------
| Id  | Operation              | Name | Rows  | Cost (%CPU)| Time     | Inst   |
--------------------------------------------------------------------------------
|   0 | SELECT STATEMENT REMOTE|      |     1 | 68860   (5)| 00:13:47 |        |
|   1 |  SORT AGGREGATE        |      |     1 |            |          |        |
|   2 |   MERGE JOIN CARTESIAN |      |   100M| 68860   (5)| 00:13:47 |        |
|   3 |    TABLE ACCESS FULL   | T1   | 10000 |     8   (0)| 00:00:01 | UKJA1~ |
|   4 |    BUFFER SORT         |      | 10000 | 68851   (5)| 00:13:47 |        |
|   5 |     TABLE ACCESS FULL  | T1   | 10000 |     7   (0)| 00:00:01 | UKJA1~ |
--------------------------------------------------------------------------------


Note
-----
   - fully remote statement
   - dynamic sampling used for this statement
4. 이제 다음과 같은 SQL문을 수행하면 오랜 시간 동안 대기상태에 빠지게 됩니다.
-- UKJA1106
UKJA@ukja1106>
UKJA@ukja1106> select count(*)
  2  from t1@ukja1021, t1@ukja1021, t1@ukja1021
  3  ;
............
5. 대기 이벤트를 보면 다음과 같이 SQL*Net message from dblink 이벤트를 대기합니다.
  SID EVENT                     P1              P2              P3
----- ------------------------- --------------- --------------- ----------
SECONDS_IN_WAIT
---------------
  133 SQL*Net message from dbli 1413697536(0000 1(0000000000000 0(00)
      nk                        000054435000)   001)
           9626
해당 SQL문은 COUNT(*)을 수행하기 때문에 결과가 나올 때가지는 전혀 데이터 전송이 이루어지지 않습니다. 즉, 아직 단 1바이트의 데이터도 네트워크를 통해 전송되지 않고 있는 상태이죠. 네트워크로 아무런 데이터다 전송되지 않고 있기 때문에 이 경우에는 네트워크 성능은 전혀 논할 가치가 없습니다.

6. 원격 데이터베이스에서는 다음과 같이 원격 세션이 모니터링됩니다.

-- UKJA1021
  SID SERIAL# PROGRAM    EVENT                SQL_TEXT
----- ------- ---------- -------------------- ------------------------------
  136     745 ORACLE.EXE SQL*Net message to c SELECT COUNT(*) FROM "T1" "A3"
                         lient                ,"T1" "A2","T1" "A1"
7. 133번 세션을 자세하게 모니터링해보면 다음과 같습니다.
UKJA@ukja1021> set echo off
01. basic session info
SID                           : 136
SERIAL#                       : 745
SPID                          : 15304
MACHINE                       : XXXX-3C2E2AF808
PROGRAM                       : ORACLE.EXE
PGA                           : 1154000
UGA                           : 680088
LAST_CALL_ET                  : 9696
LOGON_TIME                    : 2009/09/18 09:59:53
-----------------

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.01
02. session wait
SID                           : 136
EVENT                         : SQL*Net message to client
P1                            : 1413697536
P1RAW                         : 54435000
P2                            : 1
P2RAW                         : 00000001
P3                            : 0
P3RAW                         : 00
SECONDS_IN_WAIT               : 9696
STATE                         : WAITED SHORT TIME
-----------------

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.00
03. process info
PID                           : 20
PROGRAM                       : ORACLE.EXE (SHAD)
PGA_USED_MEM                  : 1037021
PGA_ALLOC_MEM                 : 1118413
PGA_MAX_MEM                   : 3245293
-----------------

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.01
04. sql info
SID                           : 136
SHARABLE_MEM                  : 12759
PERSISTENT_MEM                : 6304
RUNTIME_MEM                   : 5752
EXECUTIONS                    : 1
FETCHES                       : 0
BUFFER_GETS                   : 97
SQL_TEXT                      : SELECT COUNT(*) FROM "T1" "A3","T1" "A2","T1"
"A1"
-----------------

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.03
05. sql plan info

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------

SQL_ID  6t0k52rdrw388, child number 0
-------------------------------------
SELECT COUNT(*) FROM "T1" "A3","T1" "A2","T1" "A1"

Plan hash value: 2643210548

-----------------------------------------------------------------------
| Id  | Operation              | Name | Rows  | Cost (%CPU)| Time     |
-----------------------------------------------------------------------
|   0 | SELECT STATEMENT       |      |       |   688M(100)|          |
|   1 |  SORT AGGREGATE        |      |     1 |            |          |
|   2 |   MERGE JOIN CARTESIAN |      |  1000G|   688M  (5)|999:59:59 |
|   3 |    MERGE JOIN CARTESIAN|      |   100M| 68860   (5)| 00:13:47 |
|   4 |     TABLE ACCESS FULL  | T1   | 10000 |     8   (0)| 00:00:01 |
|   5 |     BUFFER SORT        |      | 10000 | 68851   (5)| 00:13:47 |
|   6 |      TABLE ACCESS FULL | T1   | 10000 |     7   (0)| 00:00:01 |
|   7 |    BUFFER SORT         |      | 10000 |   688M  (5)|999:59:59 |
|   8 |     TABLE ACCESS FULL  | T1   | 10000 |     7   (0)| 00:00:01 |
-----------------------------------------------------------------------

Note
-----

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------

   - dynamic sampling used for this statement


24 rows selected.

Elapsed: 00:00:00.07
06. workarea info
SID                           : 136
OPERATION_TYPE                : BUFFER
ACTIVE_TIME                   : 9696154331
WORK_AREA_SIZE                : 131072
ACTUAL_MEM_USED               : 131072
MAX_MEM_USED                  : 131072
-----------------
SID                           : 136
OPERATION_TYPE                : BUFFER
ACTIVE_TIME                   : 9696150509
WORK_AREA_SIZE                : 131072
ACTUAL_MEM_USED               : 131072
MAX_MEM_USED                  : 131072
-----------------

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.00
07. transaction info

PL/SQL procedure successfully completed.
대기 상태가 WAITED SHORT TIME이라는 것은 현재 대기 상태가 아니라 CPU를 점유하고 바쁘게 작업을 하고 있다는 것을 의미합니다. 어떤 작업을 하는지는 프로세스 정보에 잘 나타나고 있습니다.
03. process info
PID                           : 20
PROGRAM                       : ORACLE.EXE (SHAD)
PGA_USED_MEM                  : 1037021
PGA_ALLOC_MEM                 : 1118413
PGA_MAX_MEM                   : 3245293
위의 정보를 보면 현재 1G 바이트 이상의 PGA를 사용하고 있으며, 최대 3G 바이트 이상의 PGA를 사용했었음을 알 수 있습니다. 즉 대용량의 Carestian Merge Join을 처리하면서 바쁘게 일하고 있고 덕분에 원격 데이터베이스로 응답을 보내지 못하고 있는 것이죠.

대기이벤트들은 그 이름 때문에 오히려 오해하기 쉬운 경우가 많습니다. 이런 경우에는 Carry Millsap의 포스트(Dang It, People, they're syscalls not wait)를 보면 오해를 없앨 수 있을 것 같네요.

저작자 표시
신고
Trackback 0 : Comment 1
  1. 박성은 2009.09.19 15:46 신고 Modify/Delete Reply

    전혀 무관하다는게 맞는 말인지는 좀 의구심이 듭니다. ㅎㅎ

Write a comment

티스토리 툴바