2018年10月17日水曜日

percona-toolkit 3.0.12とそれ以前のpt-ioprofileがCentOS 7.xで動かない件

TL;DR

  • strace の出力がちょっと変わったのでそれをひっかけられていない
  • Percona Toolkitへのバグレポはこちら
  • パッチは以下のとおり
    • 3.0.12の /usr/bin/pt-ioprofile では574行目だけど、この行を探せば他のバージョンでも適用できるはず
574c574
< /^Process/ { mode = "strace"; }
—
> /^(strace: )?Process/ { mode = "strace"; }

ちょっと前からなんかおかしいような気はしていた。
MySQL 8.0だからいけないのかなとか思っていたけど、よく考えれば pt-ioprofileシェルスクリプト だし中で lsofstrace を取って awk で頑張っているだけなので mysqld のバージョンは関係ないはずだ。
CentOSのバージョンのせいかと思って比べてみたらどうやら当たりの様子。
$ cat /etc/centos-release
CentOS release 6.10 (Final)

$ pt-ioprofile
Wed Oct 17 12:24:46 JST 2018
Tracing process ID 365
     total      pread       read     pwrite      write      fsync  fdatasync       open      close   getdents      lseek      fcntl filename
  4.430536   0.000000   0.000000   0.159895   0.000000   4.270641   0.000000   0.000000   0.000000   0.000000   0.000000   0.000000 /var/lib/mysql/ib_logfile0
  0.071731   0.000000   0.000000   0.003155   0.000000   0.061186   0.000000   0.000452   0.000301   0.000000   0.006448   0.000189 /var/lib/mysql/mysqlslap/t1.ibd
  0.052828   0.000000   0.000000   0.004702   0.000000   0.048126   0.000000   0.000000   0.000000   0.000000   0.000000   0.000000 /var/lib/mysql/ibdata1
  0.013654   0.000436   0.001654   0.000204   0.001798   0.000000   0.006763   0.000823   0.000716   0.000000   0.001260   0.000000 /var/lib/mysql/mysqlslap/t1.frm
  0.005068   0.000000   0.000000   0.000000   0.000000   0.005068   0.000000   0.000000   0.000000   0.000000   0.000000   0.000000 /var/lib/mysql/mysql/innodb_index_stats.ibd
  0.002342   0.000000   0.000000   0.000000   0.000000   0.002342   0.000000   0.000000   0.000000   0.000000   0.000000   0.000000 /var/lib/mysql/mysql/innodb_table_stats.ibd
  0.000917   0.000000   0.000176   0.000000   0.000000   0.000000   0.000000   0.000323   0.000233   0.000185   0.000000   0.000000 /dev/urandom
  0.000911   0.000000   0.000000   0.000000   0.000000   0.000000   0.000080   0.000549   0.000141   0.000141   0.000000   0.000000 /var/lib/mysql/mysqlslap/
  0.000628   0.000000   0.000000   0.000000   0.000140   0.000000   0.000000   0.000376   0.000112   0.000000   0.000000   0.000000 /var/lib/mysql/mysqlslap/db.opt
  0.000400   0.000000   0.000000   0.000000   0.000000   0.000000   0.000000   0.000213   0.000000   0.000000   0.000187   0.000000 /var/lib/mysql/mysql/event.MYD
  0.000126   0.000000   0.000000   0.000000   0.000000   0.000000   0.000000   0.000126   0.000000   0.000000   0.000000   0.000000 /var/lib/mysql/mysql/proc.MYD
同じMySQL 5.7.23にmysqlslapをかけながら pt-ioprofile をぶっ放しても、CentOS 7.5の方は何も返してくれない。
$ cat /etc/centos-release
CentOS Linux release 7.5.1804 (Core)

$ pt-ioprofile
Wed Oct 17 12:07:17 JST 2018
Tracing process ID 27170
     total filename
取り敢えずまあ採取した stracelsof の結果を捨てずに残しておく --save-samples オプションなど使いつつ、 bash -x で何をしているのか調べていく。
$ bash -x /usr/bin/pt-ioprofile --save-samples /tmp/
..
+ _lsof 27170
..
+ strace -T -s 0 -f -p 27170
..
+ awk -f /tmp/pt-ioprofile.7393.52pjmz/tabulate_strace.awk /tmp/pt-ioprofile
+ awk -f /tmp/pt-ioprofile.7393.52pjmz/summarize_strace.awk /tmp/pt-ioprofile.7393.52pjmz/tabulated_samples
+ '[' filename '!=' all ']'
+ head -n1 /tmp/pt-ioprofile.7393.52pjmz/summarized_samples
     total filename
+ tail -n +2 /tmp/pt-ioprofile.7393.52pjmz/summarized_samples
+ sort -rn -k1
+ rm_tmpdir
+ '[' -n /tmp/pt-ioprofile.7393.52pjmz ']'
+ '[' -d /tmp/pt-ioprofile.7393.52pjmz ']'
+ rm -rf /tmp/pt-ioprofile.7393.52pjmz
+ PT_TMPDIR=
+ exit 0

$ ll /tmp/pt-ioprofile
-rw-r--r-- 1 yoku0825 yoku0825 128606368 Oct 17 12:48 /tmp/pt-ioprofile
lsofstrace はちゃんと取れているっぽい。
$ less /tmp/pt-ioprofile
+ local pid=27170
+ lsof -p 27170
COMMAND   PID     USER   FD   TYPE             DEVICE  SIZE/OFF      NODE NAME
mysqld  27170 yoku0825  cwd    DIR              253,0      4096 134572596 /usr/mysql/5.7.23/data
mysqld  27170 yoku0825  rtd    DIR              253,0      4096       128 /
mysqld  27170 yoku0825  txt    REG              253,0 686787152 201877015 /usr/mysql/5.7.23/bin/mysqld
..
strace: Process 27170 attached with 36 threads
[pid 27203] futex(0x7ff4ec03ded4, FUTEX_WAIT_PRIVATE, 347, NULL <unfinished ...>
[pid 27202] futex(0x7ff4ec03de44, FUTEX_WAIT_PRIVATE, 391, NULL <unfinished ...>
[pid 27201] futex(0x7ff4ec03ddb4, FUTEX_WAIT_PRIVATE, 455, NULL <unfinished ...>
..
じゃあまあなんか集計部分がおかしいのかな、と awk を叩いてみようと思うも
$ awk -f /tmp/pt-ioprofile.7393.52pjmz/tabulate_strace.awk /tmp/pt-ioprofile
awk: fatal: can't open source file `/tmp/pt-ioprofile.7393.52pjmz/tabulate_strace.awk' for reading (No such file or directory)
(・3・)アルェー
と思ったら、 bash -x の最後の方で /tmp/pt-ioprofile.7393.52pjmz を消してた。
どうやら一度テンポラリーディレクトリーにawkスクリプトを書き出した後にawk -fで食わせているっぽい。
rm_tmpdir から rm -rf の部分を消し去ってリトライ。
$ bash -x /usr/bin/pt-ioprofile --save-samples /tmp/pt-ioprofile
..
+ awk -f /tmp/pt-ioprofile.7897.sdNdwz/tabulate_strace.awk /tmp/pt-ioprofile
+ awk -f /tmp/pt-ioprofile.7897.sdNdwz/summarize_strace.awk /tmp/pt-ioprofile.7897.sdNdwz/tabulated_samples
..

$ ll /tmp/pt-ioprofile.7897.sdNdwz/
total 12
-rw-r--r-- 1 yoku0825 yoku0825   20 Oct 17 12:57 summarized_samples
-rw-r--r-- 1 yoku0825 yoku0825 3408 Oct 17 12:57 summarize_strace.awk
-rw-r--r-- 1 yoku0825 yoku0825    0 Oct 17 12:57 tabulated_samples
-rw-r--r-- 1 yoku0825 yoku0825 3547 Oct 17 12:57 tabulate_strace.awk

$ awk -f /tmp/pt-ioprofile.7897.sdNdwz/tabulate_strace.awk /tmp/pt-ioprofile
あれ何も起こらない…
比較用のCentOS 6.10では *_samples も0バイトじゃないし、 awk の結果も返ってくる。
$ ll /tmp/pt-ioprofile.812.PmCXAO
total 164
-rw-r--r-- 1 root root   1765 Oct 17 12:59 summarized_samples
-rw-r--r-- 1 root root   3408 Oct 17 12:59 summarize_strace.awk
-rw-r--r-- 1 root root 154779 Oct 17 12:59 tabulated_samples
-rw-r--r-- 1 root root   3547 Oct 17 12:59 tabulate_strace.awk

$ awk -f /tmp/pt-ioprofile.812.PmCXAO/tabulate_strace.awk /tmp/pt-ioprofile
517 open 62 0 0.000032 /dev/urandom
517 read 62 32 0.000016 /dev/urandom
517 close 62 0 0.000015 /dev/urandom
517 open directory) 0 0.000730 /var/lib/mysql/mysqlslap/
517 open 62 0 0.000079 /var/lib/mysql/mysqlslap/db.opt
517 write 62 65 0.000024 /var/lib/mysql/mysqlslap/db.opt
..
ということで、 tabulate_strace.awk のどこかが悪そう。
…というのを頑張った結果、最初に書いたパッチにたどり着いたのでしたん。

2018年10月10日水曜日

MySQL 8.0ではカラムのリネームに ALTER TABLE RENAME COLUMN 構文が使える

TL;DR


今まではこう
mysql57 40> CREATE TABLE t1 (num int unsigned not null, val varchar(32) not null, PRIMARY KEY(num), FULLTEXT KEY (val) WITH PARSER ngram);
Query OK, 0 rows affected (0.06 sec)

mysql57 40> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` int(10) unsigned NOT NULL,
  `val` varchar(32) NOT NULL,
  PRIMARY KEY (`num`),
  FULLTEXT KEY `val` (`val`) /*!50100 WITH PARSER `ngram` */
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4
1 row in set (0.00 sec)

mysql57 40> ALTER TABLE t1 CHANGE val abc varchar(32) NOT NULL;
Query OK, 0 rows affected (0.01 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql57 40> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` int(10) unsigned NOT NULL,
  `abc` varchar(32) NOT NULL,
  PRIMARY KEY (`num`),
  FULLTEXT KEY `val` (`abc`) /*!50100 WITH PARSER `ngram` */
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4
1 row in set (0.01 sec)
CHANGE の後にデータ型もつけなければいけなかったのが面倒だった。 NOT NULL をつけるのを忘れて死にかけたりした人も世の中には存在するんじゃなかろうか。
これがMySQL 8.0ではこうじゃ。
mysql80 24> CREATE TABLE t1 (num int unsigned not null, val varchar(32) not null, PRIMARY KEY(num), FULLTEXT KEY (val) WITH PARSER ngram);
Query OK, 0 rows affected (0.15 sec)

mysql80 24> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` int(10) unsigned NOT NULL,
  `val` varchar(32) COLLATE utf8mb4_ja_0900_as_cs NOT NULL,
  PRIMARY KEY (`num`),
  FULLTEXT KEY `val` (`val`) /*!50100 WITH PARSER `ngram` */
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_ja_0900_as_cs
1 row in set (0.00 sec)

mysql80 24> ALTER TABLE t1 RENAME COLUMN val TO abc;
Query OK, 0 rows affected (0.04 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql80 24> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` int(10) unsigned NOT NULL,
  `abc` varchar(32) COLLATE utf8mb4_ja_0900_as_cs NOT NULL,
  PRIMARY KEY (`num`),
  FULLTEXT KEY `val` (`abc`) /*!50100 WITH PARSER `ngram` */
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_ja_0900_as_cs
1 row in set (0.00 sec)
MySQL 5.7で追加されたALTER TABLE .. RENAME INDEX が好評だったんですかね!
ただし、generated columnがあると古い方のカラムを参照し続けるため ALTER TABLE が転ける。これは CHANGE でも転けるんだけれども。
mysql80 24> ALTER TABLE t1 ADD v_abc varchar(32) AS (MD5(abc)) NOT NULL;
Query OK, 0 rows affected (0.05 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql80 24> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` int(10) unsigned NOT NULL,
  `abc` varchar(32) COLLATE utf8mb4_ja_0900_as_cs NOT NULL,
  `v_abc` varchar(32) COLLATE utf8mb4_ja_0900_as_cs GENERATED ALWAYS AS (md5(`abc`)) VIRTUAL NOT NULL,
  PRIMARY KEY (`num`),
  FULLTEXT KEY `val` (`abc`) /*!50100 WITH PARSER `ngram` */
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_ja_0900_as_cs
1 row in set (0.00 sec)

mysql80 24> ALTER TABLE t1 RENAME COLUMN abc TO def;
ERROR 1054 (42S22): Unknown column 'abc' in 'generated column function'

mysql80 24> ALTER TABLE t1 CHANGE abc def varchar(32) NOT NULL;
ERROR 1054 (42S22): Unknown column 'abc' in 'generated column function'
綺麗に転けるならまだしも、 RENAME TABLE でたまにやるみたいにカラムをスワップさせようと思うと大変なことになる。
mysql80 24> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` int(10) unsigned NOT NULL,
  `abc` varchar(32) COLLATE utf8mb4_ja_0900_as_cs NOT NULL,
  `v_abc` varchar(32) COLLATE utf8mb4_ja_0900_as_cs GENERATED ALWAYS AS (md5(`abc`)) VIRTUAL NOT NULL,
  `def` varchar(32) COLLATE utf8mb4_ja_0900_as_cs DEFAULT NULL,
  PRIMARY KEY (`num`),
  FULLTEXT KEY `val` (`abc`) /*!50100 WITH PARSER `ngram` */
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_ja_0900_as_cs
1 row in set (0.00 sec)

mysql80 24> SELECT * FROM t1;
+-----+-----+----------------------------------+------+
| num | abc | v_abc                            | def  |
+-----+-----+----------------------------------+------+
|   1 | one | f97c5d29941bfb1b2fdab0874906ab82 | NULL |
+-----+-----+----------------------------------+------+
1 row in set (0.00 sec)

mysql80 24> ALTER TABLE t1 RENAME COLUMN abc TO def, RENAME COLUMN def TO abc;
Query OK, 0 rows affected (0.08 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql80 24> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` int(10) unsigned NOT NULL,
  `def` varchar(32) COLLATE utf8mb4_ja_0900_as_cs NOT NULL,
  `v_abc` varchar(32) COLLATE utf8mb4_ja_0900_as_cs GENERATED ALWAYS AS (md5(`abc`)) VIRTUAL NOT NULL,
  `abc` varchar(32) COLLATE utf8mb4_ja_0900_as_cs DEFAULT NULL,
  PRIMARY KEY (`num`),
  FULLTEXT KEY `val` (`def`) /*!50100 WITH PARSER `ngram` */
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_ja_0900_as_cs
1 row in set (0.00 sec)

mysql80 24> SELECT * FROM t1;
+-----+-----+-------+------+
| num | def | v_abc | abc  |
+-----+-----+-------+------+
|   1 | one |       | NULL |
+-----+-----+-------+------+
1 row in set (0.01 sec)
VIRTUAL generated columnはビューとかストアドと一緒で名前でしか参照されないので、「カラムが存在しない」以外ではエラーにならなさげ。
…あれ? これSTOREDだとどうなるんだ?
mysql80 24> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` int(10) unsigned NOT NULL,
  `abc` varchar(32) COLLATE utf8mb4_ja_0900_as_cs NOT NULL,
  `def` varchar(32) COLLATE utf8mb4_ja_0900_as_cs DEFAULT NULL,
  `v_abc` varchar(32) COLLATE utf8mb4_ja_0900_as_cs GENERATED ALWAYS AS (md5(`abc`)) STORED,
  PRIMARY KEY (`num`),
  FULLTEXT KEY `val` (`abc`) /*!50100 WITH PARSER `ngram` */
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_ja_0900_as_cs
1 row in set (0.00 sec)

mysql80 24> SELECT * FROM t1;
+-----+-----+------+----------------------------------+
| num | abc | def  | v_abc                            |
+-----+-----+------+----------------------------------+
|   1 | one | NULL | f97c5d29941bfb1b2fdab0874906ab82 |
+-----+-----+------+----------------------------------+
1 row in set (0.00 sec)

mysql80 24> ALTER TABLE t1 RENAME COLUMN abc TO def, RENAME COLUMN def TO abc;
Query OK, 0 rows affected (0.02 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql80 24> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` int(10) unsigned NOT NULL,
  `def` varchar(32) COLLATE utf8mb4_ja_0900_as_cs NOT NULL,
  `abc` varchar(32) COLLATE utf8mb4_ja_0900_as_cs DEFAULT NULL,
  `v_abc` varchar(32) COLLATE utf8mb4_ja_0900_as_cs GENERATED ALWAYS AS (md5(`abc`)) STORED,
  PRIMARY KEY (`num`),
  FULLTEXT KEY `val` (`def`) /*!50100 WITH PARSER `ngram` */
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_ja_0900_as_cs
1 row in set (0.00 sec)

mysql80 24> SELECT * FROM t1;
+-----+-----+------+----------------------------------+
| num | def | abc  | v_abc                            |
+-----+-----+------+----------------------------------+
|   1 | one | NULL | f97c5d29941bfb1b2fdab0874906ab82 |
+-----+-----+------+----------------------------------+
1 row in set (0.00 sec)
アッー!
ばぐれぽばぐれぽ…φ(・ω・`)

した。もうちょっとわかりやすいテストケースをつけてある。

MySQL Bugs: #92727: Swapping column by ALTER TABLE RENAME COLUMN breaks STORED generated column
ワークアラウンド: OPTIMIZE TABLE したら再計算されたようで直った
mysql80 24> OPTIMIZE TABLE t1;
+-------+----------+----------+-------------------------------------------------------------------+
| Table | Op       | Msg_type | Msg_text                                                          |
+-------+----------+----------+-------------------------------------------------------------------+
| d1.t1 | optimize | note     | Table does not support optimize, doing recreate + analyze instead |
| d1.t1 | optimize | status   | OK                                                                |
+-------+----------+----------+-------------------------------------------------------------------+
2 rows in set (0.18 sec)

mysql80 24> SELECT * FROM t1;
+-----+-----+------+-------+
| num | def | abc  | v_abc |
+-----+-----+------+-------+
|   1 | one | NULL | NULL  |
+-----+-----+------+-------+
1 row in set (0.00 sec)

2018年10月3日水曜日

mysqlrouter.logの "keepalive" が気になる人へ

TL;DR

  • アレは単に一定間隔でログを吐いているだけ、ログ監視でもしない限り意味はない
  • 実は “[keepalive]” セクションに “interval” と “runs” が設定できる
  • もちろんマニュアルには何も書いてない

初めてMySQL Routerを使い始めたころから、ずっと「なんだろうこれ」「どことkeepaliveしてんねん」と思っていたこのログ。
$ sudo less /var/log/mysqlrouter/mysqlrouter.log
..
2018-04-03 16:33:00 INFO    [7fe222415700] keepalive
2018-04-03 16:34:00 INFO    [7fe222415700] keepalive
2018-04-03 16:35:00 INFO    [7fe222415700] keepalive
実はどことも通信なんてしていない。
ソースコードはここ。
mysql-router/keepalive.cc at 8.0.12 · mysql/mysql-router
120行もないコードの中でしていることといえば、(最終的には)wait_forで “interval * 1000” ミリ秒 スリープするのを “runs” で指定された回数(0の場合は無限に)繰り返すだけ。
確かに言われてみればコンフィグファイルに書いてあったけど…なんか腑に落ちない…。。
ちなみにこの “runs” 、満了すると黙って keepalive プラグインだけが沈黙する。なんか言えよ…。(ちなみにkeepalive以外のプラグインが有効でない場合は全プラグインがアンロードされてプロセスが正常終了する)
$ tail -f /var/log/mysqlrouter/mysqlrouter.log
2018-10-03 12:30:38 main INFO [7fd33d238780] Loading all plugins.
2018-10-03 12:30:38 main INFO [7fd33d238780]   plugin 'keepalive:' loading
2018-10-03 12:30:38 main INFO [7fd33d238780]   plugin 'routing:master' loading
2018-10-03 12:30:38 main INFO [7fd33d238780] Initializing all plugins.
2018-10-03 12:30:38 main INFO [7fd33d238780]   plugin 'keepalive' initializing
2018-10-03 12:30:38 main INFO [7fd33d238780]   plugin 'routing' initializing
2018-10-03 12:30:38 main INFO [7fd33d238780] Starting all plugins.
2018-10-03 12:30:38 main INFO [7fd339fec700]   plugin 'keepalive:' starting
2018-10-03 12:30:38 keepalive INFO [7fd339fec700] keepalive started with interval 6
2018-10-03 12:30:38 keepalive INFO [7fd339fec700] keepalive will run 3 time(s)
2018-10-03 12:30:38 keepalive INFO [7fd339fec700] keepalive
2018-10-03 12:30:38 main INFO [7fd3397eb700]   plugin 'routing:master' starting
2018-10-03 12:30:38 main INFO [7fd33d238780] Running.
2018-10-03 12:30:38 routing INFO [7fd3397eb700] [routing:master] started: listening on 127.0.0.1:13306
2018-10-03 12:30:44 keepalive INFO [7fd339fec700] keepalive
2018-10-03 12:30:50 keepalive INFO [7fd339fec700] keepalive
取り敢えず3年来の謎は解けたので良いとしよう。。

2018年10月2日火曜日

MySQL Router 8.0.12に同梱されているhttp_serverプラグインの謎について

TL;DR


もちろん MySQL :: MySQL Router 8.0 を全文検索しても “http” で引っかかってこない。
コミットを見るとMySQL Router 8.0.12から入ったっぽいけれど、もちろん MySQL :: MySQL Router Release Notes :: Changes in MySQL Router 8.0.12 (2018-07-27, General Availability) にも何も書いてない。
流石に “Linux Generic” やrpmパッケージには入ってなかったけど、特にcmakeにオプションを渡すでもなく、ソースビルドすると何の断りもなく勝手に http_server.so というプラグインが出来上がる。
$ cd mysql-router-8.0.12
$ cmake .
$ make
$ ll stage/lib/mysqlrouter/http*
-rwxrwxr-x 1 yoku0825 yoku0825 494096 Oct  2 14:59 stage/lib/mysqlrouter/http_server.so
名前から察するに、全国 1.000000人のファンを擁するMySQL HTTP Plugin的な感じなのかしらん。MySQL RouterがHTTPをしゃべって、裏ではMySQLプロトコルでmysqldとやり取りしてくれる…的な。
(MySQL HTTP Pluginについてはこのへん… 日々の覚書: MySQLジャンキーにngx_mrubyを与えた結果
http_server_plugin.cc を見る限り、 [http_serevr] セクションを見つけると立ち上がるらしい。
デフォルトは 0.0.0.0:5555バインド されるようで、 static_folder というパラメーターもあるようだ。
…他は?;
取り敢えず試してみる。
plugin_folderをビルドしたパスに合わせるのと、最後に “[http_server]” とセクションだけ定義してやる。
$ cp packaging/rpm-oel/mysqlrouter.conf ./mysqlrouter.conf
$ vim ./mysqlrouter.conf
..
plugin_folder = /home/yoku0825/mysql-router-8.0.12/stage/lib/mysqlrouter
..
[http_server]

$ sudo ./stage/bin/mysqlrouter --config=./mysqlrouter.conf

$ sudo less /var/log/mysqlrouter/mysqlrouter.log

2018-10-02 16:15:52 main INFO [7f250a835780] Loading all plugins.
2018-10-02 16:15:52 main INFO [7f250a835780]   plugin 'http_server:' loading
2018-10-02 16:15:52 main INFO [7f250a835780]   plugin 'keepalive:' loading
2018-10-02 16:15:52 main INFO [7f250a835780] Initializing all plugins.
2018-10-02 16:15:52 main INFO [7f250a835780]   plugin 'http_server' initializing
2018-10-02 16:15:52 http_server INFO [7f250a835780] listening on 0.0.0.0:5555
2018-10-02 16:15:52 main INFO [7f250a835780]   plugin 'keepalive' initializing
2018-10-02 16:15:52 main INFO [7f250a835780] Starting all plugins.
2018-10-02 16:15:52 main INFO [7f2507a67700]   plugin 'http_server:' starting
2018-10-02 16:15:52 main INFO [7f2507266700]   plugin 'keepalive:' starting
2018-10-02 16:15:52 keepalive INFO [7f2507266700] keepalive started with interval 60
2018-10-02 16:15:52 keepalive INFO [7f2507266700] keepalive
2018-10-02 16:15:52 main INFO [7f250a835780] Running.

$ curl localhost:5555
<HTML><HEAD>
<TITLE>404 Not Found</TITLE>
</HEAD><BODY>
<H1>Not Found</H1>
</BODY></HTML>
…しゃべった………。
static_folderを設定してもっかい起動してみる。
$ vim ./mysqlrouter.conf
..
[http_server]
static_folder= /home/yoku0825/mysql-router-8.0.12

$ sudo ./stage/bin/mysqlrouter --config=./mysqlrouter.conf

$ curl localhost:5555/src/http/src/http_server_plugin.cc
..
ファー、見えた…。
これ、いつか static_folder 以外にもURIとSQLのマッピングとかできるようになってmyhttpプラグイン再び、になるのかしらん。
期待age(?)

2018年9月27日木曜日

db tech showcase Tokyo 2018に参加してきました

2018/09/19~21の db tech showcase Tokyo 2018 | db tech showcase (このサイト、URLに年を示すものが何もないので来年になると上書きされちゃうんですよね) に参加してきました。
タイトルは「Dive into MySQL Error」、その名の通り、MySQLのエラーのちょっと深いところを覗いていくセッションです。
当日朝イチで雨にも関わらず足を運んでくださったみなさま、スライドをご覧になっていただいたみなさま、
3日目朝イチのセッションを1日目の懇親会終了後に即決してくださった インサイトテクノロジー の石川さん、松尾さん、
本当にありがとうございました。




1日目の懇親会が終わるまでは完全にオーディエンスの予定だったので資料は何も用意しておらず、取り敢えず @mita2 さんと @keny_lala さんの発表だけ聞ければいいかな、と思いながら、「MySQL UDFとGo言語で作るビッグデータ前処理基盤」 の話が気になって聞いていたりしました。

MySQL at Yahoo! JAPAN

  • 規模すごい…(小並感)
  • 「サイズが小さいのがたくさん増えていく」
  • Percona XtraDB Cluster

LINEのMySQL運用について

  • MySQLとRedis
  • 通称mondb+
  • HA用のスクリプトを自分でメンテするとつらいけど、ブラックボックスより安心しませんか? :-P

日本発!MySQL UDFとGo言語で作るビッグデータ前処理基盤

  • Goで作った超すごい住所名寄せライブラリーをMySQLのUDFから叩く
  • MySQLのUDFがどうこうじゃなくてGoで作ったライブラリーがすごい
  • 質疑時間で MySQLでUDF作ってる人 が「わたしはこうやってますよ」って言ってたのが面白かった
  • 繰り返しになるけれどMySQLどうでもいい、Goで作ったライブラリーが超すごい
    • ミーカンパニーさんもちゃんと認識していたw

1日目のセッションを聞いて、懇親会で ミーカンパニーさんGoのライブラリーを すごいすごい言って、いい感じに酔っぱらったところで3日目の登壇を快諾していただき(その場にいた @tadayama_jp さんが「俺の時は怒られたのに…」って仰ってて超笑った(そこに立ってらしたのを認識してなかったので))、半日でスライドを仕上げて金曜日に至りました。
今年はなんか忙しさにかまけて、一日中いる日も無かったし飲んだのも初日だけでしたが、セッションやらせてもらってすごく楽しうございました。
どうもありがとうございました。

「max_allowed_packetの基本的な動き」がどうしてそうなるのかのはなし

TL;DR

  • 1SQLのサイズ上限は、max_allowed_packetとnet_buffer_lengthで制御される。
  • max_allowed_packetはグローバルにデフォルト値を持ち、コネクション確立時にセッションにコピーされ、セッション変数は読み込み専用である。(セッションに適用するにはconnectなど再接続が必要)
  • net_buffer_lengthはグローバルにデフォルト値を持ち、コネクション確立時にセッションにコピーされ、セッション変数も変更可能である。
  • net_buffer_length => max_allowed_packetの場合、net_buffer_lengthが1SQLの上限値になる。
  • net_buffer_length < max_allowed_packetの場合、max_allowed_packetが1SQLの上限値になる。
とまとめられているが、これは

ということ。

まず、 max_allowed_packet の上限に引っかかった時に出るエラーである、 “Got a packet bigger than ‘max_allowed_packet’ bytes” からたどっていくことにする。
(See also Dive into MySQL Error - Speaker Deck
ソースコードは5.7.23のものにしていますよん。
$ grep "max_allowed_packet" include/mysqld_ername.h
{ "ER_NET_PACKET_TOO_LARGE", 1153, "Got a packet bigger than \'max_allowed_packet\' bytes" },
{ "ER_TOO_LONG_STRING", 1162, "Result string is longer than \'max_allowed_packet\' bytes" },
{ "ER_WARN_ALLOWED_PACKET_OVERFLOWED", 1301, "Result of %s() was larger than max_allowed_packet (%ld) - truncated" },
MySQLへのJDBC接続で、とあるバグを踏むまでの話 -(1)「max_allowed_packet」の基本的な働き - なからなLife ではバルクインサートだったので、 ER_NET_PACKET_TOO_LARGE の方だと思う。
$ grep -r ER_NET_PACKET_TOO_LARGE . | grep -v mysql-test
./include/sql_state.h:{ ER_NET_PACKET_TOO_LARGE                 ,"08S01", "" },
./include/mysqld_ername.h:{ "ER_NET_PACKET_TOO_LARGE", 1153, "Got a packet bigger than \'max_allowed_packet\' bytes" },
./include/mysqld_error.h:#define ER_NET_PACKET_TOO_LARGE 1153
./libmysql/libmysql.c:      else if (net->last_errno == ER_NET_PACKET_TOO_LARGE)
./sql-common/client.c:    set_mysql_error(mysql, net->last_errno == ER_NET_PACKET_TOO_LARGE ?
./sql-common/client.c:    if (net->last_errno == ER_NET_PACKET_TOO_LARGE)
./sql/net_serv.cc:    net->last_errno= ER_NET_PACKET_TOO_LARGE;
./sql/net_serv.cc:    my_error(ER_NET_PACKET_TOO_LARGE, MYF(0));
./sql/rpl_rli_pdb.cc:    with error ER_NET_PACKET_TOO_LARGE.
./sql/rpl_slave.cc:          mi->report(ERROR_LEVEL, ER_NET_PACKET_TOO_LARGE,
./sql/share/errmsg-utf8.txt:ER_NET_PACKET_TOO_LARGE 08S01
./include のやつは定義系だし、 ./libmysql, ./sql-common のやつは == で比較しているのでこのエラーを受け取った後にどうするかの処理だろう。
./sql/rpl_* はレプリケーション関連なので取り敢えずパスして、 ./sql/net_serv.cc の中で代入しているからここが本丸のような気がする。
grepで引っかかった2行は net_realloc という関数の中に入っていて、名前から察するにここが
パケットメッセージバッファーは net_buffer_length バイトに初期化されますが、必要に応じて max_allowed_packet バイトまで大きくできます。
のパケットメッセージバッファーを大きくする処理なのであろう。
コイツが呼ばれているところを探しに行く。
$ grep -r net_realloc .
./include/mysql.h.pp:my_bool net_realloc(NET *net, size_t length);
./include/mysql_com.h:my_bool net_realloc(NET *net, size_t length);
./libmysql/libmysql.c:    res= net_realloc(net, buf_length + length);
./sql/net_serv.cc:my_bool net_realloc(NET *net, size_t length)
./sql/net_serv.cc:  DBUG_ENTER("net_realloc");
./sql/net_serv.cc:      must match the size of the buffer allocated in net_realloc().
./sql/net_serv.cc:  if ((pkt_data_len >= net->max_packet) && net_realloc(net, pkt_data_len))
./libmysql とはlibmysqlclient.so(Connector/C)のコードなので外すとするとまだ同じ ./sql/net_serv.cc の行。開いてみると net_read_packet の中で、「今のパケットメッセージバッファーよりもデータが大きければ net_realloc 」な記述に当たる。
というわけで、
  • net_buffer_length => max_allowed_packetの場合、net_buffer_lengthが1SQLの上限値になる。
の理由は、 net_buffer_length のサイズでアロケートされたパケットメッセージバッファが足りなくなって拡張しようとした時に初めて max_allowed_packet と比較されてエラーに分岐するから、でした。
Cこわくないよ!
(あっdbts2018のブログがまだ下書きn