2013年12月20日金曜日

Mroongaのロックが突き刺さるとどうなるか

むるーん、ガッ(挨拶
このエントリーは 全文検索エンジンGroonga Advent Calendar 2013 の20日目です。

みなさん、最近、ロック刺さりましたか?
クラッシュ以外でそうそう刺さることはないと思うんですが、いざ刺さるとどうなるのか…というのは予め考えておいた方が良いと思います(こんなエントリーを書いている時点でお察しください)

復旧作業については @yoshi_kenさん の Y-Ken Studio: groonga/mroongaの.mrnファイルがlock failedとなった場合の復旧方法 が詳しいですのでそちらで。

クラッシュして刺さるなら、クラッシュした時点で諸々通知されたりサービスから切り離されているので、まあそんなに困りはしないんですが、*何故かクラッシュせずに刺さってしまった場合* の動きは(当然)かなりシビアなものになります。

mysql> 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`)
) ENGINE=mroonga DEFAULT CHARSET=utf8
1 row in set (0.02 sec)

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

まあ、こんなテーブルを作るわけです。

ロックの刺し方(どのプロセスも触っていないのに、mrnファイルがロックされたまま解放されない状態の作り方)は すとーさん にTwitterで教えてもらいました。



$ /usr/ruby/2.0.0/bin/ruby -e 'require "groonga"; Groonga::Database.open("/usr/local/mysql/data/d1.mrn"); Groonga["t1"].lock; exit'

と、こう刺してやると、

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

mysql>
mysql> DELETE FROM t1 WHERE num= 1;

SELECTはできるけど、DELETEは返ってこなくなります。
これは良い。別に良い。想定通りの動作です。
困る(?)のはここから後。

mysql> SELECT @@global.lock_wait_timeout;
+----------------------------+
| @@global.lock_wait_timeout |
+----------------------------+
|                          1 |
+----------------------------+
1 row in set (0.00 sec)
mysql> SHOW PROCESSLIST;
+----+------+-----------+------+---------+------+----------+-----------------------------+
| Id | User | Host      | db   | Command | Time | State    | Info                        |
+----+------+-----------+------+---------+------+----------+-----------------------------+
|  3 | root | localhost | d1   | Query   |   63 | updating | DELETE FROM t1 WHERE num= 1 |
|  4 | root | localhost | d1   | Query   |    0 | init     | SHOW PROCESSLIST            |
+----+------+-----------+------+---------+------+----------+-----------------------------+
2 rows in set (0.00 sec)

実際ロックが競合してはいるんですが、lock_wait_timeoutは効きません。SHOW PROCESSLISTを見てやると、Stateはupdatingで、Lock待ち扱いではないですね。ちょっとgdbで覗いてみます。

$ gdb -p `pidof mysqld`
..
(gdb) thread apply all bt
..
Thread 3 (Thread 0x7fb2000be700 (LWP 8370)):
#0  0x0000003eb480ed2d in nanosleep () at ../sysdeps/unix/syscall-template.S:82
#1  0x00007fb200645f79 in grn_nanosleep (nanoseconds=) at ctx.c:81
#2  0x00007fb20074bc72 in grn_io_lock (ctx=0x7fb17400fb38, io=0x7fb17402b0c0, timeout=10000000) at io.c:1320
#3  0x00007fb20066df80 in grn_table_delete_by_id (ctx=0x7fb17400fb38, table=0x7fb17402adf0, id=1) at db.c:1784
#4  0x00007fb1e38ea422 in ha_mroonga::storage_delete_row (this=0x7fb17400e9e0, buf=0x7fb1740379f0 "\001")
    at ha_mroonga.cpp:6241
#5  0x0000000000590460 in handler::ha_delete_row (this=0x7fb17400e9e0, buf=0x7fb1740379f0 "\001")
    at /home/yoku0825/mysql-5.6.15/sql/handler.cc:7281
#6  0x0000000000823ebb in mysql_delete (thd=0x46a4ec0, table_list=0x7fb174005038, conds=0x7fb174005b58,
    order_list=, limit=18446744073709551615, options=0)
    at /home/yoku0825/mysql-5.6.15/sql/sql_delete.cc:373
#7  0x00000000006d5c4a in mysql_execute_command (thd=0x46a4ec0) at /home/yoku0825/mysql-5.6.15/sql/sql_parse.cc:3571
#8  0x00000000006d8607 in mysql_parse (thd=0x46a4ec0, rawbuf=, length=,
    parser_state=) at /home/yoku0825/mysql-5.6.15/sql/sql_parse.cc:6247
#9  0x00000000006d9db3 in dispatch_command (command=COM_QUERY, thd=0x46a4ec0, packet=0x7fb2000bdaf0 "\300Nj\004",
    packet_length=27) at /home/yoku0825/mysql-5.6.15/sql/sql_parse.cc:1334
#10 0x00000000006a23ed in do_handle_one_connection (thd_arg=)
    at /home/yoku0825/mysql-5.6.15/sql/sql_connect.cc:982
#11 0x00000000006a2522 in handle_one_connection (arg=)
    at /home/yoku0825/mysql-5.6.15/sql/sql_connect.cc:898
#12 0x0000000000972a37 in pfs_spawn_thread (arg=0x4766040) at /home/yoku0825/mysql-5.6.15/storage/perfschema/pfs.cc:1858
#13 0x0000003eb4807851 in start_thread (arg=0x7fb2000be700) at pthread_create.c:301
#14 0x0000003eb40e894d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
..

grn_io_lockがgrn_nanosleepを呼んでいるので、まあこの辺りですよね。
grn_io_lockはGroonga(not Mroonga)のlib/io.c に実装されています。

1290 grn_io_lock(grn_ctx *ctx, grn_io *io, int timeout)
1291 {
..
1296   for (count = 0;; count++) {
..
1306       if (!timeout || (timeout > 0 && timeout == count)) {
1307         GRN_LOG(ctx, GRN_LOG_WARNING,
1308                 "[DB Locked] time out(%d): io(%s) collisions(%d/%d)",
1309                 timeout, io->path, _ncolls, _ncalls);
1310         break;
1311       }
..
1320       grn_nanosleep(1000000);
1321       continue;
1322     }
..
1327 }

タイムアウトするまで自前でループしています。mysqld的にはMroongaストレージエンジンが勝手にループしているだけでロックを検知することができませんので、StateはLockedにはならず、Lock wait timeout exceededも起こりません(´・ω・`)

で、コイツがタイムアウトしてくれるまでが長い。

grn_nanosleep(1000000)なので、1回のスリープは1ms。timeoutはgrn_io_lockの呼び出し元すべてで10000000がハードコードされているので、10,000s。

…いちまんびょう? 3時間?;

GroongaのRedmineにも上がってる けど、長いし変更できないのはつらい。
取り敢えずゴニョゴニョしてtimeoutを1000msに変更してみる。

mysql> INSERT INTO t1 VALUES (1, 'one');
ERROR 1026 (HY000): grn_io_lock failed

$ perror 1026
MySQL error code 1026 (ER_ERROR_ON_WRITE): Error writing file '%-.200s' (errno: %d - %s)

$ less groonga.log
2013-12-19 18:04:52.165728|n|120c6700|io(d1.mrn.0000100) collisions(1000/117): lock failed 1000 times
2013-12-19 18:04:52.165901|w|120c6700|[DB Locked] time out(1000): io(d1.mrn.0000100) collisions(1000/117)
2013-12-19 18:04:52.165917|e|120c6700|grn_io_lock failed
..

うん、やっぱりこれ自分で設定したいなぁ。。(チラッチラッ
欲を言えばmy.cnfで設定したいし、更に言うならMySQLのlog-errorにも吐いてほしい。


同じくラッパーモード。

mysql> 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`)
) ENGINE=mroonga DEFAULT CHARSET=utf8 COMMENT='engine "innodb"'
1 row in set (0.00 sec)

$ /usr/ruby/2.0.0/bin/ruby -e 'require "groonga"; Groonga::Database.open("/usr/local/mysql/data/d2.mrn"); Groonga["t1"].lock; exit'

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

mysql> DELETE FROM t1 WHERE num= 1;

$ gdb -p `pidof mysqld`
..
(gdb) thread apply all bt
..
Thread 2 (Thread 0x7fd1a009d700 (LWP 16797)):
#0  0x0000003eb480ed2d in nanosleep () at ../sysdeps/unix/syscall-template.S:82
#1  0x00007fd20c481f79 in grn_nanosleep (nanoseconds=) at ctx.c:81
#2  0x00007fd20c587c72 in grn_io_lock (ctx=0x7fd17c012a18, io=0x7fd17c310200, timeout=10000000) at io.c:1320
#3  0x00007fd20c4a9f80 in grn_table_delete_by_id (ctx=0x7fd17c012a18, table=0x7fd17c330ae0, id=1) at db.c:1784
#4  0x00007fd1ed583422 in ha_mroonga::storage_delete_row (this=0x7fd17c0118c0, buf=0x7fd17c038a80 "\001")
    at ha_mroonga.cpp:6241
#5  0x0000000000590460 in handler::ha_delete_row (this=0x7fd17c0118c0, buf=0x7fd17c038a80 "\001")
    at /home/yoku0825/mysql-5.6.15/sql/handler.cc:7281
#6  0x0000000000823ebb in mysql_delete (thd=0x44a0910, table_list=0x7fd17c005038, conds=0x7fd17c005b58, 
    order_list=, limit=18446744073709551615, options=0)
    at /home/yoku0825/mysql-5.6.15/sql/sql_delete.cc:373
#7  0x00000000006d5c4a in mysql_execute_command (thd=0x44a0910) at /home/yoku0825/mysql-5.6.15/sql/sql_parse.cc:3571
#8  0x00000000006d8607 in mysql_parse (thd=0x44a0910, rawbuf=, length=, 
    parser_state=) at /home/yoku0825/mysql-5.6.15/sql/sql_parse.cc:6247
#9  0x00000000006d9db3 in dispatch_command (command=COM_QUERY, thd=0x44a0910, packet=0x7fd1a009caf0 "\020\tJ\004", 
    packet_length=27) at /home/yoku0825/mysql-5.6.15/sql/sql_parse.cc:1334
#10 0x00000000006a23ed in do_handle_one_connection (thd_arg=)
    at /home/yoku0825/mysql-5.6.15/sql/sql_connect.cc:982
#11 0x00000000006a2522 in handle_one_connection (arg=)
    at /home/yoku0825/mysql-5.6.15/sql/sql_connect.cc:898
#12 0x0000000000972a37 in pfs_spawn_thread (arg=0x45619d0) at /home/yoku0825/mysql-5.6.15/storage/perfschema/pfs.cc:1858
#13 0x0000003eb4807851 in start_thread (arg=0x7fd1a009d700) at pthread_create.c:301
#14 0x0000003eb40e894d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

全く同じところで突き刺さる。
これ、ラッパーモードだろうと更新であればmrnファイルは常に並列性が無くて、ただ mrnファイルはトランザクションのコミットに関わらず先行して更新が終わってしまう からこのジャイアントロックが問題になることは無くて…というシナリオなんだろう、きっと、たぶん(あるいは、ほんのり問題にはなっているけどそれに気付かないか)

で、mrnファイルのロックが突き刺さると更新系のクエリーが全てupdatingとかexecuteで自前ループを回し、connectionがどんどん溜まりそいつらも自前でループし、最終的にCPUを振り切って略…となったることが予想されるので、タイムアウト値は短めに設定して、groonga.logかアプリのログを監視しておいた方が良いかも。

別にしょっちゅうロックが刺さっててGroongaなんとかしる、という訳ではなく、たまたま刺さった時に大変だったそうなので備えておきましょうね、というお話でした :)


【2014/01/30 12:57】
2014/01/29リリースのMroonga 3.12で、MySQLのSET GLOBALで動的にタイムアウト閾値を変えられるようになりました!(need Groonga >= 3.1.2)

ありがとうございます!

2013年12月17日火曜日

もしMroongaのWプラグマがなかったら

このエントリーは 全文検索エンジンGroonga Advent Calendar 2013 の17日目です。

2013/05/29リリースの Mroonga 3.04 の新機能として、TritonnにあったWプラグマのバックポート(?)があります。重み付け検索というより、マルチセクションインデックスの一部を使って検索するために使うことが多いような気もします。

mysql> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  `val1` varchar(20) DEFAULT NULL,
  `val2` varchar(20) DEFAULT NULL,
  `val3` varchar(20) DEFAULT NULL,
  UNIQUE KEY `num` (`num`),
  FULLTEXT KEY `val1` (`val1`,`val2`,`val3`)
) ENGINE=mroonga AUTO_INCREMENT=100002 DEFAULT CHARSET=utf8
1 row in set (0.00 sec)

mysql> SELECT * FROM t1 WHERE MATCH(val1) AGAINST('デコ助' IN BOOLEAN MODE) ORDER BY num LIMIT 3;
ERROR 1191 (HY000): Can't find FULLTEXT index matching the column list

mysql> SELECT * FROM t1 WHERE MATCH(val1, val2, val3) AGAINST('+デコ助' IN BOOLEAN MODE) ORDER BY num LIMIT 3;
+-----+---------------------------------------+--------------------------------------+---------------------------------------------+
| num | val1                                  | val2                                 | val3                                        |
+-----+---------------------------------------+--------------------------------------+---------------------------------------------+
|   5 | アイドルマスター                      | アウトブレイク奇妙な冒険             | 人類はデコ助野郎!                           |
|   9 | 13日のデコ助野郎!                     | 恋と選挙と恋がしたい!                | ジョジョのUC[ユニコーン]                    |
|  14 | アウトブレイクデコ助野郎!             | 魔法少女カンパニー                   | コードギアス亡国の恋がしたい!               |
+-----+---------------------------------------+--------------------------------------+---------------------------------------------+
3 rows in set (0.01 sec)

mysql> SELECT * FROM t1 WHERE MATCH(val1, val2, val3) AGAINST('*W0:1,1:0,2:0 +デコ助' IN BOOLEAN MODE) ORDER BY num LIMIT 3;
+-----+---------------------------------------+---------------------------------+---------------------------------------------+
| num | val1                                  | val2                            | val3                                        |
+-----+---------------------------------------+---------------------------------+---------------------------------------------+
|   9 | 13日のデコ助野郎!                     | 恋と選挙と恋がしたい!           | ジョジョのUC[ユニコーン]                    |
|  14 | アウトブレイクデコ助野郎!             | 魔法少女カンパニー              | コードギアス亡国の恋がしたい!               |
| 115 | インフィニットデコ助野郎!             | 僕は友達が金曜日                | 魔法少女@がんばらない                      |
+-----+---------------------------------------+---------------------------------+---------------------------------------------+
3 rows in set (0.02 sec)

val1からだけ"デコ助"を検索したいのですが、val1だけに張られたフルテキストインデックスは無いので怒られます(1つ目のSELECT)し、かといってMATCH(val1, val2, val3)とするとval1, val2, val3全てから"デコ助"を探してしまいます。Wプラグマがあれば、重み付けでカラム0(=val1)の重みを1に、カラム1(=val2)とカラム2(=val3)の重みを0にしてやることで、val1からだけ検索することができます。

重みも考慮した検索結果を返したいときはORDER BYを併用して

mysql> SELECT *, MATCH(val1, val2, val3) AGAINST('+デコ助' IN BOOLEAN MODE) AS score FROM t1 WHERE MATCH(val1, val2, val3) AGA
INST('+デコ助' IN BOOLEAN MODE)  ORDER BY score DESC, num ASC LIMIT 3;
+-------+---------------------------+---------------------------------------+---------------------------------------+-------+
| num   | val1                      | val2                                  | val3                                  | score |
+-------+---------------------------+---------------------------------------+---------------------------------------+-------+
|  8808 | 13日のデコ助野郎!         | さんをつけろよデコ助野郎!             | さんをつけろよデコ助野郎!             |     3 |
| 10139 | 進撃のデコ助野郎!         | ささみさんデコ助野郎!                 | インフィニットデコ助野郎!             |     3 |
| 12213 | 人類はデコ助野郎!         | 僕は友達がデコ助野郎!                 | アイドルデコ助野郎!                   |     3 |
+-------+---------------------------+---------------------------------------+---------------------------------------+-------+
3 rows in set (0.02 sec)

mysql> SELECT *, MATCH(val1, val2, val3) AGAINST('*W0:2,1:1,2:1 +デコ助' IN BOOLEAN MODE) AS score FROM t1 WHERE MATCH(val1, val2, val3) AGAINST('*W0:2,1:1,2:1 +デコ助' IN BOOLEAN MODE)  ORDER BY score DESC, num LIMIT 3;
+-------+---------------------------+---------------------------------------+---------------------------------------+-------+
| num   | val1                      | val2                                  | val3                                  | score |
+-------+---------------------------+---------------------------------------+---------------------------------------+-------+
|  8808 | 13日のデコ助野郎!         | さんをつけろよデコ助野郎!             | さんをつけろよデコ助野郎!             |     4 |
| 10139 | 進撃のデコ助野郎!         | ささみさんデコ助野郎!                 | インフィニットデコ助野郎!             |     4 |
| 12213 | 人類はデコ助野郎!         | 僕は友達がデコ助野郎!                 | アイドルデコ助野郎!                   |     4 |
+-------+---------------------------+---------------------------------------+---------------------------------------+-------+
3 rows in set (0.03 sec)

スコアが大きい順番に並べてみたりできます。スコアだけでORDER BYしている場合、スコアが同じタプルが存在する場合、どんな順番で返すかは保証されません。たぶん.mrnファイルの内部構造に依存するんだと思います。

全ての重みが均等(Wプラグマの中で重みを指定しなかった場合、全部のカラムが重み1で扱われる)の時のスコアに比べて、val1の重みを2にした時のスコアが上がってます。わかりやすい。

さて、Wプラグマが無かった昔(といっても、半年ちょっと前のことだし、簡単にMroongaをアップグレードする訳にいかない人たちは今なお)、重み付け検索をするにはどうすれば良かったんだろうという *思考実験* です。

mysql> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  `val1` varchar(20) DEFAULT NULL,
  `val2` varchar(20) DEFAULT NULL,
  `val3` varchar(20) DEFAULT NULL,
  UNIQUE KEY `num` (`num`),
  FULLTEXT KEY `val1` (`val1`),
  FULLTEXT KEY `val2` (`val2`),
  FULLTEXT KEY `val3` (`val3`)
) ENGINE=mroonga AUTO_INCREMENT=100002 DEFAULT CHARSET=utf8
1 row in set (0.00 sec)

mysql> SELECT *, MATCH(val1) AGAINST('+デコ助' IN BOOLEAN MODE)* 2+ MATCH(val2) AGAINST('+デコ助' IN BOOLEAN MODE)+ MATCH(val3) AGAINST('+デコ助' IN BOOLEAN MODE) AS score FROM t1 WHERE MATCH(val1) AGAINST('+デコ助' IN BOOLEAN MODE)* 2+ MATCH(val2) AGAINST('+デコ助' IN BOOLEAN MODE)+ MATCH(val3) AGAINST('+デコ助' IN BOOLEAN MODE) ORDER BY score DESC, num ASC LIMIT 3;
+-------+---------------------------+---------------------------------------+---------------------------------------+-------+
| num   | val1                      | val2                                  | val3                                  | score |
+-------+---------------------------+---------------------------------------+---------------------------------------+-------+
|  8808 | 13日のデコ助野郎!         | さんをつけろよデコ助野郎!             | さんをつけろよデコ助野郎!             |     4 |
| 10139 | 進撃のデコ助野郎!         | ささみさんデコ助野郎!                 | インフィニットデコ助野郎!             |     4 |
| 12213 | 人類はデコ助野郎!         | 僕は友達がデコ助野郎!                 | アイドルデコ助野郎!                   |     4 |
+-------+---------------------------+---------------------------------------+---------------------------------------+-------+
3 rows in set (0.33 sec)

クエリーが見にくい上に重い。。容量効率も悪そうですが、他にぱっと思い付きませんでした。
プロファイルの結果はこんなかんじ(Warningが出てるのは5.6では@@profileはdeprecatedだよってアレ)

mysql> SHOW PROFILE FOR QUERY 54;
+--------------------------------+----------+
| Status                         | Duration |
+--------------------------------+----------+
| starting                       | 0.000037 |
| Waiting for query cache lock   | 0.000005 |
| init                           | 0.000004 |
| checking query cache for query | 0.000164 |
| checking permissions           | 0.000011 |
| Opening tables                 | 0.000042 |
| init                           | 0.000063 |
| System lock                    | 0.000043 |
| Waiting for query cache lock   | 0.000004 |
| System lock                    | 0.000031 |
| optimizing                     | 0.000017 |
| statistics                     | 0.000365 |
| preparing                      | 0.000027 |
| FULLTEXT initialization        | 0.020383 |
| Sorting result                 | 0.000022 |
| executing                      | 0.000005 |
| Sending data                   | 0.000018 |
| Creating sort index            | 0.302915 |
| end                            | 0.000026 |
| query end                      | 0.000008 |
| closing tables                 | 0.000212 |
| freeing items                  | 0.000355 |
| Waiting for query cache lock   | 0.000007 |
| freeing items                  | 0.000350 |
| Waiting for query cache lock   | 0.000006 |
| freeing items                  | 0.000004 |
| storing result in query cache  | 0.000006 |
| cleaning up                    | 0.000034 |
+--------------------------------+----------+
28 rows in set, 1 warning (0.01 sec)

mysql> explain SELECT *, MATCH(val1) AGAINST('+デコ助' IN BOOLEAN MODE)* 2+ MATCH(val2) AGAINST('+デコ助' IN BOOLEAN MODE)+ MATCH(val3) AGAINST('+デコ助' IN BOOLEAN MODE) AS score FROM t1 WHERE MATCH(val1) AGAINST('+デコ助' IN BOOLEAN MODE)* 2+ MATCH(val2) AGAINST('+デコ助' IN BOOLEAN MODE)+ MATCH(val3) AGAINST('+デコ助' IN BOOLEAN MODE) ORDER BY score DESC, num ASC LIMIT 3;
+----+-------------+-------+------+---------------+------+---------+------+--------+-----------------------------+
| id | select_type | table | type | possible_keys | key  | key_len | ref  | rows   | Extra                       |
+----+-------------+-------+------+---------------+------+---------+------+--------+-----------------------------+
|  1 | SIMPLE      | t1    | ALL  | NULL          | NULL | NULL    | NULL | 100001 | Using where; Using filesort |
+----+-------------+-------+------+---------------+------+---------+------+--------+-----------------------------+
1 row in set (0.00 sec)

EXPLAINがALLになっちゃった(´・ω・`) ほんとかな。
こっちがWプラグマでさっくりやった時のプロファイル。

mysql> show profile;
+--------------------------------+----------+
| Status                         | Duration |
+--------------------------------+----------+
| starting                       | 0.000039 |
| Waiting for query cache lock   | 0.000004 |
| init                           | 0.000004 |
| checking query cache for query | 0.000135 |
| checking permissions           | 0.000011 |
| Opening tables                 | 0.000041 |
| init                           | 0.000068 |
| System lock                    | 0.000020 |
| Waiting for query cache lock   | 0.000003 |
| System lock                    | 0.000024 |
| optimizing                     | 0.000017 |
| statistics                     | 0.000423 |
| preparing                      | 0.000028 |
| FULLTEXT initialization        | 0.018467 |
| Sorting result                 | 0.000028 |
| executing                      | 0.000005 |
| Sending data                   | 0.000024 |
| Creating sort index            | 0.000195 |
| end                            | 0.000010 |
| query end                      | 0.000010 |
| closing tables                 | 0.000184 |
| freeing items                  | 0.000178 |
| Waiting for query cache lock   | 0.000006 |
| freeing items                  | 0.000315 |
| Waiting for query cache lock   | 0.000006 |
| freeing items                  | 0.000003 |
| storing result in query cache  | 0.000006 |
| cleaning up                    | 0.000037 |
+--------------------------------+----------+
28 rows in set, 1 warning (0.00 sec)

mysql> explain SELECT *, MATCH(val1, val2, val3) AGAINST('*W0:2,1:1,2:1 +デコ助' IN BOOLEAN MODE) AS score FROM t1 WHERE MATCH(val1, val2, val3) AGAINST('*W0:2,1:1,2:1 +デコ助' IN BOOLEAN MODE)  ORDER BY score DESC, num ASC LIMIT 3;
+----+-------------+-------+----------+---------------+------+---------+------+------+---------------------------------------------------+
| id | select_type | table | type     | possible_keys | key  | key_len | ref  | rows | Extra                                             |
+----+-------------+-------+----------+---------------+------+---------+------+------+---------------------------------------------------+
|  1 | SIMPLE      | t1    | fulltext | val1          | val1 | 0       | NULL |    1 | Using where with pushed condition; Using filesort |
+----+-------------+-------+----------+---------------+------+---------+------+------+---------------------------------------------------+
1 row in set (0.00 sec)

意外なのは、FULLTEXT initやfreeing itemsはそこまで盛大に時間がかかる訳じゃなく、ソートの部分(Creating sort index)でのみ大きく差が出ていること。

mysql> SELECT *, MATCH(val1, val2, val3) AGAINST('+デコ助' IN BOOLEAN MODE)+ (val1 LIKE '%デコ助%') AS score FROM t1 WHERE MATCH(val1, val2, val3) AGAINST('+デコ助' IN BOOLEAN MODE) ORDER BY score DESC, num ASC LIMIT 3;
+-------+---------------------------+---------------------------------------+---------------------------------------+-------+
| num   | val1                      | val2                                  | val3                                  | score |
+-------+---------------------------+---------------------------------------+---------------------------------------+-------+
|  8808 | 13日のデコ助野郎!         | さんをつけろよデコ助野郎!             | さんをつけろよデコ助野郎!             |     4 |
| 10139 | 進撃のデコ助野郎!         | ささみさんデコ助野郎!                 | インフィニットデコ助野郎!             |     4 |
| 12213 | 人類はデコ助野郎!         | 僕は友達がデコ助野郎!                 | アイドルデコ助野郎!                   |     4 |
+-------+---------------------------+---------------------------------------+---------------------------------------+-------+
3 rows in set (0.09 sec)

mysql> explain SELECT *, MATCH(val1, val2, val3) AGAINST('+デコ助' IN BOOLEAN MODE)+ (val1 LIKE '%デコ助%') AS score FROM t1 WHERE MATCH(val1, val2, val3) AGAINST('+デコ助' IN BOOLEAN MODE) ORDER BY score DESC, num ASC LIMIT 3;
+----+-------------+-------+----------+---------------+------+---------+------+------+---------------------------------------------------+
| id | select_type | table | type     | possible_keys | key  | key_len | ref  | rows | Extra                                             |
+----+-------------+-------+----------+---------------+------+---------+------+------+---------------------------------------------------+
|  1 | SIMPLE      | t1    | fulltext | val1          | val1 | 0       | NULL |    1 | Using where with pushed condition; Using filesort |
+----+-------------+-------+----------+---------------+------+---------+------+------+---------------------------------------------------+
1 row in set (0.00 sec)

mysql> SHOW PROFILE FOR QUERY 77;
+--------------------------------+----------+
| Status                         | Duration |
+--------------------------------+----------+
| starting                       | 0.000055 |
| Waiting for query cache lock   | 0.000005 |
| init                           | 0.000004 |
| checking query cache for query | 0.000141 |
| checking permissions           | 0.000011 |
| Opening tables                 | 0.000043 |
| init                           | 0.000070 |
| System lock                    | 0.000019 |
| Waiting for query cache lock   | 0.000003 |
| System lock                    | 0.000018 |
| optimizing                     | 0.000015 |
| statistics                     | 0.000356 |
| preparing                      | 0.000025 |
| FULLTEXT initialization        | 0.011795 |
| Sorting result                 | 0.000020 |
| executing                      | 0.000004 |
| Sending data                   | 0.000018 |
| Creating sort index            | 0.075364 |
| end                            | 0.000023 |
| query end                      | 0.000009 |
| closing tables                 | 0.000201 |
| freeing items                  | 0.000181 |
| Waiting for query cache lock   | 0.000006 |
| freeing items                  | 0.000318 |
| Waiting for query cache lock   | 0.000006 |
| freeing items                  | 0.000002 |
| storing result in query cache  | 0.000007 |
| cleaning up                    | 0.000033 |
+--------------------------------+----------+
28 rows in set, 1 warning (0.00 sec)

重みをつけるカラムが大したことない数の場合は、(val1 LIKE '%..%')で無理矢理重みをつけてしまう(LIKE句にマッチした場合は1, マッチしない場合は0が戻るので、掛け算なり足し算なりある程度スコアとして使える)
こっちの方がまだマシそうな速度。。ただしクエリーはいやんな感じだなあ。。

やっぱりおとなしく最新のMroonga使うべきですね! :)

ちなみに、テストデータは MySQL Casual Advent Calendar 2013 の13日目、 @meijikさん の テストデータ作成時に便利なストアドファンクション で作りました :)


明日は @ongaeshiさん の2回目です! :)

2013年12月14日土曜日

wsrep_sst_authでハマったメモ

Percona XtraDB Clusterでクラスターの初期化中に、

wsrep_sst_method= xtrabackup
wsrep_sst_auth= username:password
としてても、JOINER側で

131212 17:22:05 [Note] WSREP: State transfer required:
        Group state: 64863b36-62f7-11e3-bef2-a746941be182:1
        Local state: 00000000-0000-0000-0000-000000000000:-1
131212 17:22:05 [Note] WSREP: New cluster view: global state: 64863b36-62f7-11e3-bef2-a746941be182:1, view# 10: Primary, numbe
r of nodes: 2, my index: 1, protocol version 2
131212 17:22:05 [Warning] WSREP: Gap in state sequence. Need state transfer.
131212 17:22:07 [Note] WSREP: Running: 'wsrep_sst_xtrabackup --role 'joiner' --address '192.168.xxx.xxx' --auth '' --datadir '/xxx' --defaults-file '/xxx/my.cnf' --parent '3382''
WSREP_SST: [INFO] Streaming with tar (20131212 17:22:08.058)
WSREP_SST: [INFO] Using socat as streamer (20131212 17:22:08.063)
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | tar xfi - --recursive-unlink -h; RC=( ${PIPESTATUS[@]}
 ) (20131212 17:22:08.092)
131212 17:22:08 [Note] WSREP: Prepared SST request: xtrabackup|192.168.xxx.xxx:4444/xtrabackup_sst
131212 17:22:08 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
131212 17:22:08 [Note] WSREP: Assign initial position for certification: 1, protocol version: 2
131212 17:22:08 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (64863b36-62f7-11e3-bef2-a746941be182): 1 (Operation not permitted)
         at galera/src/replicator_str.cpp:prepare_for_IST():445. IST will be unavailable.
131212 17:22:08 [Note] WSREP: Node 1 (xxx) requested state transfer from '*any*'. Selected 0 (xxx)(SYNCED) as donor.
131212 17:22:08 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 1)
131212 17:22:08 [Note] WSREP: Requesting state transfer: success, donor: 0
tar: これは tar アーカイブではないようです
tar: 処理中にエラーが起きましたが、最後まで処理してからエラー終了させました
WSREP_SST: [ERROR] Error while getting data from donor node:  exit codes: 0 2 (20131212 17:22:09.063)
WSREP_SST: [ERROR] Cleanup after exit with status:32 (20131212 17:22:09.068)
131212 17:22:09 [Warning] WSREP: 0 (xxx): State transfer to 1 (xxx) failed: -1 (Operation not permitted)
131212 17:22:09 [ERROR] WSREP: gcs/src/gcs_group.c:gcs_group_handle_join_msg():719: Will never receive state. Need to abort.

SSTに失敗したログが出てて、DONOR側でも、

131214 16:12:12 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 4)
131214 16:12:12 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
131214 16:12:12 [Note] WSREP: Running: 'wsrep_sst_xtrabackup --role 'donor' --address '192.168.xxx.xxx:4444/xtrabackup_sst' --au
th '(null)' --socket '/xxx/mysql.sock' --datadir '/xxx/' --defaults-file '/xxx/my.cnf'
--gtid '64863b36-62f7-11e3-bef2-a746941be182:4''
131214 16:12:12 [Note] WSREP: sst_donor_thread signaled with 0
WSREP_SST: [INFO] Streaming with tar (20131214 16:12:13.133)
WSREP_SST: [INFO] Using socat as streamer (20131214 16:12:13.138)
WSREP_SST: [INFO] Streaming the backup to joiner at 192.168.xxx.xxx 4444 (20131214 16:12:13.154)
WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=/xxx/my.cnf $INNOEXTRA --galera-info --stream=$sfmt ${T
MPDIR} 2>${DATA}/innobackup.backup.log | socat -u stdio TCP:192.168.xxx.xxx:4444; RC=( ${PIPESTATUS[@]} ) (20131214 16:12:13.159
)
WSREP_SST: [ERROR] innobackupex finished with error: 1.  Check /xxx//innobackup.backup.log (20131214 16:12:13.569
)
WSREP_SST: [ERROR] Cleanup after exit with status:22 (20131214 16:12:13.574)
131214 16:12:13 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup --role 'donor' --address '192.168.xxx.xxx:4444/xtraback
up_sst' --auth '(null)' --socket '/xxx/mysql.sock' --datadir '/xxx/' --defaults-file '/xxx/my.cnf' --gtid '64863b36-62f7-11e3-bef2-a746941be182:4'
131214 16:12:13 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup --role 'donor' --address '192.168.xxx.xxx:4444/xtrabackup_sst' --auth '(null)' --socket '/xxx/mysql.sock' --datadir '/xxx/' --defaults-file '/xxx/my.cnf' --gtid '64863b36-62f7-11e3-bef2-a746941be182:4': 22 (Invalid argument)
131214 16:12:13 [Warning] WSREP: 1 (xxx): State transfer to 0 (xxx) failed: -1 (Operation not permitted)

innobackupexが失敗したログが出る。

innobackupexのログを見てみると、

131214 16:47:12  innobackupex: Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_file=/xxx/my.cnf;mysql_read_default_group=xtrabackup' (using password: NO).
innobackupex: Error: Failed to connect to MySQL server: DBI connect(';mysql_read_default_file=/xxx/my.cnf;mysql_read_default_group=xtrabackup','',...) failed: Access denied for user 'mysql'@'localhost' (using password: NO) at /usr/local/bin/innobackupex line 2954

うーん、wsrep_sst_authでユーザー名とパスワードを指定してるのに、まるっと無視されている様子。取り敢えず、my.cnfの[xtrabackup]セクションに
[xtrabackup]
user= username
password= password
を追加して通るようにはなったけど、これバグなのか調べ方が悪いのかよく判らん。。


上手く行ってからメモ用にわざと失敗させてログを吐かせてるので、時間がバラバラなのはご愛嬌。


【2013/12/16 18:00】
Indeed, this is not a bug.

wsrep_sst_auth=username:password

でいけた。スペース入れるとダメぽい。

【2013/12/17 10:34】
違う、判った。
wsrep_sst_authはドナーノードに設定しないといけないオプションであり、しかも、mysqldセクションに書いている限り再起動しないと再読み込みされないので、ドナーノードを再起動してやるか、SET GLOBAL wsrep_sst_auth= ..で設定してやらないといけない。

_| ̄|○

2013年12月6日金曜日

あなたのMySQL 5.6トレンド力をチェックする15の質問

このエントリーは MySQL Casual Advent Calendar 2013 参加記事です。カジュアルカジュアル。
MySQL 5.6のGAリリースからはや10ヶ月、みなさんそろそろカジュアルに導入なされていることだと思います。

漢(オトコ)のコンピュータ道: 優れたMySQL DBAを見分ける27+3の質問 のオマージュです。
Islands in the byte stream: 「優れたPerlプログラマを見分ける27の質問」の日本語訳@__gfx__さん からメンションをいただいたので作りました :)

がんばってみます :)
独断と偏見で有名そうなの並べてあるだけですので、他にも色々ありますよ探してみましょう :)

  1. mysql_install_dbに加わった新機能2つ。
  2. mysqlコマンドラインクライアントは~/.mysql_historyにコマンド履歴を格納するが、5.6から--histignoreオプションで指定した文字列と'ある文字列'を含む行は格納されなくなった(上矢印とか押しても履歴として出てこない) この除外される文字列2つ。
    • ユーザーを量産する時にちょっと不便(´・ω・`)
    • こたえ=> "PASSWORDとIDENTIFIED"
    • なお、これ以外の文字列を--histignoreで指定しても上書きはされず、追加されるだけなので無効化するにはソースコードをいじる必要がある。
  3. InnoDBに追加された新機能を5つ以上
  4. 予めWHERE句以外でパーティションを指定してSELECT, UPDATE, DELETEその他が可能になったが、そのシンタックス。
  5. 5.6になって *非推奨* になった機能2つ以上
  6. 待望のスレーブ自動昇格スクリプト mysqlfailover を動作させるための条件
    • こたえ=> GTIDが有効になっていること
  7. クラッシュセーフスレーブに必要なパラメータ2つ
  8. mysqlbinlogをバイナリーログのリアルタイムバックアップとして使う時のオプション2つ
  9. レプリケーション関連で追加された新機能3つ
  10. 5.6になってオプティマイザーは賢くなったか? [Y/N]
  11. 不正Connectのカウントアップがついにテーブルで参照できるように! スキーマとテーブルは?
  12. 5.6未満から5.6への移行はmysqldump推奨。なんで?
  13. mysql_config_editorで作った.mylogin.cnfの最大の弱点は?
  14. 5.6で追加された新しいEXPLAIN2種類
  15. Optimizer Traceの出力させ方

    さて、みなさん如何でしたか?
    答えはほとんどナッツシェルからたどればいけます。ここにピックアップしなかったものも色々ありますので、「へーこんなの追加されてたんだー」とか思っていただければ幸いです。



    明日は bluerabbit777jpさん です!

    2013年12月3日火曜日

    全文検索エンジンGroongaを囲む夕べ(以下、ぐるんべ)4に参加して感じたことなど

    このエントリーは 全文検索エンジンGroonga Advent Calendar 2013 の3日目です :)

    さて、今年もいい肉の日(11/29)に ぐるんべ4 が開催されたので今年も行ってきました。去年のぐるんべ3に続き、2年連続2回目の参加です(去年は発表とかしませんでしたが)

    少し遅れ馳せながら感想エントリーです。
    当日のまとめは おんがえしさんブログのおんがえし Groongaを囲む夕べ4をサクッと振り返る などにリンクを張りつつ誤魔化します。


    さて、今年のぐるんべで受けた印象は *かなりMySQLに寄ってきたな* というイメージでした。かなり偏見ですが。

    すとーさん が`*roonga使ってる人ー?'と振った感じでも、去年よりMroonga使いは多そう。それに対してRroonga使いの参加が少なかったイメージです。

    去年のぐるんべ3 のアジェンダと比較していただくと判るのですが(すいません、具体的な数はタイトル見ても思い出せませんでした。。)去年は半分くらいがRroongaネタ、残りがGroongaとMroonga(2本?)で、どちらかというと比較的少数派だったはず。え? Nroo…ごめん誰か来たみたい

    ところが今年は 林さん のセッションを除けば事例紹介は半分(4本)がMroonga関連、Groongaが3本にRroongaが1本といううーん、これは我ながらバイアスのかかった見方だとは思うんですが、ボリューム的にだいぶ増えた気がするんですよ。気がするんです。

    その他にも池田さんから「Mroongaサポートの紹介」があって、対応する(?)南さんのセッションはプロダクトに関わらず*roonga族全般'に関するもの、斯波さん からのMroonga今年の収穫は去年と変わらないペースだったので、やっぱりMroongaの話題が出ていた時間は長かったように思われます。
    去年の 森さんのセッション では割と`全文検索もできる *KVS*'っぽく紹介されていた感じがしましたが、今年のセッションではそれに触れてはいたものの分量は少なくなった感じ(今年はGroonga本体でなくてDroongaでしたしね)

    別に良い訳でも悪い訳でもなく、なんとなーく、そんなことを感じました。来年はどうなるでしょうね。来年こそNroo…うん何でもない。


    そういえば去年のぐるんべで斯波さんに「ねえねえMariaDBマダー?」とねだった事とか色々思い出してきました。懐かしいですが、長くなりそうなのでこのへんで。

    ( ´-`).oO(ところで、httpしゃべれるようにするとかNode.jsから叩けるようにするのは最近の流行りなんですかね。NDBCLUSTERから学ぶところとしては、memcachedプロトコルなら使う人いるかもって感じですが


    明日は KitaitiMakotoさん です!

    2013年11月22日金曜日

    MySQL 5.6のクラッシュセーフなレプリケーションの仕組み

    ちょこちょこ思うこと。

    MySQL 5.6のnutshellを読むと、`クラッシュセーフなレプリケーションを実現するためにはmaster_info_repositoryとrelay_log_info_repositoryをTABLEに設定しな! おっと、relay_log_recoveryも1にしておくんだぜ'みたいことが書いてある。

    で、このバグレポートを見た時からずっと、sync_master_infoの暗黙のデフォルト10000のまんまじゃクラッシュセーフじゃなくね? sync_master_info= 1必須? それはパフォーマンス的に死ねる。という感じでモヤモヤしていたのだが、やっと合点がいったのでメモしときます。

    まず、出てくるパラメータの説明。
    • master_info_repository
      • FILEの場合、従来どおりmaster.infoファイルに書く。
        • ファイル名はmaster_info_fileにより可変。
        • 更新があるたび(バイナリーログを受信するたび)にファイルにwrite、sync_master_info回イベントを受信するとfdatasync。5.5までの暗黙のデフォルトは0なのでfsyncはしない。5.6.6以降の暗黙のデフォルトは10000。
      • TABLEの場合、mysql.slave_master_infoテーブルに書く。
        • コイツはmysqlスキーマ初のInnoDBテーブル。
        • sync_master_info回イベントを受信するたびにUPDATE。
        • sync_master_info= 0にすると、mysql.slave_master_infoは *アップデートされない*
          • SHOW SLAVE STATUSはこのテーブルの情報を読んでいる訳ではないので、ちゃんと更新される。
    • relay_log_info_repository
      • master_info_repositoryのrelay-log.info版っぽいが、TABLEを指定した場合は少し振る舞いが異なる(俺的混乱のもとその1)
      • FILEの場合はいっしょなので割愛。
      • TABLEの場合、mysql.slave_relay_log_infoテーブルに書く。
        • SQLスレッドがリレーログから読み出したステートメントを実行する時に、同じトランザクションの中でmysql.slave_relay_log_infoを更新するようになる。
        • sync_relay_log_infoの値に依存せず、毎回テーブルは更新される。
          • mysql.slave_relay_log_infoを非トランザクションテーブルにすると、master_info_repository= TABLEの時と同じ動作(sync_relay_log_info回に1回更新)
          • 【2013/12/11 11:35】
            mysql.slave_relay_log_infoがトランザクション対応か非対応化は *関係なく* マスター側の更新されたテーブルとスレーブ側で更新が適用されるテーブルが共にトランザクション対応であるかどうか、で更新頻度が変わる。
            • Master MyISAM-> Slave MyISAM: depends on sync_relay_log_info
            • Master MyISAM-> Slave InnoDB: depends on sync_relay_log_info
            • Master InnoDB-> Slave MyISAM: depends on sync_relay_log_info
            • Master InnoDB-> Slave InnoDB: updated after each transaction
            • http://bugs.mysql.com/bug.php?id=71083
    • relay_log_recovery
      • 実は5.5からあるオプション
      • 起動した時に、持っているリレーログとrelay-log.infoを比較して、まだ適用していない(Exec_Master_Log_Pos以降の)リレーログを破棄する。
    という訳で、relay_log_recovery= ONであれば、「Exec_Master_Log_Posの情報が正しくrelay-log.info(or mysql.slave_relay_log)に反映されている限り、バイナリーログの二重取りや欠損は発生しない(はず)」、かつ、relay_log_info_repository= TABLEであれば、「SQLスレッドが変更を反映するタイミングでmysql.slave_relay_log_infoも同じトランザクションで更新されるため、All or Nothingで片方だけが失われる(不整合が起こる)ことはない(はず)」になり、

    relay_log_recovery && relay_log_info_repository= TABLEならクラッシュセーフになる、という理屈らしい。

    ………master_info_repository関係なくない? 関係ないよね?

    2013年11月6日水曜日

    MySQLインスタンス間でテーブルを移行する投げ遣りベンチマーク

    よく考えるとレアケースなんですが今月末に作業が控えているのでメモ。
    データベース名はdb1, 移行対象のテーブル(2つ)はtable1, table2とする。移行元ではMyISAMエンジンを使っていて、移行先ではInnoDBエンジンに変える。


    シンプルなパターン。何も考えずにmysqldumpでばっこ抜く。

    $ time mysqldump -S /xxx/mysql.sock -uroot -pxxx --default-character-set=binary --single-transaction db1 table1 table2 > mysqldump.sql
    
    real    0m30.573s
    user    0m27.051s
    sys     0m3.078s
    
    $ ll -h
    合計 2.0G
    -rw-rw-r-- 1 mysql mysql 2.0G 11月  6 13:38 2013 mysqldump.sql
    

    合計2GB。scpで転送して20秒ちょっと。コイツをリストア先に流し込む。
    まずはMyISAMでリストアしてからInnoDBに変換。

    $ time mysql -S /xxx/mysql.sock -uroot -pxxx --default-character-set=binary new_db1 < mysqldump.sql
    
    real    7m53.261s
    user    0m57.426s
    sys     0m1.956s
    
    mysql> ALTER TABLE table1 Engine= InnoDB;
    Query OK, 11730918 rows affected (6 min 14.90 sec)
    Records: 11730918  Duplicates: 0  Warnings: 0
    
    mysql> ALTER TABLE table2 Engine= InnoDB;
    Query OK, 16171279 rows affected (15 min 44.07 sec)
    Records: 16171279  Duplicates: 0  Warnings: 0
    
    

    合計30分弱。やっぱりmysqldumpはリストアが遅い…。
    吸い上げたmysqldumpをs/ENGINE=MyISAM/ENGINE=InnoDB/してみる。

    $ time sed -i 's/ENGINE=MyISAM/ENGINE=InnoDB/' mysqldump.sql
    
    real    0m25.722s
    user    0m3.923s
    sys     0m2.994s
    
    $ time mysql -S /xxx/mysql.sock -uroot -pxxx --default-character-set=binary new_db1 < mysqldump.sql
    
    real    23m54.496s
    user    0m46.110s
    sys     0m2.204s
    
    25分弱。多少速くなった。ALTER TABLEで変換よりはマシ。 気を取り直してmysqldumpを--tabにしたらどうだろうか。
    $ time mysqldump -S /xxx/mysql.sock -uroot -pxxx --default-characster-set=binary --single-transaction --tab=./xxx --fields-terminated-by=',' --fields-enclosed-by='"' --fields-escaped-by='\\' --lines-terminated-by='\n' db1 table1 table2
    real 0m35.618s
    user 0m0.002s
    sys 0m0.004s
    
    $ ll -h
    合計 1.9G
    -rw-rw-r-- 1 mysql mysql 2.0K 11月  6 13:34 2013 table1.sql
    -rw-rw-r-- 1 mysql mysql 728M 11月  6 13:34 2013 table1.txt
    -rw-rw-r-- 1 mysql mysql 2.1K 11月  6 13:34 2013 table2.sql
    -rw-rw-r-- 1 mysql mysql 1.2G 11月  6 13:34 2013 table2.txt
    
    MyISAMのまま入れてALTER TABLEはもういい気がするので、InnoDBにしておいてLOAD DATA INFILEで流し込むパターン。
    $ time cat table1.sql table2.sql | sed 's/ENGINE=MyISAM/ENGINE=InnoDB/' | mysql -S /xxx/mysql.sock -uroot -pxxx --default-character-set=binary new_db1
    
    real    0m0.017s
    user    0m0.005s
    sys     0m0.003s
    
    mysql> LOAD DATA INFILE '/tmp/table1.txt' INTO TABLE table1 FIELDS TERMINATED BY ',' ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n';
    Query OK, 11730887 rows affected (6 min 32.29 sec)
    Records: 11730887  Deleted: 0  Skipped: 0  Warnings: 0
    
    mysql> LOAD DATA INFILE '/tmp/table2.txt' INTO TABLE table2 FIELDS TERMINATED BY ',' ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n';
    Query OK, 16171279 rows affected (16 min 28.26 sec)
    Records: 16171279  Deleted: 0  Skipped: 0  Warnings: 0
    

    25分弱。バルクインサートより速いつもりでいたけどそんなに変わらなかった。。

    ここから本命。
    SH2さんの電波を受信してINDEXをゴニョゴニョしながらインポートする。
      ⇒ MySQL 5.6における大量データロード時の考慮点 - SH2の日記

    $ time cat table1.sql table2.sql | mysql -S /xxx/mysql.sock -uroot -pxxx --default-character-set=binary new_db1
    
    real    0m0.017s
    user    0m0.005s
    sys     0m0.003s
    
    mysql> ALTER TABLE table1 Engine= InnoDB, DEFAULT CHARACTER SET= utf8, DROP KEY xxx, DROP KEY xxx, DROP KEY xxx, AUTO_INCREMENT= 1;
    Query OK, 0 rows affected (0.01 sec)
    Records: 0  Duplicates: 0  Warnings: 0
    
    mysql> ALTER TABLE table2 Engine= InnoDB, DEFAULT CHARACTER SET= utf8, DROP KEY xxx, DROP KEY xxx, DROP KEY xxx, DROP KEY xxx;
    Query OK, 0 rows affected (0.01 sec)
    Records: 0  Duplicates: 0  Warnings: 0
    
    mysql> LOAD DATA INFILE '/tmp/table1.txt' INTO TABLE table1 FIELDS TERMINATED BY ',' ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n';
    Query OK, 11730887 rows affected (2 min 10.14 sec)
    Records: 11730887  Deleted: 0  Skipped: 0  Warnings: 0
    
    mysql> LOAD DATA INFILE '/tmp/table2.txt' INTO TABLE table2 FIELDS TERMINATED BY ',' ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n';
    Query OK, 16171279 rows affected (4 min 52.82 sec)
    Records: 16171279  Deleted: 0  Skipped: 0  Warnings: 0
    
    mysql> ALTER TABLE table1 ADD KEY xxx (..), ADD KEY xxx (..), ADD KEY xxx (..);
    Query OK, 0 rows affected (2 min 49.87 sec)
    Records: 0  Duplicates: 0  Warnings: 0
    
    mysql> ALTER TABLE table2 ADD KEY xxx (..), ADD KEY xxx (..), ADD KEY xxx (..), ADD KEY xxx (..);
    Query OK, 0 rows affected (4 min 35.72 sec)
    Records: 0  Duplicates: 0  Warnings: 0
    

    mysqldumpを入れ込んで、インデックスを外して、LOAD DATA INFILEしてからインデックスを戻す。
    合計15分もかからない。すごいはやいー。
    table1でLOAD DATA INFILE, ALTER TABLE, table2でLOAD DATA INFILE, ALTER TABLEの順番にすると、バッファプールの効率がよくなって多少速くなるかもしれない。

    今回本番で使うのは↑の手順になるけど、試した中で最速だったのは、
    ・テキトーに5.6の移動元サーバーのレプリケーションスレーブを作って
    ・そっちでInnoDB化しておいて
    ・移動先サーバーも5.6にして
    ・FLUSH TABLES .. FOR EXPORT
    でした。

    移動元サーバーで、
    mysql> FLUSH TABLES table1, table2 FOR EXPORT;
    Query OK, 0 rows affected (0.03 sec)
    
    $ ll -h
    合計 4.8G
    -rw-rw---- 1 yoku0825 yoku0825   65 11月  6 15:45 2013 db.opt
    -rw-rw---- 1 yoku0825 yoku0825 1.3K 11月  6 16:24 2013 table1.cfg
    -rw-rw---- 1 yoku0825 yoku0825 8.7K 11月  6 16:14 2013 table1.frm
    -rw-rw---- 1 yoku0825 yoku0825 1.5G 11月  6 16:17 2013 table1.ibd
    -rw-rw---- 1 yoku0825 yoku0825 1.7K 11月  6 16:24 2013 table2.cfg
    -rw-rw---- 1 yoku0825 yoku0825 8.8K 11月  6 16:17 2013 table2.frm
    -rw-rw---- 1 yoku0825 yoku0825 3.3G 11月  6 16:21 2013 table2.ibd
    

    .cfgファイルと.ibdファイルをインポート先にコピー(FLUSH TABLES .. FOR EXPORTしたクライアントを閉じちゃうと.cfgファイルが消えてしまうので、クライアントセッションは開いたまま別ターミナルを上げる感じでやる)

    ファイルをscpで転送して、移動先のサーバーで
    mysql> CREATE TABLE table1 (..) Engine= InnoDB;
    Query OK, 0 rows affected (0.35 sec)
    
    mysql> CREATE TABLE table2 (..) Engine= InnoDB;
    Query OK, 0 rows affected (0.24 sec)
    
    mysql> ALTER TABLE table1 DISCARD TABLESPACE;
    Query OK, 0 rows affected (0.66 sec)
    
    mysql> ALTER TABLE table2 DISCARD TABLESPACE;
    Query OK, 0 rows affected (0.03 sec)
    
    $ sudo mv table[12].* /xxx/new_db1
    
    mysql> ALTER TABLE table1 IMPORT TABLESPACE;
    Query OK, 0 rows affected (28.00 sec)
    
    mysql> ALTER TABLE table2 IMPORT TABLESPACE;
    Query OK, 0 rows affected (1 min 2.25 sec)
    
    流石に速い。

    知らないと手順がごちゃごちゃする&使いどころが限られてるけど、上手く使えば5GB/5分くらいで移動できちゃう、という風情。
    xtrabackupあたりがバックアップをこの形式で出力できるようにならないかな。。

    2013年10月28日月曜日

    MySQL Casual Talks vol.5 でバーボンハウスしてきた

    やあ(´・ω・`)
    ようこそ、バーボンハウスへ。



    というわけで、MySQL Casual Talks vol.5に参加してきました。
    ハッシュタグもちょこちょこ拾ってあるので、ブログ書いた方などは追加していただけると幸いです。

    今回は前の週のOSC 2013 Tokyo/Fallで死んでたのでさっくり愚痴って15分! とか思ってたんですが、前々日に30ページまで書いて5分しか保たずにあわてて追加していったらなんか60ページくらいになってしまったという。それでもやっぱり10分くらいでやったみたいですが、一発ネタなのでそれくらいで終わって良かったですね。

    内容については概ね`本当にあった怖くない話'なんですが、1つのテーブルじゃなくて2つ3つのテーブルのイケてないところを寄せ集めてデフォルメした感じです。

    あとはvarbinary型が色々あると思いますが、utf8mb4で40文字入れるだけで161bytes対41bytesになって、BIGINTだDATETIMEだTINYINTだ言ってるのが馬鹿馬鹿しいくらいの差になるので、容量がタイトな時はvarbinary型にしています。スッカスカな時は別にjsonをTEXT型に突っ込んでも(それほど)文句は言いません。

    あと、カラム名をインデックス名に流用する時は 必ず カラムと全く同じ名前のインデックスにならないように、ALTER TABLE .. DROP KEY ..のKEYキーワードを忘れてもカラムがドロップされたりしないように 気をつけて下さい。

    じゃあ、バリウム飲んできます(健康診査

    2013年10月16日水曜日

    5.1.72のmysql_upgrade --skip-write-binlogでスクリプトが転けるバグ

    昨日、MySQL 5.0.83から5.1.72へのバージョンアップをしてたんですが、バイナリー入れ替えてmysql_upgradeかけても何か様子がおかしい。
    前に5.0.83に上げた時にmysql_upgrade忘れてたんじゃないかと疑ってたんですが、実際5.1.72のmysql_upgradeのバグっぽいです。ごめんとなりのひと。

    http://dev.mysql.com/doc/refman/5.1/en/mysql-upgrade.html


    mysql_upgradeに--skip-write-binlogまたは--write-binlogのオプションを引き渡すと、実行されるべき`mysql_fix_privilege_tables'のクエリーが全て転けてアップグレードできない、というもの。
    取り敢えず5.1.72のmysql_upgradeで確認しましたが、どこで混入したのかは謎。


    $ gdb --args mysql_upgrade --socket=/xxx/mysql.sock -uroot -p'xxx' --skip-write-binlog
    
    brake mysql_check.c:770 and go on.
    
    770   run_query(mysql_fix_privilege_tables,
    771             &ds_result, /* Collect result */
    772             TRUE);
    
    (gdb) bt full
    #0  run_tool (tool_path=, ds_res=0x7fffffffe7f0) at mysql_upgrade.c:372
            ret = 
            arg = 
            args = {{gp_offset = 48, fp_offset = 0, overflow_arg_area = 0x7fffffffe170, reg_save_area = 0x7fffffffe060}}
            ds_cmdline = {
              str = 0x610650 "'/home/yoku0825/mysql-5.1.72/client/mysql' '--no-defaults' '--socket=/xxx/mysql.sock' '--user=root' '--password=xxx' '--write-binlog' '--user=root'  '--database=mysql' '--batch' '--"..., length = 240,
              max_length = 512, alloc_increment = 512}
    #1  0x00000000004019bf in run_query (ba
        query=0x4028b0 "-- Copyright (c) 2007, 2008 MySQL AB, 2009 Sun Microsystems, Inc.\n -- Use is subject to license terms.\n -- \n -- This program is free software; you can redistribute it and/or modify\n -- it under the te"...,
        ds_res=0x7fffffffe7f0, force=1 '\001') at mysql_upgrade.c:497
            ret = 
            fd = 7
            query_file_path = "/tmp/sqlQG2xcV", '\000' "\220, \353\200\313>\000\000\000\200\027\365\312>", '\000' , "\b\000\000\000\060\000\000\000\300\343\377\377\377\177\000\000\000\343\377\377\377\177", '\000' , "#\245\306\312>", '\000' "\200, \027\365\312>\000\000\000(\000\000\000\000\000\000\000\n\000\000\000\000\000\000\000\000\000\253\252\252*\000\000\066\244\306\312>\000\000\000\000\002\000\000\000\000\000\000\200\027\365\312>\000\000\000\200\027\365\312>\000\000\000\n\000\000\000\000\000\000\000\360\347\377\377\377\177\000\000\264\253\306\312>\000\000\000\200\027\365\312>\000\000\000\224\342@\000\000\000\000\000\200\027\365\312>\000\000\000\020\374\305\312>\000\000\000\224\342@\000\000\000\000\000\032\025@\000\000\000\000\000\b\000\000\000\060\000\000\000\300\343\377\377\377\177\000\000\000\343\377\377\377\177\000\000\020\000a\000\000\000\000\000\331\342@\000\000\000\000\000"...
            sql_log_bin = "SET SQL_LOG_BIN=0;"
    #2  0x000000000040211c in run_sql_fix_privilege_tables (argc=0, argv=0x6102f8) at mysql_upgrade.c:770
            found_real_errors = 0
            ds_result = {str = 0x610420 "/home/yoku0825/mysql-5.1.72/client/.libs/lt-mysql: unknown option '--write-binlog'\n",
              length = 82, max_length = 512, alloc_increment = 512}
    #3  main (argc=0, argv=0x6102f8) at mysql_upgrade.c:872
            self_name = "/home/yoku0825/mysql-5.1.72/client/.libs/mysql_upgrade", '\000' 
    (gdb)
    (gdb) p *ds_res
    $1 = {str = 0x610420 "/home/yoku0825/mysql-5.1.72/client/.libs/lt-mysql: unknown option '--write-binlog'\n", length = 82,
      max_length = 512, alloc_increment = 512}
    


    mysql_upgradeがテンポラリーファイルにアップグレード用のステートメントを書き出し(この時、--skip-write-binlogならファイルの先頭に"SET SQL_LOG_BIN= 0;"を書き込む)、mysqlコマンドラインクライアントを呼んでそのファイルを食わせる、という流れで実際のALTERが行われる手筈になっているのだけれど、その時にmysql_upgradeが--skip-write-binlog, --write-binlogオプションをmysqlコマンドラインクライアントに渡してしまうのが問題で、unknown optionって怒られる羽目に遭う。

    mysql_upgrade --skip-write-binlogの時はmysql .. --write-binlog .. --skip-write-binlogの両方を渡して、後から渡した--skipの方でオーバーライドさせてる、mysql_upgrade --write-binlogの時はmysql .. --write-binlog ..と渡してる。
    どっちも指定されていない時はどちらのオプションもmysqlに渡さず、5.1では暗黙のデフォルトとして--write-binlog扱いになり、"SET SQL_LOG_BIN= 0;"は書き込まれない。

    --write-binlogオプションを押し込むところを--loose-write-binlogにして、mysql_upgradeに渡すのを--loose-skip-write-binlogにすれば何とかなるかな、と思いつつパッチでも書こうかしら。でも電車動き始めたらしいのでそろそろ出勤するかな。

    ちなみにこれ、MySQL Bugsにも上げたんですが、backtraceの中にパスワードとか残したままにしてしまって、しかもBugsは後から投稿取り消せないのでモニョモニョな状態になってコメントで泣きついたところ、Access deniedにしてもらいました。

    「Oracle様にとってはゴミ屑のようなコミュニティエディションの1ユーザーの懇願など無視されるかな」と思ってたんですが、数時間でさっくり対応してくれて感謝感謝です。
    正直ちょっと(だけ)見直した。

    MySQL Bugs #70624 mysql_upgrade with --skip-write-binlog doesn't work
    http://bugs.mysql.com/bug.php?id=70624


    【2013/10/16 16:05】
    パッチ書きました。

    https://gist.github.com/yoku0825/7003161

    【2013/10/24 12:29】
    本家でもVerifyされたので、次のリリースでは直るといいなー。

    2013年10月7日月曜日

    ラッパーも含めて mysqldが起動するときにどのmy.cnfを舐めてるのか知りたいとき

    いやまあ、マニュアルに書いてあるけど。
    http://dev.mysql.com/doc/refman/5.6/en/option-files.html

    Linuxで公式MySQL、--defaults-file, --defaults-extra-fileを指定しない場合は、

    • /etc/my.cnf
    • /etc/mysql/my.cnf
    • /usr/local/mysql/etc/my.cnf
      • SYSCONFDIR/my.cnfのこと。
      • 公式のバイナリーはSYSCONFDIR== /usr/local/mysql/etc。cmakeのオプションで変えられる。
      • MariaDBはこいつが設定されていないっぽい。
    • /usr/local/mysql/my.cnf
      • $MYSQL_HOME/my.cnfのこと。
      • basedirを設定してれば$MYSQL_HOME== basedirになる。
    • /home/mysql/.my.cnf
      • $HOME/.my.cnfのこと。コイツだけドットファイル。
    の順番で読む。
    とはいえこんなのめんどくさくて憶えてられなかったり、SYSCONFDIRやMYSQL_HOMEが思いもしない変なところになってたりすることがあったりなかったりするかも知れないので、調べ方だけメモってみる。


    # strace -ff -e open -e stat /usr/mysql/5.5.34/bin/mysqld_multi start 55,56 2>&1 | grep "my\.cnf"
    
    [pid  7359] stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=3584, ...}) = 0
    [pid  7359] stat("/etc/mysql/my.cnf", 0x7fffa1322e40) = -1 ENOENT (No such file or directory)
    [pid  7359] stat("/usr/local/mysql/etc/my.cnf", 0x7fffa1322e40) = -1 ENOENT (No such file or directory)
    [pid  7359] stat("/root/.my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=3584, ...}) = 0
    stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=3584, ...}) = 0
    stat("/etc/mysql/my.cnf", 0x1739130)    = -1 ENOENT (No such file or directory)
    stat("/usr/mysql/5.5.34/my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    stat("/usr/mysql/5.5.34/my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    stat("/root/.my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    stat("/root/.my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    [pid  7361] stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=3584, ...}) = 0
    [pid  7361] stat("/etc/mysql/my.cnf", 0x7fffdaeb46e0) = -1 ENOENT (No such file or directory)
    [pid  7361] stat("/usr/local/mysql/etc/my.cnf", 0x7fffdaeb46e0) = -1 ENOENT (No such file or directory)
    [pid  7361] stat("/root/.my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    [pid  7365] stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=3584, ...}) = 0
    [pid  7365] stat("/etc/mysql/my.cnf", 0x7fff4038abf0) = -1 ENOENT (No such file or directory)
    [pid  7365] stat("/usr/local/mysql/etc/my.cnf", 0x7fff4038abf0) = -1 ENOENT (No such file or directory)
    [pid  7365] stat("/root/.my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    [pid  7371] stat("/usr/mysql/5.6.14/data/my.cnf", 0x7fff0d4bc2b0) = -1 ENOENT (No such file or directory)
    [pid  7371] stat("/usr/mysql/5.6.14/my.cnf", 0x7fff0d4bc2c0) = -1 ENOENT (No such file or directory)
    [pid  7371] stat("/usr/mysql/5.6.14/data/my.cnf", 0x7fff0d4bc320) = -1 ENOENT (No such file or directory)
    [pid  7407] stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=3584, ...}) = 0
    [pid  7407] stat("/etc/mysql/my.cnf", 0x7fff380ae700) = -1 ENOENT (No such file or directory)
    [pid  7407] stat("/usr/local/mysql/etc/my.cnf", 0x7fff380ae700) = -1 ENOENT (No such file or directory)
    [pid  7407] stat("/usr/mysql/5.6.14/my.cnf", 0x7fff380ae700) = -1 ENOENT (No such file or directory)
    [pid  7407] stat("/root/.my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    [pid  7364] stat("/usr/mysql/5.5.34/data/my.cnf", 0x7fffb0b1a980) = -1 ENOENT (No such file or directory)
    [pid  7364] stat("/usr/mysql/5.5.34/my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    [pid  7364] stat("/usr/mysql/5.5.34/data/my.cnf", 0x7fffb0b1a990) = -1 ENOENT (No such file or directory)
    [pid  7364] stat("/usr/mysql/5.5.34/data/my.cnf", 0x7fffb0b1a9f0) = -1 ENOENT (No such file or directory)
    [pid  7421] stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=3584, ...}) = 0
    [pid  7421] stat("/etc/mysql/my.cnf", 0x7fffde0a77e0) = -1 ENOENT (No such file or directory)
    [pid  7421] stat("/usr/local/mysql/etc/my.cnf", 0x7fffde0a77e0) = -1 ENOENT (No such file or directory)
    [pid  7421] stat("/usr/mysql/5.5.34/my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    [pid  7421] stat("/root/.my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    [pid  8339] stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=3584, ...}) = 0
    [pid  8339] stat("/etc/mysql/my.cnf", 0x7fff59e821d0) = -1 ENOENT (No such file or directory)
    [pid  8339] stat("/usr/local/mysql/etc/my.cnf", 0x7fff59e821d0) = -1 ENOENT (No such file or directory)
    [pid  8339] stat("/usr/mysql/5.6.14/my.cnf", 0x7fff59e821d0) = -1 ENOENT (No such file or directory)
    [pid  8339] stat("/root/.my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    [pid  8416] stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=3584, ...}) = 0
    [pid  8416] stat("/etc/mysql/my.cnf", 0x7fffc5f4d310) = -1 ENOENT (No such file or directory)
    [pid  8416] stat("/usr/local/mysql/etc/my.cnf", 0x7fffc5f4d310) = -1 ENOENT (No such file or directory)
    [pid  8416] stat("/usr/mysql/5.5.34/my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    [pid  8416] stat("/root/.my.cnf", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
    


    実際どれを開いたかだけでよければ、"-e stat"はイラナイ。
    小ネタ、小ネタ。


    【2015/02/18 19:39】
    mysqldの読むやつ見たいんだったらmysqld --help --verboseでいいじゃん? って何度か言われてたので追記。
    mysqld --help --verboseだと、my.cnfに設定したbasedirの値が読み取られる前にパスが解釈されるので、MYSQL_HOME/my.cnfが表示されない。


    $ /usr/mysql/5.6.23/bin/mysqld --help --verbose  | grep cnf
    /etc/my.cnf /etc/mysql/my.cnf /usr/local/mysql/etc/my.cnf ~/.my.cnf
                          my.cnf, $MYSQL_TCP_PORT, /etc/services, built-in default
    2015-02-19 19:35:47 29891 [Note] Binlog end
    2015-02-19 19:35:47 29891 [Note] Shutting down plugin 'CSV'
    2015-02-19 19:35:47 29891 [Note] Shutting down plugin 'MyISAM'
    
    $ strace -f -e stat /usr/mysql/5.6.23/bin/mysqld 2>&1 | grep my\.cnf
    stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=4456, ...}) = 0
    stat("/etc/mysql/my.cnf", 0x7fffd4f430d0) = -1 ENOENT (No such file or directory)
    stat("/usr/local/mysql/etc/my.cnf", 0x7fffd4f430d0) = -1 ENOENT (No such file or directory)
    stat("/home/yoku0825/.my.cnf", 0x7fffd4f430d0) = -1 ENOENT (No such file or directory)
    
    
    $ strace -f -e stat /usr/mysql/5.6.23/bin/mysqld_safe 2>&1 | grep my\.cnf
    stat("/usr/mysql/5.6.23/data/my.cnf", 0x7fff56f127f0) = -1 ENOENT (No such file or directory)
    stat("/usr/mysql/5.6.23/my.cnf", {st_mode=S_IFREG|0664, st_size=943, ...}) = 0
    stat("/usr/mysql/5.6.23/data/my.cnf", 0x7fff56f12800) = -1 ENOENT (No such file or directory)
    stat("/usr/mysql/5.6.23/data/my.cnf", 0x7fff56f12860) = -1 ENOENT (No such file or directory)
    [pid 28434] stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=4456, ...}) = 0
    [pid 28434] stat("/etc/mysql/my.cnf", 0x7ffffdd236c0) = -1 ENOENT (No such file or directory)
    [pid 28434] stat("/usr/local/mysql/etc/my.cnf", 0x7ffffdd236c0) = -1 ENOENT (No such file or directory)
    [pid 28434] stat("/usr/mysql/5.6.23/my.cnf", {st_mode=S_IFREG|0664, st_size=943, ...}) = 0
    [pid 28434] stat("/home/yoku0825/.my.cnf", 0x7ffffdd236c0) = -1 ENOENT (No such file or directory)
    [pid 28916] stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=4456, ...}) = 0
    [pid 28916] stat("/etc/mysql/my.cnf", 0x7fff43cc1bd0) = -1 ENOENT (No such file or directory)
    [pid 28916] stat("/usr/local/mysql/etc/my.cnf", 0x7fff43cc1bd0) = -1 ENOENT (No such file or directory)
    [pid 28916] stat("/usr/mysql/5.6.23/my.cnf", {st_mode=S_IFREG|0664, st_size=943, ...}) = 0
    [pid 28916] stat("/home/yoku0825/.my.cnf", 0x7fff43cc1bd0) = -1 ENOENT (No such file or directory)
    [pid 29004] stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=4456, ...}) = 0
    [pid 29004] stat("/etc/mysql/my.cnf", 0x7fff76cacf80) = -1 ENOENT (No such file or directory)
    [pid 29004] stat("/usr/local/mysql/etc/my.cnf", 0x7fff76cacf80) = -1 ENOENT (No such file or directory)
    [pid 29004] stat("/usr/mysql/5.6.23/my.cnf", {st_mode=S_IFREG|0664, st_size=943, ...}) = 0
    [pid 29004] stat("/home/yoku0825/.my.cnf", 0x7fff76cacf80) = -1 ENOENT (No such file or directory)
    

    よく憶えてないんだけど、たぶんこれがラッパーに隠蔽されて(mysql.serverが中でゴニョゴニョやってるとかそんなの)るのが嫌でstraceで取ったんじゃないかなぁと思う。


    $ MYSQL_HOME=/usr/mysql/5.6.23 /usr/mysql/5.6.23/bin/mysqld --help --verbose  | grep cnf
    /etc/my.cnf /etc/mysql/my.cnf /usr/local/mysql/etc/my.cnf /usr/mysql/5.6.23/my.cnf ~/.my.cnf
                          my.cnf, $MYSQL_TCP_PORT, /etc/services, built-in default
    2015-02-19 19:35:18 29889 [Note] Binlog end
    2015-02-19 19:35:18 29889 [Note] Shutting down plugin 'CSV'
    2015-02-19 19:35:18 29889 [Note] Shutting down plugin 'MyISAM'
    

    $MYSQL_HOMEをちゃんと環境変数で与えておけば、mysqld --help --verboseでも見える。

    あとはmy.cnfに!include が書いてあるケースとかも--help --verboseでは拾えないなぁとかそんなことをぼんやりと。

    Isucon #3に出場してチームをお通夜にしてしまった話

    俺の大ポカに巻き込まれたチームメイトの @studio3104 さんと @ayumu83s さんごめんなさい。
    俺がしでかしたことをありのまま話すぜ。


    • 取り敢えず吊るしのベンチマークを取る。
    • 開始早々、MySQL 5.6.13をPercona Server 5.6.13に取替え。
      • この時、datadirは使い回しでバックアップを取らなかった。
    • my.cnfをチューニングしてibdata1とib_logfile*を再作成。
      • その間アプリ側ではTCP/IP接続をsocket接続に書き換えてもらったり、プロファイル仕込んでもらったり。
    • この時点からベンチマークが通らなくなる。
      • 原因はInnoDB memcachedを殺したからなんですがこの時点では判らず。
      • アプリ側のコードを切り戻したりPercona ServerをMySQLに戻したりしたけれど、ベンチマークは相変わらずFAILする。
    • すたじおさんの到着も遅れていたし、取り敢えずエラーは後で解析するとして判るところからチューニングを開始することに。
    • テーブルにINDEXをガスガス追加。INSERT, UPDATEのトラフィックは大したことがなさそうだったので、基本covering index狙いの長めのキー。covering indexが狙えないところはORDER BY狙いのキー。
    • Percona Serverだろうとオプティマイザーは残念な感じなので、片っ端からUSE INDEXを付けてインデックスを固定。あと、変なループがあるって教えてもらったのでJOINに書き換え。
      • このJOINも、最終的にはスコアが下がったっていって切り戻したんだけど(´・ω・`)
    • Apacheをnginxに入れ替えたりアプリをデバッグしてもらっても原因が見えないし、general logを眺めていたら"WHERE id=NULL"ってクエリーが㌧でいたので、データがおかしいのかなぁと思ってinit.sql.gzからデータを再投入したり、mysqldumpを吸い上げてリストアしてみたり。当然何も起こらない。
      • ええ、InnoDB memcachedにセッション情報保存してましたから、セッション情報が引き渡されないんですよね。
    • ピンポイントに打ってくるINSERT, UPDATEとSELECTはHandlerSocketかInnoDB memcachedでやっつけるかと思ってNet::HandlerSocketをmake。InnoDB memcached PluginもPercona Serverのバイナリーには入ってなかったのでソース落としてきてmake。
      • innodb_memcache.containersをごにょごにょして何度か再起動するものの、目的の用途に使うには向かないのでHandlerSocketの方が良さそうだと判断。
      • アプリ環境周りのセットアップが全く判っていないので、HandlerSocketのライブラリをmake installしてもパスが通っておらず結局使えない(´・ω・`)
    • SQLは「結果セットを変えない」ことを大前提にちょっと書き換えただけ。
      • 普段の仕事っぷりが見事に出るなぁ。。_| ̄|○
    • 残り1時間、ついにインスタンスを破棄して新しいインスタンスを立ち上げることを決意。
      • 勿論ベンチ通る。
    • Percona Serverに変える。
      • 通らなくなる。
      • ここかよ! だがデータストアが変わっただけで何が変わる?
    • ところでなんかエラーログのInnoDB memcachedのエラー(" InnoDB_Memcached: the value column c2 in table test/demo_test should be INTEGER, CHAR or VARCHAR.")がウザいので、UNINSTALL PLUGIN。
      • 通らなくなる。
      • Σ(゚д゚lll) うっそぉ!?
      • ま・さ・か…!
    • mysql> SELECT * FROM test.demo_test;
    • うわあああああ(AA略
    • Perconaに入れ替えてインデックス作ってSQLにヒント句追加して…ここまでで、時間切れ。


    というわけで、@studio3104 さんと @ayumu83s さんに
     8 時 間 耐 久 デ バ ッ グ 祭 り
    を強要した挙句、
     責 め る べ き は た だ 一 人
    だけど、2人とも優しくて責めるに責められず、結果お通夜に。

    MySQLしかいじれなかった結果の最終スコアは3440でした。
    本当にごめんなさい。

    2013年10月1日火曜日

    MySQL 5.7.2のEXPLAIN FOR CONNECTIONの使い方

    昨日のMyNA会でちょっと話が出ていたEXPLAIN FOR CONNECTIONの使い方。
    正直これそんなに便利なものじゃないと思うんですが。

    http://dev.mysql.com/doc/refman/5.7/en/explain.html

    {explainable_stmt | FOR CONNECTION connection_id}
    となっている通り、EXPLAINに食わせるSQLステートメントの代わりにFOR CONNECTION x; として指定する。


    conn1> explain SELECT * FROM t1, t1 AS t2;
    +----+-------------+-------+------+---------------+------+---------+------+--------+---------------------------------------+
    | id | select_type | table | type | possible_keys | key  | key_len | ref  | rows   | Extra                                 |
    +----+-------------+-------+------+---------------+------+---------+------+--------+---------------------------------------+
    |  1 | SIMPLE      | t1    | ALL  | NULL          | NULL | NULL    | NULL | 953856 | NULL                                  |
    |  1 | SIMPLE      | t2    | ALL  | NULL          | NULL | NULL    | NULL | 953856 | Using join buffer (Block Nested Loop) |
    +----+-------------+-------+------+---------------+------+---------+------+--------+---------------------------------------+
    2 rows in set (0.00 sec)
    
    conn1> SELECT * FROM t1, t1 AS t2;
    ..(実行中)
    
    conn2> show processlist;
    +----+------+-----------+------+---------+------+--------------+----------------------------+
    | Id | User | Host      | db   | Command | Time | State        | Info                       |
    +----+------+-----------+------+---------+------+--------------+----------------------------+
    |  3 | root | localhost | d1   | Query   |    5 | Sending data | SELECT * FROM t1, t1 AS t2 |
    |  4 | root | localhost | NULL | Query   |    0 | init         | show processlist           |
    +----+------+-----------+------+---------+------+--------------+----------------------------+
    2 rows in set (0.51 sec)
    
    conn2> EXPLAIN FOR CONNECTION 3;
    +----+-------------+-------+------+---------------+------+---------+------+--------+---------------------------------------+
    | id | select_type | table | type | possible_keys | key  | key_len | ref  | rows   | Extra                                 |
    +----+-------------+-------+------+---------------+------+---------+------+--------+---------------------------------------+
    |  1 | SIMPLE      | t1    | ALL  | NULL          | NULL | NULL    | NULL | 953856 | NULL                                  |
    |  1 | SIMPLE      | t2    | ALL  | NULL          | NULL | NULL    | NULL | 953856 | Using join buffer (Block Nested Loop) |
    +----+-------------+-------+------+---------------+------+---------+------+--------+---------------------------------------+
    2 rows in set (0.25 sec)
    

    こんな感じ。おんなじじゃーん、て。

    ところでEXPLAIN FOR CONNECTIONかけるとかけた方のコネクション(id= 3のコネクション)がアボートするんだけどこれバグ?;

    【2013/10/01 13:36】
    EXPLAIN FOR CONNECTIONかけなくても落ちた。

    【2013/10/01 13:40】
    OOM Killerに殺されてるだけだった…(´;ω;`)

    2013年9月30日月曜日

    MySQL Cluster Casual Talksで話せなかった、俺がNDBCLUSTERを使わない理由

    なぁんて、もったいぶった話じゃないんですけど。

    あ、@kamipo さんアイスごちそうさまです。





    NDBCLUSTERを使いたくても使えない(んだか使わないんだかよく判らなくなってきた)理由は、

    • 今MySQL Serverで動いているのを全て突っ込むには容量がつらい。
      • 更新主体のテーブルだけ、というのは障害点が増えるだけなのでパス。
      • Diskテーブルに落としたらオワコンなベンチマークも見られたし。
    • ウチではmroongaによる全文検索マンセー。
      • だったらやりようによって全文検索&クラスタリングのXtraDB Clusterやりたい。
    • 何でもいいから突っ込むというのはどうも美しくない。
      • InnoDBの方が性能が出るパターンなら(ほとんど、ですね)InnoDBで上手く冗長化したい。
      • あと、それじゃあ説得力不足でサーバー出してもらえない。
    あたりです。

    シングルサインオンって訳じゃないんですが、1回ユーザー登録するといろんなサービスでそのアカウント情報を使い回せるっていう仕組みがあるので、そこの認証部分はNDBCLUSTER向きだなっと思っていたりしますが、そういうとこに限ってやっぱり改修しにくかったりするんですよねー。。


    スライドは半分くらいが余談で占められてるんですが、
     @Rkajiyama さんの話と め ち ゃ め ち ゃ カ ブ っ て る し
    でもまあいいんです色々お話楽しかったです。

    最後になりますが、ご登壇いただいた @Rkajiyama さん、@nippondanji さん、@tsakurada さん、@yyamasaki1 さん、ご来場いただいたみなさま、ハッシュタグまとめてくれた @76whizkidz さん、ブログ書いてくれたみなさま、手伝ってくれた会社のみなさま。

    どうもありがとうございました。とても楽しかったです(俺が)
    次はMyISAM Deep Talksですかね :) 楽しみにしています。

    さて、今日はMyNA会だー。

    2013年9月19日木曜日

    pt-online-schema-changeのクエリーをレプリケーションしない方法

    みんなのヒーロー pt-online-schema-change ですが、HandlerSocketと非常に相性が悪い。というかHandlerSocketとテーブルのメタデータをロックするDDL(つまりフツーのALTER TABLEでも)相性がすごく悪い。

    去年もハマってましたね。季節ものなんでしょうか。まだ試す予定ってタイトルに書いてあった割に1年放置してましたはい。
    ⇒ HandlerSocketの不思議な動作(まだ試す予定)

    HandlerSocketで読み書きしている環境でALTER TABLEをかけようとすると、

    1. ALTER TABLEはHandlerSocketのTable Closeを待つ
    2. 後続のクエリーはALTER TABLEのメタデータロックを待つ
    3. 何故かいつまでもTableをクローズせず使いまわすHandlerSocketがいる気配
    4. HandlerSocketの中にはテーブルをクローズして、ALTER TABLEのメタデータロック待ちに入るスレッドもいる
    5. もうだめぽ
    という訳で、HandlerSocketを(readの時だけ)使っているウチの環境でpt-online-schema-changeをする時は、

    1. マスターにはHandlerSocketが来ていないのでsql_log_bin= OFFでpt-online-schema-change
    2. スレーブに来ているHandlerSocketの向き先を全てマスターに向ける
    3. スレーブのHSコネクションが全部切れたら、FLUSH TABLESしてからpt-online-schema-change
    というステップでやっています。


    pt-online-schema-changeでセッション変数を押し込むには--set-vars=".."で設定します。

    $ pt-online-schema-change --execute --set-vars="sql_log_bin= OFF" --alter "MODIFY  order_col varchar(100) COLLATE utf8_bin NOT NULL, DROP KEY IX_ORDER_COL, Engine= InnoDB" h=localhost,D=dbname,t=tablename,u=root,p=xxxx,S=/var/lib/mysql/mysql.sock
    

    これで一連の操作の手前に"SET SESSION sql_log_bin= OFF;"が叩き込まれるので、1つ目のステップが実行できます。

    Percona-toolkit 2.2.1, 2.2.2のpt-online-schema-changeには--set-vars="SQL_LOG_BIN= 0"を渡すとInvalidだと怒られるバグがあるので、なんとなくsql_log_bin= OFFで設定するようにしてあります。
    ⇒ https://bugs.launchpad.net/percona-toolkit/+bug/1182856

    これ素敵だよなぁ。。

    2013年9月17日火曜日

    MySQL 5.6.11以降のInnoDBテーブルでAUTO_INCREMENTの値を小さくできない件

    なんか変だなーと思っていたんですがすっきりしました。

    mysql56> CREATE TABLE t1 (num serial, val varchar(32)) Engine= InnoDB;
    Query OK, 0 rows affected (0.05 sec)
    
    mysql56> SHOW CREATE TABLE t1\G
    *************************** 1. row ***************************
           Table: t1
    Create Table: CREATE TABLE `t1` (
      `num` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
      `val` varchar(32) DEFAULT NULL,
      UNIQUE KEY `num` (`num`)
    ) ENGINE=InnoDB DEFAULT CHARSET=utf8
    1 row in set (0.00 sec)
    
    mysql56> INSERT INTO t1 VALUES (1, 'one'), (2, 'two');
    Query OK, 2 rows affected (0.02 sec)
    Records: 2  Duplicates: 0  Warnings: 0
    
    mysql56> SELECT * FROM t1;
    +-----+------+
    | num | val  |
    +-----+------+
    |   1 | one  |
    |   2 | two  |
    +-----+------+
    2 rows in set (0.00 sec)
    
    mysql56> SHOW CREATE TABLE t1\G
    *************************** 1. row ***************************
           Table: t1
    Create Table: CREATE TABLE `t1` (
      `num` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
      `val` varchar(32) DEFAULT NULL,
      UNIQUE KEY `num` (`num`)
    ) ENGINE=InnoDB AUTO_INCREMENT=3 DEFAULT CHARSET=utf8
    1 row in set (0.00 sec)
    
    mysql56> ALTER TABLE t1 AUTO_INCREMENT= 10000;
    Query OK, 0 rows affected (0.01 sec)
    Records: 0  Duplicates: 0  Warnings: 0
    
    mysql56> SHOW CREATE TABLE t1\G
    *************************** 1. row ***************************
           Table: t1
    Create Table: CREATE TABLE `t1` (
      `num` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
      `val` varchar(32) DEFAULT NULL,
      UNIQUE KEY `num` (`num`)
    ) ENGINE=InnoDB AUTO_INCREMENT=10000 DEFAULT CHARSET=utf8
    1 row in set (0.00 sec)
    
    mysql56> ALTER TABLE t1 AUTO_INCREMENT= 10;
    Query OK, 0 rows affected (0.01 sec)
    Records: 0  Duplicates: 0  Warnings: 0
    
    mysql56> SHOW CREATE TABLE t1\G
    *************************** 1. row ***************************
           Table: t1
    Create Table: CREATE TABLE `t1` (
      `num` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
      `val` varchar(32) DEFAULT NULL,
      UNIQUE KEY `num` (`num`)
    ) ENGINE=InnoDB AUTO_INCREMENT=10000 DEFAULT CHARSET=utf8
    1 row in set (0.00 sec)
    

    5.5のInnoDBならこれできるんです。5.6のMyISAMでもできます。

    マニュアルの書き方を比較しても、5.6のInnoDBでだけAUTO_INCREMENTを小さくできない様には読めないのでなんかもやもやします。

    5.5 ALTER TABLE: http://dev.mysql.com/doc/refman/5.5/en/alter-table.html
    ⇒MAX(auto_increment_column)より小さい値を与えた場合、MyISAMはMAX(auto_increment_column)+ 1に勝手に切り詰めて、InnoDBは値が変更されない。
    ⇒MAX(auto_increment_column)より大きい値の場合は言及なし。

    5.6 ALTER TABLE: http://dev.mysql.com/doc/refman/5.6/en/alter-table.html
    ⇒MyISAMもInnoDBもMAX(auto_increment_column)より小さい値を与えた場合はMAX(auto_increment_column)+ 1に切り詰める。
    ⇒MAX(auto_increment_column)より大きい値の場合は言及なし。


    と思ったらバグレポート見つけた。これだ。

    MySQL Bug #69882: http://bugs.mysql.com/bug.php?id=69882


    バグレポートのWorkaroundにはTRUNCATEしか紹介されていませんが、ALTER TABLE .. ALGORITHM= COPYを使えば小さくできました。ドキュメントの記載漏れなのか、バグとして扱われるのか微妙なとこですね。。

    【2014/02/03 12:48】 結構前ですが、バグとしてVerifyされてます。5.6.16(2014/01/31)でFIXされています。


    mysql56> ALTER TABLE t1 ALGORITHM= COPY, AUTO_INCREMENT= 10;
    Query OK, 2 rows affected (0.11 sec)
    Records: 2  Duplicates: 0  Warnings: 0
    
    mysql56> SHOW CREATE TABLE t1\G
    *************************** 1. row ***************************
           Table: t1
    Create Table: CREATE TABLE `t1` (
      `num` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
      `val` varchar(32) DEFAULT NULL,
      UNIQUE KEY `num` (`num`)
    ) ENGINE=InnoDB AUTO_INCREMENT=10 DEFAULT CHARSET=utf8
    1 row in set (0.00 sec)
    

    これ見ても、InnoDB Online ALTER TABLEの時はできない、と言ってるようには見えないんですけどねー。。
    http://dev.mysql.com/doc/refman/5.6/en/innodb-create-index-overview.html

    2013年9月14日土曜日

    MariaDB 10.0のMulti-source replicationを試す

    MariaDB 10.0.2でインプリメントされたMulti-source replication(1スレーブに複数マスター構成)、MySQL 5.6に紛れて試していなかったんだけれど時間があったのでちょっとだけ試してみた。

    リファレンス ⇒ https://mariadb.com/kb/en/multi-source-replication/

    MariaDB KnowledgebaseはWEB遅い、マニュアル見づらい感。。



    mariadb> SHOW ALL SLAVES STATUS\G
    Empty set (0.00 sec)
    
    mariadb> CHANGE MASTER 'mysql56' TO master_host= 'localhost', master_port= 64056, master_user= 'replicator', master_log_file= 'bin.000001', master_log_pos= 1;
    Query OK, 0 rows affected (0.03 sec)
    
    mariadb> SHOW SLAVE 'mysql56' STATUS\G
    *************************** 1. row ***************************
                   Slave_IO_State:
                      Master_Host: localhost
                      Master_User: replicator
                      Master_Port: 64056
                    Connect_Retry: 60
                  Master_Log_File: bin.000001
              Read_Master_Log_Pos: 4
                   Relay_Log_File: relay-mysql56.000001
                    Relay_Log_Pos: 4
            Relay_Master_Log_File: bin.000001
                 Slave_IO_Running: No
                Slave_SQL_Running: No
    ..
    1 row in set (0.00 sec)
    
    mariadb> CHANGE MASTER 'mysql55' TO master_host= 'localhost', master_port= 64055, master_user= 'replicator', master_log_file= 'bin.000001', master_log_pos= 1;
    Query OK, 0 rows affected (0.02 sec)
    
    mariadb> SHOW ALL SLAVES STATUS\G
    *************************** 1. row ***************************
                  Connection_name: mysql55
                  Slave_SQL_State:
                   Slave_IO_State:
                      Master_Host: localhost
                      Master_User: replicator
                      Master_Port: 64055
                    Connect_Retry: 60
                  Master_Log_File: bin.000001
              Read_Master_Log_Pos: 4
                   Relay_Log_File: relay-mysql55.000001
                    Relay_Log_Pos: 4
            Relay_Master_Log_File: bin.000001
                 Slave_IO_Running: No
                Slave_SQL_Running: No
    ..
    *************************** 2. row ***************************
                  Connection_name: mysql56
                  Slave_SQL_State:
                   Slave_IO_State:
                      Master_Host: localhost
                      Master_User: replicator
                      Master_Port: 64056
                    Connect_Retry: 60
                  Master_Log_File: bin.000001
              Read_Master_Log_Pos: 4
                   Relay_Log_File: relay-mysql56.000001
                    Relay_Log_Pos: 4
            Relay_Master_Log_File: bin.000001
                 Slave_IO_Running: No
                Slave_SQL_Running: No
    ..
    2 rows in set (0.00 sec)
    
    mariadb> SHOW SLAVE STATUS\G
    Empty set (0.00 sec)
    
    mariadb> SET SESSION default_master_connection= 'mysql55';
    Query OK, 0 rows affected (0.01 sec)
    
    mariadb> SHOW SLAVE STATUS\G
    *************************** 1. row ***************************
                   Slave_IO_State:
                      Master_Host: localhost
                      Master_User: replicator
                      Master_Port: 64055
                    Connect_Retry: 60
                  Master_Log_File: bin.000001
              Read_Master_Log_Pos: 107
                   Relay_Log_File: relay-mysql55.000001
                    Relay_Log_Pos: 4
            Relay_Master_Log_File: bin.000001
                 Slave_IO_Running: No
                Slave_SQL_Running: No
    ..
    
    mariadb> START SLAVE;
    ERROR 1200 (HY000): The server is not configured as slave; fix in config file or with CHANGE MASTER TO

    こんな感じで設定。
    取り敢えずハマったのは、
    • SHOW ALL SLAVESとか。
    • SET SESSION default_master_connectionしておくと、コネクション名を指定しないSTART SLAVEとかはそのコネクションあてになる。
    • connection name(mysql55とかmysql56とかしてるやつ)はクォートしないといけない。
    • START SLAVE 'mysql55'; もSTART ALL SLAVES; も何故か通らない(何が足りないのか調べてない。。)
    とはいえ、まあ何か面白そうですよね!

    以上、PHP Conference 2013のLT聞きながらでした。。


    【2013/09/17 12:49】
    START SLAVEできなかったのは、server-idを指定していなかったというまさかのオチでしたよ! orz

    2013年9月10日火曜日

    知られざるinnodb_flush_methodの値

    innodb_flush_methodの値といえば、fdatasync(暗黙のデフォルト)かO_DIRECTくらいしか知らなかった訳だが、O_DSYNCやO_DIRECT_NO_FSYNC(5.6.7から)もあったり、Percona ServerにはALL_O_DIRECTなんてものがあったりする。
    http://dev.mysql.com/doc/refman/5.5/en/innodb-parameters.html#sysvar_innodb_flush_method
    http://dev.mysql.com/doc/refman/5.6/en/innodb-parameters.html#sysvar_innodb_flush_method
    http://www.percona.com/doc/percona-server/5.1/scalability/innodb_io.html?id=percona-server:features:innodb_io_51&redirect=2#innodb_flush_method


    が、実はlittlesyncとnosyncという値も設定できるっぽい。mysql-5.6.13/storage/innobase/srv/srv0start.cc には、

    1665         } else if (0 == ut_strcmp(srv_file_flush_method_str, "fsync")) {
    1666                 srv_unix_file_flush_method = SRV_UNIX_FSYNC;
    1667
    1668         } else if (0 == ut_strcmp(srv_file_flush_method_str, "O_DSYNC")) {
    1669                 srv_unix_file_flush_method = SRV_UNIX_O_DSYNC;
    1670
    1671         } else if (0 == ut_strcmp(srv_file_flush_method_str, "O_DIRECT")) {
    1672                 srv_unix_file_flush_method = SRV_UNIX_O_DIRECT;
    1673
    1674         } else if (0 == ut_strcmp(srv_file_flush_method_str, "O_DIRECT_NO_FSYNC")) {
    1675                 srv_unix_file_flush_method = SRV_UNIX_O_DIRECT_NO_FSYNC;
    1676
    1677         } else if (0 == ut_strcmp(srv_file_flush_method_str, "littlesync")) {
    1678                 srv_unix_file_flush_method = SRV_UNIX_LITTLESYNC;
    1679
    1680         } else if (0 == ut_strcmp(srv_file_flush_method_str, "nosync")) {
    1681                 srv_unix_file_flush_method = SRV_UNIX_NOSYNC;
     しかもちゃんと

    mysql> SHOW GLOBAL VARIABLES LIKE 'innodb_flush_method';
    +---------------------+--------+
    | Variable_name       | Value  |
    +---------------------+--------+
    | innodb_flush_method | nosync |
    +---------------------+--------+
    1 row in set (0.00 sec)
    

    認識されてるし。。


    こんな機能メンテしたくないからドキュメントからは外した、とInnoDB開発者の弁。
     ⇒http://lists.mysql.com/mysql/148920

    かなり速そうだから、バックアップからの戻しならアリかもね。。


    【2015/07/24 16:43】
    今ドキュメント見たら載ってるなぁ。。

    でもこっちはクローズされてないなぁ。。
    MySQL Bugs: #26588: innodb_flush_method, nosync and littlesync undocumented

    2013年9月6日金曜日

    MySQLのView, Stored Procedureのセキュリティ設定、デフォルトはDEFINER

    DEFINER= rootでSQL SECURITY DEFINERの話です。
    論より実験。


    d2user> SHOW GRANTS;
    +------------------------------------------------+
    | Grants for d2user@%                            |
    +------------------------------------------------+
    | GRANT USAGE ON *.* TO 'd2user'@'%'             |
    | GRANT ALL PRIVILEGES ON `d2`.* TO 'd2user'@'%' |
    +------------------------------------------------+
    2 rows in set (0.00 sec)


    d2データベースにだけ権限を持ったd2userがいます。
    ここにrootで、おとなりd1データベースのテーブルをSELECTするViewを作ります。


    root> CREATE VIEW d2.v1 AS SELECT * FROM d1.t1;
    Query OK, 0 rows affected (0.01 sec)
    
    root> SELECT * FROM d2.v1;
    +-----+-------+
    | num | val   |
    +-----+-------+
    |   1 | one   |
    |   2 | two   |
    |   3 | three |
    +-----+-------+
    3 rows in set (0.00 sec)
    


    こんな感じで。
    さてオチは読めると思いますがこのd2.v1はd2userで


    d2user> SELECT * FROM d2.v1;
    +-----+-------+
    | num | val   |
    +-----+-------+
    |   1 | one   |
    |   2 | two   |
    |   3 | three |
    +-----+-------+
    3 rows in set (0.00 sec)
    


    参照できます。
    どんなロジックが働いているかというと、


    d2user> SHOW CREATE VIEW d2.v1\G
    *************************** 1. row ***************************
                    View: v1
             Create View: CREATE ALGORITHM=UNDEFINED DEFINER=`root`@`localhost` SQL SECURITY DEFINER VIEW `v1` AS select `d1`.`t1`.`num` AS `num`,`d1`.`t1`.`val` AS `val` from `d1`.`t1`
    character_set_client: utf8
    collation_connection: utf8_general_ci
    1 row in set (0.00 sec)
    


    さっきのCREATE VIEWで設定しなかったところが暗黙のデフォルトで補完されてますね。

    ALGORITHMはViewを参照するときのベーステーブルからの取り出し方に関わるものなので今回は関係なく、DEFINER= root@localhost と SQL SECURITY DEFINERがキモです。

    DEFINERはこのViewに紐付けられたユーザー属性で、暗黙のデフォルトはCURRENT_USERです。CREATE VIEWを叩いたのはroot@localhostだったのでその値が来ています。DEFINER= でCURRENT_USER以外の値を設定できるのはSuper_priv持ちのユーザーだけです。

    SQL SECURITY DEFINERは「このビューを操作する時はDEFINERの権限を使ってViewの中身を処理する」という属性です。つまり、このビューに対するあらゆる操作はroot@localhostの権限で行われます。つまりが、

    d2user> INSERT INTO v1 VALUES (4, 'four');
    Query OK, 1 row affected (0.01 sec)
    
    d2user> SELECT * FROM v1;
    +-----+-------+
    | num | val   |
    +-----+-------+
    |   1 | one   |
    |   2 | two   |
    |   3 | three |
    |   4 | four  |
    +-----+-------+
    4 rows in set (0.00 sec)
    
    d2user> DELETE FROM v1 WHERE num= 2;
    Query OK, 1 row affected (0.02 sec)
    
    d2user> SELECT * FROM v1;
    +-----+-------+
    | num | val   |
    +-----+-------+
    |   1 | one   |
    |   3 | three |
    |   4 | four  |
    +-----+-------+
    3 rows in set (0.01 sec)


    なんでもできます。
    これを防ぐにはDEFINERをテキトーなユーザー権限に変えるか、SQL SECURITYをINVOKERにするかのどちらかです。

    DEFINERを書き換えるのはSuper_priv持ちのユーザーでないといけない、また、結局「操作したユーザーではないユーザー権限でベーステーブルにアクセスする」可能性が捨てきれないので、SQL SECURITY INVOKERにすることが多いんじゃないでしょうか。


    root> ALTER SQL SECURITY INVOKER VIEW v1 AS SELECT * FROM d1.t1;
    Query OK, 0 rows affected (0.00 sec)
    
    d2user> SELECT * FROM v1;
    ERROR 1356 (HY000): View 'd2.v1' references invalid table(s) or column(s) or function(s) or definer/invoker of view lack rights to use them
    

    Stored Procedure, Stored FunctiomもSQL SECURITY {DEFINER|INVOKER}を持っていて、同じような動き方をします。
    RDSでは逆にSQL SECURITY DEFINERを上手く使って、mysql.slow_logテーブルを「rootだろうと直接操作させず、rdsadmin(でしたっけ?)の権限で操作する」ことでローテーションさせたりできますね。

    ちなみにTRIGGERはDEFINER項目はありますがSQL SECURITY {DEFINER|INVOKER}は無く、常にDEFINER権限で操作されます。


    root> CREATE TRIGGER t1_ins_trigger AFTER INSERT ON d2.t1 FOR EACH ROW INSERT INTO d1.t2 VALUES (new.num, new.val)//
    Query OK, 0 rows affected (0.01 sec)
    
    root> SHOW CREATE TRIGGER t1_ins_trigger\G
    *************************** 1. row ***************************
                   Trigger: t1_ins_trigger
                  sql_mode: NO_ENGINE_SUBSTITUTION
    SQL Original Statement: CREATE DEFINER=`root`@`localhost` TRIGGER t1_ins_trigger AFTER INSERT ON d2.t1 FOR EACH ROW INSERT INTO d1.t2 VALUES (new.num, new.val)
      character_set_client: utf8
      collation_connection: utf8_general_ci
        Database Collation: utf8_general_ci
    1 row in set (0.00 sec)
    
    d2user> INSERT INTO d2.t1 VALUES (10, 'ten');
    Query OK, 1 row affected (0.01 sec)
    
    root> SELECT * FROM d1.t2;
    +-----+------+
    | num | val  |
    +-----+------+
    |  10 | ten  |
    +-----+------+
    1 row in set (0.00 sec)
    


    ちなみに、存在しないユーザーをDEFINER= で設定してSQL SECURITY DEFINERすると、誰からも操作できないViewが出来上がります。mysqldumpでビュー定義だけ引っ張り出してテスト環境にリストアした時にたまにやりますね。

    2013年9月5日木曜日

    --replicate-*-dbが判定するのは原則カレントデータベース

    --replicate-do-db, --replicate-ignore-dbの判定ロジックについて。

    公式はこちら。
    http://dev.mysql.com/doc/refman/5.6/en/replication-rules-db-options.html

    なんだけど、--replication-*-dbで指定しているスキーマなのにレプリケーションされない! という話はわりとあるあるなので書いておく。

    • STATEMENTモード(MIXEDでも非決定性の関数とかがなければこっち)でロギングされている場合は、default database(SELECT DATABASE()で出てくるやつ)
    • ROWモードの場合は、実際に影響を受けるデータベース
    が、--replication-*-dbと比較判定される。

    テスト。5.5がマスターで5.6がスレーブ。

    mysql56> show slave status\G
    *************************** 1. row ***************************
                   Slave_IO_State: Waiting for master to send event
                      Master_Host: localhost
                      Master_User: replicator
                      Master_Port: 64055
                    Connect_Retry: 60
                  Master_Log_File: bin.000002
              Read_Master_Log_Pos: 1986
                   Relay_Log_File: relay.000010
                    Relay_Log_Pos: 1878
            Relay_Master_Log_File: bin.000002
                 Slave_IO_Running: Yes
                Slave_SQL_Running: Yes
                  Replicate_Do_DB: d1,d2
              Replicate_Ignore_DB:
               Replicate_Do_Table:
           Replicate_Ignore_Table:
          Replicate_Wild_Do_Table:
      Replicate_Wild_Ignore_Table:..
    

    スレーブではd1, d2スキーマだけ--replicate-do-dbに指定。


    マスターのbinlog_format= STATEMENTの場合。

    $ mysql55 -e "SELECT @@global.binlog_format"
    +------------------------+
    | @@global.binlog_format |
    +------------------------+
    | STATEMENT              |
    +------------------------+
    
    $ mysql55 -e "INSERT INTO d3.t1 (val) VALUES (DATABASE())"
    $ mysql55 -e "INSERT INTO d3.t1 (val) VALUES (DATABASE())" d1
    $ mysql55 -e "INSERT INTO d3.t1 (val) VALUES (DATABASE())" d2
    $ mysql55 -e "INSERT INTO d3.t1 (val) VALUES (DATABASE())" d3
    $ mysql55 -e "INSERT INTO d3.t1 (val) VALUES (DATABASE())" information_schema
    

    カレントデータベースを変えながら5行INSERT。


    mysql55> SELECT * FROM d1.t1;
    +---------------------+--------------------+
    | ts                  | val                |
    +---------------------+--------------------+
    | 2013-09-05 11:52:21 | NULL               |
    | 2013-09-05 11:52:25 | d1                 |
    | 2013-09-05 11:52:26 | d2                 |
    | 2013-09-05 11:52:27 | d3                 |
    | 2013-09-05 11:52:31 | information_schema |
    +---------------------+--------------------+
    5 rows in set (0.05 sec)
    

    マスターでは当然こうなる。


    mysql56> SELECT * FROM d1.t1;
    +---------------------+------+
    | ts                  | val  |
    +---------------------+------+
    | 2013-09-05 11:52:25 | d1   |
    | 2013-09-05 11:52:26 | d2   |
    +---------------------+------+
    2 rows in set (0.00 sec)
    

    スレーブではこうなる。
    d3, information_schemaはd1でもd2でもないのは自明として、NULLもd1でもd2でもない、というのがよくあるハマりどころ。シェルスクリプトからmysqlコマンドラインクライアント呼んでるときとか、MySQL Workbenchで接続プロパティを作る時にDefault Schemaを空っぽのままにしてるときとか。GUI系はこれ危うい気がする。

    あとついでにこの設定はSQLスレッドのものでI/Oスレッドには関係ないので、

    $ mysqlbinlog /usr/mysql/5.6.13/data/relay.000010
    ..
    # at 2707
    #130905 11:52:21 server id 1055  end_log_pos 2917       Query   thread_id=13    exec_time=0     error_code=0
    SET TIMESTAMP=1378349541/*!*/;
    INSERT INTO d1.t1 (val) VALUES (DATABASE())
    /*!*/;
    # at 2809
    #130905 11:52:21 server id 1055  end_log_pos 2944       Xid = 87
    COMMIT/*!*/;
    # at 2836
    #130905 11:52:25 server id 1055  end_log_pos 3010       Query   thread_id=14    exec_time=0     error_code=0
    SET TIMESTAMP=1378349545/*!*/;
    BEGIN
    /*!*/;
    # at 2902
    #130905 11:52:25 server id 1055  end_log_pos 3114       Query   thread_id=14    exec_time=0     error_code=0
    use `d1`/*!*/;
    SET TIMESTAMP=1378349545/*!*/;
    INSERT INTO d1.t1 (val) VALUES (DATABASE())
    /*!*/;
    # at 3006
    #130905 11:52:25 server id 1055  end_log_pos 3141       Xid = 90
    COMMIT/*!*/;
    # at 3033
    #130905 11:52:26 server id 1055  end_log_pos 3207       Query   thread_id=15    exec_time=0     error_code=0
    SET TIMESTAMP=1378349546/*!*/;
    BEGIN
    /*!*/;
    # at 3099
    #130905 11:52:26 server id 1055  end_log_pos 3311       Query   thread_id=15    exec_time=0     error_code=0
    use `d2`/*!*/;
    SET TIMESTAMP=1378349546/*!*/;
    INSERT INTO d1.t1 (val) VALUES (DATABASE())
    /*!*/;
    # at 3203
    #130905 11:52:26 server id 1055  end_log_pos 3338       Xid = 93
    COMMIT/*!*/;
    # at 3230
    #130905 11:52:27 server id 1055  end_log_pos 3404       Query   thread_id=16    exec_time=0     error_code=0
    SET TIMESTAMP=1378349547/*!*/;
    BEGIN
    /*!*/;
    # at 3296
    #130905 11:52:27 server id 1055  end_log_pos 3508       Query   thread_id=16    exec_time=0     error_code=0
    use `d3`/*!*/;
    SET TIMESTAMP=1378349547/*!*/;
    INSERT INTO d1.t1 (val) VALUES (DATABASE())
    /*!*/;
    # at 3400
    #130905 11:52:27 server id 1055  end_log_pos 3535       Xid = 96
    COMMIT/*!*/;
    # at 3427
    #130905 11:52:31 server id 1055  end_log_pos 3617       Query   thread_id=17    exec_time=0     error_code=0
    SET TIMESTAMP=1378349551/*!*/;
    BEGIN
    /*!*/;
    # at 3509
    #130905 11:52:31 server id 1055  end_log_pos 3737       Query   thread_id=17    exec_time=0     error_code=0
    use `information_schema`/*!*/;
    SET TIMESTAMP=1378349551/*!*/;
    INSERT INTO d1.t1 (val) VALUES (DATABASE())
    /*!*/;
    # at 3629
    #130905 11:52:31 server id 1055  end_log_pos 3764       Xid = 99
    COMMIT/*!*/;
    

    リレーログまでは影響を受けずにちゃんと来ている。


    逆のパターンとして、

    $ mysql55 -e "INSERT INTO d3.t1 (val) VALUES (DATABASE())"
    $ mysql55 -e "INSERT INTO d3.t1 (val) VALUES (DATABASE())" d1
    $ mysql55 -e "INSERT INTO d3.t1 (val) VALUES (DATABASE())" d2
    $ mysql55 -e "INSERT INTO d3.t1 (val) VALUES (DATABASE())" d3
    $ mysql55 -e "INSERT INTO d3.t1 (val) VALUES (DATABASE())" information_schema
    
    mysql55> SELECT * FROM d3.t1;
    +---------------------+--------------------+
    | ts                  | val                |
    +---------------------+--------------------+
    | 2013-09-05 12:00:18 | NULL               |
    | 2013-09-05 12:00:20 | d1                 |
    | 2013-09-05 12:00:21 | d2                 |
    | 2013-09-05 12:00:23 | d3                 |
    | 2013-09-05 12:00:28 | information_schema |
    +---------------------+--------------------+
    5 rows in set (0.01 sec)
    
    mysql56> SELECT * FROM d3.t1;
    +---------------------+------+
    | ts                  | val  |
    +---------------------+------+
    | 2013-09-05 12:00:20 | d1   |
    | 2013-09-05 12:00:21 | d2   |
    +---------------------+------+
    2 rows in set (0.00 sec)
    

    --replicate-do-dbにリストされていなくても、カレントデータベースがマッチすればレプリケートされる。


    binlog_format=ROWにすると、

    $ mysql55 -e "SELECT @@global.binlog_format"
    +------------------------+
    | @@global.binlog_format |
    +------------------------+
    | ROW                    |
    +------------------------+
    
    $ mysql55 -e "INSERT INTO d2.t1 (val) VALUES (DATABASE())"
    $ mysql55 -e "INSERT INTO d2.t1 (val) VALUES (DATABASE())" d1
    $ mysql55 -e "INSERT INTO d2.t1 (val) VALUES (DATABASE())" d2
    $ mysql55 -e "INSERT INTO d2.t1 (val) VALUES (DATABASE())" d3
    $ mysql55 -e "INSERT INTO d2.t1 (val) VALUES (DATABASE())" information_schema
    
    mysql55> SELECT * FROM d2.t1;
    +---------------------+--------------------+
    | ts                  | val                |
    +---------------------+--------------------+
    | 2013-09-05 12:07:16 | NULL               |
    | 2013-09-05 12:07:18 | d1                 |
    | 2013-09-05 12:07:19 | d2                 |
    | 2013-09-05 12:07:20 | d3                 |
    | 2013-09-05 12:07:24 | information_schema |
    +---------------------+--------------------+
    5 rows in set (0.01 sec)
    
    mysql56> SELECT * FROM d2.t1;
    +---------------------+--------------------+
    | ts                  | val                |
    +---------------------+--------------------+
    | 2013-09-05 12:07:16 | NULL               |
    | 2013-09-05 12:07:18 | d1                 |
    | 2013-09-05 12:07:19 | d2                 |
    | 2013-09-05 12:07:20 | d3                 |
    | 2013-09-05 12:07:24 | information_schema |
    +---------------------+--------------------+
    5 rows in set (0.00 sec)
    


    この通り。


    本日のネタ提供は @nekogeruge_987さん でした。ごちそうさまです。