SQL文章レベルの診断イベント

次のアーティクルを見るとOracle 11gからSQL文章レベルで診断イベントを適用する機能が追加されたのが分かります。

• http://oraclue.com/2009/03/24/oracle-event-sql_trace-in-11g/
  
• http://oraclue.com/2009/03/20/oracle-diagnostic-events-part-4/
  

すなわち、特定のSQL IDに該当するSQL文章に対して10046イベントや10053イベントのような診断イベントを適用できます。Oracle 10gやその以下のバージョンでは診断イベントの最低のレベルはセッションでありました。SQL文章レベルで診断イベントを適用できることになるにつれて、システムに与える影響を最小化しながら正確に特定のSQL文章だけを分析できるようになりました。

簡単な使用例は次のようです。

UKJA@ukja1106> select * from t1 where c1 = 1;

        C1         C2
---------- ----------
         1          1

UKJA@ukja1106> 
UKJA@ukja1106> col prev_sql_id new_value sql_id
UKJA@ukja1106> select prev_sql_id from v$session where sid = userenv('sid');

PREV_SQL_ID
-------------
3c3yp27cag5mv

UKJA@ukja1106> 
UKJA@ukja1106> select sql_text from v$sql where sql_id = '&sql_id';
old   1: select sql_text from v$sql where sql_id = '&sql_id'
new   1: select sql_text from v$sql where sql_id = '3c3yp27cag5mv'

SQL_TEXT
--------------------------------------------------------------------------------
select * from t1 where c1 = 1

UKJA@ukja1106> 
UKJA@ukja1106> alter system flush shared_pool;

System altered.

UKJA@ukja1106> -- Enable 10046 Event
UKJA@ukja1106> alter system set events 'sql_trace[sql:&sql_id] level=12';
old   1: alter system set events 'sql_trace[sql:&sql_id] level=12'
new   1: alter system set events 'sql_trace[sql:3c3yp27cag5mv] level=12'

System altered.

UKJA@ukja1106> -- Enable 10053 Event
UKJA@ukja1106> alter system set events 'trace[sql_costing][sql:&sql_id]';
old   1: alter system set events 'trace[sql_costing][sql:&sql_id]'
new   1: alter system set events 'trace[sql_costing][sql:3c3yp27cag5mv]'

System altered.

UKJA@ukja1106> 
UKJA@ukja1106> select * from t1 where c1 = 1;

        C1         C2
---------- ----------
         1          1

UKJA@ukja1106> 
UKJA@ukja1106> select * from t1 where c1 = 2;

        C1         C2
---------- ----------
         2          2

UKJA@ukja1106> -- Disable 10046 Event
UKJA@ukja1106> alter system set events 'sql_trace[sql:&sql_id] off';
old   1: alter system set events 'sql_trace[sql:&sql_id] off'
new   1: alter system set events 'sql_trace[sql:3c3yp27cag5mv] off'

System altered.

UKJA@ukja1106> -- Disable 10053 Event
UKJA@ukja1106> alter system set events 'trace[sql_costing][sql:&sql_id] off';
old   1: alter system set events 'trace[sql_costing][sql:&sql_id] off'
new   1: alter system set events 'trace[sql_costing][sql:3c3yp27cag5mv] off'

System altered.

トレースファイルを見てみたら指定されたSQL IDに当たるSQL文章だけに対して診断イベントが適用されたことが分かります。

-- 10053 Event
OPTIMIZER INFORMATION

******************************************
----- Current SQL Statement for this session (sql_id=3c3yp27cag5mv) -----
select * from t1 where c1 = 1
*******************************************
Legend
The following abbreviations are used by optimizer trace.
CBQT - cost-based query transformation
JPPD - join predicate push-down
OJPPD - old-style (non-cost-based) JPPD
...

-- 10046 Event
PARSING IN CURSOR #6 len=29 dep=0 uid=88 oct=3 lid=88 tim=1619996238190 hv=3634861691 ad='355836ec' sqlid='3c3yp27cag5mv'
select * from t1 where c1 = 1
END OF STMT
EXEC #6:c=0,e=60,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1619996238186
WAIT #6: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=375 tim=1619996238266
FETCH #6:c=0,e=50,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=1,tim=1619996238382
WAIT #6: nam='SQL*Net message from client' ela= 258 driver id=1413697536 #bytes=1 p3=0 obj#=375 tim=1619996238690
FETCH #6:c=0,e=13,p=0,cr=1,cu=0,mis=0,r=0,dep=0,og=1,tim=1619996238739
STAT #6 id=1 cnt=1 pid=0 pos=1 obj=79656 op='TABLE ACCESS BY INDEX ROWID T1 (cr=4 pr=0 pw=0 time=0 us cost=2 size=7 card=1)'
STAT #6 id=2 cnt=1 pid=1 pos=1 obj=79657 op='INDEX RANGE SCAN T1_N1 (cr=3 pr=0 pw=0 time=0 us cost=1 size=0 card=1)'

まだこの機能が公式的に文書化されてはいないようです。従って本番環境で使用する前に十分な検証をしなければなりません。Oracle 11.1.0.6のテスト環境ではこの機能のせいでセッションが非正常終了する場合もたまにありました。