最も一般的なInnoDBのエラーの1つは、InnoDBロック待機タイムアウトを超えたことです。例:
SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction
上記は単に、デフォルトで50秒の排他ロックを取得するのを待っている間にトランザクションがinnodb_lock_wait_timeoutに到達したことを意味します。一般的な原因は次のとおりです。
- 攻撃的なトランザクションは、innodb_lock_wait_timeout期間内にトランザクションをコミットまたはロールバックするのに十分な速度ではありません。
- 攻撃的なトランザクションは、別のトランザクションによって行ロックが解放されるのを待っています。
InnoDBロック待機タイムアウトの影響
InnoDBロック待機タイムアウトは、2つの主要な影響を引き起こす可能性があります。
- innodb_rollback_on_timeoutが有効になっている場合でも、トランザクションでステートメントが失敗した場合、ROLLBACKはCOMMITよりもコストのかかる操作です。
効果をよりよく理解するために、簡単な例を試してみましょう。データベースmydbの次の2つのテーブルについて考えてみます。
mysql> CREATE SCHEMA mydb;
mysql> USE mydb;
最初のテーブル(table1):
mysql> CREATE TABLE table1 ( id INT PRIMARY KEY AUTO_INCREMENT, data VARCHAR(50));
mysql> INSERT INTO table1 SET data = 'data #1';
2番目のテーブル(table2):
mysql> CREATE TABLE table2 LIKE table1;
mysql> INSERT INTO table2 SET data = 'data #2';
注文 | トランザクション#1(T1) | トランザクション#2(T2) |
1 | SELECT * FROM table1; (OK) | SELECT * FROM table1; (OK) |
2 | UPDATE table1 SET data='T1は行を更新しています'WHEREid =1; (OK) | |
3 | UPDATE table2 SET data='T2は行を更新しています'WHEREid =1; (OK) | |
4 | UPDATE table1 SET data='T2は行を更新しています'WHEREid =1; (しばらくハングし、最終的に「ロック待機タイムアウトを超えました。トランザクションを再開してみてください」というエラーが返されます) | |
5 | COMMIT; (OK) | |
6 | COMMIT; (OK) |
mysql> SELECT * FROM table1 WHERE id = 1;
+----+-----------------------------------+
| id | data |
+----+-----------------------------------+
| 1 | T1 is updating the row |
+----+-----------------------------------+
mysql> SELECT * FROM table2 WHERE id = 1;
+----+-----------------------------------+
| id | data |
+----+-----------------------------------+
| 1 | T2 is updating the row |
+----+-----------------------------------+
T2が正常にコミットされた後、table1とtable2の両方で「T2は行を更新しています」という同じ出力が得られると予想されますが、結果はtable2のみが更新されたことを示しています。トランザクション内でエラーが発生した場合、トランザクション内のすべてのステートメントが自動的にロールバックされるか、トランザクションが正常にコミットされた場合、ステートメント全体がアトミックに実行されたと考える人もいるかもしれません。これはデッドロックには当てはまりますが、InnoDBロック待機タイムアウトには当てはまりません。
innodb_rollback_on_timeout =1(デフォルトは0-無効)を設定しない限り、InnoDBロック待機タイムアウトエラーに対して自動ロールバックは発生しません。つまり、デフォルト設定に従うことで、MySQLが失敗してトランザクション全体をロールバックすることはなく、タイムアウトしたステートメントを再試行して、COMMITまたはROLLBACKに達するまで次のステートメントを処理することもありません。これは、トランザクションT2が部分的にコミットされた理由を説明しています!
InnoDBのドキュメントには、「InnoDBはトランザクションタイムアウトの最後のステートメントのみをロールバックする」と明記されています。 デフォルトでは」。この場合、InnoDBによって提供されるトランザクションの原子性は取得されません。ACID準拠の原子性は、トランザクションのすべてを取得するか、まったく取得しないかのいずれかです。つまり、部分的なトランザクションは単に受け入れられません。
InnoDBロック待機タイムアウトの処理
したがって、デッドロックで発生するのと同様に、InnoDBロック待機エラーが発生したときにトランザクションが自動ロールバックすることを期待している場合は、MySQL構成ファイルで次のオプションを設定します。
innodb_rollback_on_timeout=1
MySQLの再起動が必要です。 MySQLベースのクラスターをデプロイする場合、ClusterControlは常にすべてのノードでinnodb_rollback_on_timeout=1を設定します。このオプションがない場合、アプリケーションは失敗したステートメントを再試行するか、トランザクションの原子性を維持するために明示的にROLLBACKを実行する必要があります。
構成が正しくロードされているかどうかを確認するには:
mysql> SHOW GLOBAL VARIABLES LIKE 'innodb_rollback_on_timeout';
+----------------------------+-------+
| Variable_name | Value |
+----------------------------+-------+
| innodb_rollback_on_timeout | ON |
+----------------------------+-------+
新しい構成が機能するかどうかを確認するために、このエラーが発生したときにcom_rollbackカウンターを追跡できます。
mysql> SHOW GLOBAL STATUS LIKE 'com_rollback';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Com_rollback | 1 |
+---------------+-------+
mysql> SHOW ENGINE INNODB STATUS\G
------------
TRANSACTIONS
------------
...
---TRANSACTION 3100, ACTIVE 2 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s)
MySQL thread id 50, OS thread handle 139887555282688, query id 360 localhost ::1 root updating
update table1 set data = 'T2 is updating the row' where id = 1
------- TRX HAS BEEN WAITING 2 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 6 page no 4 n bits 72 index PRIMARY of table `mydb`.`table1` trx id 3100 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 80000001; asc ;;
1: len 6; hex 000000000c19; asc ;;
2: len 7; hex 020000011b0151; asc Q;;
3: len 22; hex 5431206973207570646174696e672074686520726f77; asc T1 is updating the row;;
------------------
---TRANSACTION 3097, ACTIVE 46 sec
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 48, OS thread handle 139887556167424, query id 358 localhost ::1 root
Trx read view will not see trx with id >= 3097, sees < 3097
上記の情報から、サーバーで現在アクティブになっているトランザクションの概要を取得できます。トランザクション3097は現在、トランザクション3100がアクセスする必要のある行をロックしています。ただし、上記の出力は、クエリ/ステートメント/トランザクションのどの部分をさらに調査する必要があるかを判断するのに役立つ実際のクエリテキストを示していません。 。ブロッカーのMySQLスレッドID48を使用して、MySQLプロセスリストから何を収集できるかを見てみましょう。
mysql> SHOW FULL PROCESSLIST;
+----+-----------------+-----------------+--------------------+---------+------+------------------------+-----------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+-----------------+-----------------+--------------------+---------+------+------------------------+-----------------------+
| 4 | event_scheduler | localhost | <null> | Daemon | 5146 | Waiting on empty queue | <null> |
| 10 | root | localhost:56042 | performance_schema | Query | 0 | starting | show full processlist |
| 48 | root | localhost:56118 | mydb | Sleep | 145 | | <null> |
| 50 | root | localhost:56122 | mydb | Sleep | 113 | | <null> |
+----+-----------------+-----------------+--------------------+---------+------+------------------------+-----------------------+
スレッドID48は、コマンドを「スリープ」として示しています。それでも、これは、他のトランザクションをブロックするステートメントを知るのにあまり役立ちません。これは、このトランザクションのステートメントが実行されており、このオープントランザクションは現在基本的に何もしていないためです。このスレッドで何が起こっているかを確認するには、さらに深く掘り下げる必要があります。
MySQL 8.0の場合、InnoDBロック待機インストルメンテーションは、performance_schemaデータベース内のdata_lock_waitsテーブル(またはsysデータベース内のinnodb_lock_waitsテーブル)で使用できます。ロック待機イベントが発生している場合は、次のように表示されます。
mysql> SELECT * FROM performance_schema.data_lock_waits\G
***************************[ 1. row ]***************************
ENGINE | INNODB
REQUESTING_ENGINE_LOCK_ID | 139887595270456:6:4:2:139887487554680
REQUESTING_ENGINE_TRANSACTION_ID | 3100
REQUESTING_THREAD_ID | 89
REQUESTING_EVENT_ID | 8
REQUESTING_OBJECT_INSTANCE_BEGIN | 139887487554680
BLOCKING_ENGINE_LOCK_ID | 139887595269584:6:4:2:139887487548648
BLOCKING_ENGINE_TRANSACTION_ID | 3097
BLOCKING_THREAD_ID | 87
BLOCKING_EVENT_ID | 9
BLOCKING_OBJECT_INSTANCE_BEGIN | 139887487548648
MySQL 5.6および5.7では、同様の情報がinformation_schemaデータベースの下のinnodb_lock_waitsテーブル内に格納されていることに注意してください。 BLOCKING_THREAD_ID値に注意してください。この情報を使用して、events_statements_historyテーブルでこのスレッドによって実行されているすべてのステートメントを探すことができます。
mysql> SELECT * FROM performance_schema.events_statements_history WHERE `THREAD_ID` = 87;
0 rows in set
スレッド情報がなくなったようです。次のクエリを使用して、events_statements_historyテーブルのthread_id列の最小値と最大値を確認することで確認できます。
mysql> SELECT min(`THREAD_ID`), max(`THREAD_ID`) FROM performance_schema.events_statements_history;
+------------------+------------------+
| min(`THREAD_ID`) | max(`THREAD_ID`) |
+------------------+------------------+
| 98 | 129 |
+------------------+------------------+
探していたスレッド(87)がテーブルから切り捨てられました。これは、event_statements_historyテーブルのサイズを確認することで確認できます:
mysql> SELECT @@performance_schema_events_statements_history_size;
+-----------------------------------------------------+
| @@performance_schema_events_statements_history_size |
+-----------------------------------------------------+
| 10 |
+-----------------------------------------------------+
上記は、events_statements_historyが保存できるのは最後の10スレッドのみであることを意味します。幸い、performance_schemaには、events_statements_history_longという別の行を格納するテーブルがあります。このテーブルには、同様の情報がすべてのスレッドに格納され、さらに多くの行を含めることができます。
mysql> SELECT @@performance_schema_events_statements_history_long_size;
+----------------------------------------------------------+
| @@performance_schema_events_statements_history_long_size |
+----------------------------------------------------------+
| 10000 |
+----------------------------------------------------------+
ただし、events_statements_history_longテーブルを初めてクエリしようとすると、空の結果が得られます。次のsetup_consumersテーブルに示されているように、デフォルトでは、このインストルメンテーションはMySQLで無効になっているため、これは予想されます。
mysql> SELECT * FROM performance_schema.setup_consumers;
+----------------------------------+---------+
| NAME | ENABLED |
+----------------------------------+---------+
| events_stages_current | NO |
| events_stages_history | NO |
| events_stages_history_long | NO |
| events_statements_current | YES |
| events_statements_history | YES |
| events_statements_history_long | NO |
| events_transactions_current | YES |
| events_transactions_history | YES |
| events_transactions_history_long | NO |
| events_waits_current | NO |
| events_waits_history | NO |
| events_waits_history_long | NO |
| global_instrumentation | YES |
| thread_instrumentation | YES |
| statements_digest | YES |
+----------------------------------+---------+
テーブルevents_statements_history_longをアクティブ化するには、setup_consumersテーブルを次のように更新する必要があります。
mysql> UPDATE performance_schema.setup_consumers SET enabled = 'YES' WHERE name = 'events_statements_history_long';
今すぐevents_statements_history_longテーブルに行があるかどうかを確認します:
mysql> SELECT count(`THREAD_ID`) FROM performance_schema.events_statements_history_long;
+--------------------+
| count(`THREAD_ID`) |
+--------------------+
| 4 |
+--------------------+
涼しい。これで、InnoDBロック待機イベントが再び発生するまで待機できます。発生すると、data_lock_waitsテーブルに次の行が表示されます。
mysql> SELECT * FROM performance_schema.data_lock_waits\G
***************************[ 1. row ]***************************
ENGINE | INNODB
REQUESTING_ENGINE_LOCK_ID | 139887595270456:6:4:2:139887487555024
REQUESTING_ENGINE_TRANSACTION_ID | 3083
REQUESTING_THREAD_ID | 60
REQUESTING_EVENT_ID | 9
REQUESTING_OBJECT_INSTANCE_BEGIN | 139887487555024
BLOCKING_ENGINE_LOCK_ID | 139887595269584:6:4:2:139887487548648
BLOCKING_ENGINE_TRANSACTION_ID | 3081
BLOCKING_THREAD_ID | 57
BLOCKING_EVENT_ID | 8
BLOCKING_OBJECT_INSTANCE_BEGIN | 139887487548648
ここでも、BLOCKING_THREAD_ID値を使用して、このスレッドによって実行されたすべてのステートメントをevents_statements_history_longテーブルに対してフィルタリングします。
mysql> SELECT `THREAD_ID`,`EVENT_ID`,`EVENT_NAME`, `CURRENT_SCHEMA`,`SQL_TEXT` FROM events_statements_history_long
WHERE `THREAD_ID` = 57
ORDER BY `EVENT_ID`;
+-----------+----------+-----------------------+----------------+----------------------------------------------------------------+
| THREAD_ID | EVENT_ID | EVENT_NAME | CURRENT_SCHEMA | SQL_TEXT |
+-----------+----------+-----------------------+----------------+----------------------------------------------------------------+
| 57 | 1 | statement/sql/select | <null> | select connection_id() |
| 57 | 2 | statement/sql/select | <null> | SELECT @@VERSION |
| 57 | 3 | statement/sql/select | <null> | SELECT @@VERSION_COMMENT |
| 57 | 4 | statement/com/Init DB | <null> | <null> |
| 57 | 5 | statement/sql/begin | mydb | begin |
| 57 | 7 | statement/sql/select | mydb | select 'T1 is in the house' |
| 57 | 8 | statement/sql/select | mydb | select * from table1 |
| 57 | 9 | statement/sql/select | mydb | select 'some more select' |
| 57 | 10 | statement/sql/update | mydb | update table1 set data = 'T1 is updating the row' where id = 1 |
+-----------+----------+-----------------------+----------------+----------------------------------------------------------------+
最後に、犯人を見つけました。上記のトランザクション(T1)がまだ終了していない(COMMITまたはROLLBACKがない)スレッド57のイベントのシーケンスを見ると、最後のステートメントが更新のために行への排他的ロックを取得していることがわかります。他のトランザクション(T2)で必要な操作で、そこにぶら下がっています。これが、MySQLプロセスリストの出力に「スリープ」が表示される理由を説明しています。
ご覧のとおり、上記のSELECTステートメントでは、事前にthread_id値を取得する必要があります。このクエリを単純化するために、IN句とサブクエリを使用して両方のテーブルを結合できます。次のクエリは、上記と同じ結果を生成します:
mysql> SELECT `THREAD_ID`,`EVENT_ID`,`EVENT_NAME`, `CURRENT_SCHEMA`,`SQL_TEXT` from events_statements_history_long WHERE `THREAD_ID` IN (SELECT `BLOCKING_THREAD_ID` FROM data_lock_waits) ORDER BY `EVENT_ID`;
+-----------+----------+-----------------------+----------------+----------------------------------------------------------------+
| THREAD_ID | EVENT_ID | EVENT_NAME | CURRENT_SCHEMA | SQL_TEXT |
+-----------+----------+-----------------------+----------------+----------------------------------------------------------------+
| 57 | 1 | statement/sql/select | <null> | select connection_id() |
| 57 | 2 | statement/sql/select | <null> | SELECT @@VERSION |
| 57 | 3 | statement/sql/select | <null> | SELECT @@VERSION_COMMENT |
| 57 | 4 | statement/com/Init DB | <null> | <null> |
| 57 | 5 | statement/sql/begin | mydb | begin |
| 57 | 7 | statement/sql/select | mydb | select 'T1 is in the house' |
| 57 | 8 | statement/sql/select | mydb | select * from table1 |
| 57 | 9 | statement/sql/select | mydb | select 'some more select' |
| 57 | 10 | statement/sql/update | mydb | update table1 set data = 'T1 is updating the row' where id = 1 |
+-----------+----------+-----------------------+----------------+----------------------------------------------------------------+
ただし、InnoDBロック待機イベントが発生するたびに上記のクエリを実行することは実用的ではありません。アプリケーションからのエラーとは別に、ロック待機イベントが発生していることをどのようにして知ることができますか? track_lockwait.shと呼ばれる次の単純なBashスクリプトを使用して、このクエリの実行を自動化できます。
$ cat track_lockwait.sh
#!/bin/bash
## track_lockwait.sh
## Print out the blocking statements that causing InnoDB lock wait
INTERVAL=5
DIR=/root/lockwait/
[ -d $dir ] || mkdir -p $dir
while true; do
check_query=$(mysql -A -Bse 'SELECT THREAD_ID,EVENT_ID,EVENT_NAME,CURRENT_SCHEMA,SQL_TEXT FROM events_statements_history_long WHERE THREAD_ID IN (SELECT BLOCKING_THREAD_ID FROM data_lock_waits) ORDER BY EVENT_ID')
# if $check_query is not empty
if [[ ! -z $check_query ]]; then
timestamp=$(date +%s)
echo $check_query > $DIR/innodb_lockwait_report_${timestamp}
fi
sleep $INTERVAL
done
実行可能権限を適用し、バックグラウンドでスクリプトをデーモン化します:
$ chmod 755 track_lockwait.sh
$ nohup ./track_lockwait.sh &
ここで、/ root/lockwaitディレクトリの下にレポートが生成されるのを待つ必要があります。データベースのワークロードと行アクセスパターンによっては、このディレクトリの下に多くのファイルが表示される場合があります。ディレクトリを注意深く監視してください。そうしないと、レポートファイルが多すぎていっぱいになります。
ClusterControlを使用している場合は、[パフォーマンス]-> [トランザクションログ]でトランザクションログ機能を有効にできます。この機能では、ClusterControlがデッドロックと長時間実行トランザクションに関するレポートを提供し、原因を見つけるのに役立ちます。
要約すると、MySQLで「LockWait Timeout Exceeded」エラーが発生した場合、最初にそのようなエラーがインフラストラクチャに与える影響を理解してから、攻撃的なトランザクションを追跡して対処する必要があります。 track_lockwait.shのようなシェルスクリプト、またはClusterControlのようなデータベース管理ソフトウェアのいずれかを使用します。
シェルスクリプトを使用する場合は、費用を節約できる可能性がありますが、その仕組みについて1つか2つ知っておく必要があるため、時間がかかることに注意してください。権限を取得し、場合によってはバックグラウンドで実行するようにします。シェルジャングルで迷子になった場合は、サポートいたします。
実装することに決めたものは何でも、Twitterでフォローするか、RSSフィードを購読して、MySQLの6つの一般的な障害シナリオをカバーするこの投稿など、ソフトウェアとそれをサポートするデータベースの両方のパフォーマンスを改善するためのヒントを入手してください。