本番データ de CLONEプラグイン、そして思ったこと

TL;DR

• みんなだいすきCLONEプラグインを使って本番のマスター（稼働中）から本番のスレーブ（諸事情により再構築が必要だった）を作った。
  • 何度かリトライはしたけど、ちゃんと動いているような気がする
• CLONE INSTANCE FROM .. を実行するターミナルは tmux などで切断から保護しましょう…

---

CLONEプラグインって何的な人は先にこっちを読んでいただくと良いかも知れない。

• 日々の覚書: MySQL 8.0.17のCLONE INSTANCE FROMを使うとすごく楽にレプリケーションスレーブが作れる

取り敢えず
何も考えずにクローン用のアカウントをマスターに作成する。

mysql> CREATE USER cloner@xxx.xxx.xxx.xxx IDENTIFIED BY 'xxxx';
Query OK, 0 rows affected (0.00 sec)

mysql> GRANT BACKUP_ADMIN ON *.* TO cloner@xxx.xxx.xxx.xxx;
Query OK, 0 rows affected (0.00 sec)

スレーブ用地から CLONE INSTANCE FROM .. でクローンを開始しようとする。

mysql> SET GLOBAL SEESSION clone_valid_donor_list = 'yyy.yyy.yyy.yyy:3306';
Query OK, 0 rows affected (0.00 sec)

mysql> CLONE INSTANCE FROM cloner@yyy.yyy.yyy.yyy:3306 IDENTIFIED BY 'xxxx';
ERROR 3862 (HY000): Clone Donor Error: 1016 : Can't open file: './undo001' (errno: 2 - No such file or directory).

(つд⊂)ｺﾞｼｺﾞｼ

ERROR 3862は「ドナーからこんなエラーを受け取った」ためのエラーコードなので、ERROR 1016 Can’t open file .. がドナーから受け取った生のエラー。

クローンに関する進捗とかその他は全てドナーノード側のエラーログに出力される。 Note レベルなのでドナー側が log_error_verbosity= 3 でないと出力されないと思う。

こっちがドナー側のエラーログ。

2019-11-26T10:39:22.974397+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Acquired backup lock.'
2019-11-26T10:39:22.974459+09:00 34186 [Note] [MY-013457] [InnoDB] Clone Begin Master Task by cloner@172.21.160.132
2019-11-26T10:39:22.979792+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_INIT: Storage Initialize.'
2019-11-26T10:39:22.979825+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_RES_COMPLETE.'
2019-11-26T10:39:51.981458+09:00 34187 [Note] [MY-013458] [InnoDB] Clone set state change ACK: 1
2019-11-26T10:39:51.981516+09:00 34187 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_ACK: Storage Ack.'
2019-11-26T10:39:51.981544+09:00 34187 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_RES_COMPLETE.'
2019-11-26T10:39:52.081398+09:00 34186 [Note] [MY-013458] [InnoDB] Clone Master received state change ACK
2019-11-26T10:39:52.081463+09:00 34186 [Note] [MY-013458] [InnoDB] Clone State Change : Number of tasks = 1
2019-11-26T10:39:52.081483+09:00 34186 [Note] [MY-013458] [InnoDB] Clone State BEGIN FILE COPY
2019-11-26T10:39:52.087133+09:00 34186 [Note] [MY-011845] [InnoDB] Clone Start PAGE ARCH : start LSN : 1927678359668, checkpoint LSN : 1927629671670
2019-11-26T10:39:52.094897+09:00 34186 [Note] [MY-013458] [InnoDB] Clone Set Error code: 1815 Saved Error code: 0
2019-11-26T10:39:52.094936+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_EXECUTE: Storage Execute: error: 1815: Can't open file: './undo001' (errno: 2 - No such file or directory).'
2019-11-26T10:39:52.094954+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Before sending COM_RES_ERROR:  : error: 1815: Can't open file: './undo001' (errno: 2 - No such file or directory).'
2019-11-26T10:39:52.095022+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: After sending COM_RES_ERROR.'
2019-11-26T10:39:52.095295+09:00 34187 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_EXIT: Storage End.'
2019-11-26T10:39:52.095347+09:00 34187 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_RES_COMPLETE.'
2019-11-26T10:39:52.095375+09:00 34187 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Exiting clone protocol.'
2019-11-26T10:39:52.096028+09:00 34186 [Note] [MY-011846] [InnoDB] Clone Stop  PAGE ARCH : end   LSN : 1927629671670, log sys LSN : 1927678363098
2019-11-26T10:39:52.096207+09:00 34186 [Note] [MY-013457] [InnoDB] Clone End Master Task ID: 0 Passed, code: 0:
2019-11-26T10:39:52.096234+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_EXIT: Storage End.'
2019-11-26T10:39:52.096268+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_RES_COMPLETE.'
2019-11-26T10:39:52.096302+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Exiting clone protocol.'

こっちがレシピエント側のエラーログ。

2019-11-26T10:39:22.963763+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Task Connect.'
2019-11-26T10:39:22.974258+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Master ACK Connect.'
2019-11-26T10:39:22.974323+09:00 139 [Note] [MY-013457] [InnoDB] Clone Apply Begin Master Version Check
2019-11-26T10:39:22.975340+09:00 139 [Note] [MY-013457] [InnoDB] Clone Apply Version End Master Task ID: 0 Passed, code: 0:
2019-11-26T10:39:22.975382+09:00 139 [Note] [MY-013457] [InnoDB] Clone Apply Begin Master Task
2019-11-26T10:39:22.976280+09:00 139 [Warning] [MY-013460] [InnoDB] Clone removing all user data for provisioning: Started
2019-11-26T10:39:22.976316+09:00 139 [Note] [MY-011977] [InnoDB] Clone Drop all user data
2019-11-26T10:39:24.122046+09:00 139 [Note] [MY-011977] [InnoDB] Clone: Fix Object count: 2314 task: 0
2019-11-26T10:39:51.598531+09:00 139 [Note] [MY-011977] [InnoDB] Clone Drop User schemas
2019-11-26T10:39:51.598901+09:00 139 [Note] [MY-011977] [InnoDB] Clone: Fix Object count: 14 task: 0
2019-11-26T10:39:51.623511+09:00 139 [Note] [MY-011977] [InnoDB] Clone Drop User tablespaces
2019-11-26T10:39:51.624095+09:00 139 [Note] [MY-011977] [InnoDB] Clone: Fix Object count: 6 task: 0
2019-11-26T10:39:51.625091+09:00 132 [Note] [MY-010596] [Repl] Error reading relay log event for channel '': slave SQL thread was killed
2019-11-26T10:39:51.625136+09:00 132 [Note] [MY-010587] [Repl] Slave SQL thread for channel '' exiting, replication stopped in log 'FIRST' at position 0
2019-11-26T10:39:51.742987+09:00 139 [Note] [MY-011977] [InnoDB] Clone Drop: finished successfully
2019-11-26T10:39:51.743073+09:00 139 [Warning] [MY-013460] [InnoDB] Clone removing all user data for provisioning: Finished
2019-11-26T10:39:51.981055+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Command COM_INIT.'
2019-11-26T10:39:52.095229+09:00 139 [Note] [MY-013458] [InnoDB] Clone Set Error code: 3862 Saved Error code: 0
2019-11-26T10:39:52.095271+09:00 139 [Note] [MY-013458] [InnoDB] Clone Apply set error code: 3862: Clone Donor Error: 1016 : Can't open file: './undo001' (errno: 2 - No such file or directory).
2019-11-26T10:39:52.095290+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Wait for remote after local issue: error: 3862: Clone Donor Error: 1016 : Can't open file: './undo001' (errno: 2 - No such file or directory)..'
2019-11-26T10:39:52.095305+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Command COM_EXECUTE: error: 3862: Clone Donor Error: 1016 : Can't open file: './undo001' (errno: 2 - No such file or directory)..'
2019-11-26T10:39:52.095552+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Master ACK COM_EXIT.'
2019-11-26T10:39:52.095941+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Master ACK Disconnect : abort: false.'
2019-11-26T10:39:52.096479+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Task COM_EXIT.'
2019-11-26T10:39:52.096798+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Task Disconnect : abort: false.'
2019-11-26T10:39:52.096858+09:00 139 [Note] [MY-013458] [InnoDB] Clone Set Error code: 3862 Saved Error code: 3862
2019-11-26T10:39:52.096890+09:00 139 [Note] [MY-013458] [InnoDB] Clone Apply set error code: 3862: Clone Donor Error: 1016 : Can't open file: './undo001' (errno: 2 - No such file or directory).
2019-11-26T10:39:52.096944+09:00 139 [Note] [MY-013458] [InnoDB] Clone Set Error code: 3862 Saved Error code: 3862
2019-11-26T10:39:52.097189+09:00 139 [Note] [MY-013457] [InnoDB] Clone Apply End Master Task ID: 0 Failed, code: 3862: Clone Donor Error: 1016 : Can't open file: './undo001' (errno: 2 - No such file or directory).

目をこらして良く見ていただくとわかるのだが、 [Warning] [MY-013460] [InnoDB] Clone removing all user data for provisioning: Finished なので、クローンが始まった時点でレシピエントのdatadirからは諸々が消える。

---

ちなみにドナー側の undo001 、ちゃんとあるんですけどねってすったもんだした後、レシピエントを再起動したりドナーの innodb_undo_log_truncate = ON にしてみたり色々したけれど、結局ドナー(= 稼働中のマスター)を再起動するまでクローンは同じエラーで転け続けた。

• ひょっとしたら、ドナーを5.7から8.0にバージョンアップした時に、「自動で更新かかるから良いっしょー」ってアップグレード後に再起動してなかったのがいけないんじゃないかなと思っている（ mysql_upgrade の時は自分で再起動してたけど、すっかり忘れていたんじゃないかなと）
• 【2019/11/26 18:45】
• innodb_undo_tablespaces= 2とかで5.7をインストールして、その後8.0にアップグレードするとこうなることまでは分かった。やっぱり単に再起動すればいいだけの気がする。
• MySQL Bugs: #97784: clone plugin misunderstanding UNDO table-space file name

mysql> CLONE INSTANCE FROM cloner@yyy.yyy.yyy.yyy:3306 IDENTIFIED BY 'xxxx';
Query OK, 0 rows affected (37 min 23.83 sec)

再起動後はすんなり通った。
レシピエントの方のエラーログには

2019-11-26T11:08:19.464385+09:00 7 [Note] [MY-011978] [InnoDB] Clone estimated size: 188.15 GiB Available space: 359.75 GiB

と書いてあったので、「何も設定しない(= ほぼ無制限にCLONEがリソースを欲しがる)状態」で85MB/sくらい。
m4.xlarge + 900IOPSなgp2のEBSなので「マスターでトラフィックを受けながらにしてはまあまあ？」みたいな感じはする。

ただしまあ dstat を見てたら結構iowait出てるしストレージもかなり読むし出ていくパケットも多いし…で、2台目やる時はちょっと制限しようかなとか思った（↓ はドナー側）

$ dstat -amrl
----total-cpu-usage---- -dsk/total- -net/total- ---paging-- ---system-- ------memory-usage----- --io/total- ---load-avg---
usr sys idl wai hiq siq| read  writ| recv  send|  in   out | int   csw | used  buff  cach  free| read  writ| 1m   5m  15m
 53   1  12  33   0   0|  90M  318k| 337k   90M|   0     0 |  20k 5285 |12.0G    0  1602M 1952M| 751   105 |5.57 6.21 5.83
 62   1   7  30   0   0|  90M  378k| 220k   90M|   0     0 |  16k 5335 |12.0G    0  1602M 1953M| 752   118 |5.57 6.21 5.83
 53   1  17  29   0   1|  89M  321k| 291k   89M|   0     0 |  18k 5428 |12.0G    0  1602M 1950M| 751   103 |5.57 6.21 5.83

2019-11-26T11:08:46.108105+09:00 112 [Note] [MY-013458] [InnoDB] Stage progress: 1% completed.
2019-11-26T11:10:31.546724+09:00 112 [Note] [MY-013458] [InnoDB] Stage progress: 11% completed.

制限するにはこの辺のパラメーターをいじるんだけれど、

• MySQL :: MySQL 8.0 Reference Manual :: 5.6.7.12 Clone System Variables

複数個所いっぺんに変えるとわからなくなる（というか、なったので一度中断してやり直している）ので今回は clone_enable_compression = ONだけ変更して実行（↓もドナー側）

mysql> SET GLOBAL SEESSION clone_valid_donor_list = 'yyy.yyy.yyy.yyy:3306';
Query OK, 0 rows affected (0.00 sec)

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

mysql> CLONE INSTANCE FROM cloner@yyy.yyy.yyy.yyy:3306 IDENTIFIED BY 'xxxx';

----total-cpu-usage---- -dsk/total- -net/total- ---paging-- ---system-- ------memory-usage----- --io/total-
usr sys idl wai hiq siq| read  writ| recv  send|  in   out | int   csw | used  buff  cach  free| read  writ
 50   0  46   4   0   0|  14M 2675k|  47k 4043k|   0     0 |7780  6601 |12.0G    0  2152M 1425M| 143   277
 49   1  48   3   0   0|  16M  692k|  29k 4434k|   0     0 |5988  4010 |12.0G    0  2152M 1425M| 171  92.0
 50   1  47   3   0   0|  12M  843k|  35k 3330k|   0     0 |7091  5590 |12.0G    0  2152M 1425M| 127   141

2019-11-26T12:17:54.871875+09:00 474 [Note] [MY-013458] [InnoDB] Stage progress: 1% completed.
2019-11-26T12:27:37.153130+09:00 474 [Note] [MY-013458] [InnoDB] Stage progress: 11% completed.

( ﾟдﾟ)

いやー、IOがぐっと下がったのは良いけど、遅い遅い。
読み出し速度が14MB/secしか出てなくて単純計算6倍近くかかるってことは3時間かー…ごはんでも食べてこようそうしよう。

＿人人人人人＿
＞　時は流れた　＜
￣Y^Y^Y^Y^Y^￣

さーてクローンどうなったかな。

mysql> CLONE INSTANCE FROM cloner@yyy.yyy.yyy.yyy:3306 IDENTIFIED BY 'xxxx';
Timeout, server 192.168.211.58 not responding.

Σ(ﾟдﾟlll) VPN切れてる！？

2019-11-26T15:31:25.203117+09:00 474 [Note] [MY-013458] [InnoDB] Stage progress: 96% completed.
2019-11-26T15:33:30.443342+09:00 475 [Note] [MY-013458] [InnoDB] Clone set error ACK: 1317
2019-11-26T15:33:30.443418+09:00 475 [Note] [MY-013458] [InnoDB] Clone Set Error code: 1317 Saved Error code: 0
2019-11-26T15:33:30.443440+09:00 475 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_ACK: Storage Ack.'
2019-11-26T15:33:30.443488+09:00 475 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_RES_COMPLETE.'
2019-11-26T15:33:30.443902+09:00 475 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_EXIT: Storage End.'
2019-11-26T15:33:30.443943+09:00 475 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_RES_COMPLETE.'
2019-11-26T15:33:30.443959+09:00 475 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Exiting clone protocol.'
2019-11-26T15:33:30.464396+09:00 474 [Note] [MY-013458] [InnoDB] Clone Set Error code: 1160 Saved Error code: 1317
2019-11-26T15:33:30.464443+09:00 474 [Note] [MY-013458] [InnoDB] Clone Set Error code: 1160 Saved Error code: 1317
2019-11-26T15:33:30.464465+09:00 474 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_EXECUTE: Storage Execute: error: 1160: Got an error writing communication packets.'
2019-11-26T15:33:30.464491+09:00 474 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Before sending COM_RES_ERROR: network : error: 1160: Got an error writing communication packets.'
2019-11-26T15:33:30.464566+09:00 474 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: After sending COM_RES_ERROR: error: 1160: Got an error writing communication packets.'
2019-11-26T15:33:30.464646+09:00 474 [Note] [MY-013458] [InnoDB] Clone Set Error code: 1317 Saved Error code: 1317
2019-11-26T15:33:30.464687+09:00 474 [Note] [MY-011846] [InnoDB] Clone Stop  PAGE ARCH : end   LSN : 1928777840909, log sys LSN : 1928826565652
2019-11-26T15:33:30.464922+09:00 474 [Note] [MY-013457] [InnoDB] Clone End Master Task ID: 0 Failed, code: 1317: Got an error writing communication packets
2019-11-26T15:33:30.464955+09:00 474 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Exiting clone protocol: error: 1160: Got an error writing communication packets.'

Σ(ﾟдﾟlll)

というわけで今、圧縮しない設定でCLONE取り直してます。ちゃんとtmux使って。

機会があれば他のパラメーターも試す。

​

innodb_autoinc_lock_mode = 1 vs 2 でバルクインサートが競合した時のAUTO_INCREMENTの挙動が違うはなし

TL;DR

• innodb_autoinc_lock_mode のデフォルトはMySQL 8.0で2になった(5.7とそれ以前は1)
• innodb_autoinc_lock_mode= 2だとステートメントベースのレプリケーションではアンセーフだ 、というのはよく語られるけど
• INSERT INTO .. SELECT .. や LOAD DATA .. でauto_incrementで連番を払い出すようなステートメント同士が競合すると、1と2で差が出る
• SELECT LAST_INSERT_ID() からの、SELECT .. WHERE id > その値  みたいなクエリーを使っている時は気を付けた方が良い鴨

---

(0, 'one') な値を INSERT INTO .. SELECT .. で1000万件突っ込んで、オートインクリメントで払い出させる。

 MySQL  localhost:3306 ssl  SQL > CREATE DATABASE d1;
Query OK, 1 row affected (0.0334 sec)

 MySQL  localhost:3306 ssl  SQL > CREATE TABLE d1.t1 (num int auto_increment PRIMARY KEY, val varchar(32));
Query OK, 0 rows affected (0.1181 sec)

 MySQL  localhost:3306 ssl  SQL > SELECT @@innodb_autoinc_lock_mode;
+----------------------------+
| @@innodb_autoinc_lock_mode |
+----------------------------+
|                          2 |
+----------------------------+
1 row in set (0.0007 sec)

 MySQL  localhost:3306 ssl  SQL > SET SESSION cte_max_recursion_depth = 50000000;
Query OK, 0 rows affected (0.0002 sec)

 MySQL  localhost:3306 ssl  SQL > INSERT INTO d1.t1 WITH RECURSIVE a AS (SELECT 1 AS n UNION ALL SELECT n + 1 FROM a WHERE n < 10000000) SELECT 0, 'one' FROM a;

 MySQL  localhost:3306 ssl  SQL > SELECT * FROM t1 ORDER BY num ASC LIMIT 3;
+-----+-----+
| num | val |
+-----+-----+
|   1 | one |
|   2 | one |
|   3 | one |
+-----+-----+
3 rows in set (0.0183 sec)

 MySQL  localhost:3306 ssl  SQL > SELECT * FROM d1.t1 ORDER BY num DESC LIMIT 3;
+----------+-----+
| num      | val |
+----------+-----+
| 10000000 | one |
|  9999999 | one |
|  9999998 | one |
+----------+-----+
3 rows in set (0.0004 sec)

 MySQL  localhost:3306 ssl  SQL > SELECT COUNT(*) FROM d1.t1;
+----------+
| COUNT(*) |
+----------+
| 10000000 |
+----------+
1 row in set (0.2423 sec)

これは従来( innodb_autoinc_lock_mode= 1 )の動作と変わりはない。
で、これを競合させる。

 MySQL  localhost:3306 ssl  SQL > TRUNCATE d1.t1;
Query OK, 0 rows affected (0.2704 sec)

 MySQL  localhost:3306 ssl  SQL > INSERT INTO d1.t1 WITH RECURSIVE a AS (SELECT 1 AS n UNION ALL SELECT n + 1 FROM a WHERE n < 10000000) SELECT 0, 'one' FROM a;

 MySQL  localhost:3306 ssl  SQL > INSERT INTO d1.t1 WITH RECURSIVE a AS (SELECT 1 AS n UNION ALL SELECT n + 1 FROM a WHERE n < 10000000) SELECT 0, 'two' FROM a; -- こっちは別のターミナル && valカラムに 'two' を割り当てる

とするとこうなる。

 MySQL  localhost:3306 ssl  SQL > SELECT * FROM d1.t1 ORDER BY num ASC LIMIT 3;
+-----+-----+
| num | val |
+-----+-----+
|   1 | one |
|   2 | one |
|   3 | one |
+-----+-----+
3 rows in set (0.0006 sec)

 MySQL  localhost:3306 ssl  SQL > SELECT * FROM d1.t1 ORDER BY num DESC LIMIT 3;
+----------+-----+
| num      | val |
+----------+-----+
| 20026855 | two |
| 20026854 | two |
| 20026853 | two |
+----------+-----+
3 rows in set (0.0018 sec)

 MySQL  localhost:3306 ssl  SQL > SELECT COUNT(*) FROM d1.t1;
+----------+
| COUNT(*) |
+----------+
| 20000000 |
+----------+
1 row in set (1.8136 sec)

多少の歯抜けが存在するのは良いとして（AUTO_INCREMENTはもともとそういうもの）、ちゃんと入っているように見える…が。

 MySQL  localhost:3306 ssl  SQL > WITH a AS (SELECT num, val = LEAD(val) OVER (ORDER BY num) AS same_val_prev_row FROM d1.t1)
                               -> SELECT num FROM a WHERE same_val_prev_row <> 1;
+----------+
| num      |
+----------+
|    16383 |
|    20478 |
|    36862 |
..
| 19791570 |
| 19857105 |
| 19895785 |
+----------+
307 rows in set (1 min 1.3050 sec)

このクエリーが何を意味しているかというと、 (1, 'one'), (2, 'one') のように直後の行と同じvalの値を持つ行は1、 (2, 'one'), (3, 'two') のように違うvalを持つ行は0が返されるような same_val_prev_row カラムを計算してそれを <> 1（つまり、直後の行とvalの値が違う) 行を抽出している。

この抽出結果を鑑みて前後の行を確認してみると

 MySQL  localhost:3306 ssl  SQL > SELECT * FROM d1.t1 WHERE num BETWEEN 16383 - 1 AND 16383 + 1;
+-------+-----+
| num   | val |
+-------+-----+
| 16382 | one |
| 16383 | one |
| 16384 | two |
+-------+-----+
3 rows in set (0.0554 sec)

 MySQL  localhost:3306 ssl  SQL > SELECT * FROM d1.t1 WHERE num BETWEEN 19857105 - 1 AND 19857105 + 1;
+----------+-----+
| num      | val |
+----------+-----+
| 19857104 | two |
| 19857105 | two |
| 19857106 | one |
+----------+-----+
3 rows in set (0.5144 sec)

確かに途中でvalの値が変わるのが発生している。これが innodb_autoinc_lock_mode= 2 の時の動作。

innodb_autoinc_lock_mode はオンラインで変更できないので、 SET PERSIST_ONLY を使って書き込んでから RESTART ステートメントで再起動。

 MySQL  localhost:3306 ssl  SQL > TRUNCATE d1.t1;
SERR ^HQuery OK, 0 rows affected (1.3815 sec)

 MySQL  localhost:3306 ssl  SQL > SET PERSIST_ONLY innodb_autoinc_lock_mode = 1;
Query OK, 0 rows affected (0.0201 sec)

 MySQL  localhost:3306 ssl  SQL > RESTART;
Query OK, 0 rows affected (0.0147 sec)

で、同じことをもう一回。

 MySQL  localhost:3306 ssl  SQL > SELECT @@innodb_autoinc_lock_mode;
+----------------------------+
| @@innodb_autoinc_lock_mode |
+----------------------------+
|                          1 |
+----------------------------+
1 row in set (0.6702 sec)

 MySQL  localhost:3306 ssl  SQL > INSERT INTO d1.t1 WITH RECURSIVE a AS (SELECT 1 AS n UNION ALL SELECT n + 1 FROM a WHERE n < 10000000) SELECT 0, 'one' FROM a;

 MySQL  localhost:3306 ssl  SQL > INSERT INTO d1.t1 WITH RECURSIVE a AS (SELECT 1 AS n UNION ALL SELECT n + 1 FROM a WHERE n < 10000000) SELECT 0, 'two' FROM a;

 MySQL  localhost:3306 ssl  SQL > SELECT COUNT(*) FROM d1.t1;
+----------+
| COUNT(*) |
+----------+
| 20000000 |
+----------+
1 row in set (0.4621 sec)

 MySQL  localhost:3306 ssl  SQL > SELECT * FROM d1.t1 ORDER BY num LIMIT 3;
+-----+-----+
| num | val |
+-----+-----+
|   1 | one |
|   2 | one |
|   3 | one |
+-----+-----+
3 rows in set (0.0006 sec)

 MySQL  localhost:3306 ssl  SQL > SELECT * FROM d1.t1 ORDER BY num DESC LIMIT 3;
+----------+-----+
| num      | val |
+----------+-----+
| 20026855 | two |
| 20026854 | two |
| 20026853 | two |
+----------+-----+
3 rows in set (0.0006 sec)

 MySQL  localhost:3306 ssl  SQL > WITH a AS (SELECT num, val = LEAD(val) OVER (ORDER BY num) AS same_val_prev_row FROM d1.t1 WHERE num) SELECT * FROM a WHERE same_val_prev_row <> 1;
+----------+
| num      |
+----------+
| 10000000 |
+----------+
1 row in set (1 min 8.4337 sec)

 MySQL  localhost:3306 ssl  SQL > SELECT * FROM d1.t1 WHERE num >= 9999999 ORDER BY num LIMIT 3;
+----------+-----+
| num      | val |
+----------+-----+
|  9999999 | one |
| 10000000 | one |
| 10026856 | two |
+----------+-----+
3 rows in set (0.0005 sec)

今度は切り替わりが1回だけになった。
performance_schema.data_locks を見ると、 innodb_autoinc_lock_mode= 1 の時はAUTO_INCロックでぶつかりまくっているのに対して

 MySQL  localhost:3306 ssl  performance_schema  SQL > SELECT @@innodb_autoinc_lock_mode;
+----------------------------+
| @@innodb_autoinc_lock_mode |
+----------------------------+
|                          1 |
+----------------------------+
1 row in set (0.0007 sec)

 MySQL  localhost:3306 ssl  performance_schema  SQL > SELECT * FROM data_locks;
+--------+--------------------------------------+-----------------------+-----------+----------+---------------+-------------+----------------+-------------------+------------+-----------------------+-----------+-----------+-------------+-----------+
| ENGINE | ENGINE_LOCK_ID                       | ENGINE_TRANSACTION_ID | THREAD_ID | EVENT_ID | OBJECT_SCHEMA | OBJECT_NAME | PARTITION_NAME | SUBPARTITION_NAME | INDEX_NAME | OBJECT_INSTANCE_BEGIN | LOCK_TYPE | LOCK_MODE | LOCK_STATUS | LOCK_DATA |
+--------+--------------------------------------+-----------------------+-----------+----------+---------------+-------------+----------------+-------------------+------------+-----------------------+-----------+-----------+-------------+-----------+
| INNODB | 140684506070480:1065:140684405311704 |                  2183 |        47 |       47 | d1            | t1          | NULL           | NULL              | NULL       |       140684405311704 | TABLE     | AUTO_INC  | WAITING     | NULL      |
| INNODB | 140684506071352:1065:140682660470608 |                  2182 |        57 |        5 | d1            | t1          | NULL           | NULL              | NULL       |       140682660470608 | TABLE     | AUTO_INC  | GRANTED     | NULL      |
| INNODB | 140684506071352:1065:140684405317672 |                  2182 |        57 |        5 | d1            | t1          | NULL           | NULL              | NULL       |       140684405317672 | TABLE     | IX        | GRANTED     | NULL      |
+--------+--------------------------------------+-----------------------+-----------+----------+---------------+-------------+----------------+-------------------+------------+-----------------------+-----------+-----------+-------------+-----------+
3 rows in set (0.0217 sec)

 MySQL  localhost:3306 ssl  performance_schema  SQL > SELECT SUM(count_star), SUM(sum_timer_wait) FROM events_waits_summary_by_instance WHERE event_name = 'wait/synch/mutex/innodb/autoinc_mutex';
+-----------------+---------------------+
| SUM(count_star) | SUM(sum_timer_wait) |
+-----------------+---------------------+
|             338 |            49899332 |
+-----------------+---------------------+
1 row in set (0.0146 sec)

innodb_autoinc_lock_mode= 2 ではAUTO_INCロックはぶつかってはいない。mutex取ってる回数は変わらなさげだけどAUTO_INCREMENTを払い出す回数は変わらないだろうからそれはそれで合っている気がする。

 MySQL  localhost:3306 ssl  performance_schema  SQL > SELECT @@innodb_autoinc_lock_mode;
+----------------------------+
| @@innodb_autoinc_lock_mode |
+----------------------------+
|                          2 |
+----------------------------+
1 row in set (0.0005 sec)

 MySQL  localhost:3306 ssl  performance_schema  SQL > SELECT * FROM data_locks;
+--------+--------------------------------------+-----------------------+-----------+----------+---------------+-------------+----------------+-------------------+------------+-----------------------+-----------+-----------+-------------+-----------+
| ENGINE | ENGINE_LOCK_ID                       | ENGINE_TRANSACTION_ID | THREAD_ID | EVENT_ID | OBJECT_SCHEMA | OBJECT_NAME | PARTITION_NAME | SUBPARTITION_NAME | INDEX_NAME | OBJECT_INSTANCE_BEGIN | LOCK_TYPE | LOCK_MODE | LOCK_STATUS | LOCK_DATA |
+--------+--------------------------------------+-----------------------+-----------+----------+---------------+-------------+----------------+-------------------+------------+-----------------------+-----------+-----------+-------------+-----------+
| INNODB | 140413401562576:1065:140413285501144 |                  2570 |        47 |        5 | d1            | t1          | NULL           | NULL              | NULL       |       140413285501144 | TABLE     | IX        | GRANTED     | NULL      |
| INNODB | 140413401561704:1065:140413285495192 |                  2569 |        48 |        7 | d1            | t1          | NULL           | NULL              | NULL       |       140413285495192 | TABLE     | IX        | GRANTED     | NULL      |
+--------+--------------------------------------+-----------------------+-----------+----------+---------------+-------------+----------------+-------------------+------------+-----------------------+-----------+-----------+-------------+-----------+
2 rows in set (0.0206 sec)

 MySQL  localhost:3306 ssl  performance_schema  SQL > SELECT SUM(count_star), SUM(sum_timer_wait) FROM events_waits_summary_by_instance WHERE event_name = 'wait/synch/mutex/innodb/autoinc_mutex';
+-----------------+---------------------+
| SUM(count_star) | SUM(sum_timer_wait) |
+-----------------+---------------------+
|             349 |            25780608 |
+-----------------+---------------------+
1 row in set (0.0009 sec)

という訳で、「バルクロードの先頭から最後まではAUTO_INCREMENTが一貫していなきゃイヤン！」という場合は innodb_autoinc_lock_mode= 1 の時がいいかもですね。
（ SELECT last_insert_id() からの SELECT .. FROM id > さっきの値 でバルクロードしたレコード(だけ)をフェッチできると期待しているような場合かな… )

​

MyNA 望年LT大会2019に参加してきました

MyNA(日本MySQLユーザ会) 望年LT大会2019＠赤坂 - connpass に参加してきました。

昨年に引き続き SCSK さんのご支援で nomuno さんでの開催。美味しいごはんとお酒をありがとうございましたm(＿ ＿)m

---

終わってしまってからでなんなんですが「どんな雰囲気なの？」「フツーのLT大会と違うの？」みたいなのを（事前に）何回か聞かれたので紹介します。

• 飲みながらしゃべりたい人がしゃべりたいことをしゃべります
  • そういう意味では MySQL Casual Talks にも近いですがLT枠onlyでした（ただし厳密に5分きっかりなスタイルではない）
• 椅子に座って全員同じ方向を向いて始まるというスタイルでは ない です
  • 立食パーティーをしながら、一角ではLTやってるという感じ
  • 興味があれば聞いてもいいし、お酒を嗜みながら他の人と談笑するもいいし
    • これは珍しいスタイルかも知れません
• 赤坂です
  • だいじなことなのでもう一度言います、赤坂です（少なくとも2018と2019は赤坂でした）

---

私はここ最近 ~(といってもそろそろ熱が冷め始めてきていて困っている)~ MySQL Shellを使って、5分で(間に合わなかった) InnoDB Clusterのサンドボックスを構築するのにチャレンジしました。

• 日々の覚書: MySQL Shellのdba.deploySandboxInstanceでサクッとmysqldを起動する
• 日々の覚書: InnoDB Clusterの構築だけMySQL Shellでやって、運用はSQLインターフェイスでやるのはアリ？

( ´-｀).oO（記事を書いた当時はWSL1で、昨日の時点ではWSL2を使っていて、かかる時間の想定に若干のブレが（いいわけ

個人的には keny_lala さんの「MySQLの気持ちになって答えるクイズ」が面白かったです！ スライド公開期待 :)

しかし後で聞いてみたら「一応LTは準備してきてた(けど発表{しな|できな}かった)」みたいな人が多くて、そういう話こそ聞きたかった感もあり、そういうイベントしたいなって思った赤坂の夜でした！

あと、作って以来渡そう渡そうと思っていた マイナくんのウインドブレーカー をようやく堤井さんに渡せたので俺の2019年は無事に終わりそうです。

来年もよろしくお願いしますm(＿ ＿)m

​