Oracle ASH解析の実践ノウハウ|CPU・I/O・ロック問題の切り分け手法

はじめに

Oracleのパフォーマンス問題において、

・AWRでは問題が見つからない
・特定の時間帯だけ急激に遅くなる
・原因となるSQLや待機イベントが特定できない

といったケースに遭遇したことはないでしょうか?

このような「瞬間的な性能劣化」や「再現性の低い問題」に対して、
強力な分析手段となるのが ASH(Active Session History)です。

ASH

まずはASHに関する基本情報を記載します。

ASHとは?

ASHとは、アクティブセッションの状態を約1秒間隔でサンプリングした履歴データです。

アクティブセッションとは、CPUで処理を実行している、またはI/Oやロックなどのリソース待機状態にあるセッションを指します。ASHでは、これらのアクティブなセッションの情報がサンプリングされ、履歴として記録されます。

具体的には以下のような情報を記録しています。

  • 実行中SQL(SQL_ID)
  • セッション情報(SID)
  • 待機イベント(EVENT)
  • CPU使用 or WAIT状態

AWRが数分から1時間程度の集計データを記録しているのに対し、ASHは1秒間隔でサンプルでデータを取得しています。したがって、短期間のスパイク問題の解析に有効であるという点が特徴です。

ただし、あくまでサンプルで情報取得した断面を見ているだけなので、1秒以内に終わってしまっている処理については情報取得ができない点はご留意ください。なお、情報取得間隔1秒を変更することはできません。

※AWRに関しては、以下の記事を参考にしてください。
Oracle AWRレポートの見方と解析ポイントを徹底解説|パフォーマンス改善・トラブル調査に必須

ASH取得/保存の仕組み

MMNL(Manageability Monitor Lite)というバックグラウンドプロセスによって、ASHの収集と書き込みが行われます。MMNLはアクティブセッションを約1秒間隔でサンプリングし、SGA上のASHバッファに格納します。このデータは、V$ACTIVE_SESSION_HISTORYを通じて参照することができます。

ASHバッファに蓄積されたデータは、バッファ使用状況に応じたタイミング、あるいはAWRスナップショット取得のタイミングで、MMNLによってSYSAUX表領域上のAWRへフラッシュされます。この際、すべてのデータがAWRに保存されるわけではなく、一部がサンプリング(間引き)されてDBA_HIST_ACTIVE_SESS_HISTORYに格納されます。

※ASH解析時の注意点

  • ASHはメモリ保持のため短期間のみ保存
    約1秒間隔でサンプリングされるASHは、SGA内の専用領域(ASHバッファ)に保存されます。これはリングバッファ構造になっており、容量はSGAサイズに応じて動的に決まります。古いデータは自動的に上書きされるため、長期間保持することはできません。そのため、トラブル発生時はASHの保持期間内に分析することが重要です。SGAサイズを大きくすることで結果的に保持期間が伸びる可能性はありますが、保持期間を明示的に制御するパラメータは存在しません。ASHを確実に残したい場合は、定期的にスクリプトで取得・保存する仕組みを構築する必要があります。
  • 長期分析はAWR(DBA_HIST_ACTIVE_SESS_HISTORY)を使用
    AWRではスナップショット単位でデータが永続保存されるため、長期的な傾向分析が可能です。ただし、利用にはDiagnostic Packライセンスが必要です。

ASH取得方法

ASHの取得方法をご説明します。取得できる項目と、実際の取得方法を記載します。

ASHで取得できる項目

ASHで取得できる情報をご説明します。取得できる項目は多岐にわたっているため、主要な項目だけ取得して解析することを推奨します。なお、V$ACTIVE_SESSION_HISTORYとDBA_HIST_ACTIVE_SESS_HISTORYのカラムはほぼ同じ(DBA_HIST_ACTIVE_SESS_HISTORYにSNAP_IDなどのカラムが追加されている。)となります。

カラム説明
SAMPLE_TIMEサンプリングした時刻となります。特定の時間帯に発生した事象を解析できます。
SESSION_IDOracle内部でセッションに割り当てられるセッション識別子です。本値は再利用されるため、次のSESSION_SERIAL#と合わせてセッションを特定します。
SESSION_SERIAL#セッション・シリアル番号となります。
SESSION_TYPEセッションが「ユーザ処理」か「Oracle内部処理」かを区別する項目です。
FOREGROUND:ユーザ処理
BACKGROUND:Oracle内部処理
USER_ID実行ユーザに関する情報となります。オンラインのアプリケーションで実行されているのか、あるいはバッチによる処理なのかを切り分けることができます。例えば、JDBC Thin Client となっていたらJavaアプリケーションから実行されていると判断することが可能です。
SQL_IDサンプリング時にセッションで実行されていたSQL文の識別子です。解析対象のSQLを特定することができます。
SQL_CHILD_NUMBERサンプリング時にセッションで実行されていたSQL文の子カーソル※の識別番号です。
※子カーソル:同じSQL文(SQL_ID)に対して生成される個別の実行計画などが格納されています。
TOP_LEVEL_SQL_IDトップレベルSQL文の識別子です。バッチ、PL/SQLの呼び出し元SQLを特定することができます。
EVENT待機イベント名です。SQL処理遅延の原因特定につながる重要な項目となります。典型的な待機イベントを記載します。
・db file sequential read(I/O):単一ブロック読み取りによる待機
・enq: TX – row lock contention(ロック):行ロック競合による待機
WAIT_CLASS待機の分類となります。代表的な分類は以下です。
・User I/O:ユーザI/O待機
・System I/O:バックグラウンドプロセスI/O待機
・Concurrency:内部データベース・リソースの待機(ロック/ラッチ)
・Cluster:RACに関連する待機
参考情報:待機イベントのクラス
SESSION_STATEセッションの状態が表示されます。
WAITING:ディスクI/O、ロック待ちなどで待ちになっている状態
ON CPUCPUを使って処理を実行している状態
TIME_WAITEDSESSION_STATE = WAITINGの場合は、セッションで実際に費やされたイベントの待機時間(マイクロ秒)。
BLOCKING_SESSION_STATUSブロックしているセッションの状態。
VALID:BLOCKING_SESSIONが特定できている
NO HOLDER:ブロックしているセッションが存在しない
UNKNOWN:ブロッカーが特定できない
NOT IN WAIT:セッションが待機状態ではない
BLOCKING_SESSIONブロックしているセッションのセッション識別子です。

ASH取得方法

sqlplus等でデータベースにアクセスした後に、V$ACTIVE_SESSION_HISTORY のレコードを確認していきましょう。

表示列が多いので、まずは表示関連の設定を入れておきます。

SQL> SET LINESIZE 1000
SQL> SET PAGESIZE 1000
SQL> SET WRAP OFF
SQL>

それでは、select文でASHの情報を取得してみましょう。下記のような情報が取得できて入れば成功です。

SQL> SELECT
    sample_time,
    session_id,
    session_serial#,
    session_type,
    user_id,
    sql_id,
    sql_child_number,
    top_level_sql_id,
    event,
    wait_class,
    session_state,
    time_waited,
    blocking_session_status,
    blocking_session
FROM
    v$active_session_history
WHERE
    sample_time BETWEEN SYSDATE - INTERVAL '1' MINUTE AND SYSDATE
ORDER BY
    sample_time;

SAMPLE_TIME                                                                 SESSION_ID SESSION_SERIAL# SESSION_TY    USER_ID SQL_ID        SQL_CHILD_NUMBER TOP_LEVEL_SQL EVENT                                                            WAIT_CLASS           SESSION TIME_WAITED BLOCKING_SE BLOCKING_SESSION
--------------------------------------------------------------------------- ---------- --------------- ---------- ---------- ------------- ---------------- ------------- ---------------------------------------------------------------- ---------------------------------------------------------------- ------- ----------- ----------- ----------------
01-APR-26 11.07.04.906 AM                                                           43           23816 FOREGROUND          0 fvpyk22nm5ak5                0 f23ynb3tnn5vg                                                                                       ON CPU             0 NOT IN WAIT

ASHとAWRとの使い分け

ASHとAWRはどちらも性能分析に利用されますが、用途が異なります。

・AWR:長期間の傾向分析(マクロ視点)
・ASH:瞬間的な詳細分析(ミクロ視点)

AWRで問題の時間帯や傾向を特定し、
ASHでその時間帯の詳細なセッション状態を分析する、
という使い分けが基本となります。

よくある性能トラブルに対するASH解析方法

性能トラブル発生時の具体的なASH解析方法をご紹介していきます。ぜひ自身の環境で試してみてください。

CPUボトルネック

フルスキャン発生により、CPUがボトルネックになっているケースを想定してみましょう。
まず、100万件のダミーデータを持っているテーブルを作成します。

SQL> CREATE TABLE test_cpu AS
SELECT
 LEVEL AS id,
 DBMS_RANDOM.STRING('A', 100) AS data
FROM dual
CONNECT BY LEVEL <= 1000000;

Table created.

SQL> 

フルスキャンが発生するSQLを実行してみましょう。

SQL> BEGIN
  FOR i IN 1..50 LOOP
    DECLARE v_cnt NUMBER;
    BEGIN
      SELECT /*+ FULL(test_cpu) */
      COUNT(*)
      INTO v_cnt
      FROM test_cpu
      WHERE UPPER(data) LIKE '%ABC%';
    END;
  END LOOP;
END;
/

PL/SQL procedure successfully completed.

Elapsed: 00:00:51.00
SQL>

v$active_session_historyのレコードを確認してください。今回は、FOREGROUNDで実行されているSQLに絞って表示します。

SQL> SELECT
    sample_time,
    session_id,
    session_serial#,
    session_type,
    user_id,
    sql_id,
    sql_child_number,
    top_level_sql_id,
    event,
    wait_class,
    session_state,
    time_waited,
    blocking_session_status,
    blocking_session
FROM
    v$active_session_history
WHERE
    session_type = 'FOREGROUND'
    AND sample_time BETWEEN SYSDATE - INTERVAL '1' MINUTE AND SYSDATE
ORDER BY
    sample_time;

SAMPLE_TIME                                                                 SESSION_ID SESSION_SERIAL# SESSION_TY    USER_ID SQL_ID        SQL_CHILD_NUMBER TOP_LEVEL_SQL EVENT                                                            WAIT_CLASS           SESSION TIME_WAITED BLOCKING_SE BLOCKING_SESSION
--------------------------------------------------------------------------- ---------- --------------- ---------- ---------- ------------- ---------------- ------------- ---------------------------------------------------------------- ---------------------------------------------------------------- ------- ----------- ----------- ----------------
01-APR-26 11.42.41.422 AM                                                           43           23816 FOREGROUND          0 fvpyk22nm5ak5                0 f23ynb3tnn5vg                                                                                       ON CPU             0 NOT IN WAIT
01-APR-26 11.42.42.450 AM                                                           43           23816 FOREGROUND          0 fvpyk22nm5ak5                0 f23ynb3tnn5vg                                                                                       ON CPU             0 NOT IN WAIT
01-APR-26 11.42.43.471 AM           

出力されたASHから確認できる情報は以下となります。
・SESSION_STATE が ON CPU
・EVENTが空
したがって、待機イベントによる処理遅延は発生しておらず、SQLがCPUを使用して処理を実行している状態であると判断できます。

ただし、CPU処理に時間がかかっている原因については、ASHのみでは特定できません。処理量が多い、または非効率なSQLである可能性が考えられるため、実行計画の確認などを通じて詳細な原因分析を行う必要があります。

本例における実行計画の取得結果です。TABLE ACCESS FULLとなっており、フルスキャンが実行されていることが確認できます。必要に応じてインデックスを設定するなどの対策を講じてください。

SQL> SELECT * FROM table(DBMS_XPLAN.DISPLAY_CURSOR('fvpyk22nm5ak5'));

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  fvpyk22nm5ak5, child number 0
-------------------------------------
SELECT /*+ FULL(test_cpu) */ COUNT(*) FROM TEST_CPU WHERE UPPER(DATA)
LIKE '%ABC%'

Plan hash value: 2653270503

-------------------------------------------------------------------------------
| Id  | Operation          | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |          |       |       |  4182 (100)|          |

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   1 |  SORT AGGREGATE    |          |     1 |  2002 |            |          |
|*  2 |   TABLE ACCESS FULL| TEST_CPU |  5617 |    10M|  4182   (1)| 00:00:01 |
-------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - filter(UPPER("DATA") LIKE '%ABC%')

Note
-----

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
   - dynamic statistics used: dynamic sampling (level=2)


24 rows selected.

SQL>

I/Oボトルネック

I/Oがボトルネックとは、ディスクの読み書きが遅く、処理が待たされている状態を指します。
では、I/Oボトルネックの原因となる待機イベントを実際に発生させてみましょう。まず、先ほど作成したテーブルに対して、以下のSQLを複数回実行し、レコードを増やします。

SQL> INSERT INTO test_cpu SELECT * FROM test_cpu;
COMMIT;

この状態でフルスキャンが発生するSQLを実行してみます。

BEGIN
  FOR i IN 1..50 LOOP
    DECLARE v_cnt NUMBER;
    BEGIN
      SELECT /*+ FULL(test_cpu) */
      COUNT(*)
      INTO v_cnt
      FROM test_cpu
      WHERE UPPER(data) LIKE '%ABC%';
    END;
  END LOOP;
END;
/

ASHを確認してみます。

SQL> SELECT
    sample_time,
    session_id,
    session_serial#,
    session_type,
    user_id,
    sql_id,
    sql_child_number,
    top_level_sql_id,
    event,
    wait_class,
    session_state,
    time_waited,
    blocking_session_status,
    blocking_session
FROM
    v$active_session_history
WHERE
    session_type = 'FOREGROUND'
    AND sample_time BETWEEN SYSDATE - INTERVAL '1' MINUTE AND SYSDATE
ORDER BY
    sample_time;

SAMPLE_TIME                                                                 SESSION_ID SESSION_SERIAL# SESSION_TY    USER_ID SQL_ID        SQL_CHILD_NUMBER TOP_LEVEL_SQL EVENT                              WAIT_CLASS                                                        SESSION TIME_WAITED BLOCKING_SE BLOCKING_SESSION
--------------------------------------------------------------------------- ---------- --------------- ---------- ---------- ------------- ---------------- ------------- ---------------------------------------------------------------- ---------------------------------------------------------------- ------- ----------- ----------- ----------------
12-APR-26 10.32.15.773 PM                                                          254           20975 FOREGROUND          0 fvpyk22nm5ak5                0 f23ynb3tnn5vg direct path read                   User I/O                                                          WAITING        2211 UNKNOWN
12-APR-26 10.32.19.910 PM                                                          254           20975 FOREGROUND          0 fvpyk22nm5ak5                0 f23ynb3tnn5vg direct path read                   User I/O                                                          WAITING        3069 UNKNOWN
12-APR-26 10.32.21.048 PM                                                          254           20975 FOREGROUND          0 fvpyk22nm5ak5                0 f23ynb3tnn5vg direct path read                   User I/O                                                          WAITING        2769 UNKNOWN

待機イベント direct path read が発生していることが確認できました。direct path read とはキャッシュを使わない読み取りを意味しています。フルスキャンなどによって大量読み込みが発生している可能性がありますので、インデックスを付与するなどの対策を検討してみてください。

その他、代表的なI/O関連の待機イベントとしては以下があります。

  • db file sequential read
    単一ブロック読み込みの際に発生する待機イベントです。インデックススキャンなどで発生します。
  • db file scattered read
    複数ブロック読み込みの際に発生する待機イベントです。テーブルフルスキャンなどで発生します。
  • log file sync
    COMMIT時のREDOログ書き込みの際に発生する待機イベントです。

ロック競合

ロック競合とは、複数のセッション(トランザクション)が同じデータに同時にアクセスしようとして、互いに待たされる状態のことです。

それでは、複数セッションでデータを更新することでロック競合を発生させてみましょう。
まず、ひとつめのセッションで以下のSQLを実行してください。commit実行待ちとなっています。

SQL> UPDATE test_cpu
SET data = 'AAAA'
WHERE id BETWEEN 1 AND 100;

続いて、ふたつめのセッションで以下のSQLを実行してください。

SQL> UPDATE test_cpu
SET data = 'BBBB'
WHERE id BETWEEN 50 AND 150;

この状態でASHを取得してみてください。

SQL> SELECT
    sample_time,
    session_id,
    session_serial#,
    session_type,
    user_id,
    sql_id,
    sql_child_number,
    top_level_sql_id,
    event,
    wait_class,
    session_state,
    time_waited,
    blocking_session_status,
    blocking_session
FROM
    v$active_session_history
WHERE
    sample_time BETWEEN SYSDATE - INTERVAL '1' MINUTE AND SYSDATE
ORDER BY
    sample_time;

SAMPLE_TIME                                                                 SESSION_ID SESSION_SERIAL# SESSION_TY    USER_ID SQL_ID        SQL_CHILD_NUMBER TOP_LEVEL_SQL EVENT                                                            WAIT_CLASS           SESSION TIME_WAITED BLOCKING_SE BLOCKING_SESSION
--------------------------------------------------------------------------- ---------- --------------- ---------- ---------- ------------- ---------------- ------------- ---------------------------------------------------------------- ---------------------------------------------------------------- ------- ----------- ----------- ----------------
12-APR-26 10.45.16.882 PM                                                          278           36418 FOREGROUND          0 6dz5jp4ampg36                0 6dz5jp4ampg36 enq: TX - row lock contention                                    Application          WAITING            0 VALID                     40
12-APR-26 10.45.17.897 PM                                                          278           36418 FOREGROUND          0 6dz5jp4ampg36                0 6dz5jp4ampg36 enq: TX - row lock contention                                    Application          WAITING            0 VALID                     40
12-APR-26 10.45.18.916 PM                                                          278           36418 FOREGROUND          0 6dz5jp4ampg36                0 6dz5jp4ampg36 enq: TX - row lock contention                                    Application          WAITING            0 VALID                     40

待機イベント enq: TX – row lock contention が発生していることが確認できました。本待機イベントを減らすためには、トランザクションを短くしたり、更新対象を分散するといった対処を検討してみてください。

ASH解析のノウハウ・注意点

  • ASHは1秒ごとに取得したサンプルデータ
    短時間の処理は検知できない一方で、長時間継続する待機や処理はサンプリングされやすく、実際よりも多く観測される傾向があります。
  • 事象発生時の時間帯に絞って解析する
    ASHを全量取得するとかなりの情報量になってしまうので、事象が発生した時間帯に絞って解析を進めるようにしましょう。
  • 件数の割合を確認する
    AWRではDB Timeを基準に各待機イベントやSQLの割合を確認することで、システム全体に対する影響度を評価できます。
  • ASHはメモリ保持のため短期間のみ保存
    約1秒間隔でサンプリングされるASHは、SGA内の専用領域(ASHバッファ)に保存されます。これはリングバッファ構造になっており、容量はSGAサイズに応じて動的に決まります。古いデータは自動的に上書きされるため、長期間保持することはできません。そのため、トラブル発生時はASHの保持期間内に分析することが重要です。SGAサイズを大きくすることで結果的に保持期間が伸びる可能性はありますが、保持期間を明示的に制御するパラメータは存在しません。ASHを確実に残したい場合は、定期的にスクリプトで取得・保存する仕組みを構築する必要があります。
  • 長期分析はAWR(DBA_HIST_ACTIVE_SESS_HISTORY)を使用
    AWRではスナップショット単位でデータが永続保存されるため、長期的な傾向分析が可能です。ただし、利用にはDiagnostic Packライセンスが必要です。

まとめ

ASH(Active Session History)は、約1秒間隔でアクティブセッションの状態を記録することで、データベース内部で「その瞬間に何が起きていたのか」を可視化できる強力な分析ツールです。本記事で解説した通り、ASHを活用することで以下のような分析が可能になります。

・CPU使用中(ON CPU)なのか、待機(WAITING)なのかを切り分ける
・待機イベントからボトルネック(I/O・ロック・REDOなど)を特定する
・SQL_IDをもとに問題のSQLを特定する
・BLOCKING_SESSIONからロックの原因セッションを特定する

また、CPU・I/O・ロックといった典型的な性能問題についても、ASHを用いることで「どのSQLが」「どのリソースで詰まっているのか」を具体的に把握できます。

一方で、ASHはサンプリングデータであるため、
・1秒未満で終了する処理は検知できない
・長時間の処理は実際より多く観測されやすい(サンプリングバイアス)
・メモリ上に保持されるため保存期間が短い
といった制約がある点には注意が必要です。

そのため、実務においては以下の使い分けが重要になります。
・AWR:長期的な傾向分析(どの時間帯に問題が起きているか)
・ASH:短時間の詳細分析(その瞬間に何が起きていたか)

AWRで問題の発生時間帯や傾向を特定し、ASHでその時間帯の詳細なセッション状態を分析する、という流れを意識することで、より効率的かつ正確にパフォーマンス問題の原因を特定できるようになります。

ASHは「どの瞬間に、誰が、何をして、何で待っているのか」を把握するためのツールです。本記事の内容を参考に、ぜひ実際のトラブル解析に活用してみてください。

コメント