はじめに
システムの稼働中に突然パフォーマンスが悪くなったり、処理が終わらずエラーになったなどのトラブルはデータベース運用において多くの方が経験したことがあると思います。
Oracle Databaseでは特定のセッションが他のセッションをブロックして処理が待機したケースなどの一部のセッション起因のトラブル調査に利用できる、ASH(Active Session History)という機能を提供しています。
ASHの分析にはEnterprise Managerなどを活用したGUIによる分析が一般的ですが、担当システムの開発や保守の人以外は直接GUI画面を操作することもできないケースもあるかと思います。
その場合はビュー(DBA_HIST_ACTIVE_SESS_HISTORY)の情報をCSVやDataPumpのdmpで依頼して調査する形になりますが、調査に必要な観点とビューのカラムの内容を見比べながらSelect文を書くことになり、ある程度労力やスキルが必要になるため、慣れている人でないと最初はハードルが高いと感じてしまうかもしれません。
今回はOracle DatabaseのマネージドサービスとなるAutonomous Databaseの最新バージョンで利用可能なAI機能の1つである、Select AIを用いてASHを自然言語で問い合わせ、その当時何が起きていたのかをSQLを書くことなく確認してみました。
こちらの記事の内容は個人的な検証結果をまとめた内容となります。
サービスや機能に関しての詳細はマニュアルもあわせてご確認ください。
また、こちらの記事の内容を元にしたOracleサポートへの問い合わせはご遠慮ください。
前提条件
- 分析元データベース
- OCI Base Database Service(BaseDB)を利用
- バージョンは19cの最新版(検証時では19.28)を利用
- ワークロード
- swingbenchを利用
- こちらのOCIチュートリアルなどを参考に実行
- 分析環境
- Autonomous Database 23ai
- LLMはOCI Generative AI Service内のCohereを利用
事前準備
分析元環境でデータ生成
swingbenchのoewizardでSOEスキーマおよびデータを作成します。
[oracle@nyaol8 swingbench]$ ./swingbench/bin/oewizard -cs <ホスト名>:<ポート番号>/<DBサービス名> -ts DATA -dbap <パスワード> -dba system -u soe -p <パスワード> -async_off -scale 1 -hashpart -create -cl -v
SwingBench Wizard
Author : Dominic Giles
Version : 2.7.0.1511
Running in Lights Out Mode using config file : ../wizardconfigs/oewizard.xml
Running script ../sql/orderentry/soedgcreatetablespace.sql
Script completed in 0 hour(s) 0 minute(s) 14 second(s) 361 millisecond(s)
Running script ../sql/orderentry/soedgcreateuser.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 162 millisecond(s)
Starting run
Starting script ../sql/orderentry/soedgdrop2.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 56 millisecond(s)
Starting script ../sql/orderentry/soedgcreatetableshash2.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 152 millisecond(s)
Starting script ../sql/orderentry/soedgviews.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 23 millisecond(s)
Starting script ../sql/orderentry/soedgsqlset.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 62 millisecond(s)
Inserting data into table ADDRESSES_2
Inserting data into table ADDRESSES_1
Inserting data into table CUSTOMERS_2
Inserting data into table CUSTOMERS_1
Completed processing table ADDRESSES_1 in 0:00:18
Inserting data into table ORDER_ITEMS_714894
Inserting data into table ORDERS_2
Completed processing table ADDRESSES_2 in 0:00:18
Completed processing table CUSTOMERS_1 in 0:00:22
Inserting data into table ORDER_ITEMS_0
Inserting data into table ORDERS_1
Completed processing table CUSTOMERS_2 in 0:00:23
Completed processing table ORDERS_2 in 0:01:37
Inserting data into table CARD_DETAILS_2
Completed processing table ORDER_ITEMS_714894 in 0:01:38
Inserting data into table CARD_DETAILS_1
Completed processing table ORDERS_1 in 0:01:35
Inserting data into table LOGON_2
Completed processing table ORDER_ITEMS_0 in 0:01:37
Inserting data into table LOGON_1
Inserting data into table PRODUCT_INFORMATION
Completed processing table CARD_DETAILS_2 in 0:00:17
Inserting data into table INVENTORIES
Completed processing table PRODUCT_INFORMATION in 0:00:00
Completed processing table CARD_DETAILS_1 in 0:00:18
Inserting data into table PRODUCT_DESCRIPTIONS
Completed processing table PRODUCT_DESCRIPTIONS in 0:00:00
Inserting data into table WAREHOUSES
Completed processing table WAREHOUSES in 0:00:00
Completed processing table INVENTORIES in 0:00:08
Completed processing table LOGON_2 in 0:00:23
Starting script ../sql/orderentry/soedganalyzeschema2.sql
Script completed in 0 hour(s) 1 minute(s) 5 second(s) 148 millisecond(s)
Starting script ../sql/orderentry/soedgconstraints2.sql
Script completed in 0 hour(s) 0 minute(s) 6 second(s) 501 millisecond(s)
Starting script ../sql/orderentry/soedgindexes2.sql
Script completed in 0 hour(s) 0 minute(s) 14 second(s) 943 millisecond(s)
Starting script ../sql/orderentry/soedgsequences2.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 313 millisecond(s)
Starting script ../sql/orderentry/soedgpackage2_header.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 104 millisecond(s)
Starting script ../sql/orderentry/soedgpackage2_body.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 103 millisecond(s)
Starting script ../sql/orderentry/soedgsetupmetadata.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 328 millisecond(s)
Data Generation Runtime Metrics
+-------------------------+-------------+
| Description | Value |
+-------------------------+-------------+
| Connection Time | 0:00:00.006 |
| Data Generation Time | 0:02:22.948 |
| DDL Creation Time | 0:01:27.818 |
| Total Run Time | 0:03:50.774 |
| Rows Inserted per sec | 110,982 |
| Actual Rows Generated | 15,895,788 |
| Commits Completed | 817 |
| Batch Updates Completed | 79,501 |
+-------------------------+-------------+
Validation Report
The schema appears to have been created successfully.
Valid Objects
Valid Tables : 'ORDERS','ORDER_ITEMS','CUSTOMERS','WAREHOUSES','ORDERENTRY_METADATA','INVENTORIES','PRODUCT_INFORMATION','PRODUCT_DESCRIPTIONS','ADDRESSES','CARD_DETAILS'
Valid Indexes : 'PRD_DESC_PK','PROD_NAME_IX','PRODUCT_INFORMATION_PK','PROD_SUPPLIER_IX','PROD_CATEGORY_IX','INVENTORY_PK','INV_PRODUCT_IX','INV_WAREHOUSE_IX','ORDER_PK','ORD_SALES_REP_IX','ORD_CUSTOMER_IX','ORD_ORDER_DATE_IX','ORD_WAREHOUSE_IX','ORDER_ITEMS_PK','ITEM_ORDER_IX','ITEM_PRODUCT_IX','WAREHOUSES_PK','WHS_LOCATION_IX','CUSTOMERS_PK','CUST_EMAIL_IX','CUST_ACCOUNT_MANAGER_IX','CUST_FUNC_LOWER_NAME_IX','ADDRESS_PK','ADDRESS_CUST_IX','CARD_DETAILS_PK','CARDDETAILS_CUST_IX'
Valid Views : 'PRODUCTS','PRODUCT_PRICES'
Valid Sequences : 'CUSTOMER_SEQ','ORDERS_SEQ','ADDRESS_SEQ','LOGON_SEQ','CARD_DETAILS_SEQ'
Valid Code : 'ORDERENTRY'
Schema Created
[oracle@nyaol8 swingbench]$
[oracle@nyaol8 swingbench]$ ./swingbench/bin/sbutil -soe -cs <ホスト名>:<ポート番号>/<DBサービス名> -u soe -p <パスワード> -val
The Order Entry Schema appears to be valid.
--------------------------------------------------
|Object Type | Valid| Invalid| Missing|
--------------------------------------------------
|Table | 10| 0| 0|
|Index | 26| 0| 0|
|Sequence | 5| 0| 0|
|View | 2| 0| 0|
|Code | 1| 0| 0|
--------------------------------------------------
[oracle@nyaol8 swingbench]$ ./swingbench/bin/sbutil -soe -cs <ホスト名>:<ポート番号>/<DBサービス名> -u soe -p <パスワード> -tables
Order Entry Schemas Tables
+----------------------+-----------+--------+---------+-------------+--------------+
| Table Name | Rows | Blocks | Size | Compressed? | Partitioned? |
+----------------------+-----------+--------+---------+-------------+--------------+
| ORDER_ITEMS | 7,179,686 | 68,480 | 544.0MB | | Yes |
| CARD_DETAILS | 1,500,000 | 12,158 | 256.0MB | | Yes |
| CUSTOMERS | 1,000,000 | 20,096 | 256.0MB | | Yes |
| ORDERS | 1,429,790 | 28,160 | 256.0MB | | Yes |
| ADDRESSES | 1,500,000 | 20,096 | 256.0MB | | Yes |
| LOGON | 2,382,984 | 11,906 | 95.0MB | | Yes |
| INVENTORIES | 900,328 | 10,996 | 87.0MB | Disabled | No |
| WAREHOUSES | 1,000 | 124 | 1024KB | Disabled | No |
| PRODUCT_INFORMATION | 1,000 | 124 | 1024KB | Disabled | No |
| PRODUCT_DESCRIPTIONS | 1,000 | 124 | 1024KB | Disabled | No |
| ORDERENTRY_METADATA | 4 | 124 | 1024KB | Disabled | No |
+----------------------+-----------+--------+---------+-------------+--------------+
Total Space 1.7GB
分析元環境に対して負荷掛け
charbenchを用いてBaseDB環境に対してワークロードを実行します。
[oracle@nyaol8 swingbench]$ ./swingbench/bin/charbench -c ~/labs/swingbench/swingbench/configs/SOE_Server_Side_V22.xml -cs <ホスト名>:<ポート番号>/<DBサービス名> -u soe -p <パスワード> -uc 10 -v users,tpm,tps,errs,vresp
Swingbench
Author : Dominic Giles
Version : 2.7.0.1511
Results will be written to results.xml
Hit Return to Terminate Run...
Time Users TPM TPS Errors NCR UCD BP OP PO BO SQ WQ WA
12:42:18 [0/10] 0 0 0 0 0 0 0 0 0 0 0 0
12:42:19 [7/10] 0 0 0 0 0 0 0 0 0 0 0 0
12:42:20 [10/10] 1652 1652 0 6 3 3 8 6 5 0 0 0
12:42:21 [10/10] 3612 1960 0 6 2 3 8 5 4 0 0 0
12:42:22 [10/10] 5604 1992 0 5 2 3 9 5 4 0 0 0
12:42:23 [10/10] 7553 1949 0 4 2 2 10 3 4 0 0 0
12:42:24 [10/10] 9655 2102 0 5 2 3 8 4 4 0 0 0
：
12:48:21 [10/10] 100763 1812 0 5 2 3 10 5 4 0 0 0
12:48:22 [10/10] 100492 1758 0 6 2 3 10 5 4 0 0 0
12:48:23 [10/10] 100109 1699 0 6 2 4 10 4 4 0 0 0
12:48:24 [10/10] 99928 1832 0 6 2 3 10 5 4 0 0 0
12:48:25 [10/10] 99574 1707 0 6 2 3 10 5 4 0 0 0
12:48:26 [10/10] 99238 1737 0 6 2 3 10 5 4 0 0 0
12:48:27 [10/10] 99026 1860 0 5 2 3 10 4 4 0 0 0
12:48:28 [10/10] 98952 1807 0 5 2 3 10 4 4 0 0 0
12:48:29 [10/10] 98775 1752 0 6 2 3 10 5 4 0 0 0
12:48:30 [10/10] 98569 1775 0 6 2 3 10 5 4 0 0 0
12:48:31 [10/10] 98166 1643 0 6 2 4 11 4 3 0 0 0
12:48:32 [10/10] 97930 1819 0 6 2 3 10 5 4 0 0 0
12:48:33 [10/10] 97675 1817 0 5 2 3 10 5 4 0 0 0
12:48:34 [10/10] 96362 753 0 5 2 3 10 5 4 0 0 0
12:48:35 [10/10] 94254 0 0 0 0 0 0 0 0 0 0 0
12:48:36 [10/10] 92149 0 0 0 0 0 0 0 0 0 0 0
：
12:50:02 [10/10] 0 0 0 0 0 0 0 0 0 0 0 0
12:50:03 [10/10] 0 0 0 0 0 0 0 0 0 0 0 0
12:50:04 [10/10] 495 495 0 6 2 3 6801 5 5 0 0 0
12:50:05 [10/10] 2249 1754 0 6 2 3 10 4 5 0 0 0
12:50:06 [10/10] 4011 1762 0 6 2 3 10 5 5 0 0 0
12:50:07 [10/10] 5808 1797 0 6 2 3 10 5 4 0 0 0
：
12:51:02 [10/10] 104510 2033 0 5 2 3 9 4 3 0 0 0
^C[oracle@nyaol8 swingbench]$
[oracle@nyaol8 swingbench]$
負荷掛け中に別セッションから処理を妨害
今回はテストとしてワークロード実行中に別セッションを開いて利用中の表に対して排他表ロックをかけてみました。
上記の12:48:35～12:50:03あたりまでロックを取得しており、TPS列の値も0になっています。
本番運用環境でついうっかり同じ真似をすると大事件になるのでお気をつけください。
[oracle@nyaol8 ~]$ sqlplus soe@pnyabase
SQL*Plus: Release 23.0.0.0.0 - for Oracle Cloud and Engineered Systems on Sat Sep 13 12:43:16 2025
Version 23.5.0.24.07
Copyright (c) 1982, 2024, Oracle. All rights reserved.
Enter password:
Last Successful login time: Sat Sep 13 2025 12:42:19 +00:00
Connected to:
Oracle Database 19c EE High Perf Release 19.0.0.0.0 - Production
Version 19.28.0.0.0
SQL> lock table ORDER_ITEMS in EXCLUSIVE MODE;
Table(s) Locked.
SQL> rollback;
Rollback complete.
SQL> exit
分析用の表の作成及びexport
dba_hist_active_sess_historyから分析用に時間帯で絞った新しい表を作成して、Autonomous Databaseへ持っていくためにexportします。
[oracle@nyabase ~]$ sqlplus soe@pnyabase
SQL> create table swingbench_ash
2 as select *
3 from dba_hist_active_sess_history
4 where SAMPLE_TIME_UTC BETWEEN TO_DATE('2025-09-13 12:40:00', 'YYYY-MM-DD HH24:MI:SS')
5 AND TO_DATE('2025-09-13 12:50:00', 'YYYY-MM-DD HH24:MI:SS');
Table created.
SQL> exit
Disconnected from Oracle Database 19c EE High Perf Release 19.0.0.0.0 - Production
Version 19.28.0.0.0
[oracle@nyabase ~]$ expdp soe@pnyabase tables=swingbench_ash dumpfile=swingbench_ash.dmp logfile=swingbench_ash.log
Export: Release 19.0.0.0.0 - Production on Sat Sep 13 22:17:50 2025
Version 19.28.0.0.0
Copyright (c) 1982, 2019, Oracle and/or its affiliates. All rights reserved.
Password:
Connected to: Oracle Database 19c EE High Perf Release 19.0.0.0.0 - Production
Starting "SOE"."SYS_EXPORT_TABLE_01": soe/********@pnyabase tables=swingbench_ash dumpfile=swingbench_ash.dmp logfile=swingbench_ash.log
Processing object type TABLE_EXPORT/TABLE/TABLE_DATA
Processing object type TABLE_EXPORT/TABLE/STATISTICS/TABLE_STATISTICS
Processing object type TABLE_EXPORT/TABLE/STATISTICS/MARKER
Processing object type TABLE_EXPORT/TABLE/TABLE
. . exported "SOE"."SWINGBENCH_ASH" 213.3 KB 371 rows
ORA-39173: Encrypted data has been stored unencrypted in dump file set.
Master table "SOE"."SYS_EXPORT_TABLE_01" successfully loaded/unloaded
******************************************************************************
Dump file set for SOE.SYS_EXPORT_TABLE_01 is:
/u01/app/oracle/admin/ORCL/dpdump/3A0B53EC09F61F5AE0631007F40AE5F4/swingbench_ash.dmp
Job "SOE"."SYS_EXPORT_TABLE_01" successfully completed at Sat Sep 13 22:18:09 2025 elapsed 0 00:00:14
Autonomous Databaseへインポート
事前にAutonomous Database内に分析用のスキーマ(ashchk)を作成しておき、オブジェクトストレージにexportしたdmpを配置してimportします。
[oracle@nyaol8 swingbench]$ impdp ashchk@nyaadw_high remap_schema=soe:ashchk dumpfile='https://objectstorage.ap-tokyo-1.oraclecloud.com/p/xxxx/o/swingbench_ash.dmp' logfile=tmp.log directory=DATA_PUMP_DIR
Import: Release 23.0.0.0.0 - for Oracle Cloud and Engineered Systems on 土 9月 13 13:31:57 2025
Version 23.5.0.24.07
Copyright (c) 1982, 2024, Oracle and/or its affiliates. All rights reserved.
パスワード:
接続先: Oracle Database 23ai Enterprise Edition Release 23.0.0.0.0 - for Oracle Cloud and Engineered Systems
マスター表"ASHCHK"."SYS_IMPORT_FULL_01"は正常にロード/アンロードされました
"ASHCHK"."SYS_IMPORT_FULL_01"を起動しています: ashchk/********@nyaadw_high remap_schema=soe:ashchk dumpfile=https://objectstorage.ap-tokyo-1.oraclecloud.com/p/xxxx/o/swingbench_ash.dmp logfile=tmp.log directory=DATA_PUMP_DIR
オブジェクト型TABLE_EXPORT/TABLE/TABLEの処理中です
オブジェクト型TABLE_EXPORT/TABLE/TABLE_DATAの処理中です
. . "ASHCHK"."SWINGBENCH_ASH" 213.3 KB 371行がインポートされました
オブジェクト型TABLE_EXPORT/TABLE/STATISTICS/TABLE_STATISTICSの処理中です
ジョブ"ASHCHK"."SYS_IMPORT_FULL_01"が土 9月 13 13:32:19 2025 elapsed 0 00:00:13で正常に完了しました
[oracle@nyaol8 swingbench]$
Select AI実行の前準備
Select AIの実行のため、事前にOCI GenAI Service内のLLMへアクセスするためのAPIキーやクレデンシャルを準備しておきます。
こちらのチュートリアルも参考にしています。
まずはOCI Generative AI Serviceへアクセスする際の資格証明を作成します。
※各値はマスクしています。
SQL> BEGIN
2 DBMS_CLOUD.CREATE_CREDENTIAL(
3 credential_name => 'OCI_GENAI_CRED',
4 user_ocid => 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx',
5 tenancy_ocid => 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx',
6 private_key => '-----BEGIN PRIVATE KEY-----
:
33 -----END PRIVATE KEY-----',
34 fingerprint => 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'
35 );
36 END;
37 /
PL/SQLプロシージャが正常に完了しました。
続いて大阪リージョンにあるcohereをLLMとして利用するプロファイルを作成します。
このプロファイル内でSelect AIが参照する表(swingbench_ash)を指定しています。
SQL> BEGIN
2 DBMS_CLOUD_AI.CREATE_PROFILE(
3 'GENAI_COHERE_ASH',
4 '{
5 "provider": "oci",
6 "credential_name": "OCI_GENAI_CRED",
7 "model":"cohere.command-r-08-2024",
8 "oci_apiformat":"COHERE",
9 "region": "ap-osaka-1",
10 "object_list": [
11 {"owner": "ashchk", "name": "swingbench_ash"}
12 ]
13 }'
14 );
15 END;
16 /
PL/SQLプロシージャが正常に完了しました。
SQL>EXEC DBMS_CLOUD_AI.SET_PROFILE('GENAI_COHERE_ASH');
PL/SQLプロシージャが正常に完了しました。
Select AIを使ってASH表を分析
それでは実際にいろいろと自然言語でDBに聞いてみようと思います。
アクティブセッション数の推移
いい感じに出してくれていそうです。
結果の時間表記が若干不親切なので聞き方には工夫の余地はあるかもしれません。
SQL> select ai UTC時間の'2025/9/13 12:40'から'2025/9/13 12:50'までに実行されたセッション数を1分毎に数えてください;
分 セッション数
---------- ------------
42 30
43 46
44 47
45 45
46 45
47 43
48 55
49 60
待機イベント
待機イベントという言葉もしっかり解釈し、必要な列の情報からきっちり集計してくれています。
今回明示的に表ロックをかけたので'ENQ: TM - CONTENTION'が発生していることがわかります。
SQL> select ai 発生した待機イベントを多い順に数もあわせて教えてください。;
EVENT OCCURRENCE_COUNT
---------------------------------------- ----------------
148
LOG FILE SYNC 121
ENQ: TM - CONTENTION 90★
LOG FILE SWITCH (PRIVATE STRAND FLUSH IN 10
COMPLETE)
BUFFER BUSY WAITS 1
LIBRARY CACHE: MUTEX X 1
特定の待機イベントで待ったアプリケーションの情報
怪しい待機イベントで待っているアプリケーションの情報も聞いてみます。
今回swingbenchを動かしたクライアントサーバとアプリケーションの情報が出力されています。
SQL> select ai 'ENQ: TM - CONTENTION'で待機したセッションの接続元とアプリケーションを集計して教えてください。;
接続元 アプリケーション
---------- ----------------
nyaol8 New Order
特定の待機イベントを発生させたブロックセッションの情報
'ENQ: TM - CONTENTION'を発生させた要因となるセッションの情報も聞いてみます。
セッションID=337が諸悪の根源であることがわかります。
SQL> select ai 'ENQ: TM - CONTENTION'で待機していたセッションのブロッカーセッションのセッション識別子とセッションシリアル番号を教えてください。結果はセッション識別子とセッションシリアル番号で集計して数とともに教えてください;
BLOCKER_SESSION_ID BLOCKER_SESSION_SERIAL_NUMBER NUMBER_OF_SESSIONS
------------------ ----------------------------- ------------------
337★ 508 90★
なお、この後セッションID=337の情報も聞いてみたのですが、問題のセッションはロックを取得したあとに放置をしていた(=インアクティブなセッションだった)ため、ASH上からは確認できませんでした。(テストケースが悪かった)
ただし特定のSQLの実行計画が悪くなり長時間化した、などのケースでは十分補足可能だと思われます。
実際に実行しているSQLの確認
select aiにはshowsqlオプションをつけることで実際に生成したSQLを確認することが可能です。
結果の確からしさの確認やSQLの叩き台を作成してもらって、その後必要に応じて自分でカスタマイズする、といったことが容易に可能です。
SQL> select ai showsql 'ENQ: TM - CONTENTION'で待機していたセッションのブロッカーセッションのセッション識別子とセッションシリアル番号を教えてください。結果はセッション識別子とセッションシリアル番号で集計して数とともに教えてください;
RESPONSE
-----------------------------------------------------------------------------------------------
SELECT
BLOCKING_SESSION AS "BLOCKER_SESSION_ID",
BLOCKING_SESSION_SERIAL# AS "BLOCKER_SESSION_SERIAL_NUMBER",
COUNT(*) AS "NUMBER_OF_SESSIONS"
FROM "ASHCHK"."SWINGBENCH_ASH"
WHERE UPPER(EVENT) = 'ENQ: TM - CONTENTION'
GROUP BY BLOCKING_SESSION,BLOCKING_SESSION_SERIAL#
LLMへの確認
また、chatオプションを使うことでデータベースへの問合せは行わず、LLMから直接レスポンスを生成することも可能です。
例えばASHの分析を進める中で待機イベントなどの意味や公開情報として載っている一般的な内容を確認する際などに端末を切り替えたりせずにそのまま聞けたりして便利です。
SQL> select ai chat 'ENQ: TM - CONTENTION'の待機が発生する原因について教えてください。;
RESPONSE
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
'ENQ: TM - CONTENTION'の待機が発生する原因は、通常、複数のプロセスやスレッドが同じ共有リソースにアクセスしようとして競合していることが考えられます。この競合により、リソースの利用が一時的にブロックされ、待機が発生します。
この問題は、特にデータベースやファイルシステムなどの共有リソースへのアクセスが集中する環境でよく起こります。複数のプロセスが同時に同じデータを読み書きしようとすると、リソースのロックや排他制御が必要になり、その結果、待機が発生することがあります。
この問題を解決するためには、以下のような対策が考えられます。
1. 並列処理の改善: 並列処理の効率を高めることで、リソースへのアクセスをよりスムーズに制御することができます。並列処理のアルゴリズムやデータ構造を最適化することで、競合を減らし、待機を軽減することが可能です。
2. ロックの管理: 適切なロックの管理により、リソースへのアクセスを制御し、競合を防ぐことができます。ロックの粒度を調整したり、ロックの取得と解放を適切に管理することで、待機を最小限に抑えることができます。
3. データベースのスケーリング: データベースのスケールアップやスケールアウトにより、リソースの容量を増やし、アクセスを分散させることができます。これにより、複数のプロセスが同時にアクセスしても、リソースの利用がより効率的に管理され、待機が減る可能性があります。
4. キャッシングの利用: キャッシングを利用することで、頻繁にアクセスされるデータをメモリに保持し、リソースへのアクセス回数を減らすことができます。これにより、リソースへの負荷が軽減され、待機を軽減することが可能です。
5. 負荷分散: 負荷分散技術を利用することで、リソースへのアクセスを複数のサーバーやインスタンスに分散させることができます。これにより、個々のサーバーへの負荷が軽減され、待機の発生を防ぐことができます。
これらの対策を組み合わせたり、アプリケーションやシステムの特性に合わせて最適な方法を選択することで、'ENQ: TM - CONTENTION'の待機を軽減し、パフォーマンスを向上させることが可能です。
他にも narrate や explainsql などのいろいろなパラメータもあるため、ぜひ遊んでみてください。
おわりに
Select AIを活用することでデータへのアクセス、取得に必要なSQLなどのスキルセットの敷居を下げることが容易になり、より多くの人が直感的にデータへアクセス可能になります。
Autonomous Databaseそのものに業務データを格納して活用することはもちろんですが、なかなか社内ルールなどで実データをまだ活用できる状況にない方でも、今回のような運用情報を蓄積して分析するためのツールの位置づけであったり、表のメタデータのみをAutonomous Databaseへ作成してNL2SQLのツールとして開発効率化に使うケースなど、いろいろな用途での活用がありそうです。
ぜひいろいろ触って試して遊んでみていただけたらと思います。
おまけ
長期間ロックやハング系のトラブルの場合はデータベース内で動くハング・マネージャという機能によりトレースファイルに詳細が出力されていることがよくあります。
dia0という名前の付くトレースファイルの中身を見ることで原因がわかることも多々あるので、アラートログやトレースファイルもあわせて確認することをお勧めします。
今回のケースではnyabase_dia0_13682_lws_1.trcというトレースファイルにいろいろと情報が出力されていました。
nyabase_dia0_13682_lws_1.trc
*** 2025-09-13T21:49:06.731250+09:00 (CDB$ROOT(1))
HM: Early Warning - Session ID 24 serial# 19113 OS PID 43341 (FG)
is waiting on 'enq: TM - contention' for 32 seconds, wait id 271216
p1: 'name|mode'=0x544d0002, p2: 'object #'=0x1289e, p3: 'table/partition'=0x0
Final Blocker is Session ID 337★ serial# 508★ on instance 1
which is waiting on 'SQL*Net message from client'★ for 31 seconds, wait id 19
p1: 'driver id'=0x74637000, p2: '#bytes'=0x1, p3: ''=0x0
IO
Total Self- Total Total Outlr Outlr Outlr
Hung Rslvd Rslvd Wait WaitTm Wait WaitTm Wait
Sess Hangs Hangs Count Secs Count Secs Count Wait Event
------ ------ ------ ------ ------ ------ ------ ------ -----------
0 0 0 1 0 0 0 0 enq: TM - contention
HM: Dumping Short Stack of pid[76.43341] (sid:24, ser#:19113)
Short stack dump:
ksedsts()+426<-ksdxfstk()+63<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-semtimedop()+14<-sskgpwwait()+245<-skgpwwait()+187<-ksliwat()+2311<-kslwaitctx()+200<-ksqcmi()+27949<-ksqgtlctx()+3643<-ktaiam()+719<-ktagetg0()+438<-ktagetp_internal()+130<-ktagdw()+113<-ktaadm()+208<-kksfbc()+2595<-opiexe()+2951<-opipls()+2217<-opiodr()+1264<-rpidrus()+198<-skgmstack()+65<-rpidru()+132<-rpiswu2()+543<-rpidrv()+1281<-psddr0()+467<-psdnal()+624<-pevm_EXECC()+306<-pfrinstr_EXECC()+56<-pfrrun_no_tool()+60<-pfrrun()+904<-plsql_run()+752<-peicnt()+279<-kkxexe()+720<-opiexe()+31516<-kpoal8()+2360<-opiodr()+1264<-ttcpip()+1240<-opitsk()+1908<-opiino()+935<-opiodr()+1264<-opidrv()+1094<-sou2o()+165<-opimai_real()+422<-ssthrdmain()+417<-main()+256<-__libc_start_main()+229<-_start()+46
HM: Current SQL: INSERT INTO ORDERS ( ORDER_ID, ORDER_DATE, ORDER_MODE, CUSTOMER_ID, ORDER_STATUS, WAREHOUSE_ID, DELIVERY_TYPE, DELIVERY_ADDRESS_ID, COST_OF_DELIVERY, WAIT_TILL_ALL_AVAILABLE, CUSTOMER_CLASS, CARD_ID, INVOICE_ADDRESS_ID ) VALUES ( ORDERS_SEQ.NEXTVAL + :B8 , SYSTIMESTAMP , 'online', :B7 , 1, :B6 , 'Standard', :B1 , DBMS_
HM: Dumping Short Stack of Final Blocker pid[82.43947] (sid:337, ser#:508)
Short stack dump:
ksedsts()+426<-ksdxfstk()+63<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-__read()+16<-read()+84<-snttread()+16<-nttrd()+341<-nsprecv()+448<-nsrdr()+258<-nsfull_pkt_rcv()+8261<-nsfull_brc()+78<-nioqrc()+438<-opikndf2()+986<-opitsk()+896<-opiino()+935<-opiodr()+1264<-opidrv()+1094<-sou2o()+165<-opimai_real()+422<-ssthrdmain()+417<-main()+256<-__libc_start_main()+229<-_start()+46
SID=337、Serial#=558がFinal Blockerとして表示されており、ASHで確認した結果とも一致しています。
SID=337のセッションの最終的な待機イベントはクライアントからの応答を待つ'SQL*Net message from client'による待機になっています。
lock tableコマンドを実行してから放置していたのが原因ですね。
ちなみに待たされていたセッションが実行しようとしていたSQLはORDERS表へのInsert文でした。