Deferred Segment Creation機能の面白い2つのバグ

Oracle 11gR2ではDeferred Segment Creationという機能が追加されました。

• マニュアルはこちら
  

簡単に言えば、CREATE TABLE文を実行しても実際にデータが追加されるまでにはセグメントが生成されない機能です。このポストではDeferred Segment CreationとINSERT ... SELECT文に関する面白い2つのバグを紹介します。

• バグ9078678: セグメントのないテーブルへの並列INSERT ... SELECT文に対しる予想実行計画（Explain Plan）は並列ではなく直列実行計画に表示されます。しかし、実際には並列で行なわれます。
  
• バグ9329566: セグメントのないテーブルに対してINSERT ...SELECT文を実行すれば、SELECT文を二回実行するバグです。
  

2つのバグはすべてセグメントかないという特徴から発生するバグです。簡単なテストケースを見ましょう。まずバグ9078678に当たる現象です。

1. オラクルバージョンは11.2.0.1です。

TPACK@ukja1120> -- version
TPACK@ukja1120> select * from v$version where rownum = 1;

BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production

2. テーブルT1を作ります。テーブルT1はセグメントが存在しない状態です。テーブルT1に対して並列INSERT文章を行なう場合実行計画がどうなるか見ましょう。

TPACK@ukja1120> create table t1(c1 number);

Table created.

TPACK@ukja1120> alter session enable parallel dml;

Session altered.

TPACK@ukja1120> explain plan for
  2  insert /*+ parallel(t1 4) */ into t1
  3  select level from dual connect by level <= 10000;

Explained.

TPACK@ukja1120> select * from table(dbms_xplan.display);

------------------------------------------------------------------------------
| Id  | Operation                     | Name | Rows  | Cost (%CPU)| Time     |
------------------------------------------------------------------------------
|   0 | INSERT STATEMENT              |      |     1 |     2   (0)| 00:00:01 |
|   1 |  LOAD AS SELECT               | T1   |       |            |          |
|*  2 |   CONNECT BY WITHOUT FILTERING|      |       |            |          |
|   3 |    FAST DUAL                  |      |     1 |     2   (0)| 00:00:01 |
------------------------------------------------------------------------------

ヒントを付けて並列実行を指定したが直列実行の実行計画が選択されました。

3. 予想実行計画ではなくて実際にSQL文を実行した後並列で実行するかどうかを見ましょう。

TPACK@ukja1120> insert /*+ parallel(t1 4) */ into t1
  2  select level from dual connect by level <= 10000;

10000 rows created.

TPACK@ukja1120> 
TPACK@ukja1120> commit;

Commit complete.

-- https://sites.google.com/site/ukja/sql-scripts-1/o-s/pqstat
TPACK@ukja1120> @pq_stat

DFO_NUMBER      TQ_ID SERVER_TYP PROCESS      NUM_ROWS 
---------- ---------- ---------- ---------- ---------- 
         1          0 Consumer   P000             2500 
         1          0 Consumer   P001             2500 
         1          0 Consumer   P002             2500 
         1          0 Consumer   P003             2500 
         1          0 Producer   QC              10000 
         1          1 Consumer   QC                  4 
         1          1 Producer   P000                1 
         1          1 Producer   P001                1 
         1          1 Producer   P002                1 
         1          1 Producer   P003                1 


10 rows selected.

STATISTIC                      LAST_QUERY SESSION_TOTAL
------------------------------ ---------- -------------
Queries Parallelized                    0             0
DML Parallelized                        1             1
DDL Parallelized                        0             0
DFO Trees                               1             1
Server Threads                          4             0
Allocation Height                       4             0
Allocation Width                        1             0
Local Msgs Sent                        44            44
Distr Msgs Sent                         0             0
Local Msgs Recv'd                      44            44
Distr Msgs Recv'd                       0             0

11 rows selected.

Explain Planをよる予想実行計画では直列実行という結果がでてきたが、実際の結果からは並列に実行されたのがわかります。もっと面白いのはこの状態で（すなわち、テーブルT1にデータが追加された状態）予想実行計画を見直すと並列実行計画にかえるとくうことです。

TPACK@ukja1120> explain plan for
  2  insert /*+ append parallel(t1 4) */ into t1
  3  select level from dual connect by level <= 10000;

Explained.

------------------------------------------------------
| Id  | Operation                         | Name     |
------------------------------------------------------
|   0 | INSERT STATEMENT                  |          |
|   1 |  PX COORDINATOR                   |          |
|   2 |   PX SEND QC (RANDOM)             | :TQ10001 |
|   3 |    LOAD AS SELECT                 | T1       |
|   4 |     PX RECEIVE                    |          |
|   5 |      PX SEND ROUND-ROBIN          | :TQ10000 |
|*  6 |       CONNECT BY WITHOUT FILTERING|          |
|   7 |        FAST DUAL                  |          |
------------------------------------------------------

これはバグです。セグメントがまだ生成されていないテーブルに対する並列実行文章の予想実行計画はまるで直列に実行されうように見えるが、実際には並列に実行されるバグです。すなわち、セグメントのないテーブルに対する並列実行文章の予想実行計画を正確に見せてくれないバグです。

バグ9329566に該当するテストケースも見ましょう。

1. テーブルT1とテーブルT2を同一に生成します。ただ、テーブルT2には一件の行を追加してセグメントもあらかじめ作っておきます。テーブルT1はセグメントがまだ存在しない状態です。10,000ブロックのサイズのテーブルT3も作っておきます。

TPACK@ukja1120> create table t1(c1 varchar2(2000), c2 varchar2(2000), c3 varchar2(2000), c4 varchar2(1000));

Table created.

TPACK@ukja1120> create table t2(c1 varchar2(2000), c2 varchar2(2000), c3 varchar2(2000), c4 varchar2(1000));

Table created.

TPACK@ukja1120> 
TPACK@ukja1120> -- insert 1 row into table t2 to create the segment
TPACK@ukja1120> insert into t2 values('1','1','1','1');

1 row created.

TPACK@ukja1120> -- table size 10000 block
TPACK@ukja1120> create table t3
  2  as
  3  select rpad('x',2000) as c1, rpad('x',2000) as c2, rpad('x',2000) as c3, rpad('x',1000) as c4
  4  from dual
  5  connect by level <= 10000;

Table created.

2. テーブルT3から最高値を読み込んでテーブルT1（セグメントない）、テーブルT2（セグメントある）へINSERTするクエリのそれぞれのConsistent Getsを比べてみましょう。手軽なテストのためにティパックのSession Snapshot Reportを利用します。

TPACK@ukja1120> exec tpack.begin_session_snapshot;

PL/SQL procedure successfully completed.

TPACK@ukja1120> insert into t1
  2  select max(c1), max(c2), max(c3), max(c4) from t3;

1 row created.

TPACK@ukja1120> exec tpack.add_session_snapshot;

PL/SQL procedure successfully completed.

TPACK@ukja1120> insert into t2
  2  select max(c1), max(c2), max(c3), max(c4) from t3;

1 row created.

TPACK@ukja1120> 
TPACK@ukja1120> exec tpack.add_session_snapshot;

PL/SQL procedure successfully completed.

次の結果を見たら、テーブルT1（セグメントない）に対するINSERTがテーブルT2（セグメントある）に対するINSERTに比べて2倍程度のConsistentを見せます。

TPACK@ukja1120> col item format a40
TPACK@ukja1120> col deltas format a20
TPACK@ukja1120> select item, deltas from table(tpack.session_snapshot_report)
  2  where type = 'STAT';

TPACK@ukja1120> select item, deltas from table(tpack.session_snapshot_report)
  2  where type = 'STAT';

ITEM                                     DELTAS
---------------------------------------- --------------------
...
physical read bytes                      164339712->82305024
consistent gets                          20451->10327
...

これもやはりバグです。

1. テーブルT3からデータを読んでからそのデータをテーブルT1へINSERTしようとします。
   
2. どころが、テーブルT1はまだセグメントがありません。したがってまずセグメントを作ります。
   
3. ここでオラクルは1番段階で獲得したデータを再活用できずまたテーブルT3からデータを読み込みます。現在のクエリはテーブルT3から最高値(MAX)を取り出しているから、クエリを実行するたびにテーブルのサイズである10,000ブロックを全部読み込まなければなりません。このために、テーブルT1に対するINSERTの際には20,000ブロック（二回読み込むから）、テーブルT2に対するINSERTは10,000ブロック（1回読み込むから）を読み込むようになるのです。
   

このバグたちはセグメントのないテーブルに対してのみ発生するから致命的なバグとは言いかねます。むしろ開発者がいくら基本的な罠に陥るのかをわかる良い例だといえます。オラクルで発生する多い性能問題がこのようなロジック穴から発生します。性能問題が起こった時このようなロジック穴を見破るテスト能力備えることが重要だといえます。

Batching NLJ最適化と整列

Batching NLJ最適化って聞いたこたあります？Batching NLJとはOracle 11gで紹介されたNested Loops Joinの最適化技法であります。例えば、次の２つの実行計画を見てください。

-- Oracle 10g
------------------------------------------------
| Id  | Operation                      | Name  |
------------------------------------------------
|   0 | SELECT STATEMENT               |       |
|*  1 |  COUNT STOPKEY                 |       |
|   2 |   TABLE ACCESS BY INDEX ROWID  | T2    |  <-- Here
|   3 |    NESTED LOOPS                |       |
|   4 |     TABLE ACCESS BY INDEX ROWID| T1    |
|*  5 |      INDEX RANGE SCAN          | T1_N1 |
|*  6 |     INDEX RANGE SCAN           | T2_N1 |
------------------------------------------------

-- Oracle 11g
------------------------------------------------
| Id  | Operation                      | Name  |
------------------------------------------------
|   0 | SELECT STATEMENT               |       |
|*  1 |  COUNT STOPKEY                 |       |
|   2 |   NESTED LOOPS                 |       |
|   3 |    NESTED LOOPS                |       |
|   4 |     TABLE ACCESS BY INDEX ROWID| T1    |
|*  5 |      INDEX RANGE SCAN          | T1_N1 |
|*  6 |     INDEX RANGE SCAN           | T2_N1 |
|   7 |    TABLE ACCESS BY INDEX ROWID | T2    |   <-- And here
------------------------------------------------

TABLE ACCESS BY INDEX ROWID (T2)のオペレーションの位置の違いに気付いたんでしょうか。これがOracle 11gのNested Loops Join最適化(Batching NLJ)の現れ方です。Batching NLJによって、論理読み込みが減り、性能が効率的になるはずです。

さて、ほんの数日前、Batching NLJ関連の変な整列問題に出会いました。下記は再現のできるテストケースです。ORDER BYのオーバーヘッドなく整列をするために、索引T1_N1を利用していることに注意してください。

create table t1
as
select 1 as c1, mod(level, 4) as c2, level as c3, level as c4, rpad('x',1000) as dummy
from dual
connect by level <= 1000;

create table t2
as
select 1001-level as c1, level as c2, rpad('x',1000) as dummy
from dual
connect by level <= 100;

create index t1_n1 on t1(c1, c2, c3);
create index t2_n1 on t2(c1);

exec dbms_stats.gather_table_stats(user, 't1');
exec dbms_stats.gather_table_stats(user, 't2');

explain plan for
select /*+ leading(t1 t2) use_nl(t2) index_asc(t1) index_asc(t2) */
 rownum as rnum,
 t2.c1,
 t1.c4,
 t2.c2
from t1, t2
where
 t1.c3 = t2.c1
 and t1.c1 = 1
 and t1.c2 = 0
 and rownum <= 20
;

select * from table(dbms_xplan.display);

-- Read from the disk
alter system flush buffer_cache;

select * from (
 select /*+ leading(t1 t2) use_nl(t2) index_asc(t1) index_asc(t2) */
  rownum as rnum,
  t2.c1,
  t1.c4,
  t2.c2
 from t1, t2
 where
  t1.c3 = t2.c1
  and t1.c1 = 1
  and t1.c2 = 0
  and rownum <= 20
) where rnum >= 15
;

-- Read from the buffer cache
select * from (
 select /*+ leading(t1 t2) use_nl(t2) index_asc(t1) index_asc(t2) */
  rownum as rnum,
  t2.c1,
  t1.c4,
  t2.c2
 from t1, t2
 where
  t1.c3 = t2.c1
  and t1.c1 = 1
  and t1.c2 = 0
  and rownum <= 20
) where rnum >= 15
;

-- Disable exceptions for buffer cache misses
alter session set "_nlj_batching_misses_enabled" = 0;

-- Read from the disk
alter system flush buffer_cache;

select * from (
 select /*+ leading(t1 t2) use_nl(t2) index_asc(t1) index_asc(t2) */
  rownum as rnum,
  t2.c1,
  t1.c4,
  t2.c2
 from t1, t2
 where
  t1.c3 = t2.c1
  and t1.c1 = 1
  and t1.c2 = 0
  and rownum <= 20
) where rnum >= 15
;

-- Read from the buffer cache
select * from (
 select /*+ leading(t1 t2) use_nl(t2) index_asc(t1) index_asc(t2) */
  rownum as rnum,
  t2.c1,
  t1.c4,
  t2.c2
 from t1, t2
 where
  t1.c3 = t2.c1
  and t1.c1 = 1
  and t1.c2 = 0
  and rownum <= 20
) where rnum >= 15
;

時間の節約のために、コメントが付いた簡単な結果を見ましょう。

-- Case1 : batching NLJ enabled
-- when the query reads from the disk
      RNUM         C1         C4         C2
---------- ---------- ---------- ----------
        15        960        960         41
        16        964        964         37
        17        980        980         21  <-- Why 980 here?
        18        968        968         33
        19        972        972         29
        20        976        976         25

-- when the query reads from the buffer cache
      RNUM         C1         C4         C2
---------- ---------- ---------- ----------
        15        960        960         41
        16        964        964         37
        17        968        968         33
        18        972        972         29
        19        976        976         25
        20        980        980         21

-- Case 2: batching NLJ disabled
-- when the query reads from the disk
      RNUM         C1         C4         C2
---------- ---------- ---------- ----------
        15        960        960         41
        16        964        964         37
        17        968        968         33
        18        972        972         29
        19        976        976         25
        20        980        980         21

-- when the query reads from the buffer cache
      RNUM         C1         C4         C2
---------- ---------- ---------- ----------
        15        960        960         41
        16        964        964         37
        17        968        968         33
        18        972        972         29
        19        976        976         25
        20        980        980         21

いかがでしょう。整列の順序に変わったこと

これは次のように解説できます。
「新しいNested Loops Joinの最適化コードは行が整列されたまま返されることを保障しない。特にディスクからデータを読み出している際には」

これはページネーションクエリ(Pagination Query)を索引とNested Loops Joinを利用して作成したい時に制約になる可能性があると思います。では、この制約がバグというのではありません。オラクルで整列順序を保障する雄一な方法はORDER BY句を与えることだけからです。

この制約を抜けていくためには次の方法で1つくらいを進めます。

• 隠しパラメーター_nlj_batching_misses_enabledを0にセット
  
• 隠しパラメーター_nlj_batching_enabledを0にセット
  
• NO_NLJ_BATCHING(T2)ヒントの追加
  

「ティパック」知能的な待機イベントの分析 - Part 1

オラクルが提供する待機イベントとは本?に?特です。どんなDBMSでも待機現象をこんなに詳細に報告してくれる製品はありません。

これはオラクルの性能問題を分析かつ解決すべき私たちには大きいプレゼントである同時?みであります。まるで初?の運?者にポルシェを?えるのと同じだと言えないでしょうか。ポルシェのような車を走らせようとしたらまず丈夫な運?わざが必要です。

待機イベント分析も同?です。正確な分析のためにはオラクルのア?キテクチャ?に?する相?な知識が必要です。これが待機イベント分析の技法がより?範?に使用されうことに邪魔となっています。

待機イベント分析で1つ?をつけなければならないのが大?イベントだけでは意味のある情報を引き出し難しいということです。?連のあるほかの情報が必要である場合がたくさんあります。ティパックではこれを知能的な待機イベントの分析と呼びます。例えをあげてみればこのような追加的な情報が必要です。

1. cache buffers chainsラッチで競合が?生する場合、おもにどんなブロックで?生しているかわかる？
   
2. 　row cache objectsラッチで競合が?生する場合、おもにどんなディクショナリ?オブジェクトなのかわかる？
   
3. db file sequential readのようなI/O待機いの場合、どんなセグメントのどのような種類のブロックで?生するかわかる？
   
4. ラッチ、ロック（Enqueue）、library cache lock、library cache pin、row cache lock、Mutexなどの同期化客?で競合が?生する場合、ホルダ?情報および?連の客?の情報が得られる？
   

これから?回にわたって待機イベントをもっと知能的に分析するためにどんなデ?タを追加的に分析する必要があらのかいくつかの例を見るつもりです。

1. ホルダ?を突き止め！　

オラクルでの競合は次の六つ程度の同期化客?により?生します。

• ラッチ
  
• ロック
  
• Library cache lock
  
• Library cache pin
  
• Row cache lock
  
• Mutex
  

個?の客?が何を意味しているのかすでにわかっている方?も多いはずなので、詳細な?明は足らないと思います。

同期化客?の種類別に提供されるビュ?が違いですから、ホルダ?を突き止めるときも違うビュ?を?索しなければなりません。幸いに最近バ?ジョンのオラクルではV$SESSIONビィ?のBLOCKING_SESSION、BLOCKING_INSTANCE
などの列から大部分の?況でホルダ?情報が提供されます。大?有?な情報だと言えます。しかし、待機イベントによっては?純にホルダ?を知るだけでは不足である場合もあります。正確にどんなオブジェクトで、どんなモ?ドで?生しているのかなどの情報が必要である場合もあります。

これから公開する情報はたぶん（！）ホルダ?を突き止める方法を今までのどんな文書より一番?範?で完璧にまとめていることであるはずです。

1.1 ラッチのホルダ?

ラッチホルダ?はV$LATCHHOLDERビュ?から突き止められます。

-- ラッチホルダ?
select h.pid, h.sid, h.laddr, h.name, h.gets
from v$latchholder h, v$session_wait s
where s.sid = &sid
   and s.p1raw = h.laddr;

ラッチはとても短い時間に獲得されうため、上のような?純なクエリだけでは欲しい結果を得ることができない場合がたくさんあります。（もちろんオラクルのバグなどによって特定のラッチを長い間持っている場合もあります）

この時に使用できるのがプロファイル方法です。ティパックは1)スナップショット、2)プロファイル2つの方法を使用しています。この中で、プロファイルとは短い時間に記?され、消えてしまう値を可能な限りよく取り出して、要約する方法を意味します。V$LATCHHOLDERビュ?も次のようにプロファイリングできます。

-- ラッチホルダ?プロファイリング
TPACK@ukja1021> select /*+ ordered use_nl(x) */
  2     x.sid, x.name, count(*)
  3  from
  4     (select /*+ no_merge */ level from dual connect by level <= 10000) t1,
  5     (select  /*+ no_merge */ h.pid, h.sid, h.laddr, h.name, h.gets
  6             from v$latchholder h, v$session_wait s
  7             where s.sid = &sid
  8                             and s.p1raw = h.laddr) x
  9  group by x.sid, x.name
 10  ;
old   7:                where s.sid = &sid
new   7:                where s.sid =        138

       SID NAME                             COUNT(*)
---------- ------------------------------ ----------
       134 shared pool                            33
       134 library cache                         308

1.3 ロックのホルダ?

ロックホルダ?はV$LOCKビュ?で十分です。

-- ロックホルダ?
select
 h.sid,  -- ホルダ?SID
 h.type,   -- ロックタイプ
 h.id1,  -- ID1
 h.id2,  -- ID2
 h.lmode, 
 t.name,
 t.id1_tag,
 t.id2_tag,
 t.description
from v$lock h, v$lock w, v$lock_type t
where w.sid = { waiter_sid }
 and h.id1 = w.id1
 and h.id2 = w.id2
 and h.lmode > 0 
 and h.block > 0
 and h.type = t.type
;

1.3 Library cache lockのホルダ?

Library cache lockとはLCO(Library Cache Object)を保護するシステムロックです。競合が?生すればlibrary cache lock待機イベントを持ちます。Library cache lockのホルダ?はX$KGLLKビュ?を通じて突き止められます。

-- Library cache lock ホルダ?　　　　　　　　　　
select
 (select sid from v$session where saddr = k.kgllkuse) as sid,  -- ホルダ?SID
 k.kglhdnsp,  -- 客?の種類
 k.kglnaobj,  -- 客?名（SQL文章や表、プロシ?ジャ名など）
 decode(k.kgllkmod, 3, '3(X)', 2, '2(S)', 1, '1(N)', k.kgllkmod) as lkmode
from x$kgllk k
where k.kgllkhdl = { v$session_wait.p1raw }
   and k.kgllkmod > 0
;

1.4 Library cache pinのホルダ?

Library cache pinとはカ?ソルやプロシ?ジャの?行を保護するシステムロックです。競合が?生すればlibrary cache pin待機イベントを待ちます。Library cache pinホルダ?はX$LGLPNビュ?を通じて突き止められます。

-- Library cache pin　ホルダ?
select
  (select sid from v$session where saddr = n.kglpnuse) as sid, 
  o.kglnaobj,
  o.kglhdnsp,
  decode(n.kglpnmod, 3, '3(X)', 2, '2(S)', 1, '1(N)', n.kglpnmod) as lkmode
from x$kglpn n, x$kglob o
where n.kglpnhdl = { v$session_wait.p1raw }
   and n.kglpnmod > 0
   and o.kglhdadr = n.kglpnhdl
;

1.5 Row cache lockのホルダ?

Row cache lockとはディクショナリ?オブジェクトを保護するロックです。競合が?生すればrow cache lock待機イベントを待ちます。Row cache lockのホルダ?はV$ROWCACHE_PARENTビュ?から突き止められます。

-- Row cache lock ホルダ?
select 
 (select sid from v$session where saddr = h.saddr) as sid,  -- ホルダ?SID
 h.cache_name,  -- ディクショナリ?オブジェクトの種類
 h.lock_mode,    
 h.inst_lock_type 
from v$rowcache_parent h, v$rowcache_parent w, v$session s
where h.address = w.address
   and w.saddr = s.saddr 
   and s.sid = { waiter_sid }
   and h.lock_mode > 0
;   

1.6 Mutexのホルダ?

Mutexのホルダ?はV$MUTEX_SLEEP_HISTORYビュ?を通じて突き止められます。

-- Mutexのホルダ?
select * from (
 select
   blocking_session as sid,  -- ホルダ?SID
  (select kglnaobj from x$kglob 
  where kglnahsh = mutex_identifier 
  and rownum = 1) as obj_name,   -- オブジェクト命(11gで追加)
   mutex_type,  -- Mutexのタイプ
   location,  -- Mutexを獲得した位置、すなわち何のためにMutexを獲得しようとしているのか？
   sleeps,
   gets,
   to_char(sleep_timestamp,'yyyy/mm/dd hh24:mi:ss') as sleep_timestamp
 from v$mutex_sleep_history
 where requesting_session = session_id
 order by sleep_timestamp desc
) where rownum <= 1 ;

11gからはMUTEX_IDENTIFIERという有?なコラムが追加されMutex競合の分析がもっと易くなりました。

上の情報からわかるようにホルダ?の?索も大事ものの、もっと具?的にどんな情報で、どんあ客?で問題が?生しているのかを把握することも重要です。このような理由から、文書化されていないV$ビュ?やX$ビュ?を?索するしかありません。

ティパックではSession Detail Reportを通じて上の情報を取り出すことができます。ほぼ同じクエリを使用します。

Library cache pin競合の例で?明してみます。

-- とても長いSQL文章を作ります。正確にいえばハ?ドパ?スの時間が長いSQL文章です。
-- http://sites.google.com/site/ukja/sql-scripts-1/j-m/make_long
TPACK@ukja1021> @make_long
select count(*) from TPACK_REPORT_PARAMS, TPACK_REPORT_CONDITIONS,
TPACK_REPORT_JOB_HIST, TPACK_REPORT_SESSION_TEMP, TPACK_FUNCTION_NAMES,
...

-- セッション＃１で上のクエリを行います。（私のテスト環境で２分５０秒くらいかかります）
TPACK@ukja1021> exec dbms_application_info.set_client_info('session1');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.39
TPACK@ukja1021> @long_parse
....

-- セッション＃１と同時にセッション＃２で同じクエリを行います。
TPACK@ukja1021> exec dbms_application_info.set_client_info('session2');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.04
TPACK@ukja1021> @long_parse
...

セッション＃２はセッション＃１がハ?ドパ?スを行なう間、待機?態になります。セッション＃２に?してSession Detail Reportを?集して待機イベントを詳細に分析します。

-- セッション＃２のSID
TPACK@ukja1021> col sid new_value sid
TPACK@ukja1021> select sid from v$session where client_info = 'session2';

       SID
----------
       138

1 row selected.

Elapsed: 00:00:00.14

-- セッション＃２のSession Detail Report
TPACK@ukja1021> col name format a30
TPACK@ukja1021> col value format a45
TPACK@ukja1021> set pages 200
TPACK@ukja1021> set long 10000000
TPACK@ukja1021> select * from table(tpack.session_detail(&sid, 'wait_detail'));
old   1: select * from table(tpack.session_detail(&sid, 'wait_detail'))
new   1: select * from table(tpack.session_detail(       138, 'wait_detail'))

NAME                           VALUE
------------------------------ ---------------------------------------------
SID                            138
Serial#                        711
SPID                           3724
Program                        sqlplus.exe
Process                        5364:5208
Module                         SQL*Plus
SQL ID
Child No
SQL Text
Status                         ACTIVE
Blocking Instance              1
Blocking Session               134
Event                          library cache pin
Seq#                           4137
P1(P1raw)                      970230240(39D489E0)
P2(P2raw)                      970230240(36A9AB34)
P3(P3raw)                      970230240(000000C8)
Seconds in wait                10
State                          WAITING
Wait Event                     library cache pin
Holder SID                     134
Namespace                      CURSOR
Object                         select count(*) from TPACK_SGA_STAT, TPACK_SG
                               A_STAT, TPACK_SGA_STAT, TPACK_SGA_STAT, TPACK
                               _SGA_STAT, TPACK_SGA_STAT, TPACK_SGA_STAT, TP
                               ACK_SGA_STAT, TPACK_SGA_STAT, TPACK_SGA_STAT,
                                TPACK_SGA_STAT, TPACK_SGA_STAT, TPACK_SGA_ST
                               AT, TPACK_SGA_STAT, TPACK_SGA_STAT, TPACK_SGA
                               _STAT, TPACK_SGA_STAT, TPACK_SGA_STAT, TPACK_
                               SGA_STAT, TPACK_SGA_STAT, TPACK_SGA_STAT, TPACK_S

                               GA_STAT, TPACK_SGA_STAT, TPACK_SGA_STAT, TPAC
                               K_SGA_STAT, TPACK_SGA_STAT, TPACK_SGA_STAT, T
                               PACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_D
                               UMP, TPACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_
                               HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_DUMP,
                               TPACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_
                               DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK
                               _HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPA

                               CK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_DUM
                               P, TPACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HE
                               AP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_DUMP, TP
                               ACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_DU
                               MP, TPACK_HEAP_DUMP_SUM, TPACK_HEAP_DUMP_SUM,
                                TPACK_HEAP_DUMP_SUM, TPACK_HEAP_DUMP_SUM, TP
                               AC

Holding Mode                   3(X)

NamespaceとObject情報からlibrary cache pin待機に?するより正確な分析が可能です。Oracle 11gではlibrary cache pinではなくてMutexに?する競合が?生します。

TPACK@ukja1106> select * from table(tpack.session_detail(&sid, 'wait_detail'));
old   1: select * from table(tpack.session_detail(&sid, 'wait_detail'))
new   1: select * from table(tpack.session_detail(       127, 'wait_detail'))

NAME                           VALUE
------------------------------ ---------------------------------------------
SID                            127
Serial#                        1642
SPID                           2656
Program                        sqlplus.exe
Process                        5364:5208
Module                         SQL*Plus
SQL ID
Child No
SQL Text
Status                         ACTIVE
Blocking Instance              1
Blocking Session               139
SQL Exec Start
Event                          cursor: pin S wait on X
Seq#                           631
P1(P1raw)                      3859422310(00000000E60A1C66)
P2(P2raw)                      3859422310(00000000008B0000)
P3(P3raw)                      3859422310(0000000000050256)
Seconds in wait                0
State                          WAITING
Wait Event                     cursor: pin S wait on X
Holder SID                     139
Mutex Type                     Cursor Pin
Location
Target Object                  select count(*) from TPACK_SGA_STAT, TPACK_SG
                               A_STAT, TPACK_SGA_STAT, TPACK_SGA_STAT, TPACK
                               _SGA_STAT, TPACK_SGA_STAT, TPACK_SGA_STAT, TP
                               ACK_SGA_STAT, TPACK_SGA_STAT, TPACK_SGA_STAT,
                                TPACK_SGA_STAT, TPACK_SGA_STAT, TPACK_SGA_ST
                               AT, TPACK_SGA_STAT, TPACK_SGA_STAT, TPACK_SGA
                               _STAT, TPACK_SGA_STAT, TPACK_SGA_STAT, TPACK_
                               SGA_STAT, TPACK_SGA_STAT, TPACK_SGA_STAT, TPACK_S

                               GA_STAT, TPACK_SGA_STAT, TPACK_SGA_STAT, TPAC
                               K_SGA_STAT, TPACK_SGA_STAT, TPACK_SGA_STAT, T
                               PACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_D
                               UMP, TPACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_
                               HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_DUMP,
                               TPACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_
                               DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK
                               _HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPA

                               CK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_DUM
                               P, TPACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HE
                               AP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_DUMP, TP
                               ACK_HEAP_DUMP, TPACK_HEAP_DUMP, TPACK_HEAP_DU
                               MP, TPACK_HEAP_DUMP_SUM, TPACK_HEAP_DUMP_SUM,
                                TPACK_HEAP_DUMP_SUM, TPACK_HEAP_DUMP_SUM, TP
                               AC

Last Sleep Time                2010/06/29 16:03:51
Gets                           1
Sleeps                         611

重要なのは待機現象が?生するとき適切なビュ?から適切なデ?タを?索することができるかということです。ティパックはその中核心的なデ?タを自動に?集してくれるだけです。

以前のポスト

1. 「ティパック」性能問題をトラブルシュ?ティングする２つのフレ?ム
   
2. 「ティパック」oradebug
   

「ティパック」oradebug

このポストの目的はoradebugの使用法全?を?明することではなくてティパックで使われているoradebugコマンドを簡?に紹介することです。

1. 特定のプロセスにバインディング

ティパックがoradebugコマンドを使用する理由は特定のプロセスに自由にバインディングできるからです。

-- SYSDBA ユ?ザ?でログイン

sqlplus "/as sysdba"



-- 現在のプロセスにバインディング

SQL> oradebug setmypid



-- 特定のセッションのOS Process IDでバインディング

SQL> select sid, serial#,

   (select spid from v$process where addr = paddr) as ospid

from v$session 

where sid = (select sid from v$mystat where rownum = 1);



       SID    SERIAL# OSPID

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

       144       2446 4872



SQL> oradebug setospid 4872

Oracle pid: 16, Windows thread id: 4872, image: ORACLE.EXE (SHAD)

特定のプロセスにバインディングするには次の４つの方法があります。

SQL> oradebug help

SETMYPID                                 Debug current process

SETOSPID       {ospid}                   Set OS pid of process to debug

SETORAPID      {orapid} ['force']        Set Oracle pid of process to debug

SETORAPNAME    {orapname}                Set Oracle process name to debug  -- 11g에서 추가

...

SETOSPIDコマンドを主に使用する理由はUnix/Linux環境ではProcess ID(PID)を得るのが易いからです。でも、ティパックでは特定のセッションを指定するためにSession ID(SID)をパラメ?タ?で使用します。オラクルではSIDが一番認識しやすい値からです。

2. トレ?スファイルの名前の獲得

ティパックでは特定のプロセスに?してイベントやダンプを行い、その中身を?み?む作業がいくつかあります。したがって、トレ?スファイルの名前を正確にえるのが大事です。oradebug tracefile_name名前がそれに?たります。

SQL> oradebug tracefile_name

c:\oracle\admin\ukja1021\udump\ukja1021_ora_4872.trc

上の作業をティパックでは次のように行なえます。

-- 143番セッションのトレ?スファイルの名前

SQL> select tpack.get_tracefile_name(143) from dual;

c:\oracle\admin\ukja1021\udump\ukja1021_ora_4872.trc



-- レ?スファイルの中身

SQL> select * from table(tpack.get_tracefile_contents('c:\oracle\admin\ukja1021\udump\ukja1021_ora_4872.trc'))

あるいは次のようなクエリを通じても得られます。しかし、ファイル名の正確なフォ?マットはバ?ジョンやＯＳにより?わられます。もう１つの短所は該?プロセスがサ?バ?プロセスなのか、バックグラウンドプロセスなのかを事前に知ることが必要で、プロセスの種類によりどんなディレクトリ?にファイルが書き?まれるのかも判?したければならないということです。このような複?性のためにティパックではoradebug tracefile_nameコマンドを利用します。

select

  d.value||'\'||p.value||'_ora_'||s.spid||'.trc'   as trace_file_name

from 

  (

  select value 

  from v$parameter

  where name = 'instance_name'

  ) p, 

  (

  select value

  from v$parameter

  where name = 'user_dump_dest'

  ) d,

  (

  select spid

  from v$process

  where addr = (

    select paddr 

    from v$session

    where sid = {sid here}

    )

  ) s

3. 診?イベントの修行

特定のプロセスにバインディングした後は該?プロセスに?して診?イベントが行なわれます。

-- 診?イベントの活性化

SQL> oradebug event 10046 trace name context forever, level 12



-- 診?イベントの非活性化

SQL> oradebug event 10046 context off



-- トレ?スファイルの確認

SQL> oradebug tracefile_name

SQL> ed {tracefile_name}

上の作業をティパックでは次のように行われます。

-- 診?イベントの活性化

SQL> exec tpack.begin_diag_trace(143, 10046, 12);



-- 診?イベントの非活性化

SQL> exec tpack.end_diag_trace(143, 10046);



-- トレ?スファイルの確認

SQL> select * from table(tpack.get_diag_trace(143));

ティパックを利用すればoradebugを利用するためにテルネットで接?する必要かないし、クライアントでSQL*Plusですべての作業ができます。ティパックのもう１つの長所は診?イベントを活性した後に生成された中身だけを?み?むということです。すなわち、診?イベントを活性する前に、もうほかの作業により書き?まれた多くのデ?タわスキップされ、今度の作業により書き?まれた中身だけを?み?みます。

4. ダンプの修行

特定のプロセスにバインディングした後、該?プロセスに?して多?なダンプファイルを生成できます。次に簡?な例があります。

-- レベル１でCallstackダンプの修行

SQL> oradebug dump callstack 1



-- PGA Heap Dump。Level 0x20000001とは最上位ヒ?プだけではなくてサイズが大きい五つのサブヒ?プに?して再?的にダンプを修行しろという意味です。非常に有?な機能だと言えます。

SQL> oradebug dump heapdump 0x20000001

ティパックではヒ?プダンプファイルから?み?んだデ?タを加工して分析レポ?トを提供します。

-- 143番セッションに?してCallstackダンプを1秒?たり10回行い、その結果を要約してレポ?ト

SQL> select * from table(tpack.callstack_prof_report(143));



-- 143番セッションに?してPGA Heap Dumpをレベル0x20000001で行い、この結果をレポ?ト

SQL> select * from table(tpack.pga_heap_report(143, 2));

ティパックは性能トラブルシュ?ティングに必要な基本的なデ?タの一部を診?イベントやダンプを通じて得ています。PGA Heap DumpやCallstack Dumpが代表的な例です。このようなデ?タを得るための一番易い（もしかしたら唯一
な）方法としてoradebugを使用しています。

1つの技術的な難しさはSQLコマンドからどうすればoradebugを自由に呼び出すのかということです。ティパックではJava Stored Procedureを利用しています。これに?する詳細なお話は次のポストで進める予定です。

性能トラブルシュ?ティングの段階が深まるほどoradebugの魅力におぼれるはずです。特にOracle 11gでは完全に新しく設計されたOracle Debugging Frameworkが提供され、それに連れてoradebugの機能ももっと?くなりました。詳細な?容は次の文書を?考してください。

• Oradebug DOC
  

以前のポスト

1. 「ティパック」性能問題をトラブルシュ?ティングする２つのフレ?ム