Oracle Database 11g ASHの強化 : SQL_EXEC_IDの活用

Oracle Database 11g
2013.05.29
渡部亮太

Excelを用いたASH分析方法の紹介とdb tech showcase 大阪 2013セッション担当のお知らせに引き続き、db tech showcase 大阪 2013で担当させていただく"Analyzing Oracle Database hang issues using various diagnostics."のセッション内容に関連するエントリです。

"Analyzing Oracle Database hang issues using various diagnostics." ではハング分析における有効な診断情報として、ASH について触れます。先日ご紹介した Oracle Database 11g HANG ANALYZE診断情報の強化と同様にASHもOracle Database 11gで改善され、いくつかの列が追加されています。

追加された列の中で、SQL_EXEC_IDという列が地味に便利なのでご紹介します。

SQL_EXEC_IDは、同一のSQLが複数回実行された場合に、それぞれのSQL実行を区別できる識別子です。 Tanel PoderさんのWhat the heck is the SQL Execution ID ? SQL_EXEC_ID? において、SQL_EXEC_IDの上位8ビットがインスタンスの識別子、下位24ビットがインスタンススコープのSQL実行カウンタであると結論付けられています。

SQL_EXEC_IDがASHをもとにした解析においてどのように役立つかというと、SQLの実行時間の算出です。Oracle DatabaseではSQL_IDという識別子により、SQLを一意に識別できます。しかし、Oracle Database 10.2までは、同一のSQLが複数回実行された場合に、それぞれのSQL実行を区別することができませんでした。このため、あるセッションで同一のSQLが複数回実行された場合、それぞれを区別できず、ASHのデータを基にしてSQLの実行時間を算出することができませんでした。

具体的には、SQL_IDとSQL_EXEC_IDをGROUP BY句に指定した以下のSQLで、SQLの実行時間を算出できます。

define ashtab=DBA_HIST_ACTIVE_SESS_HISTORY
SELECT  sql_id
      , SQL_EXEC_ID
      , max(sample_time) - min(sample_time) exec_time
  FROM &ashtab
  WHERE sql_id IS NOT NULL
  GROUP BY sql_id, SQL_EXEC_ID

実際の利用においては、上記SQLを実行時間の降順でソートし、かつ、件数を限定して、実行時間の上位XX件のSQL実行のみを抜き出すようなSQLを使うことになるでしょう。

define ashtab=DBA_HIST_ACTIVE_SESS_HISTORY
SELECT * FROM (
SELECT  sql_id
      , sql_exec_id
      , max(sample_time) - min(sample_time) exec_time
  FROM &ashtab
  WHERE sql_id IS NOT NULL
  GROUP BY sql_id, sql_exec_id
  ORDER BY  exec_time desc
  ) WHERE rownum <=10;

実行結果の例

SQL_ID        SQL_EXEC_ID EXEC_TIME
------------- ----------- ------------------------------
79k0kvn8a93tu    16777216 +000000000 00:01:12.413
dc7hp77jzwbs5    16777216 +000000000 00:01:10.293
cj83gjts6pb3r    16777216 +000000000 00:01:09.293
9nyrk6h1rqzu8    16777216 +000000000 00:00:49.233
6h68mf7za57a8    16777216 +000000000 00:00:48.113
6n8t7dcc44mv7    16777216 +000000000 00:00:48.113
4xuff27382g1w    16777216 +000000000 00:00:47.203
3dy26apu9p0xr    16777216 +000000000 00:00:47.203
fvr9zj89546cx    16777216 +000000000 00:00:45.083
d6upgmxm6f709    16777216 +000000000 00:00:18.163

10行が選択されました。

あとは、SQL_IDが示すSQL文を得たり、

SQL> SELECT SQL_ID, SQL_TEXT FROM  DBA_HIST_SQLTEXT WHERE SQL_ID='79k0kvn8a93tu';

SQL_ID
-------------
SQL_TEXT
-------------------------------------------------------------------------------
79k0kvn8a93tu
SELECT channels.channel_desc, calendar_month_desc,
       countries.country_iso_code,
       TO_CHAR(SUM(amount_sold), '9,999,999,999') SALES$
FROM sales, customers, times, channels, countries
WHERE sales.time_id=times.time_id
  AND sales.cust_id=customers.cust_id
  AND customers.country_id = countries.country_id
  AND sales.channel_id = channels.channel_id
  AND channels.channel_desc IN ('Partners')
  AND times.calendar_month_desc IN ('1999-02','1999-03')
  AND countries.country_iso_code IN ('MY','NL')
GROUP BY
  ROLLUP(channels.channel_desc, calendar_month_desc, countries.country_iso_code
)

SQL_IDが示すSQLを実行しているセッションを特定したりなどの様々な調査が可能です。

SQL> SELECT distinct SESSION_ID, SESSION_SERIAL#, PROGRAM FROM DBA_HIST_ACTIVE_SESS_HISTORY WHERE SQL_ID='79k0kvn8a93tu';

SESSION_ID SESSION_SERIAL# PROGRAM
---------- --------------- ----------------------------------------
        35               1 JDBC Thin Client