日々の覚書: 2月 2017

2017/02/20

MariaDB 10.2.4の --flashback を触ってみる

ドキュメントはこちら。
Flashback - MariaDB Knowledge Base

"Common use case" をとっても雑に説明すると、
- `--flashback` をつけたmysqldが吐いたバイナリーログに対して
- `mysqlbinlog --flashback` でデコードすると、フラッシュバックっぽいことができる
という感じ。

まず、サーバー側の `--flashback` について。

https://github.com/MariaDB/server/blob/mariadb-10.2.4/sql/mysqld.cc#L9541-L9551

binlog_format= ROWにセットしてくれるだけぽい。 `--flashback` じゃなくても `--log-bin --binlog_format=ROW --binlog-row-format=FULL` で吐かせたバイナリーログでも大丈夫だった。ので、特に気にしなくて良さそう。

mysqlbinlog側の `--flashback` が肝。

https://github.com/MariaDB/server/blob/mariadb-10.2.4/client/mysqlbinlog.cc#L1455-L1468

↑で順番にイベントを読み込んでバッファに入れておいたものを（この時点でchange_to_flashback_eventを呼んでフラッシュバック用にクエリーを書き換えているぽい）
↓で後ろから順番に取り出す。

https://github.com/MariaDB/server/blob/mariadb-10.2.4/client/mysqlbinlog.cc#L3019-L3034

バイナリーログのイベントを逆転させてるのは↓のあたり。

https://github.com/MariaDB/server/blob/mariadb-10.2.4/sql/log_event.cc#L3417-L3460

というわけで、

MariaDB [(none)]> use d2;
MariaDB [d2]> create table t2 (num serial, val varchar(32));
MariaDB [d2]> INSERT INTO t2 VALUES (1, 'eins');
MariaDB [d2]> UPDATE t2 SET val = 'one' WHERE num = 1;

なんてことをやったbinlogを見ると、

C:\Users\yoku0825\Desktop\mariadb-10.2.4-winx64>bin\mysqlbinlog.exe -vv data\myhost-bin.000002
..
use `d2`/*!*/;
SET TIMESTAMP=1487580544/*!*/;
create table t2 (num serial, val varchar(32))
/*!*/;
# at 745
#170220 17:49:20 server id 1  end_log_pos 787 CRC32 0x3a401e2f  GTID 0-1-9 trans

/*!100001 SET @@session.gtid_seq_no=9*//*!*/;
BEGIN
/*!*/;
# at 787
# at 843
#170220 17:49:20 server id 1  end_log_pos 843 CRC32 0xee91dd13  Annotate_rows:
#Q> INSERT INTO t2 VALUES (1, 'eins')
#170220 17:49:20 server id 1  end_log_pos 889 CRC32 0xfac503f9  Table_map: `d2`.`t2` mapped to number 23
# at 889
#170220 17:49:20 server id 1  end_log_pos 936 CRC32 0x9cc43e21  Write_rows: table id 23 flags: STMT_END_F

BINLOG '
kK2qWBMBAAAALgAAAHkDAAAAABcAAAAAAAEAAmQyAAJ0MgACCA8CIAAC+QPF+g==
kK2qWBcBAAAALwAAAKgDAAAAABcAAAAAAAEAAv/8AQAAAAAAAAAEZWlucyE+xJw=
'/*!*/;
### INSERT INTO `d2`.`t2`
### SET
###   @1=1 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @2='eins' /* VARSTRING(32) meta=32 nullable=1 is_null=0 */
# at 936
#170220 17:49:20 server id 1  end_log_pos 967 CRC32 0x7e5f60b7  Xid = 9
COMMIT/*!*/;
# at 967
#170220 17:49:31 server id 1  end_log_pos 1009 CRC32 0x55d0a0bc         GTID 0-1-10 trans
/*!100001 SET @@session.gtid_seq_no=10*//*!*/;
BEGIN
/*!*/;
# at 1009
# at 1071
#170220 17:49:31 server id 1  end_log_pos 1071 CRC32 0xb32de27c         Annotate_rows:
#Q> UPDATE t2 SET val = 'one' WHERE num = 1
#170220 17:49:31 server id 1  end_log_pos 1117 CRC32 0x4ee231f4         Table_map: `d2`.`t2` mapped to number 23
# at 1117
#170220 17:49:31 server id 1  end_log_pos 1178 CRC32 0xe87e056f         Update_rows: table id 23 flags: STMT_END_F

BINLOG '
m62qWBMBAAAALgAAAF0EAAAAABcAAAAAAAEAAmQyAAJ0MgACCA8CIAAC9DHiTg==
m62qWBgBAAAAPQAAAJoEAAAAABcAAAAAAAEAAv///AEAAAAAAAAABGVpbnP8AQAAAAAAAAADb25l
bwV+6A==
'/*!*/;
### UPDATE `d2`.`t2`
### WHERE
###   @1=1 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @2='eins' /* VARSTRING(32) meta=32 nullable=1 is_null=0 */
### SET
###   @1=1 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @2='one' /* VARSTRING(32) meta=32 nullable=1 is_null=0 */
# at 1178
#170220 17:49:31 server id 1  end_log_pos 1209 CRC32 0xdd417c80         Xid = 10

COMMIT/*!*/;
..

これが、 `--flashback` をつけるとこうなる。

C:\Users\yoku0825\Desktop\mariadb-10.2.4-winx64>bin\mysqlbinlog.exe --flashback -vv data\myhost-bin.000002
..

BEGIN/*!*/;
#170220 17:49:31 server id 1  end_log_pos 1178 CRC32 0xe87e056f         Update_rows: table id 23 flags: STMT_END_F

BINLOG '
m62qWBMBAAAALgAAAF0EAAAAABcAAAAAAAEAAmQyAAJ0MgACCA8CIAAC9DHiTg==
m62qWBgBAAAAPQAAAJoEAAAAABcAAAAAAAEAAv///AEAAAAAAAAAA29uZfwBAAAAAAAAAARlaW5z
bwV+6A==
'/*!*/;
### UPDATE `d2`.`t2`
### WHERE
###   @1=1 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @2='one' /* VARSTRING(32) meta=32 nullable=1 is_null=0 */
### SET
###   @1=1 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @2='eins' /* VARSTRING(32) meta=32 nullable=1 is_null=0 */
COMMIT
/*!*/;
#170220 17:49:20 server id 1  end_log_pos 967 CRC32 0x7e5f60b7  Xid = 9
BEGIN/*!*/;
#170220 17:49:20 server id 1  end_log_pos 936 CRC32 0x9cc43e21  Delete_rows: table id 23 flags: STMT_END_F

BINLOG '
kK2qWBMBAAAALgAAAHkDAAAAABcAAAAAAAEAAmQyAAJ0MgACCA8CIAAC+QPF+g==
kK2qWBkBAAAALwAAAKgDAAAAABcAAAAAAAEAAv/8AQAAAAAAAAAEZWlucyE+xJw=
'/*!*/;
### DELETE FROM `d2`.`t2`
### WHERE
###   @1=1 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @2='eins' /* VARSTRING(32) meta=32 nullable=1 is_null=0 */
COMMIT
/*!*/;
..

`--flashback` の方は時間降順に並んでいるのがちょっと面白い。
これで、`--start-datetime` で時間を指定してやれば、それ以降のDMLをフラッシュバック（個人的にはリバートと呼びたい）するためのDMLが手に入って、それを適用すればフラッシュバック（個人的には略）完了。

RBRだからそれなりには時間がかかるはず。やっぱリバートで良いじゃん。。

デフォルトのbinlog-row-imageはfullなので、変更前後をすべて記録していてます。なので通常変更前→変更後、を変更後をキーに変更前、に戻していくんじゃないですかね? https://t.co/dnyg3Qbe5Q
— 君の名は? シン明治! (@meijik) 2017年2月6日

めいじさんエスパー！ :)

この辺（ `--review` みたいなのがある）は後々なのかな（このマクロが有効化されてる箇所は見当たらなかった）

https://github.com/MariaDB/server/blob/mariadb-10.2.4/client/mysqlbinlog.cc#L1587-L1599

2017/02/13

mysqlimportはトランザクションがきくのかどうか

TL;DR

- 1テキストファイル内でのトランザクションは利く
- 複数テキストファイル食わせた時のテキストファイル間のトランザクションは ~~autocommit 依存~~ 効かない
- というか、 autocommit=0 だと mysqlimport さん使えないことが判明
- ~~ただし --use-threads を指定していない場合に限る（使ってる場合はそもそも別のトランザクションとしてパラレルで実行される）~~

今は英語化した MySQL CasualのSlack でそんな話題があったから調べてみた。

ざっと mysqlimportのソースを追ってみたけど、なんかどうもトランザクションをハンドルしている箇所はなさげ。ということはコマンドラインクライアントで LOAD DATA INFILE する時と同じになるのかな？

というわけでここからテスト。

まずは準備。t1.txtとt2.txtをそれぞれ datadir/d1 の下に作る。
中身は何でもいい。

$ cat t1.txt
1       one
2       two

$ cat t2.txt
1       one
2       two

main関数を読む限り、 --use-threads の指定がない場合は左から順に引数を読んで LOAD DATA INFILE ステートメントに変換するので、t2の方をロックしてやればいいはず。

mysql57> SELECT @@session.autocommit, @@global.autocommit;
+----------------------+---------------------+
| @@session.autocommit | @@global.autocommit |
+----------------------+---------------------+
|                    1 |                   1 |
+----------------------+---------------------+
1 row in set (0.00 sec)

mysql57> BEGIN;
Query OK, 0 rows affected (0.00 sec)

mysql57> SELECT * FROM t2 FOR UPDATE;
Empty set (0.00 sec)

これで t1にはロードできるけどt2にはロードできない状態になったので、別のターミナルからmysqlimportを実行。

$ mysqlimport -S /usr/mysql/5.7.17/data/mysql.sock d1 t1.txt t2.txt
d1.t1: Records: 2  Deleted: 0  Skipped: 0  Warnings: 0

ターミナルはここでハングする（t2の行ロック待ちで）
Ctrl + Cで終了して、さっきのターミナルに戻る。

mysql57> show processlist;
+----+------+-----------+------+---------+------+-----------+------------------------------------------------------------+
| Id | User | Host      | db   | Command | Time | State     | Info                                                       |
+----+------+-----------+------+---------+------+-----------+------------------------------------------------------------+
| 77 | root | localhost | d1   | Query   |    0 | starting  | show processlist                                           |
| 86 | root | localhost | d1   | Query   |   11 | executing | LOAD DATA   INFILE 't2.txt' INTO TABLE `t2` IGNORE 0 LINES |
+----+------+-----------+------+---------+------+-----------+------------------------------------------------------------+
2 rows in set (0.00 sec)

ハマりどころその1。
mysqlimportのプロセスを終了しても、mysqldの中のスレッドは残ったままだったので、コイツをKILLする前にロックを解除すると

(゜∀。) あれなんでロードされてんの？

ってなる。

mysql57> KILL 86;
Query OK, 0 rows affected (0.00 sec)

mysql57> COMMIT; -- REPEATABLE-READをリフレッシュするためにコミット
Query OK, 0 rows affected (0.00 sec)

mysql57> SELECT * FROM t1;
+-----+------+
| num | val  |
+-----+------+
|   1 | one  |
|   2 | two  |
+-----+------+
2 rows in set (0.00 sec)

mysql57> SELECT * FROM t2;
Empty set (0.00 sec)

予想通り、t1に対するLOAD DATA INFILE, オートコミット, t2に対するLOAD DATA INFILE, 行ロック待ちの間にKILL、でt1だけにデータがロードされる。
一度t1とt2をTRUNCATEして次。

mysql57> SELECT @@session.autocommit, @@global.autocommit;
+----------------------+---------------------+
| @@session.autocommit | @@global.autocommit |
+----------------------+---------------------+
|                    0 |                   0 |
+----------------------+---------------------+
1 row in set (0.00 sec)

mysql57> BEGIN;
Query OK, 0 rows affected (0.00 sec)

mysql57> SELECT * FROM t2 FOR UPDATE;
Empty set (0.01 sec)

$ mysqlimport -S /usr/mysql/5.7.17/data/mysql.sock d1 t1.txt t2.txt
d1.t1: Records: 2  Deleted: 0  Skipped: 0  Warnings: 0


mysql57> show processlist;
+----+------+-----------+------+---------+------+-----------+------------------------------------------------------------+
| Id | User | Host      | db   | Command | Time | State     | Info                                                       |
+----+------+-----------+------+---------+------+-----------+------------------------------------------------------------+
| 87 | root | localhost | d1   | Query   |    0 | starting  | show processlist                                           |
| 88 | root | localhost | d1   | Query   |   16 | executing | LOAD DATA   INFILE 't2.txt' INTO TABLE `t2` IGNORE 0 LINES |
+----+------+-----------+------+---------+------+-----------+------------------------------------------------------------+
2 rows in set (0.00 sec)

mysql57> kill 88;
Query OK, 0 rows affected (0.00 sec)

mysql57> commit;
Query OK, 0 rows affected (0.00 sec)

mysql57> SELECT * FROM t1;
Empty set (0.00 sec)

mysql57> SELECT * FROM t2;
Empty set (0.00 sec)

autocommit= 0なので複数のLOAD DATA INFILEが全部1つのトランザクションとして扱われる。
なるほど。

…ここでなんか違和感を感じる。アレ？

ざっと mysqlimportのソースを追ってみたけど、なんかどうもトランザクションをハンドルしている箇所はなさげ。ということはコマンドラインクライアントで LOAD DATA INFILE する時と同じになるのかな？

ん？ autocommit=0 でコマンドラインクライアントからLOAD DATA INFILE投げて、commitせずにquitしたらデータ残らなくね？

$ mysqlimport -S /usr/mysql/5.7.17/data/mysql.sock d1 t1.txt t2.txt
d1.t1: Records: 2  Deleted: 0  Skipped: 0  Warnings: 0
d1.t2: Records: 2  Deleted: 0  Skipped: 0  Warnings: 0

$ mysqlimport -S /usr/mysql/5.7.17/data/mysql.sock d1 t1.txt t2.txt
d1.t1: Records: 2  Deleted: 0  Skipped: 0  Warnings: 0
d1.t2: Records: 2  Deleted: 0  Skipped: 0  Warnings: 0

$ mysqlimport -S /usr/mysql/5.7.17/data/mysql.sock d1 t1.txt t2.txt
d1.t1: Records: 2  Deleted: 0  Skipped: 0  Warnings: 0
d1.t2: Records: 2  Deleted: 0  Skipped: 0  Warnings: 0

$ mysqlimport -S /usr/mysql/5.7.17/data/mysql.sock d1 t1.txt t2.txt
d1.t1: Records: 2  Deleted: 0  Skipped: 0  Warnings: 0
d1.t2: Records: 2  Deleted: 0  Skipped: 0  Warnings: 0

$ mysqlimport -S /usr/mysql/5.7.17/data/mysql.sock d1 t1.txt t2.txt
d1.t1: Records: 2  Deleted: 0  Skipped: 0  Warnings: 0
d1.t2: Records: 2  Deleted: 0  Skipped: 0  Warnings: 0

:(；ﾞﾟ'ωﾟ'): 残ってない…残ってたら

mysqlimport: Error: 1062, Duplicate entry '1' for key 'num', when using table: t1

って言われるから…autocommit=0だと本当に残ってない…

2017/02/02

MySQL Casual Talks vol.10でトークしてきたMySQL的アンチパターン

昨夜の MySQL Casual Talks vol.10 は盛り上がりましたね！

総勢10名の登壇者ズがおよそ3時間にわたって繰り広げた **カジュアルな** トークの模様は↓にまとめました。

MySQL Casual Talks vol.10まとめ - Togetterまとめ

で、俺のヤーツは久々に（？）愚痴っぽい「これをやるとMySQLは死ぬ」あるいは「これをやるとMySQLerが疲弊する」みたいなのをまとめたやつでした。

ちなみにこれ去年の新卒研修で使った資料を 90% くらいリライトしたやつで（リライト #とは）、もともとはもうちょっと本来のSQLアンチパターンっぽい項目が多かったはず。

MySQLアンチパターン from yoku0825

ちょくちょく笑っていただけたようで何よりです。

MySQL Casual Talksに参加するような人自身はこんなことしないかも知れませんけど、油断していると足元から火が付いたりするので啓蒙活動にご活用ください。

360日問題あれほど言ってたのに #mysqlcasual
— Tatsuro Hisamori (@myfinder) 2017年2月1日

ほんとだよ！！！ _|￣|○

登録: 投稿 ( Atom )

GA