日々の覚書: 8月 2022

2022/08/30

MySQL on Windowsで8.0.20とそれ以降のmysqld.exeが--skip-grant-tablesでクラッシュすることがある

TL;DR

パラメーターの組み合わせを間違えた場合、本来Abortして起動しないもの(ここまでは意図的)がAbortの処理に失敗してクラッシュする
- “Not a Bug”, 仕様だということらしいので、気にせず正しい組み合わせで起動してやれば良いだけのはず
  - MySQL Bugs: #108304: mysqld.exe crashes --skip-grant-tables without --shared-memory or --named-pipe
skip-grant-tablesしたい時はmy.iniに一緒にshared-memoryを書いてね！

MySQL 8.0では skip-grant-tables を設定した時に自動で skip-networking も設定されるようになった。

これ自体は、「権限テーブル無視してノーガード状態(どこからでもroot相当の権限でノーパスワードでログインできる)のMySQLを守る」ためなので妥当な変更だと思う。

が、Linuix系のMySQLはskip-networkingでもソケット接続が自動(?)で残るので問題ないが、WindowsのMySQLはデフォルトではTCP/IP接続しか使えない = skip-networkingだけを指定するとアクセス方法が全断するのでAbortする。

↓クラッシュしない8.0.19のAbortのログ。

C:\Users\yoku0825\Downloads\mysql-8.0.19-winx64\mysql-8.0.19-winx64>bin\mysqld --console --skip-grant-tables
2022-08-30T02:13:13.537027Z 0 [System] [MY-010116] [Server] C:\Users\yoku0825\Downloads\mysql-8.0.19-winx64\mysql-8.0.19-winx64\bin\mysqld.exe (mysqld 8.0.19) starting as process 11792
2022-08-30T02:13:14.070774Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2022-08-30T02:13:14.086299Z 0 [System] [MY-010931] [Server] C:\Users\yoku0825\Downloads\mysql-8.0.19-winx64\mysql-8.0.19-winx64\bin\mysqld.exe: ready for connections. Version: '8.0.19'  socket: ''  port: 0  MySQL Community Server - GPL.
2022-08-30T02:13:14.086409Z 0 [ERROR] [MY-010131] [Server] TCP/IP, --shared-memory, or --named-pipe should be configured on NT OS
2022-08-30T02:13:14.086814Z 0 [ERROR] [MY-010119] [Server] Aborting
2022-08-30T02:13:14.271648Z 0 [Warning] [MY-011311] [Server] Plugin mysqlx reported: 'All I/O interfaces are disabled, X Protocol won't be accessible'
2022-08-30T02:13:15.239054Z 0 [System] [MY-010910] [Server] C:\Users\yoku0825\Downloads\mysql-8.0.19-winx64\mysql-8.0.19-winx64\bin\mysqld.exe: Shutdown complete (mysqld 8.0.19)  MySQL Community Server - GPL.

Windowsで非TCP/IP通信をするには shared-memory （これは俺使ったことある）または named-pipe （なんか使うのに失敗して以来使ってない）を「明示的に」my.iniに追加しないといけない。

追加していない場合、 [ERROR] [MY-010131] [Server] TCP/IP, --shared-memory, or --named-pipe should be configured on NT OS (skip-networkingによって)TCP/IPも有効じゃないし、shared-memoryもnamed-pipeも1つも有効になってないよ（少なくとも1つは有効にしろよ）とエラーになって起動に失敗する（ [MY-010119] [Server] Aborting ）

ここまでは良いのだが、8.0.20とそれ以降ではこのAbort処理に失敗して（ [ERROR] [MY-013183] [InnoDB] Assertion failure ）バックトレースを吐く。

PS C:\Users\yoku0\Downloads\mysql-8.0.30-winx64\mysql-8.0.30-winx64> bin\mysqld --console --skip-grant-tables

2022-08-26T16:11:22.498164Z 0 [System] [MY-010116] [Server] C:\Users\yoku0\Downloads\mysql-8.0.30-winx64\mysql-8.0.30-winx64\bin\mysqld.exe (mysqld 8.0.30) starting as process 20292
2022-08-26T16:11:22.519344Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2022-08-26T16:11:22.803359Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2022-08-26T16:11:22.970565Z 0 [Warning] [MY-011311] [Server] Plugin mysqlx reported: 'All I/O interfaces are disabled, X Protocol won't be accessible'
2022-08-26T16:11:23.124791Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2022-08-26T16:11:23.125007Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2022-08-26T16:11:23.137076Z 0 [System] [MY-010931] [Server] C:\Users\yoku0\Downloads\mysql-8.0.30-winx64\mysql-8.0.30-winx64\bin\mysqld.exe: ready for connections. Version: '8.0.30'  socket: ''  port: 0  MySQL Community Server - GPL.
2022-08-26T16:11:23.137232Z 0 [ERROR] [MY-010131] [Server] TCP/IP, --shared-memory, or --named-pipe should be configured on NT OS
2022-08-26T16:11:23.137332Z 0 [ERROR] [MY-010119] [Server] Aborting
2022-08-26T16:11:25.018791Z 0 [ERROR] [MY-013183] [InnoDB] Assertion failure: trx0sys.cc:643:UT_LIST_GET_LEN(trx_sys->mysql_trx_list) == 0 thread 8748
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/8.0/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
16:11:25 UTC - mysqld got exception 0x16 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
7ff752740858    mysqld.exe!my_print_stacktrace()[stacktrace.cc:429]
7ff7518de92b    mysqld.exe!print_fatal_signal()[signal_handler.cc:130]
7ff7518de6f3    mysqld.exe!my_server_abort()[signal_handler.cc:241]
7ff7527247fa    mysqld.exe!my_abort()[my_init.cc:263]
7ff75296ca99    mysqld.exe!ut_dbg_assertion_failed()[ut0dbg.cc:99]
7ff752951d0e    mysqld.exe!trx_sys_close()[trx0sys.cc:643]
7ff752903f81    mysqld.exe!srv_shutdown()[srv0start.cc:3240]
7ff75281cb6a    mysqld.exe!innodb_shutdown()[ha_innodb.cc:1603]
7ff7516add5b    mysqld.exe!ha_finalize_handlerton()[handler.cc:726]
7ff7516e9754    mysqld.exe!plugin_deinitialize()[sql_plugin.cc:1121]
7ff7516ef199    mysqld.exe!reap_plugins()[sql_plugin.cc:1190]
7ff7516ede10    mysqld.exe!plugin_shutdown()[sql_plugin.cc:2090]
7ff7516866b9    mysqld.exe!clean_up()[mysqld.cc:2581]
7ff75169aa5a    mysqld.exe!unireg_abort()[mysqld.cc:2444]
7ff75169941f    mysqld.exe!setup_conn_event_handler_threads()[mysqld.cc:3280]
7ff75169d196    mysqld.exe!win_main()[mysqld.cc:8120]
7ff7516954b5    mysqld.exe!mysql_service()[mysqld.cc:8215]
7ff751695adb    mysqld.exe!mysqld_main()[mysqld.cc:8431]
7ff752de4cb4    mysqld.exe!__scrt_common_main_seh()[exe_common.inl:288]
7ffa9f2554e0    KERNEL32.DLL!BaseThreadInitThunk()
7ffa9fee485b    ntdll.dll!RtlUserThreadStart()
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains

明らかにクラッシュはしているものの、直すのは大変だからこのまま（だったらStatusは “Not a Bug” ではなく “Won’t fix” では？とは思うけど）らしいので、この事象にあたった人が焦らないようにこの情報をここに書き残しておきます。

MySQL Bugs: #108304: mysqld.exe crashes --skip-grant-tables without --shared-memory or --named-pipe

skip-grant-tablesしたい時はmy.iniに一緒にshared-memoryを書いてね！

完全な余談。

これ、起動時に起こるクラッシュながら、見えるバックトレースは完全に「終了シーケンスの中でのクラッシュ」なのがちょっと面白かった。Abort処理の中でおかしくなってる（たぶん、InnoDBの初期化が終わってないのにInnoDBの終了処理をしているのがいけない）から終了シーケンスの中でのクラッシュなんだけど、逆にそれが「起動時…だよね…？」とバックトレースに目を取られて [MY-010131] [Server] TCP/IP, --shared-memory, or --named-pipe should be configured on NT OS を見落とさないように注意。

2022/08/25

PKの無いテーブルに、後からAUTO_INCREMENT PRIMARY KEYなカラムを足すときの罠

TL;DR

InnoDBの暗黙の行IDはテーブルにINSERTした順番で払い出される
ソースでは並列で走ると、INSERTした順番がCOMMITした順番とは限らない
レプリカではMulti Thread Applierを使っていない限り、COMMITした順番にINSERTがされる
よってソースとレプリカでは暗黙の行IDがズレることがある
【2022/08/25 12:01】書き込みロックをとっても(テーブルを読み書き一切できない時間があって)良いなら多少安全にやる方法はある

https://gist.github.com/yoku0825/9482455b42cb2cdfaf52288792441b12

百聞は一見に如かず。再現方法。


### on Source, connection 1

master [localhost] {msandbox} ((none)) > CREATE DATABASE d1;

Query OK, 1 row affected (0.00 sec)

master [localhost] {msandbox} ((none)) > CREATE TABLE d1.t1(num int);

Query OK, 0 rows affected (0.02 sec)

master [localhost] {msandbox} ((none)) > BEGIN;

Query OK, 0 rows affected (0.00 sec)

master [localhost] {msandbox} ((none)) > INSERT INTO d1.t1 VALUES (1);

Query OK, 1 row affected (0.03 sec)

### まだCOMMITしない

connection1でINSERTをした後に、connection2で先にCOMMIT

### on Source, connection 2
master [localhost] {msandbox} ((none)) > BEGIN;
Query OK, 0 rows affected (0.00 sec)

master [localhost] {msandbox} ((none)) > INSERT INTO d1.t1 VALUES (2);
Query OK, 1 row affected (0.00 sec)

master [localhost] {msandbox} ((none)) > COMMIT;
Query OK, 0 rows affected (0.00 sec)

で、connection1でCOMMIT

master [localhost] {msandbox} ((none)) > COMMIT;
Query OK, 0 rows affected (0.00 sec)

こうすると、ソースではINSERTした順番が num = 1, num = 2の順番だけど、コミットされた順番が num = 2, num = 1の順番なのでレプリカでINSERTが走るのは num = 2, num = 1の順になる。

よって、PKもないので暗黙の行IDがズレて、ORDER BY無しのSELECTで比較するとこんな感じになる。

$ ./use_all -e "SELECT * FROM d1.t1"
# master
num
1
2
# server: 1:
num
2
1

ここで、ALTER TABLEでAUTO_INCREMENTなPKを足すじゃろ？

master [localhost] {msandbox} ((none)) > ALTER TABLE d1.t1 ADD id BIGINT UNSIGNED NOT NULL PRIMARY KEY AUTO_INCREMENT;
Query OK, 0 rows affected (0.03 sec)
Records: 0  Duplicates: 0  Warnings: 0

AUTO_INCREMENTの値はその時の暗黙の行IDの順番に依存して振られていくので、ソースとレプリカでズレる。

$ ./use_all -e "SELECT * FROM d1.t1"
# master
num     id
1       1
2       2
# server: 1:
num     id
2       1
1       2

当然、この状態で DELETE FROM d1.t1 WHERE id = 2 なんてやるともう取り返しがつかない。numが数字だからわかりにくいけど、emailとかだともう致命的にダメだってことが想像できる。

master [localhost] {msandbox} ((none)) > DELETE FROM d1.t1 WHERE id = 2;
Query OK, 1 row affected (0.00 sec)

$ ./use_all -e "SELECT * FROM d1.t1"
# master
num     id
1       1
# server: 1:
num     id
2       1

レプリケーションとしては正常(ALTER TABLEはステートメント形式で伝達されてそれぞれのノードで再計算されるし、 id = 2は行ベースレプリケーションでもPKしか比較しないのでそれぞれでid = 2の行が消える)なので、気を付けないとこのデータ不整合に気が付けない。

$ ./check_slaves
master
port: 25038
             File: mysql-bin.000001
         Position: 6184
Executed_Gtid_Set:
slave # 1
port: 25039
              Master_Log_File: mysql-bin.000001
          Read_Master_Log_Pos: 6184
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
          Exec_Master_Log_Pos: 6184
           Retrieved_Gtid_Set:
            Executed_Gtid_Set:

俺も同僚から教えてもらったんですが、 MySQL Bugs: #108229: Exists gaps when add a auto_increment column の原因ってこれじゃないかなと思います。まる。

【2022/08/25 12:01】

限りなくユニークに近いカラムがあって、LOCK TABLE WRITE (= ほかのスレッドは読み書きできない）を取っても良いなら、多少安全にやる方法はある。

master [localhost] {msandbox} ((none)) > LOCK TABLE d1.t1 WRITE;
Query OK, 0 rows affected (0.00 sec)

master [localhost] {msandbox} ((none)) > ALTER TABLE d1.t1 ORDER BY num;  ### numが限りなくユニークに近いことが必要だけれども
Query OK, 2 rows affected (0.03 sec)
Records: 2  Duplicates: 0  Warnings: 0

master [localhost] {msandbox} ((none)) > ALTER TABLE d1.t1 ADD id BIGINT UNSIGNED NOT NULL PRIMARY KEY AUTO_INCREMENT;
Query OK, 0 rows affected (0.02 sec)
Records: 0  Duplicates: 0  Warnings: 0

master [localhost] {msandbox} ((none)) > UNLOCK TABLES;
Query OK, 0 rows affected (0.00 sec)


$ ./use_all -e "SELECT * FROM d1.t1"
# master
num     id
1       1
2       2
# server: 1:
num     id
1       1
2       2

https://gist.github.com/yoku0825/9482455b42cb2cdfaf52288792441b12

2022/08/22

replica_parallel_workers > 1 && replica_preserve_commit_order=ON && slave_parallel_type = LOGICAL_CLOCK && FLUSH PRIVILEGES + アカウント権限周りのステートメントをほぼ同時に打つとMySQLがデッドロックすることがある

TL;DR

MySQL Bugs: #89229: FLUSH PRIVILEGES may cause MTS deadlock を踏んだ

再現方法。

8.0.19でレプリケーション設定をしたMySQLを用意する(8.0.28では再現しなかった。5.7.39でも今のところ再現していない)


$ make_replication_sandbox --how_many_slaves=1 8.0.19

$ cd sandboxes/rsandbox_8_0_19/

$ vim master/my.sandbox.cnf

..

binlog_group_commit_sync_delay = 1000000  ### binlogのgroup_commitを起こしやすくするため

$ vim node1/my.sandbox.cnf

..

slave_parallel_workers = 2

slave_preserve_commit_order = ON

slave_parallel_type = LOGICAL_CLOCK

$ ./restart_all

俺は未だにMySQL::Sandboxを使っているのだ、すまんな…。

2つのターミナルを用意して、↓の2ステートメントを1秒以内( binlog_group_commit_sync_delay を100万マイクロ秒に設定しているので、1秒なら同じグループコミットに入れる)に実行する

### Terminal1
$ ./m -e "FLUSH PRIVILEGES"

### Terminal2
$ ./m -e "CREATE USER yoku0825"

体感、50%くらいで再現する。
再現すると、ソースは無事だけどレプリカに一切合切ログインできなくなる。

$ ./s1  ### 刺さって返ってこなくなる

新規接続は全部デッドロックに巻き込まれて動けなくなるけれど、既にログインしているアカウントなら動ける（ただし USE mysql とかすると噛まれて動けなくなる）

SHOW PROCESSLISTで見ると、 FLUSH PRIVILEGES は Waiting for table metadata lock で止まり、そのMDLをもってそうなDROP USERは Waiting for preceding transaction to commit で待っている。

あとから追いかけてきたコネクションは Waiting for acl cache lock で待たされている。

slave1 [localhost] {msandbox} ((none)) > SHOW PROCESSLIST;
+----+----------------------+-----------------+------+---------+------+--------------------------------------------------------+--------------------+
| Id | User                 | Host            | db   | Command | Time | State                                                  | Info               |
+----+----------------------+-----------------+------+---------+------+--------------------------------------------------------+--------------------+
|  4 | system user          |                 | NULL | Query   |   95 | Slave has read all relay log; waiting for more updates | NULL               |
|  5 | event_scheduler      | localhost       | NULL | Daemon  |  186 | Waiting on empty queue                                 | NULL               |
|  8 | system user          |                 |      | Connect |   96 | Waiting for table metadata lock                        | FLUSH PRIVILEGES   |
|  9 | system user          |                 |      | Connect |   95 | Waiting for preceding transaction to commit            | DROP USER yoku0825 |
| 10 | system user          | connecting host | NULL | Connect |  186 | Waiting for master to send event                       | NULL               |
| 15 | msandbox             | localhost       | NULL | Query   |    0 | starting                                               | SHOW PROCESSLIST   |
| 16 | unauthenticated user | localhost       | NULL | Connect |   92 | Waiting for acl cache lock                             | NULL               |
+----+----------------------+-----------------+------+---------+------+--------------------------------------------------------+--------------------+
7 rows in set (0.03 sec)

FLUSH PRIVILEGES, DROP USER の順番でソースのbinlogに入る
FLUSH PRIVILEGES, DROP USER の順番でレプリカのrelaylogに入る
last_committed=6 (同じLOGICAL_CLOCK)の枠の中にあるので、コイツらはパラレルで動かされる
DROP USER が先に終わってしまうと、 slave_preserve_commit_order のために FLUSH PRIVILEGES が終わるのを( mysql.user とかの排他メタデータロックを持ったまま) 待つ
FLUSH PRIVILEGES は ACL_Cache (= mysql.user とかの情報をメモリ上にロードしているアレ) の排他ロックをかけたまま、 mysql.user とかの共有メタデータロックが欲しいので待つ (デッドロック！）
それ以降の接続や権限の読みなおし要求は全て ACL_Cache の排他ロックに阻まれてブロックされる
死！

slave1 [localhost] {msandbox} (mysql) > SELECT * FROM performance_schema.metadata_locks;
+-------------------+--------------------+------------------+-----------------------+-----------------------+----------------------+---------------+-------------+------------------------+-----------------+----------------+
| OBJECT_TYPE       | OBJECT_SCHEMA      | OBJECT_NAME      | COLUMN_NAME           | OBJECT_INSTANCE_BEGIN | LOCK_TYPE            | LOCK_DURATION | LOCK_STATUS | SOURCE                 | OWNER_THREAD_ID | OWNER_EVENT_ID |
+-------------------+--------------------+------------------+-----------------------+-----------------------+----------------------+---------------+-------------+------------------------+-----------------+----------------+
| GLOBAL            | NULL               | NULL             | NULL                  |       140468113535472 | INTENTION_EXCLUSIVE  | STATEMENT     | GRANTED     | sql_base.cc:5398       |              48 |             15 |
| BACKUP LOCK       | NULL               | NULL             | NULL                  |       140468113913600 | INTENTION_EXCLUSIVE  | TRANSACTION   | GRANTED     | sql_base.cc:5405       |              48 |             15 |
| SCHEMA            | mysql              | NULL             | NULL                  |       140468113563696 | INTENTION_EXCLUSIVE  | TRANSACTION   | GRANTED     | sql_base.cc:5385       |              48 |             15 |
| TABLE             | mysql              | columns_priv     | NULL                  |       140468113536896 | SHARED_NO_READ_WRITE | TRANSACTION   | GRANTED     | table.h:2553           |              48 |             15 |
| TABLE             | mysql              | db               | NULL                  |       140468113982576 | SHARED_NO_READ_WRITE | TRANSACTION   | GRANTED     | table.h:2553           |              48 |             15 |
| TABLE             | mysql              | columns_priv     | NULL                  |       140468181071040 | SHARED_READ_ONLY     | TRANSACTION   | PENDING     | table.h:2553           |              47 |             39 |
| TABLE             | mysql              | default_roles    | NULL                  |       140468113772864 | SHARED_NO_READ_WRITE | TRANSACTION   | GRANTED     | table.h:2553           |              48 |             15 |
| TABLE             | mysql              | global_grants    | NULL                  |       140468113772960 | SHARED_NO_READ_WRITE | TRANSACTION   | GRANTED     | table.h:2553           |              48 |             15 |
| TABLE             | mysql              | password_history | NULL                  |       140468113540192 | SHARED_NO_READ_WRITE | TRANSACTION   | GRANTED     | table.h:2553           |              48 |             15 |
| TABLE             | mysql              | procs_priv       | NULL                  |       140468113540288 | SHARED_NO_READ_WRITE | TRANSACTION   | GRANTED     | table.h:2553           |              48 |             15 |
| TABLE             | mysql              | proxies_priv     | NULL                  |       140468113540384 | SHARED_NO_READ_WRITE | TRANSACTION   | GRANTED     | table.h:2553           |              48 |             15 |
| TABLE             | mysql              | role_edges       | NULL                  |       140468113534816 | SHARED_NO_READ_WRITE | TRANSACTION   | GRANTED     | table.h:2553           |              48 |             15 |
| TABLE             | mysql              | tables_priv      | NULL                  |       140468113534912 | SHARED_NO_READ_WRITE | TRANSACTION   | GRANTED     | table.h:2553           |              48 |             15 |
| TABLE             | mysql              | user             | NULL                  |       140468113535008 | SHARED_NO_READ_WRITE | TRANSACTION   | GRANTED     | table.h:2553           |              48 |             15 |
| TABLESPACE        | NULL               | mysql            | NULL                  |       140468113897264 | INTENTION_EXCLUSIVE  | TRANSACTION   | GRANTED     | lock.cc:795            |              48 |             15 |
| ACL CACHE         | NULL               | NULL             | NULL                  |       140468113911328 | EXCLUSIVE            | EXPLICIT      | GRANTED     | sql_auth_cache.cc:3393 |              48 |             16 |
| COMMIT            | NULL               | NULL             | NULL                  |       140468113899824 | INTENTION_EXCLUSIVE  | EXPLICIT      | GRANTED     | handler.cc:1719        |              48 |             16 |
| ACL CACHE         | NULL               | NULL             | NULL                  |       140468448997264 | SHARED               | EXPLICIT      | PENDING     | sql_auth_cache.cc:3393 |              57 |              1 |

バイナリログを開くと、 last_committed が同じになっている。
ただ、これでも先に DROP USER が処理されないと再現はしないので、100%再現とまではいかなかった。

#220822 14:39:48 server id 1  end_log_pos 1411 CRC32 0x3c26f86e         Anonymous_GTID  last_committed=6        sequence_number=7       rbr_only=no     original_committed_timestamp=1661146788679412   immediate_commit_timestamp=1661146788679412     transaction_length=167
# original_commit_timestamp=1661146788679412 (2022-08-22 14:39:48.679412 JST)
# immediate_commit_timestamp=1661146788679412 (2022-08-22 14:39:48.679412 JST)
/*!80001 SET @@session.original_commit_timestamp=1661146788679412*//*!*/;
/*!80014 SET @@session.original_server_version=80019*//*!*/;
/*!80014 SET @@session.immediate_server_version=80019*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 1411
#220822 14:39:48 server id 1  end_log_pos 1501 CRC32 0xd17997a8         Query   thread_id=15    exec_time=0     error_code=0
SET TIMESTAMP=1661146788/*!*/;
FLUSH PRIVILEGES
/*!*/;

# at 1501
#220822 14:39:49 server id 1  end_log_pos 1578 CRC32 0x91c06a81         Anonymous_GTID  last_committed=6        sequence_number=8       rbr_only=no     original_committed_timestamp=1661146789250989   immediate_commit_timestamp=1661146789250989     transaction_length=178
# original_commit_timestamp=1661146789250989 (2022-08-22 14:39:49.250989 JST)
# immediate_commit_timestamp=1661146789250989 (2022-08-22 14:39:49.250989 JST)
/*!80001 SET @@session.original_commit_timestamp=1661146789250989*//*!*/;
/*!80014 SET @@session.original_server_version=80019*//*!*/;
/*!80014 SET @@session.immediate_server_version=80019*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 1578
#220822 14:39:49 server id 1  end_log_pos 1679 CRC32 0xf4243118         Query   thread_id=16    exec_time=0     error_code=0    Xid = 34
SET TIMESTAMP=1661146789/*!*/;
DROP USER yoku0825
/*!*/;

InnoDBとかで刺さる時と違って、CPU使用率も大して上がらずに緩やかに刺さった。
対処方法は kill -9 での再起動（もう kill -15 や mysqladmin shutdown では落ちてくれない）

gtid_mode=ONになってないとMTS中の異常終了で起動した後もSQL_Threadが止まったり(これはもうgtid_mode=ONの時以外MTSは危険…)、そもそも起動の時にまた同じ組み合わせをパラレル適用しようとしてまた刺さったり(replica_parallel_workers = 1にして起動して回避する)とか、なかなかエグい。

いつかぶち当たる人がいたら、参考にしてください…。
（バージョンアップすれば当たらなくなりそうだからバージョン上げましょう…）

2022/08/15

Re: 続・歯抜けを埋めるSQL（10万件編）

この記事は

続・歯抜けを埋めるSQL（10万件編） - sakaikの日々雑感～(T)編

への「俺ならこうひねるかな」版です。

やってることは坂井さんと大して変わっていませんが、方向性が結構違うのが面白いのでメモしておきます。

というかSQLだけでやっていないのでタイトルに反しています（）

坂井さんの手法でやった時の所要時間はこんなものでした。290ms。


mysql80 237> SET @@cte_max_recursion_depth=100005;

Query OK, 0 rows affected (0.00 sec)

mysql80 237> INSERT INTO t22

    -> WITH RECURSIVE num(n) AS (SELECT 1 UNION ALL SELECT n+1 FROM num WHERE n<(SELECT MAX(id) FROM t22))

    -> SELECT n id, null, null FROM num LEFT OUTER JOIN t22 ON (num.n=t22.id) WHERE t22.id IS NULL;

Query OK, 1005 rows affected (0.29 sec)

Records: 1005  Duplicates: 0  Warnings: 0

俺ならこうやるかなはこんな感じになります。

$ for n in $(seq 1 10000 100000) ; do 
>  mysql80 -vve "SET SESSION cte_max_recursion_depth = 100000; INSERT IGNORE INTO d1.t22 WITH RECURSIVE v AS (SELECT $n AS id UNION
 ALL SELECT id + 1 FROM v WHERE id <= $n + 10000) SELECT id, NULL, NULL FROM v"
> done

bashのforとseqコマンドにより、idのレンジを10000区切りにして10回実行します。

--------------
SET SESSION cte_max_recursion_depth = 100000
--------------

Query OK, 0 rows affected (0.00 sec)

--------------
INSERT IGNORE INTO d1.t22 WITH RECURSIVE v AS (SELECT 1 AS id UNION ALL SELECT id + 1 FROM v WHERE id <= 1 + 10000) SELECT id, NULL, NULL FROM v
--------------

Query OK, 0 rows affected, 10002 warnings (0.04 sec)
Records: 10002  Duplicates: 10002  Warnings: 10002

Bye
--------------
SET SESSION cte_max_recursion_depth = 100000
--------------

Query OK, 0 rows affected (0.00 sec)

--------------
INSERT IGNORE INTO d1.t22 WITH RECURSIVE v AS (SELECT 10001 AS id UNION ALL SELECT id + 1 FROM v WHERE id <= 10001 + 10000) SELECT id, NULL, NULL FROM v
--------------

Query OK, 110 rows affected, 9892 warnings (0.06 sec)
Records: 10002  Duplicates: 9892  Warnings: 9892

Bye

..

こんな感じね。
この場合 INSERT IGNORE なので「本当は空きじゃないレコード」にも触わる(= バッファプールを多少荒らす) ので、1万刻みにした部分は調整するかも知れません。あとは実際にやるなら多少sleepを入れるでしょう。

雑に一発60msecくらいなので、10回やると600msでだいぶ赤字ですが、この方法のメリットとデメリット。

メリット

たとえ詰める行の数が数百万になっても、1回あたりで取るロックの行は高々1万行で、ループの回数が増えるだけで単発のクエリの速度は一定する
- 坂井さんバージョンだと、INSERT INTO .. SELECT ..のSELECT側は共有ロックを取るので、行数が増えてクエリ時間が長くなれば長くなるほど「既存のレコードを更新できない時間が増え」ます。
- 外側分割パターンだとsleepの時間とseqで飛ぶ数さえ調整すればこの辺は調整できます。

mysql80 261> SELECT object_name, index_name, lock_type, lock_mode, COUNT(*) FROM performance_schema.data_locks GROUP BY 1, 2, 3, 4;
+-------------+------------+-----------+---------------+----------+
| object_name | index_name | lock_type | lock_mode     | COUNT(*) |
+-------------+------------+-----------+---------------+----------+
| t22         | NULL       | TABLE     | IX            |        1 |
| t22         | NULL       | TABLE     | IS            |        1 |
| t22         | PRIMARY    | RECORD    | S             |      136 |
| t22         | PRIMARY    | RECORD    | S,REC_NOT_GAP |    98046 |
| t22         | PRIMARY    | RECORD    | S,GAP         |     3870 |
+-------------+------------+-----------+---------------+----------+
5 rows in set (0.70 sec)

たとえ詰める行の数が（略）レプリケーション遅延を起こしにくいです。
- MySQL 8.0のbinlog_formatはROWなので、レプリケーションソースで行った計算を再度レプリカで行うわけではないですが(binlog_format=STATEMENTだとレプリカで再計算する)、それでも行の数が増えれば増えるほどレプリケーションは遅延します。
- こちらもsleepとseqで調整できます。
中断が簡単
- 1ステートメントだと「All or nothing」なので既存のトラフィックに影響が出た…Ctrl + C!! からのロールバックが始まります
- こっちは中断しても最後のnの値を持っていれば、最後のn - 1から再開できます(最後のnのところはロールバックされるであろうので、マイナス1)。たとえnを控えずに先頭から再開しても処理が終わったところは空振りするだけなので、中断したところまでは全て空振りのままサクサク進むでしょう（sleepぶんが無駄になりますが）

デメリット

アトミックでない
- これが最大の問題。「歯抜けを埋めている最中の様子がAppに観測されても良い」場合しか使えないので、一発で洗い替えをしたい場合はこの手法は選べない。
  - でもそれなら俺、pt-oscっぽくトリガー貼って埋め直したテーブル作ってRENAME TABLEで入れ替えようかな…
美しくない、というかタイトルに反している
- 結局アプリケーションコードを書いているのと一緒なので（この程度のループなら好きなプログラミング言語であっさり書けるはず）、わざわざドヤ顔するほどのものではない
トータルの所要時間が伸びる
- ロックやレプリカが許容できるうちは特に分割する必要もない

ああ、俺って「それを実機に投入することを前提に考え」がちなんだなあと気づきました（ロックとかレプリカとか）

見方が違って楽しいなと思ったメモです。

登録: 投稿 ( Atom )