2018年7月28日土曜日

MySQLでワイルドカード証明書が扱えないという話をしたらすぐ扱えるようになった件

07/23日の日本MySQLユーザ会で、MySQLのSSLや透過的暗号化について発表してきました。



発表の中で、 SSLのワイルドカード証明書がうまく扱えず、大量にサーバを管理するときは大変。。。という話をしました。 ところが、発表してから4日後にリリースされた、MySQL 8.0.12でワイルドカード証明書が扱えるようになってました!!

8.0.11 クライアントだとサーバ証明書がワイルドカード証明書だと、--ssl-mode=VERIFY_IDENTITYで通らない
$ mysql --version
mysql  Ver 8.0.11 for Linux on x86_64 (MySQL Community Server - GPL)

$ mysql -h db01.example.jp --ssl-ca=ca.pem --ssl-mode=VERIFY_IDENTITY -unativeuser -p
ERROR 2026 (HY000): SSL connection error: SSL certificate validation failure

8.0.12だと、無事通る。
$ mysql --version
mysql  Ver 8.0.12 for Linux on x86_64 (MySQL Community Server - GPL)

$ mysql -h db01.example.jp --ssl-ca=ca.pem --ssl-mode=VERIFY_IDENTITY -unativeuser -p
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1103
Server version: 8.0.11 MySQL Community Server - GPL

Copyright (c) 2000, 2018, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> exit
Bye


booking.com の方がコントリビュートされたようです。
https://github.com/mysql/mysql-server/pull/196

リリースノートにはワイルドカード証明書が扱えるようになったとは書かれておらず、SANが扱えるようになったと記載されています。
Previously, for the --ssl-mode=VERIFY_IDENTITY option, the client checked whether the host name that it used for connecting matched the Common Name value in the certificate but not the Subject Alternative Name value. Now, if the client uses OpenSSL 1.0.2 or higher, the client checks whether the host name matches either the Subject Alternative Name value or the Common Name value in the server certificate. Thanks to Daniël van Eeden for a patch on which this change was based. (Bug #16211011, Bug #68052, Bug #27511233, Bug #89578)

SSL証明書には複数のドメインを扱うための、Subject Alternative Nameという領域があります。 今回の修正で、名前のチェックをMySQL独自の実装からopensslのライブラリを使うように置き換えられました。
これによって、SANだけでなく、ワイルドカード証明書も期待したとおりの動きになりました。

めでたしめでたし。

2018年5月14日月曜日

MySQL 8.0 でクエリーキャッシュはなくなりました

先日、MySQL 8.0 がGAリリースされました。888888!
こないだ、MySQL 5.7がGAになった気がしたんですが、調べてみたら、5.7 GAは2015/10でした。
いつのまにか約2年半もたっていたようです。。。


頂いたMySQL 8.0 Tシャツ。これは背中側。 

さて、MySQL 8.0 でクエリーキャッシュは廃止されます!私は大歓迎です

なぜ、廃止になるのか?



クエリーキャッシュが効果がある場面は限定的です。
テーブルのデータが変更されると、クエリの結果に変化があろうとなかろうと、そのテーブルに関するキャッシュは無効になります。
更新頻度が高いデータであれば、キャッシュヒット率は低くなり、効果を発揮しません。更新頻度が低いデータであれば、キャッシュヒット率は高くなりますが、更新頻度が低いのであれば、データベースに保存せず、静的なファイル等で保存したほうがより良いレスポンスタイムを期待できると思います。
私の経験ではクエリーキャッシュを正しく理解して利用している人はごく一部でした。

また、レスポンスタイムや負荷のバラ付きも問題です。
キャッシュヒットの有無によりレスポンスタイムのバラ付きが大きくなります。
普段は負荷の低いDBサーバが、テーブルに更新が入るタイミングで、急に負荷がスパイクし、
クエリーキャッシュヒットを狙っていなかったクエリも含めてレスポンスが全体的に悪化する・・・という場面を経験したことがあります。
負荷が安定しなかったり、予測がつかないというのは非常に運用しにくいものです。

そして、スケーラビリティの問題もあります。
MySQLのクエリーキャッシュは内部でmutexが競合するため、性能向上を妨げてしまいます。

詳しい経緯は、yakst さんに翻訳記事が上がっています。


ということで、クエリキャッシュはなくなります!

2018年3月22日木曜日

MEMORYエンジンが勝手にGTIDを進めてた

スレーブの gtid_executed がいつのまにかマスターとずれていることがあって、「スレーブに書き込んだうっかりさんは誰・・・?」と思ったらMEMORYエンジンが犯人だった。

MEMORYエンジンはディスクにはデータを保存せず、メモリ上のみデータを保存する。DBを再起動するとデータは消える。

レプリケーションを組んでいて、マスターだけ再起動したとする。 そうすると、マスターではデータが消えて、スレーブではデータが残ったままになる。
これでは、都合が悪い・・・ということで、MEMORYエンジンを利用している場合、再起動するとDELETE文をバイナリログに追記して整合性を取るようになっている。

マスターサーバーがシャットダウンして再起動すると、その MEMORY テーブルは空になります。マスターはこの影響をスレーブに複製するために、起動後に所定の MEMORY テーブルを最初に使用するときに、空にすべきテーブルの
DELETE ステートメントをバイナリログに書き込むことで、そのテーブルを空にする必要があることをスレーブに通知するイベントのログを記録します。
https://dev.mysql.com/doc/refman/5.6/ja/replication-features-memory.html


マニュアルでは「マスターサーバ」としているが、バイナリログがONになっていると、スレーブでもこの挙動になる。
スレーブを再起動すると、スレーブのバイナリログにDELETE文が書かれ、スレーブのUUIDのGTIDが進む。マスターとgtid_executedが一致しなくなる。

元の状態
マスター(UUID:aaaaaaaa-1111-2222-3333-bbbbbbbbbbbb) のgtid_executed:
aaaaaaaa-1111-2222-3333-bbbbbbbbbbbb:1-10
スレーブ(UUID:zzzzzzzz-1111-2222-3333-xxxxxxxxxxxx) のgtid_executed:
aaaaaaaa-1111-2222-3333-bbbbbbbbbbbb:1-10
スレーブ再起動。スレーブのUUID(zzzzzzzz-1111-2222-3333-xxxxxxxxxxxx)のGTIDが進む。
マスター(UUID:aaaaaaaa-1111-2222-3333-bbbbbbbbbbbb) のgtid_executed:
aaaaaaaa-1111-2222-3333-bbbbbbbbbbbb:1-10
スレーブ(UUID:zzzzzzzz-1111-2222-3333-xxxxxxxxxxxx) のgtid_executed:
aaaaaaaa-1111-2222-3333-bbbbbbbbbbbb:1-10, zzzzzzzz-1111-2222-3333-xxxxxxxxxxxx:1
もっかいスレーブ再起動
マスター(UUID:aaaaaaaa-1111-2222-3333-bbbbbbbbbbbb) のgtid_executed:
aaaaaaaa-1111-2222-3333-bbbbbbbbbbbb:1-10
スレーブ(UUID:zzzzzzzz-1111-2222-3333-xxxxxxxxxxxx) のgtid_executed:
aaaaaaaa-1111-2222-3333-bbbbbbbbbbbb:1-10, zzzzzzzz-1111-2222-3333-xxxxxxxxxxxx:1-2

この状態で、ある日、マスターとスレーブを入れ替えるとする。
新スレーブ(旧マスター)は自分に未適用のGTIDのトランザクションを新マスター(旧スレーブ)からレプリケーションしようとする。
上記でいうと、zzzzzzzz-1111-2222-3333-xxxxxxxxxxxx:1-2。
バイナリログが残っていれば、MEMORYエンジンのテーブルがDELETEされる(これはまぁ、いいかもしれない。MEMORYエンジンのデータはいつ消えてもいい前提だし)
もし、バイナリログが残ってないと、「そんなGTIDのイベントのログはもう持ってません~ ┐(´д`)┌ 」とレプリケーションが止まってしまう。。。

新マスターでダミーのコミットを実行し、gtid_executed を無理やり揃えて回避。

SET SQL_LOG_BIN=0;

SET GTID_NEXT='zzzzzzzz-1111-2222-3333-xxxxxxxxxxxx:1';
BEGIN; COMMIT;

SET GTID_NEXT='zzzzzzzz-1111-2222-3333-xxxxxxxxxxxx:2';
BEGIN; COMMIT;

SET GTID_NEXT='AUTOMATIC'

2018年3月17日土曜日

Index column size too large エラーでレプリケーションが停止

マスターが MySQL 5.5 で スレーブが 5.6 の構成で、Index column size too large エラー でCREATE TABLEがコケてレプリケーションが止まった。

はて?5.5で通ったDDLがなぜ5.6でエラー?

mysql> SET GLOBAL innodb_large_prefix=OFF;
Query OK, 0 rows affected (0.00 sec)

-- warning が出てインデックス長は自動的に切り詰められる
mysql> CREATE TABLE t (pk serial, col1 varchar(2000), index(col1));
Query OK, 0 rows affected, 1 warning (0.19 sec)
mysql> SET GLOBAL innodb_large_prefix=ON;
Query OK, 0 rows affected (0.00 sec)
 
mysql> CREATE TABLE t2 (pk serial, col1 varchar(2000), index(col1));
ERROR 1709 (HY000): Index column size too large. The maximum column size is 767 bytes.

innodb_large_prefix による挙動の違いでした。
innodb_large_prefix が OFF のときは、warning でクエリは通る(インデックス長は自動で短くされてしまう)が、ONだとエラーになるようだ。
innodb_large_prefix がマスター(5.5)ではOFFで、スレーブ(5.6)ではON になっていた。

「せっかくinndb_large_prefix をONにしてるんだから、ROW_FORMAT=Dynamicを指定すれば、長いインデックス作れますよ!」というMySQLさんのアピールか。

スレーブのinnodb_large_prefixをOFFにしてレプリケーション再開することで復旧。

実はさらに孫スレーブが5.7なのだが、5.7ではinnodb_default_row_format が Dynamic になっててエラーにならなかった&長いインデックスが作成されてた。MySQLの歴史を感じた。

2018年2月17日土曜日

Percona XtraDB Cluster 5.7 のバグたち(修正済)

私はRDBで一番大事なのは、durability (永続性、整合性) だと思っている。

データの整合性は、気づくことが難しい。整合性を疑って、正しいデータと比較して初めて気づける。
気づいたときには影響が広くなっており、すでに取り戻せないデータが発生している・・・ということも有り得る。

Availability (可用性) や Performance (性能) は、問題が出たとしても、いろいろな手段でカバー可能であることは多い。


ということで、踏み抜いておいた(踏み抜いてしまった)PXCのdurabilityに関わるバグたちを紹介。

1. LOAD DATA INFILE 利用時にノード間不整合


Wrong count if LOAD DATA used with GTIDs
https://jira.percona.com/browse/PXC-879

GTID を有効にしている状態で、かつ、LDI中にバイナリログのローテが入ると発動。
PXCにはパフォーマンスをあげるため、LDI時にデータを1万件ごとに小分けにしてコミットする機能が入っている。この機能にバグが潜んでいたようだ。
このバグを踏むと、例えば、31000件ロードしたら、LDIを実行したノードには31000件、正しく書き込まれる、
しかし、その他のノードでは1000件が失われ30000件だけ書き込まれる。

このバグは 5.7.20-29.24 で修正されている。

2. INSERT INTO ~ ON DUPLICATE KEY UPDATE でノード間不整合


Node consistency compromized for simple INSERT INTO ... ON DUPLICATE KEY UPDATE workload
https://jira.percona.com/browse/PXC-2039

複数ノードに同時並列でINSERT INTO ~ ON DUPLICATE KEY UPDATEを行うとノード間データ不整合が発生。

このバグはパッチは出ているものの、まだパッケージとしてはリリースされていない。
次のリリースに取り込まれるであろう。

3. Crash recovery 時にリカバリされないデータが発生


Transaction lost after recovery
https://jira.percona.com/browse/PXC-895

前提として、いわゆる durable (以下)なパラメータでPXCを運用している人のみが気にすべきバグである。
innodb_flush_log_at_trx_commit = 1
innodb_double_write = 1
PXCは複数ノードでデータを複製している。ノードが死んだ場合は、生きてるノードから最新のデータを
コピーする(SST)ため、crash recovery が必要なことは基本的にない。
Crash recovery が必要になるのは、全ノードがダウンした際だけである。

durable なパラメータで運用していない場合、全ノード ダウン時、少々データがロストするのはそもそも「仕様」である。

自分は durable で運用している。
複数のサーバが同時に死ぬことは、ほとんどありえないが、「ドミノ倒し」になることは有り得るからだ。
負荷やバグでノードが次々と死んでいくケースである。

実際、上記の1,2 のバグを踏んだ結果、残り1ノードになってしまうケースがある。
PXCではデータ不整合を検知すると、そのノードは自発的にシャットダウンする。
これ自体はデータ不整合が新たな不整合を生まないための仕組みで、望ましい挙動である。
しかし、結果として、1ノードになってしまうのだ。

このような状態でさらに想定外の事態が起きても、データロストしないよう durableな設定 で保険をかけているのだが、その保険が有効に機能してなかったという・・・
このバグも 5.7.20-29.24 で修正されている。

いずれも報告からすぐ修正がなされており、PXCのサポート体制は評価できる。
PXC5.7を利用している人は、最新バージョンに今すぐバージョンアップしよう。
(2のバグFIXはまだリリースされてないけど・・・)

2017年12月9日土曜日

ファイル倉庫系DBをSQLiteでなんとかできるか

MySQLのDBAをしていると、MySQLを「SQLでアクセス可能なファイル倉庫」として使う人たちに出会うことがある。

彼らの要件はだいたいこんな感じ・・・

  • SQLを喋れる「何か」である必要があるが、MySQLである必要はない
  • DBサーバに入れておけば、可用性やバックアップ面が担保されているので楽チンだからDBに入れる
  • DBサーバを自分たちで運用したくない
  • 処理はアドホックに行われ、雑なSQLが流れる、多くは解析系
  • ログやバイナリを雑に保存する。容量が増えていく

ファイル倉庫系は「そこそこ」動いてれば良いので問題が出ても根本対策がされず、だましだまし運用を続ける、「癌化」しやすい注意案件である。

Excel 以上、MySQL 未満 がマッチしているような案件…SQLite が使えるかも?と思ったので検証してみる。

SQLite は今や Mac OSやiOSに同梱されており、実績は十分である。Percona LIVEのkeynote のスライドを見るとSQLiteはぜんぜん「Lite」ではない高機能なプロダクトであることがわかる。

SQLiteのデータベースは単一ファイル。レプリカを作りたければ、他のサーバにデータファイルをコピーするだけで良い。
冗長化やバックアップも(そこそこのレベルで良いのであれば)非常にお手軽である。

検証環境

SQLite はローカルで更新・参照して計測した、MySQL はDBサーバとクライアントは分離する。
設定は全部デフォ。メモリはデータ量以上に積んでるので基本すべてメモリにキャッシュされている状態で試した。 サーバはVMと、、、割りと雑な検証です。。。
$ rpm -qa |egrep 'sqlite|mysql-community-server'
sqlite-3.7.17-8.el7.x86_64
mysql-community-server-5.7.20-1.el7.x86_64

容量比較

sysbench を利用して500万行のテーブルを作る。

$ sudo ls -alh /var/lib/mysql/sbtest
total 1.2G
drwxr-x--- 2 mysql mysql   55 Dec  9 15:26 .
drwxr-x--x 7 mysql mysql 4.0K Dec  9 15:22 ..
-rw-r----- 1 mysql mysql   65 Dec  9 15:22 db.opt
-rw-r----- 1 mysql mysql 8.5K Dec  9 15:26 sbtest1.frm
-rw-r----- 1 mysql mysql 1.2G Dec  9 15:26 sbtest1.ibd
こいつを、SELECT OUT INTO でCSVとして出力→sqliteでロードした。
$ ls -alh tmp.db
-rw-r--r--  1 user user 1.1G Dec  9 15:54 tmp.db
どっちも1Gちょい。容量はあまり変わらない。ただし、MySQL (InnoDB) は圧縮が利用できるので、MySQLで圧縮するほうが物理容量面では有利である。
※ データにも依存するが、InnoDBで圧縮すればだいたい半分ぐらいになることが多い。

インポートの時間

ほとんど差がなかった・・・! ネットワーク経由でデータを送るMySQLのほうが多少遅くなると思ったが、そうでもないようだ。

mysql> LOAD DATA LOCAL INFILE 'tmp2.csv' INTO TABLE sbtest1 FIELDS TERMINATED BY ',' ENCLOSED BY '"';
Query OK, 5000000 rows affected (2 min 28.06 sec)
Records: 5000000  Deleted: 0  Skipped: 0  Warnings: 0
$ time sqlite3 tmp.db  < imp.sql

real    2m28.788s
user    0m53.754s
sys     0m19.732s

エクスポートの時間

SQLiteのほうが3割ぐらい速い。

mysql> SELECT * FROM sbtest1 INTO OUTFILE '/var/lib/mysql-files/out.csv' FIELDS TERMINATED BY ','   OPTIONALLY ENCLOSED BY '"';
Query OK, 5000000 rows affected (14.96 sec)
sqlite> .mode csv
sqlite> .output result.csv
sqlite> .timer on
sqlite> SELECT * FROM sbtest1;
CPU Time: user 7.159407 sys 1.355699
ちなみにMySQLでローカルでやった場合もあまり時間は変わらなかった。
mysql>  SELECT * FROM sbtest1 INTO OUTFILE '/var/lib/mysql-files/aout.csv'   FIELDS TERMINATED BY ','   OPTIONALLY ENCLOSED BY '"';
Query OK, 5000000 rows affected (16.35 sec)

まとめ

ファイル倉庫系のワークロードでSQLiteが劣っているようなことはなさそう。
Excel以上、MySQL未満を必要とするユーザに提案してみたい。

2017年12月7日木曜日

MySQLのデッドロックについて

この記事は MySQL Casual Advent Calendar 2017 の7日目です。 最近、デッドロックを真剣に対応する機会があったのでその時のメモです。

デッドロックとは?

デッドロックとは「複数のトランザクションが互いがロックの開放を待ち、結果として、どの処理も先に進めなくなってしまった状態」を指す。 単にロック待ちが長時間になっているケースはデッドロックとは呼ばない。

時間 TRANSACTION(1) TRANSACTION(2)
1 BEGIN
2 BEGIN
3 UPDATE t1 SET col1 = 'session1' WHERE pk = 1;
4 UPDATE t2 SET col1 = 'session2' WHERE pk = 1;
5 UPDATE t2 SET col1 = 'session1' WHERE pk = 1;
※ TRANSACTION 2 がt2のロックを持ってるので進めない
6 UPDATE t1 SET col1 = 'session2' WHERE pk = 1;
※ TRANSACTION 1 がt1のロックを持ってるので進めない

MySQL (InnoDB) はデッドロック状態になった場合、片方のトランザクションを強制ロールバックし、もう片方のトランザクションに必要な ロックを獲得させ、処理を進める。その際、強制ロールバックされたクエリは以下のエラーが発生する。

mysql> UPDATE t1 SET col1 = 'session2' WHERE pk = 1;
ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

デッドロックの対処方法


1. リトライ

根本的な対応ではないが、良くとられる解決策。 タイミング悪く更新が重なったときに起こる程度であれば、リトライで十分。

2. クエリを修正し、ロックを獲得する順番を揃える

上記の例でいうと、片方のトランザクションがt1→t2 という順でロックしているのに対し、もう片方はt2→t1という順でロックしているため、互いにロックを取り合う構造になっている。 ロックを取る順番を揃えれば、デッドロックにはならない(後続のクエリは待つ)。

3. ロックを取る範囲を小さくする

MySQL は条件に一致した行ではなく、スキャンした行やインデックスをロックする。 例えば、以下のクエリは条件にマッチする行が1つもないが、全部の行をロックしてしまう。

mysql> SELECT * FROM t1;
+----+------+
| pk | col1 |
+----+------+
|  1 | t1-1 |
|  2 | t1-2 |
|  3 | t1-3 |
|  4 | t1-4 |
|  5 | t1-5 |
+----+------+
5 rows in set (0.00 sec)

mysql> BEGIN;

-- mysql> EXPLAIN SELECT * FROM t1 WHERE col1 = 'INVALID' FOR UPDATE;
-- +----+-------------+-------+------------+------+---------------+------+---------+------+------+----------+-------------+
-- | id | select_type | table | partitions | type | possible_keys | key  | key_len | ref  | rows | filtered | Extra       |
-- +----+-------------+-------+------------+------+---------------+------+---------+------+------+----------+-------------+
-- |  1 | SIMPLE      | t1    | NULL       | ALL  | NULL          | NULL | NULL    | NULL |    5 |    20.00 | Using where |
-- +----+-------------+-------+------------+------+---------------+------+---------+------+------+----------+-------------+


-- col1 にインデックスがないのでフルスキャン
mysql> SELECT * FROM t1 WHERE col1 = 'INVALID' FOR UPDATE;
Query OK, 0 rows affected (0.00 sec)

適切なインデックスを追加し、スキャンする範囲を小さくする、もしくは、
SELECTしたあとに主キーで対象の行のみを狙って更新する方法が有効。yoku0825さんの MySQLから大量のレコードをちまちま削除するメモ はその例。

SHOW ENGINE INNODB STATUS から情報を得る

SHOW ENGINE INNODB STATUS の LATEST DETECTED DEADLOCK にデッドロックの詳細が記録される。
どのような経緯でデッドロックに到ったか確認する手助けになる。

------------------------
LATEST DETECTED DEADLOCK
------------------------
2017-11-30 17:21:52 0x7fd26c11d700
*** (1) TRANSACTION:
TRANSACTION 1383, ACTIVE 25 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 8, OS thread handle 140541732701952, query id 84 localhost root updating
UPDATE t2 SET col1 = 'session1' WHERE pk = 1
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 28 page no 3 n bits 80 index PRIMARY of table `lockt`.`t2` trx id 1383 lock_mode X locks rec but not gap waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 000000000568; asc      h;;
 2: len 7; hex 46000001530110; asc F   S  ;;
 3: len 8; hex 73657373696f6e32; asc session2;;

*** (2) TRANSACTION:
TRANSACTION 1384, ACTIVE 15 sec starting index read
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 7, OS thread handle 140541732968192, query id 85 localhost root updating
UPDATE t1 SET col1 = 'session2' WHERE pk = 1
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 28 page no 3 n bits 72 index PRIMARY of table `lockt`.`t2` trx id 1384 lock_mode X locks rec but not gap
Record lock, heap no 7 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 000000000568; asc      h;;
 2: len 7; hex 46000001530110; asc F   S  ;;
 3: len 8; hex 73657373696f6e32; asc session2;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 27 page no 3 n bits 80 index PRIMARY of table `lockt`.`t1` trx id 1384 lock_mode X locks rec but not gap waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 000000000567; asc      g;;
 2: len 7; hex 45000001520110; asc E   R  ;;
 3: len 8; hex 73657373696f6e31; asc session1;;

*** WE ROLL BACK TRANSACTION (2)

1. 取得するタイミングに注意

LATEST DETECTED DEADLOCK とあるとおり、「最後に発生したデッドロック」の情報になる。 複数のデッドロックが発生している場合、自分が狙ってる情報が取れるよう、必要に応じて定期的にSHOW ENGINE INNODB STATUSを実行するなどする。

2. 最後のクエリしか記載されない

SHOW ENGINE INNODB STATUSの情報にはトランザクションの最後のクエリしか表示されない。 例でいうと
TRANSACTION(1) の UPDATE t1 SET col1 = 'session1' WHERE pk = 1;
TRANSACTION(2) の UPDATE t2 SET col1 = 'session2' WHERE pk = 1;
が表示されてない。

どういうクエリが原因でデッドロックが発生したか特定するには、LATEST DETECTED DEADLOCKに記載されているクエリを手がかりにソースコードなどから トランザクション全体のクエリを把握する必要がある(SHOW ENGINE INNODB STATUSだけでは全体の流れはわからない)。

3. HOLDS THE LOCKS はTRANSACTION(2)しか表示されない

HOLDS THE LOKCS がTRANSACTION(1)に表示されてないがロックは取ってる。 X row lock(s) に注目したほうが良い。