synch/cond/sql/MDL_context::COND_wait_status - Amazon Aurora

synch/cond/sql/MDL_context::COND_wait_status

synch/cond/sql/MDL_context::COND_wait_status イベントは、テーブルメタデータロックに待機中のスレッドがあるときに発生します。

サポート対象エンジンバージョン

この待機イベント情報は、以下のエンジンバージョンでサポートされています。

  • Aurora MySQL バージョン 2 から 2.09.2 まで

  • Aurora MySQL バージョン 1 から 1.23.1 まで

Context

イベント synch/cond/sql/MDL_context::COND_wait_status は、テーブルメタデータロックを待機中のスレッドがあることを示します。場合によっては、あるセッションがテーブルのメタデータロックを保持し、別のセッションが同じテーブルで同じロックを取得しようとする場合があります。このような場合、2 番目のセッションは synch/cond/sql/MDL_context::COND_wait_status 待機イベントで待機します。

MySQL は、メタデータロックを使用して、データベースオブジェクトへの同時アクセスを管理し、データの整合性を確保します。メタデータのロックは、get_lock 関数で取得したスケジュールされたイベント、テーブルスペース、ユーザーロックテーブル、および ストアドプログラムに適用されます。ストアドプログラムには、プロシージャ、関数、トリガーが含まれます。詳細については、MySQL ドキュメントのメタデータロックを参照してください。

MySQL プロセスリストは、このセッションを状態 waiting for metadata lock で表示されます。Performance Insights では、Performance_schema がオンになっている場合、イベント synch/cond/sql/MDL_context::COND_wait_status が表示されます。

メタデータロックで待っているクエリのデフォルトタイムアウトは lock_wait_timeout パラメータ値に基づきます。デフォルトは 31,536,000 秒 (365 日) です。

さまざまな InnoDB ロックと競合を引き起こす可能性のあるロックの種類の詳細については、MySQL ドキュメントの InnoDB ロックを参照してください。

待ち時間増加の考えられる原因

synch/cond/sql/MDL_context::COND_wait_status イベントが通常よりも多く表示され、パフォーマンスの問題を示している可能性がある場合、典型的な原因は次のとおりです。

実行時間が長いトランザクション

1 つ以上のトランザクションが大量のデータを変更し、非常に長い間テーブルのロックを保持しています。

Idle トランザクション

1 つ以上のトランザクションは、コミットまたはロールバックされることなく、長い間開いたままです。

大きなテーブルの DDL ステートメント

1 つ以上のデータ定義ステートメント (DDL) ステートメント。ALTER TABLEコマンドは、非常に大きなテーブルで実行されました。

明示的なテーブルロック

テーブルには、タイムリーに解放されない明示的なロックがあります。例えば、アプリケーションが実行されているとします。LOCK TABLE不適切にステートメント。

アクション

待機イベントの原因と Aurora MySQL DB クラスターのバージョンに応じて、さまざまなアクションをお勧めします。

イベントの原因となるセッションとクエリを特定する

Performance Insights を使用して、synch/cond/sql/MDL_context::COND_wait_status 待機イベントによってブロックされたクエリを表示できます。ただし、ブロッキングセッションを特定するには、からメタデータテーブルをクエリします。performance_schemaそしてinformation_schemaDB クラスター上にあります。

通常、ロードが中程度から重大なデータベースには、待機イベントがあります。パフォーマンスが最適であれば、待機イベントは受け入れられる可能性があります。パフォーマンスが最適でない場合は、データベースが最も長い時間を費やしている場所を調べます。最も高いロードに寄与する待機イベントを調べて、データベースとアプリケーションを最適化してこれらのイベントを削減できるかどうかを調べます。

高ロードの原因となる SQL クエリを検索するには

  1. AWS Management Console にサインインし、Amazon RDS コンソール (https://console.aws.amazon.com/rds/) を開きます。

  2. ナビゲーションペインで、[Performance Insights] を選択します。

  3. DB インスタンスを選択します。この DB インスタンスに Performance Insights ダッシュボードが表示されます。

  4. データベースロードで、待機でスライスを選択します。

  5. ページの下部で トップ SQL を選択します。

    グラフには、ロードの原因となる SQL クエリがリストされます。リスト上部にあるクエリに、最も責任があります。ボトルネックを解決するには、これらのステートメントに注目してください。

Performance Insights を使用したトラブルシューティングの便利な概要については、AWS データベースブログ記事の Performance Insights を使用した Amazon Aurora MySQL ワークロードの分析を参照してください。

過去のイベントをチェックする

この待機イベントについてのインサイトを取得して、過去のイベントが発生していないかどうかをチェックできます。そのためには、以下のアクションを実行します。

  • データ操作言語 (DML) と DDL のスループットとレイテンシーを調べて、ワークロードに変更があったかどうかをチェックします。

    Performance Insights を使用して、問題発生時にこのイベントで待っているクエリを検索できます。また、発行時に実行されたクエリのダイジェストを表示することもできます。

  • DB クラスターの監査ログまたは一般ログがオンになっている場合、待機中のトランザクションに含まれるオブジェクト (schema.table) で実行されるすべてのクエリをチェックできます。また、トランザクションの前に実行が完了したクエリをチェックすることもできます。

過去のイベントのトラブルシューティングに使用できる情報は限られています。これらのチェックを実行しても、どのオブジェクトが情報を待っているのかは示されません。ただし、イベント時にロードが大きいテーブルや、発行時に競合の原因となる頻繁に操作される一連の行を特定できます。この情報を使用して、テスト環境で問題を再現し、その原因に関するインサイトを使用できます。

Aurora MySQL バージョン 1 でクエリを実行する

Aurora MySQL バージョン 1 では、information_schemaperformance_schema のテーブルにクエリを実行してブロッキングセッションを識別します。クエリを実行するには、DB クラスターがperformance_schema コンシューマー events_statements_history で設定されていることを確認して下さい。また、performance_schemaevents_statements_history テーブルで適切な数のクエリを維持します。そのテーブルで保持されるクエリの数は、performance_schema_events_statements_history_size パラメータで管理できます。performance_schema で必要なデータが利用できない場合は、監査ログまたは一般ログをチェックできます。

例は、ブロックしているクエリとセッションを識別するため、テーブルにクエリを実行する方法を示しています。この例では、すべてのセッションで実行されるステートメントが 10 個未満で、必要なコンシューマーが DB クラスターで有効になっています。

次のプロセスリストの出力では、プロセス ID 59 (TRUNCATE コマンドを実行) とプロセス ID 53 (INSERT コマンドを実行) が 33 秒間メタデータロックを待っています。また両方のスレッドが、sbtest.sbtest1 という名前の同じテーブルに対してクエリを実行しています。

MySQL [(none)]> select @@version, @@aurora_version; +-----------+------------------+ | @@version | @@aurora_version | +-----------+------------------+ | 5.6.10 | 1.23.0 | +-----------+------------------+ 1 row in set (0.00 sec) MySQL [performance_schema]> select * from setup_consumers where name='events_statements_history'; +---------------------------+---------+ | NAME | ENABLED | +---------------------------+---------+ | events_statements_history | YES | +---------------------------+---------+ 1 row in set (0.00 sec) MySQL [performance_schema]> show global variables like 'performance_schema_events_statements_history_size'; +---------------------------------------------------+-------+ | Variable_name | Value | +---------------------------------------------------+-------+ | performance_schema_events_statements_history_size | 10 | +---------------------------------------------------+-------+ 1 row in set (0.00 sec) MySQL [performance_schema]> show processlist; +----+------------------+--------------------+--------------------+---------+------+---------------------------------+------------------------------------------------------------------------------------------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------------------+--------------------+--------------------+---------+------+---------------------------------+------------------------------------------------------------------------------------------------------+ | 11 | rdsadmin | localhost | NULL | Sleep | 0 | cleaned up | NULL | | 14 | rdsadmin | localhost | NULL | Sleep | 1 | cleaned up | NULL | | 15 | rdsadmin | localhost | NULL | Sleep | 14 | cleaned up | NULL | | 16 | rdsadmin | localhost | NULL | Sleep | 1 | cleaned up | NULL | | 17 | rdsadmin | localhost | NULL | Sleep | 214 | cleaned up | NULL | | 40 | auroramysql56123 | 172.31.21.51:44876 | sbtest123 | Query | 1843 | User sleep | select sleep(10000) | | 41 | auroramysql56123 | 172.31.21.51:44878 | performance_schema | Query | 0 | init | show processlist | | 48 | auroramysql56123 | 172.31.21.51:44894 | sbtest123 | Execute | 0 | delayed commit ok initiated | COMMIT | | 49 | auroramysql56123 | 172.31.21.51:44899 | sbtest123 | Execute | 0 | delayed commit ok initiated | COMMIT | | 50 | auroramysql56123 | 172.31.21.51:44896 | sbtest123 | Execute | 0 | delayed commit ok initiated | COMMIT | | 51 | auroramysql56123 | 172.31.21.51:44892 | sbtest123 | Execute | 0 | delayed commit ok initiated | COMMIT | | 52 | auroramysql56123 | 172.31.21.51:44898 | sbtest123 | Execute | 0 | delayed commit ok initiated | COMMIT | | 53 | auroramysql56123 | 172.31.21.51:44902 | sbtest | Query | 33 | Waiting for table metadata lock | INSERT INTO sbtest1 (id, k, c, pad) VALUES (0, 5021, '91560616281-61537173720-56678788409-8805377477 | | 56 | auroramysql56123 | 172.31.21.51:44908 | NULL | Query | 118 | User sleep | select sleep(10000) | | 58 | auroramysql56123 | 172.31.21.51:44912 | NULL | Sleep | 41 | cleaned up | NULL | | 59 | auroramysql56123 | 172.31.21.51:44914 | NULL | Query | 33 | Waiting for table metadata lock | truncate table sbtest.sbtest1 | +----+------------------+--------------------+--------------------+---------+------+---------------------------------+------------------------------------------------------------------------------------------------------+ 16 rows in set (0.00 sec)

この出力に基づいて、次のクエリを実行します。このクエリは、33 秒以上 テーブルのロックを待っている接続 ID 59 で、同じ期間実行されているトランザクションを識別します。

MySQL [performance_schema]> select b.id, a.trx_id, a.trx_state, a.trx_started, TIMESTAMPDIFF(SECOND,a.trx_started, now()) as "Seconds Transaction Has Been Open", a.trx_rows_modified, b.USER, b.host, b.db, b.command, b.time, b.state from information_schema.innodb_trx a, information_schema.processlist b where a.trx_mysql_thread_id=b.id and TIMESTAMPDIFF(SECOND,a.trx_started, now()) > 33 order by trx_started; +----+---------+-----------+---------------------+-----------------------------------+-------------------+------------------+--------------------+-----------+---------+------+------------+ | id | trx_id | trx_state | trx_started | Seconds Transaction Has Been Open | trx_rows_modified | USER | host | db | command | time | state | +----+---------+-----------+---------------------+-----------------------------------+-------------------+------------------+--------------------+-----------+---------+------+------------+ | 40 | 1907737 | RUNNING | 2021-02-02 12:58:16 | 1955 | 0 | auroramysql56123 | 172.31.21.51:44876 | sbtest123 | Query | 1955 | User sleep | | 56 | 3797992 | RUNNING | 2021-02-02 13:27:01 | 230 | 0 | auroramysql56123 | 172.31.21.51:44908 | NULL | Query | 230 | User sleep | | 58 | 3895074 | RUNNING | 2021-02-02 13:28:18 | 153 | 0 | auroramysql56123 | 172.31.21.51:44912 | NULL | Sleep | 153 | cleaned up | +----+---------+-----------+---------------------+-----------------------------------+-------------------+------------------+--------------------+-----------+---------+------+------------+ 3 rows in set (0.00 sec)

出力では、プロセス 40、56、および 58 が長い間アクティブになっています。では、sbtest.sbtest1 テーブル上でこれらのセッションによって実行されるクエリを特定しましょう。

MySQL [performance_schema]> select t.processlist_id, t.thread_id, sql_text from performance_schema.threads t join events_statements_history sh on t.thread_id=sh.thread_id where processlist_id in (40,56,58) and SQL_TEXT like '%sbtest1%' order by 1; +----------------+-----------+------------------------------------------+ | processlist_id | thread_id | sql_text | +----------------+-----------+------------------------------------------+ | 56 | 84 | select * from sbtest123.sbtest10 limit 1 | | 58 | 86 | select * from sbtest.sbtest1 limit 1 | +----------------+-----------+------------------------------------------+ 2 rows in set (0.01 sec)

この出力では、58processlist_id を使用したセッションはテーブルに対してクエリを実行し、オープントランザクションを保持しています。そのオープントランザクションが TRUNCATE コマンドをブロックしています。

Aurora MySQL バージョン 2 でクエリを実行する

Aurora MySQL バージョン 2 の場合、performance_schema テーブルないし sys ビューに対してクエリを実行して、ブロックされたセッションを直接識別できます。。例は、ブロックしているクエリとセッションを識別するため、テーブルにクエリを実行する方法を示しています。

次のプロセスリストの出力では、接続 ID 89 がメタデータロックを待っていて、TRUNCATE TABLE コマンドを実行しています。performance_schema テーブルないし sys スキーマビューのクエリの場合、出力が表示するブロッキングセッションは 76 です。

MySQL [(none)]> select @@version, @@aurora_version; +-----------+------------------+ | @@version | @@aurora_version | +-----------+------------------+ | 5.7.12 | 2.09.0 | +-----------+------------------+ 1 row in set (0.01 sec) MySQL [(none)]> show processlist; +----+-----------------+--------------------+-----------+---------+------+---------------------------------+-------------------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+-----------------+--------------------+-----------+---------+------+---------------------------------+-------------------------------+ | 2 | rdsadmin | localhost | NULL | Sleep | 0 | NULL | NULL | | 4 | rdsadmin | localhost | NULL | Sleep | 2 | NULL | NULL | | 5 | rdsadmin | localhost | NULL | Sleep | 1 | NULL | NULL | | 20 | rdsadmin | localhost | NULL | Sleep | 0 | NULL | NULL | | 21 | rdsadmin | localhost | NULL | Sleep | 261 | NULL | NULL | | 66 | auroramysql5712 | 172.31.21.51:52154 | sbtest123 | Sleep | 0 | NULL | NULL | | 67 | auroramysql5712 | 172.31.21.51:52158 | sbtest123 | Sleep | 0 | NULL | NULL | | 68 | auroramysql5712 | 172.31.21.51:52150 | sbtest123 | Sleep | 0 | NULL | NULL | | 69 | auroramysql5712 | 172.31.21.51:52162 | sbtest123 | Sleep | 0 | NULL | NULL | | 70 | auroramysql5712 | 172.31.21.51:52160 | sbtest123 | Sleep | 0 | NULL | NULL | | 71 | auroramysql5712 | 172.31.21.51:52152 | sbtest123 | Sleep | 0 | NULL | NULL | | 72 | auroramysql5712 | 172.31.21.51:52156 | sbtest123 | Sleep | 0 | NULL | NULL | | 73 | auroramysql5712 | 172.31.21.51:52164 | sbtest123 | Sleep | 0 | NULL | NULL | | 74 | auroramysql5712 | 172.31.21.51:52166 | sbtest123 | Sleep | 0 | NULL | NULL | | 75 | auroramysql5712 | 172.31.21.51:52168 | sbtest123 | Sleep | 0 | NULL | NULL | | 76 | auroramysql5712 | 172.31.21.51:52170 | NULL | Query | 0 | starting | show processlist | | 88 | auroramysql5712 | 172.31.21.51:52194 | NULL | Query | 22 | User sleep | select sleep(10000) | | 89 | auroramysql5712 | 172.31.21.51:52196 | NULL | Query | 5 | Waiting for table metadata lock | truncate table sbtest.sbtest1 | +----+-----------------+--------------------+-----------+---------+------+---------------------------------+-------------------------------+ 18 rows in set (0.00 sec)

次に、performance_schema テーブルないし sys スキーマビューのクエリはブロッキングセッションが 76 であることを示します。

MySQL [(none)]> select * from sys.schema_table_lock_waits; +---------------+-------------+-------------------+-------------+------------------------------+-------------------+-----------------------+-------------------------------+--------------------+-----------------------------+-----------------------------+--------------------+--------------+------------------------------+--------------------+------------------------+-------------------------+------------------------------+ | object_schema | object_name | waiting_thread_id | waiting_pid | waiting_account | waiting_lock_type | waiting_lock_duration | waiting_query | waiting_query_secs | waiting_query_rows_affected | waiting_query_rows_examined | blocking_thread_id | blocking_pid | blocking_account | blocking_lock_type | blocking_lock_duration | sql_kill_blocking_query | sql_kill_blocking_connection | +---------------+-------------+-------------------+-------------+------------------------------+-------------------+-----------------------+-------------------------------+--------------------+-----------------------------+-----------------------------+--------------------+--------------+------------------------------+--------------------+------------------------+-------------------------+------------------------------+ | sbtest | sbtest1 | 121 | 89 | auroramysql5712@192.0.2.0 | EXCLUSIVE | TRANSACTION | truncate table sbtest.sbtest1 | 10 | 0 | 0 | 108 | 76 | auroramysql5712@192.0.2.0 | SHARED_READ | TRANSACTION | KILL QUERY 76 | KILL 76 | +---------------+-------------+-------------------+-------------+------------------------------+-------------------+-----------------------+-------------------------------+--------------------+-----------------------------+-----------------------------+--------------------+--------------+------------------------------+--------------------+------------------------+-------------------------+------------------------------+ 1 row in set (0.00 sec)

ブロッキングセッションに応答する

セッションを特定する際、次のようなオプションが含まれます。

  • アプリケーションの所有者またはユーザーにお問い合わせください。

  • ブロッキングセッションがアイドル状態の場合は、ブロッキングセッションを終了することを検討してください。このアクションは、長いロールバックをトリガーする可能性があります。セッションを終了する方法については、Amazon RDS ユーザーガイドセッションやクエリの終了を参照してください。

ブロックトランザクションの識別の詳細については、MySQL ドキュメントのInnoDB トランザクションの使用と情報のロックを参照してください。