replica_preserve_commit_order=OFFでのコミット順序逆転を観測する

Transcript

1. replica_preserve_commit_order=OFF でのコミット順序逆転を観測する MySQLアンカンファレンス 2025.10.7 Suzuki Shunya
2. 自己紹介 • Suzuki Shunya ◦ とある企業のDBA ◦ MySQL歴ちょうど2年くらい ◦ Indexが好き ◦ X：@ssuzuki67
3. replica_preserve_commit_orderとは • マルチスレッドレプリケーション（MTR）時、 レプリカのコミット順序をソースと同じにするかを制御する変数 ◦ ON ：レプリカのコミット順序がソースと同じ ◦ OFF ：レプリカのコミット順序が必ずしもソースと同じにならない • 基本ONでOK ◦ MySQL 8.0.27からデフォルトでON • しかし、8.0.32以下のバージョンでは以下のようなバグが...🥺 ◦ 長時間高負荷で稼働するとレプリケーションスレッドがハングする（ 8.0.33でfix） ▪ https://bugs.mysql.com/bug.php?id=103636 ◦ ACL系のStatementでDeadLock（8.0.23でfix??） ▪ https://bugs.mysql.com/bug.php?id=89229
4. どういう時にコミット順序が前後しうる？ • MTRで、SQLスレッドがパラレルにトランザクションを適用する時 ◦ 先行するトランザクションの方が実行時間が長いと、後追いのトランザクションが追い越す • 注：ソース側でパラレル実行しても良いと判断したトランザクションのみ ◦ ソース側のbinlog_transaction_dependency_trackingの設定による ◦ COMMIT_ORDER ：Binlogの同一グループコミットに含まれるトランザクション ◦ WRITESET_SESSION：書き込みセットが重複しない、別セッションのトランザクション ◦ WRITESET ：書き込みセットが重複ししないトランザクション → 各binlog_transaction_dependency_trackingでのコミット順序の前後を観測
5. 観察｜共通設定 • MySQL version：8.0.28 • Source ◦ binlog_transaction_dependency_history_size = 1000000 • Replica ◦ replica_preserve_commit_order = OFF ◦ replica_parallel_workers = 4 ◦ replica_parallel_type = LOGICAL_CLOCK • Target table ◦ CREATE TABLE `t1` ( `id` int NOT NULL AUTO_INCREMENT, `created_at` datetime DEFAULT NULL, PRIMARY KEY (`id`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin
6. 観察｜COMMIT_ORDERの時 • Source設定 ◦ binlog_transaction_dependency_tracking = COMMIT_ORDER ◦ binlog_group_commit_sync_delay = 1000000（=1秒、同時コミットをやりやすくするため） • session2をsession1のコミット完了の直前に開始し、同時にコミット完了 ◦ session2は0.75secなので、session1より後にコミットが発行されているはず replica> select * from t1 limit 3; +--------+---------------------+ | id | created_at | +--------+---------------------+ | 524281 | 2025-10-03 23:40:11 | +--------+---------------------+ 1 row in set (0.05 sec) replica> select * from t1 limit 3; +----+---------------------+ | id | created_at | +----+---------------------+ | 1 | 2025-10-03 23:40:08 | | 2 | 2025-10-03 23:40:08 | | 3 | 2025-10-03 23:40:08 | +----+---------------------+ 3 rows in set (0.00 sec) source session1> INSERT INTO t1(created_at) WITH RECURSIVE seq(n) AS (SELECT 1 UNION ALL SELECT n + 1 FROM seq WHERE n < 500000) SELECT NOW() FROM seq;SELECT NOW(3); Query OK, 500000 rows affected (3.37 sec) Records: 500000 Duplicates: 0 Warnings: 0 +-------------------------+ | NOW(3) | +-------------------------+ | 2025-10-03 23:40:12.230 | +-------------------------+ 1 row in set (0.00 sec) source session2> INSERT INTO t1 (created_at) values (NOW()); SELECT NOW(3); Query OK, 1 row affected (0.75 sec) +-------------------------+ | NOW(3) | +-------------------------+ | 2025-10-03 23:40:12.228 | +-------------------------+ 1 row in set (0.01 sec) 後に発行された コミットの方から あられた！ session1より後に コミット発行、 同時コミット完了
7. 観察｜COMMIT_ORDERの時（補足） • COMMIT_ORDER & replica_preserve_commit_order=ONの時、 Replica側は並列Trxを同時にコミットするわけではない • 場合によっては、replica_preserve_commit_order=ONでも先ほどのような snapshotが観測される ◦ ONの時は、コミットが発行された時刻（ ≠コミット完了した時刻）の順序を守るっぽい ◦ 先ほどの例の場合、 session2のコミットが先に発行されていれば session2の コミットを先に適用する ▪ （この場合は普通、Sourceでもsession2が先に完了するけど） • → ONでもSourceには存在しないSnapshotを読む可能性がある（！？）
8. 観察｜WRITESET_SESSIONの時 • Source設定 ◦ binlog_transaction_dependency_tracking = WRITESET_SESSION ◦ binlog_group_commit_sync_delay = 0 • session2は、session1がコミットされた直後にINSERT → Replicaでsession2の書き込みが先に適用された！ replica> select * from t1 limit 3; +--------+---------------------+ | id | created_at | +--------+---------------------+ | 524281 | 2025-10-06 19:20:26 | +--------+---------------------+ 1 row in set (0.05 sec) replica> select * from t1 limit 3; +----+---------------------+ | id | created_at | +----+---------------------+ | 1 | 2025-10-06 19:20:22 | | 2 | 2025-10-06 19:20:22 | | 3 | 2025-10-06 19:20:22 | +----+---------------------+ 3 rows in set (0.00 sec) source session1> INSERT INTO t1(created_at) WITH RECURSIVE seq(n) AS (SELECT 1 UNION ALL SELECT n + 1 FROM seq WHERE n < 500000) SELECT NOW() FROM seq;SELECT NOW(3); Query OK, 500000 rows affected (2.88 sec) Records: 500000 Duplicates: 0 Warnings: 0 +-------------------------+ | NOW(3) | +-------------------------+ | 2025-10-06 19:20:25.704 | +-------------------------+ 1 row in set (0.00 sec) source session2> INSERT INTO t1 (created_at) values (NOW()); SELECT NOW(3); Query OK, 1 row affected (0.01 sec) +-------------------------+ | NOW(3) | +-------------------------+ | 2025-10-06 19:20:26.093 | +-------------------------+ 1 row in set (0.00 sec) Sourceで後に コミットされた行が先に あらわれた！ session1の コミット直後、 session2コミット
9. 観察｜WRITESETの時 • Source設定 ◦ binlog_transaction_dependency_tracking = WRITESET ◦ binlog_group_commit_sync_delay = 0 • 同一セッションで、順番にINSERT replica> select * from t1 limit 3; +--------+---------------------+ | id | created_at | +--------+---------------------+ | 524281 | 2025-10-06 19:26:35 | +--------+---------------------+ 1 row in set (0.07 sec) replica> select * from t1 limit 3; +----+---------------------+ | id | created_at | +----+---------------------+ | 1 | 2025-10-06 19:26:33 | | 2 | 2025-10-06 19:26:33 | | 3 | 2025-10-06 19:26:33 | +----+---------------------+ 3 rows in set (0.00 sec) source session1> INSERT INTO t1(created_at) WITH RECURSIVE seq(n) AS (SELECT 1 UNION ALL SELECT n + 1 FROM seq WHERE n < 500000) SELECT NOW() FROM seq; select NOW(3); Query OK, 500000 rows affected (2.71 sec) Records: 500000 Duplicates: 0 Warnings: 0 +-------------------------+ | NOW(3) | +-------------------------+ | 2025-10-06 19:26:35.745 | +-------------------------+ 1 row in set (0.00 sec) source session1> INSERT INTO t1 (created_at) values (NOW()); select NOW(3); Query OK, 1 row affected (0.00 sec) +-------------------------+ | NOW(3) | +-------------------------+ | 2025-10-06 19:26:35.758 | +-------------------------+ 1 row in set (0.01 sec) Sourceの 同一sessionで後に コミットされた行が先に あらわれた！ 同一sessionで、 順番にコミット
10. 観察｜無限に追い越される...？ • Replicaでt1への書き込みブロック → t2への書き込みが1,000,000行追い越し source session1> INSERT INTO t1 (created_at) values (NOW()); SELECT NOW(3); Query OK, 1 row affected (0.00 sec) +-------------------------+ | NOW(3) | +-------------------------+ | 2025-10-06 19:34:41.577 | +-------------------------+ 1 row in set (0.00 sec) source session1> INSERT INTO t2(created_at) WITH RECURSIVE seq(n) AS (SELECT 1 UNION ALL SELECT n + 1 FROM seq WHERE n < 500000) SELECT NOW() FROM seq; Query OK, 500000 rows affected (2.78 sec) Records: 500000 Duplicates: 0 Warnings: 0 source session1> INSERT INTO t2(created_at) WITH RECURSIVE seq(n) AS (SELECT 1 UNION ALL SELECT n + 1 FROM seq WHERE n < 500000) SELECT NOW() FROM seq; Query OK, 500000 rows affected (2.99 sec) Records: 500000 Duplicates: 0 Warnings: 0 source session1> SELECT NOW(3); +-------------------------+ | NOW(3) | +-------------------------+ | 2025-10-06 19:34:56.753 | +-------------------------+ 1 row in set (0.00 sec) replica session1>LOCK TABLES t1 READ; SELECT NOW(3); Query OK, 0 rows affected (0.01 sec) +-------------------------+ | NOW(3) | +-------------------------+ | 2025-10-06 19:34:34.962 | +-------------------------+ 1 row in set (0.00 sec) replica session2>select count(*) as "t1 count", NOW() from t1; select count(*) as "t2 count", NOW() from t2; +----------+---------------------+ | t1 count | NOW() | +----------+---------------------+ | 0 | 2025-10-06 19:36:14 | +----------+---------------------+ 1 row in set (0.00 sec) +----------+---------------------+ | t2 count | NOW() | +----------+---------------------+ | 1000000 | 2025-10-06 19:36:14 | +----------+---------------------+ 1 row in set (0.15 sec) t2の方が1000000行も 追い越してる 同一sessionで、 t1に1行Write後、 t2に1,000,000行Write
11. 観察｜無限に追い越される...？ • そんなことはない ...（続き） source session1> INSERT INTO t2 (created_at) values (NOW()); SELECT NOW(3); Query OK, 1 row affected (0.00 sec) +-------------------------+ | NOW(3) | +-------------------------+ | 2025-10-06 19:38:01.145 | +-------------------------+ 1 row in set (0.00 sec) source session1> source session1> INSERT INTO t2 (created_at) values (NOW()); SELECT NOW(3); Query OK, 1 row affected (0.00 sec) +-------------------------+ | NOW(3) | +-------------------------+ | 2025-10-06 19:38:03.014 | +-------------------------+ 1 row in set (0.00 sec) ...（続き） replica session2>select count(*) as "t1 count", NOW() from t1; select count(*) as "t2 count", NOW() from t2; +----------+---------------------+ | t1 count | NOW() | +----------+---------------------+ | 0 | 2025-10-06 19:38:06 | +----------+---------------------+ 1 row in set (0.00 sec) +----------+---------------------+ | t2 count | NOW() | +----------+---------------------+ | 1000000 | 2025-10-06 19:38:06 | +----------+---------------------+ 1 row in set (0.15 sec) replica session1>LOCK TABLES t1 READ; SELECT NOW(3); Query OK, 0 rows affected (0.01 sec) +-------------------------+ | NOW(3) | +-------------------------+ | 2025-10-06 19:34:34.962 | +-------------------------+ 1 row in set (0.00 sec) t2の追い越しが 1000000行でStop 続けて t2に2行Write
12. 観察｜無限に追い越される...？ • 並列に実行可能なクエリは更新行数の合計は binlog_transaction_dependency_history_size（最大1000000）以内 ◦ これを超えるとBinlog依存追跡（並列化可能性）の判定が COMMIT_ORDERになる ◦ →追い越す更新もbinlog_transaction_dependency_history_sizeに収まる • 余談：最初はbinlog_transaction_dependency_history_sizeをデフォルト （25000）に設定していて全然再現できなかった
13. まとめ • replica_preserve_commit_order=OFFの時に、コミット順序が保持されない事象 を観測した • COMMIT_ORDERの順序逆転は、あまり気にしなくてよさそう ◦ ONでもOFFでもPrimaryに存在しないSnapshotを読みうる • WRITESETの時は、同一sessionでさえ順番を無視する可能性あり • WRITESET_SESSIONは性能と整合性のバランスが取れてるかも ◦ 公式でもお勧めしてるっぽい？ ▪ Improving the Parallel Applier with Writeset-based Dependency Tracking
14. 各binlog_transaction_dependency_trackingでのコミット順の保持 • 以下の通り ◦ （replica_preserve_commit_order=OFF） ◦ ⚠：守られない, ✅：守られる WRITESET WRITESET_SESSION COMMIT_ORDER 同時コミット ⚠ ⚠ ⚠ 依存なし・別セッション ⚠ ⚠ ✅ 依存なし・同セッション ⚠ ✅ ✅ 依存あり ✅ ✅ ✅
15. 所感 • バージョンを上げて、replica_preserve_commit_order=ONで運用しよう！！ ◦ 8.0, 8.4の最新系ならバグは解消されているはず • OFFで運用するならBinlog依存追跡はCOMMIT_ORDERが良さそう • OFFで運用していて、MTR性能を上げたかったら？ ◦ WRITESET_SESSIONにする ◦ COMMIT_ORDERで、binlog_group_commit_sync_delayを上げる ◦ binlog_transaction_dependency_history_sizeはデフォルトが無難？
16. Thank you!! 🐬