Oracle(오라클) 11gR2 SQL Monitoring(dbms_sqltune.report_sql_monitor)

Share

Last Updated on 11월 10, 2020 by Jade(정현호)

안녕하세요 
이번 포스팅에서는 11gR2 에 새롭게 추가된 기능인 Real-Time SQL Monitoring 기능에 대해서 확인 해 보도록 하겠습니다. 
          

Real-Time SQL Monitoring

SQL Monitoring Oracle 11gR2에서 Real-Time SQL Monitoring 기능이 추가되었으며 아래의 조건일  경우 정보를 수집하게 됩니다.

1. 실행 시간이 5초 이상(_SQLMON_THRESHOLD 히든 파라미터로 조정)인 모든 쿼리


2. 병렬처리로 수행된 쿼리의 의 실행 이력 정보


위의 조건으로 수집된 SQL 및 수행 이력 정보 남기게 되고 V$SQL_MONITOR 뷰와 V$SQL_PLAN_MONITOR 뷰 에서 확인 할 수 있습니다

View 를 조회하는 것 이외에 다른 방법으로 dbms_sqltune.report_sql_monitor 함수를 이용해서 간편하게 조회 및 HTML 형태로도 출력 할 수 있습니다.
         

사용 방법

명시적으로 SQL 수행 이력 기록을 남기고 확인 하고자 할 때에는 힌트를 통해서 사용할 수 있습니다

Hint 명 : 
/*+ MONITOR */


힌트를 사용하여 SQL을 실행 하면 수행시간과 무관하게 수행 이력이 저장 되게 됩니다.


SQL monitoring 기능은 STATISTICS_LEVEL parameter 를 'TYPICAL' or 'ALL' 로 설정이 필요하고, CONTROL_MANAGEMENT_PACK_ACCESS parameter 가 'DIAGNOSTIC+TUNING'  으로 설정 되어있어야 사용이 가능 합니다.

그러므로 Enterprise Edition 에서만 가능하며, Standard Edition 에서는 사용이 불가 합니다.

장점은 10046 이나 dbms_xplan 으로는 알 수 없는 병렬쿼리의 일량등을 알 수 있습니다. 또한 파라미터의 default 값(5초) 이상으로 수행된 SQL 의 수행정보 중 실제 바인드 값 이 저장 된다는 것 입니다.
           

report_sql_monitor

수행된 SQL 에 대해서 자세한 정보를 손쉽게 확인 하려고 할때에는 dbms_sqltune.report_sql.monitor 를 사용하면 됩니다.
SQL을 실행 후에 dbms_sqltune.report_sql_monitor  로 조회 하면 아래와 같은 결과를 확인 할 수 있습니다


select dbms_sqltune.report_sql_monitor(sql_id=>'5m83g8fdycnwx',event_detail=>'YES') from dual;


SQL Monitoring Report 예시

SQL Monitoring Report

SQL Text
------------------------------
SELECT /*+ MONITOR USE_NL(E D) */ * FROM EMP E, DEPT D
WHERE E.DEPTNO = D.DEPTNO AND D.DEPTNO IN (:1, :2 , :3, :4, :5)


Global Information
------------------------------
 Status              :  DONE (ALL ROWS)                                      
 Instance ID         :  1                                                    
 Session             :  SCOTT (3029:17)                                      
 SQL ID              :  5m83g8fdycnwx                                        
 SQL Execution ID    :  16777216                                             
 Execution Started   :  07/09/2014 23:47:05                                  
 First Refresh Time  :  07/09/2014 23:47:05                                  
 Last Refresh Time   :  07/09/2014 23:47:06                                  
 Duration            :  1s                                                   
 Module/Action       :  Orange for ORACLE (Unicode) DBA /5.0.12 (Build:331,S)
 Service             :  testdb                                                
 Program             :  OrangeMainU.exe                                      
 Fetch Calls         :  1001                                                 
 

Binds
==============================================
| Name | Position |     Type     |    Value  |
==============================================
| :1   |        1 | VARCHAR2(32) |     10    |
| :2   |        2 | VARCHAR2(32) |     20    |
| :3   |        3 | VARCHAR2(32) |     30    |
| :4   |        4 | VARCHAR2(32) |     40    |
| :5   |        5 | VARCHAR2(32) |     50    |
==============================================
 

Global Stats
=================================================
| Elapsed |   Cpu   |  Other   | Fetch | Buffer |
| Time(s) | Time(s) | Waits(s) | Calls |  Gets  |
=================================================
|    0.07 |    0.05 |     0.02 |  1001 |   2612 |
=================================================

 

SQL Plan Monitoring Details (Plan Hash Value=3285654456)

============================================================================================================================================
| Id |            Operation             |  Name   |  Rows   | Cost  |   Time    | Start  | Execs |   Rows   | Activity | Activity Detail |
|    |                                  |         | (Estim) |       | Active(s) | Active |       | (Actual) |   (%)    |   (# samples)   |
============================================================================================================================================
|  0 | SELECT STATEMENT                 |         |         |       |         2 |     +0 |     1 |    99999 |          |                 |
|  1 |   NESTED LOOPS                   |         |         |       |         2 |     +0 |     1 |    99999 |          |                 |
|  2 |    NESTED LOOPS                  |         |      6M | 47672 |         2 |     +0 |     1 |    99999 |          |                 |
|  3 |     INLIST ITERATOR              |         |         |       |         1 |     +0 |     1 |        1 |          |                 |
|  4 |      TABLE ACCESS BY INDEX ROWID | DEPT    |       5 |     2 |         1 |     +0 |     5 |        5 |          |                 |
|  5 |       INDEX UNIQUE SCAN          | DEPT_U1 |       5 |     1 |         2 |     +0 |     5 |        5 |          |                 |
|  6 |     INDEX RANGE SCAN             | EMP_N1  |      1M |  2495 |         2 |     +0 |     5 |    99999 |          |                 |
|  7 |    TABLE ACCESS BY INDEX ROWID   | EMP     |      1M | 10414 |         2 |     +0 | 99999 |    99999 |          |                 |
============================================================================================================================================


실행시 사용된 실제 바인드 값이 추출 되고 , 실행계획과 일량, 수행시간이 출력 되게 됩니다.
예제 SQL에서는 5초 미만으로 수행 되어서 MONITOR 힌트를 사용하여 수행을 기록을 남기고 결과를 추출 하였습니다.


HTML 형태로도 출력할 수 있습니다.

select dbms_sqltune.report_sql_monitor(sql_id=>'5m83g8fdycnwx',event_detail=>'YES', type => 'HTML', report_level => 'ALL') from dual;

사용자 삽입 이미지



Real-Time SQL Monitoring 를 사용하면 10046 trace 과 dbms_xplan 에서는 볼수 없는  병렬처리로 수행된 쿼리의 의 실행 이력 정보를 확인 할 수있습니다.


10046 trace 를 사용하게 되면 병렬쿼리 Slave Process 의 일량 정보가 확인되지 않아서 10046 Event 로 Trace 를 생성 할 때 Parallel 힌트를  제거하고 수행 해야 하지만 Real-Time SQL Monitoring 를 이용하면 아래와 같이 병렬쿼리의 상세한 정보를 확인 할 수 있습니다.

SQL Monitoring Report
 

SQL Text
------------------------------
SELECT /*+ MONITOR PARALLEL(E 4) */ * FROM EMP E, DEPT D
WHERE E.DEPTNO = D.DEPTNO AND D.DEPTNO IN (:1, :2 , :3, :4, :5)

 

Global Information
------------------------------
 Status              :  DONE (ALL ROWS)                                      
 Instance ID         :  1                                                     
 Session             :  SCOTT (3029:17)                                      
 SQL ID              :  f0snf4ha6n4j6                                        
 SQL Execution ID    :  16777216                                              
 Execution Started   :  07/10/2014 00:19:36                                  
 First Refresh Time  :  07/10/2014 00:19:36                                  
 Last Refresh Time   :  07/10/2014 00:19:48                                   
 Duration            :  12s                                                  
 Module/Action       :  Orange for ORACLE (Unicode) DBA /5.0.12 (Build:331,S)
 Service             :  testdb                                               
 Program             :  OrangeMainU.exe                                      
 Fetch Calls         :  1001                                                 
 
Binds
====================================================
| Name | Position |     Type     |        Value    |
====================================================
| :1   |        1 | VARCHAR2(32) |         10      |
| :2   |        2 | VARCHAR2(32) |         20      |
| :3   |        3 | VARCHAR2(32) |         30      |
| :4   |        4 | VARCHAR2(32) |         40      |
| :5   |        5 | VARCHAR2(32) |         50      |
====================================================
 
Global Stats
=========================================================================================
| Elapsed |   Cpu   |    IO    | Concurrency |  Other   | Fetch | Buffer | Read | Read  |
| Time(s) | Time(s) | Waits(s) |  Waits(s)   | Waits(s) | Calls |  Gets  | Reqs | Bytes |
=========================================================================================
|      30 |    2.95 |       27 |        0.04 |     0.06 |  1001 |  44121 | 1435 | 343MB |
=========================================================================================
 
Parallel Execution Details (DOP=4 , Servers Allocated=4)
============================================================================================================================================
|      Name      | Type  | Server# | Elapsed |   Cpu   |    IO    | Concurrency |  Other   | Buffer | Read | Read  |      Wait Events      |
|                |       |         | Time(s) | Time(s) | Waits(s) |  Waits(s)   | Waits(s) |  Gets  | Reqs | Bytes |      (sample #)       |
============================================================================================================================================
| PX Coordinator | QC    |         |    0.11 |    0.05 |          |        0.03 |     0.03 |      8 |      |     . | os thread startup (1) |
| p000           | Set 1 |       1 |    8.47 |    1.13 |     7.34 |             |          |  12735 |  411 |  99MB | direct path read (5)  |
| p001           | Set 1 |       2 |    8.08 |    0.78 |     7.30 |        0.00 |          |  11886 |  386 |  93MB | direct path read (8)  |
| p002           | Set 1 |       3 |    4.97 |    0.32 |     4.62 |             |     0.03 |   6792 |  223 |  53MB | direct path read (5)  |
| p003           | Set 1 |       4 |    8.32 |    0.67 |     7.65 |        0.00 |          |  12700 |  415 |  99MB | direct path read (8)  |
============================================================================================================================================

SQL Plan Monitoring Details (Plan Hash Value=1303667667)
===========================================================================================================================================================================
| Id |              Operation               |   Name   |  Rows   | Cost |   Time    | Start  | Execs |   Rows   | Read | Read  |  Mem  | Activity |    Activity Detail    |
|    |                                      |          | (Estim) |      | Active(s) | Active |       | (Actual) | Reqs | Bytes | (Max) |   (%)    |      (# samples)      |
===========================================================================================================================================================================
|  0 | SELECT STATEMENT                     |          |         |      |         3 |    +10 |     5 |    99999 |      |       |       |          |                       |
|  1 |   PX COORDINATOR                     |          |         |      |        13 |     +0 |     5 |    99999 |      |       |       |     3.33 | os thread startup (1) |
|  2 |    PX SEND QC (RANDOM)               | :TQ10001 |      6M | 3358 |         3 |    +10 |     4 |    99999 |      |       |       |          |                       |
|  3 |     HASH JOIN                        |          |      6M | 3358 |        11 |     +2 |     4 |    99999 |      |       |    3M |          |                       |
|  4 |      BUFFER SORT                     |          |         |      |         3 |     +2 |     4 |       20 |      |       |  8192 |          |                       |
|  5 |       PX RECEIVE                     |          |       5 |    2 |         3 |     +2 |     4 |       20 |      |       |       |          |                       |
|  6 |        PX SEND BROADCAST             | :TQ10000 |       5 |    2 |         1 |     +2 |     1 |       20 |      |       |       |          |                       |
|  7 |         INLIST ITERATOR              |          |         |      |         1 |     +2 |     1 |        5 |      |       |       |          |                       |
|  8 |          TABLE ACCESS BY INDEX ROWID | DEPT     |       5 |    2 |         1 |     +2 |     5 |        5 |      |       |       |          |                       |
|  9 |           INDEX UNIQUE SCAN          | DEPT_U1  |       5 |    1 |         1 |     +2 |     5 |        5 |      |       |       |          |                       |
| 10 |      PX BLOCK ITERATOR               |          |     10M | 3348 |         3 |    +10 |     4 |    99999 |      |       |       |          |                       |
| 11 |       TABLE ACCESS FULL              | EMP      |     10M | 3348 |        10 |     +3 |    52 |    99999 | 1435 | 343MB |       |    96.67 | Cpu (3)               |
|    |                                      |          |         |      |           |        |       |          |      |       |       |          | direct path read (26) |
===========================================================================================================================================================================



HTML 타입으로 추출하면 아래와 같은 내용을 포함한 그래픽 웹페이지 형태로 보실 수 있습니다.

사용자 삽입 이미지

                

Conclusion

아래와 같이 기능에 대해서 정리 할 수 있을 것 같습니다.

1) 5초 이상(파라미터 default) 수행된 쿼리에 대해서는 수행정보(바인드 값, 실제 일량, 수행시간 등) 이 자동으로 기록 됩니다.

   - V$SQL_BIND_CAPTURE 의 정보는 모든 바인드 값을 저장하지 않고 있기 때문에 , 바인드 값에 의하여 수행 시간의 폭이 클 때 5초 이상 수행된 바인드값을 정확하게 알수 있다는 장점이 있습니다.
   - 실제로 수행된 수행통계데이터 이기 때문에, 얼마나 소요되었는지 실제 실행시간(5초이상) 을 확인 할 수 있습니다.

2) 병렬 쿼리에 대한 Parallel Slave Process 에대한 일량까지 확인 할 수 있습니다.

3) GATHER_PLAN_STATISTICS 힌트를 이용하여 실제 수행통계를 확인 하듯이 5초 미만이라도 MONITOR 힌트를 이용하여 실제 SQL 수행통계 정보를 확인 할 수 있습니다.


관련된 다른 글

 

 

 

 

 

 

         

2
0
글에 대한 당신의 생각을 기다립니다. 댓글 의견 주세요!x