GA

2015/04/30

MySQL 5.7.5から複数のユーザーレベルロック(get_lock関数のアレ)を取れるようになった

今までは

mysql56 1> SELECT @@pseudo_thread_id;
+--------------------+
| @@pseudo_thread_id |
+--------------------+
|                  3 |
+--------------------+
1 row in set (0.00 sec)

mysql56 1>SELECT get_lock('yoku0825', 1);
+-------------------------+
| get_lock('yoku0825', 1) |
+-------------------------+
|                       1 |
+-------------------------+
1 row in set (0.02 sec)

mysql56 2> SELECT is_used_lock('yoku0825');
+--------------------------+
| is_used_lock('yoku0825') |
+--------------------------+
|                        3 |
+--------------------------+
1 row in set (0.00 sec)

こんなロックを取った状態で次のロックを取ると


mysql56 1> SELECT get_lock('yoku08253', 1);
+--------------------------+
| get_lock('yoku08253', 1) |
+--------------------------+
|                        1 |
+--------------------------+
1 row in set (0.00 sec)

mysql56 2> SELECT is_used_lock('yoku0825');
+--------------------------+
| is_used_lock('yoku0825') |
+--------------------------+
|                     NULL |
+--------------------------+
1 row in set (0.00 sec)

何も言われずに古い方のロックはリリースされていた。
これが、


mysql57 1> SELECT @@pseudo_thread_id;
+--------------------+
| @@pseudo_thread_id |
+--------------------+
|                 89 |
+--------------------+
1 row in set (0.01 sec)

mysql57 1> SELECT get_lock('yoku0825', 1);
+-------------------------+
| get_lock('yoku0825', 1) |
+-------------------------+
|                       1 |
+-------------------------+
1 row in set (0.02 sec)

mysql57 2> SELECT is_used_lock('yoku0825');
+--------------------------+
| is_used_lock('yoku0825') |
+--------------------------+
|                       89 |
+--------------------------+
1 row in set (0.01 sec)

mysql57 1> SELECT get_lock('yoku08253', 1);
+--------------------------+
| get_lock('yoku08253', 1) |
+--------------------------+
|                        1 |
+--------------------------+
1 row in set (0.00 sec)

mysql57 2> SELECT is_used_lock('yoku0825');
+--------------------------+
| is_used_lock('yoku0825') |
+--------------------------+
|                       89 |
+--------------------------+
1 row in set (0.00 sec)

複数取っても勝手にリリースされなくなった。
ユーザーロックの状態もperformance_schemaで見られるようになった的なことが書いてあるんだけど

mysql57 2> SELECT * FROM performance_schema.metadata_locks;
Empty set (0.00 sec)

mysql57 2> SELECT @@performance_schema_max_metadata_locks;
+-----------------------------------------+
| @@performance_schema_max_metadata_locks |
+-----------------------------------------+
|                                      -1 |
+-----------------------------------------+
1 row in set (0.00 sec)


あれれ…まあいいや。
-1はautosizedって書いてある けど、実際autoでいくつに設定されたんだかよくわからん。。


ところでアレだ。ロックを順次取れるようになると必ず現れてくるアイツ。そう、アイツ。

mysql57 2> SELECT get_lock('yoku0826', 1);
+-------------------------+
| get_lock('yoku0826', 1) |
+-------------------------+
|                       1 |
+-------------------------+
1 row in set (0.00 sec)

mysql57 2> SELECT get_lock('yoku08253', 1000);

mysql57 1> SELECT get_lock('yoku0826', 1);
ERROR 3058 (HY000): Deadlock found when trying to get user-level lock; try rolling back transaction/releasing locks and restarting lock acquisition.

Error 3058番。ちゃんと検出してくれるのはありがたいんだけど、この間も2番目のスレッドはget_lock関数で待ちっぱなしの状態で勝手にリリースはしてくれない。
release_lockかrelease_all_locksでリリースしてやらないとダメ。


mysql57 1> SELECT release_all_locks();
+---------------------+
| release_all_locks() |
+---------------------+
|                   2 |
+---------------------+
1 row in set (0.00 sec)

mysql57 2> SELECT get_lock('yoku08253', 1000);
+-----------------------------+
| get_lock('yoku08253', 1000) |
+-----------------------------+
|                           1 |
+-----------------------------+
1 row in set (1 min 30.79 sec)

InnoDBのデッドロックと違って *勝手にリリースしてくれない* ので、エラーをハンドルしたらrelease_lockするか接続を閉じればロックは開放されるのでそうしなければならない。
そう、お前のことだ、 *つなぎっぱなしのConnector/J氏*


MySQL :: MySQL 5.7 Release Notes :: Changes in MySQL 5.7.5 (2014-09-25, Milestone 15)

ここで"get_lock"って探すと詳しく書いてありました。

MySQL 5.7.6以降では暗黙のテンポラリーテーブルがあふれると死ぬ

MySQL 5.7.6から、JOINした時とかに作る暗黙のテンポラリーテーブルでMemoryストレージエンジンで収まらなくなった時に固定化するテンポラリーテーブル(Created_tmp_disk_tablesがカウントアップされるアレ)のストレージエンジンがInnoDBになった。

MySQL :: MySQL 5.7 Reference Manual :: 8.4.4 How MySQL Uses Internal Temporary Tables
MySQL :: MySQL 5.7 Reference Manual :: 5.1.4 Server System Variables

テンポラリーテーブル用(こっちはCREATE TEMPORARY TABLEで作るやつも含んだ言い方だと思いねえ)のテーブルスペースはREDOロギングを無効化してあったりといいこともたくさんあるんだけれど、mysqldを再起動しない限りibtmp1ファイルは決して小さくならない。



こんなエラーを見たことはないだろうか。俺はある。設定が古いサーバーだと特によくある。

mysql57> SELECT @@internal_tmp_disk_storage_engine;
+------------------------------------+
| @@internal_tmp_disk_storage_engine |
+------------------------------------+
| MYISAM                             |
+------------------------------------+
1 row in set (0.00 sec)

mysql57> SELECT * FROM (SELECT * FROM t1 WHERE val LIKE 'abc%') AS t1, (SELECT * FROM t1 WHERE val LIKE 'def%') AS t2 ORDER BY t1.num;
ERROR 126 (HY000): Incorrect key file for table '/tmp/#sql_2974_0.MYI'; try to repair it


$ tail error.log
..
2015-04-30T14:59:45.558360+09:00 87 [ERROR] /usr/mysql/5.7.7/bin/mysqld: Incorrect key file for table '/tmp/#sql_2974_0.MYI'; try to repair it
2015-04-30T14:59:45.573411+09:00 87 [ERROR] Got an error from unknown thread, /home/yoku0825/mysql-5.7.7-rc/storage/myisam/mi_write.c:223


暗黙のテンポラリーテーブルがtmpdirに作られて、容量が足りなくなるとこうなる。

$ ll /tmp
合計 792816
-rw-r----- 1 yoku0825 yoku0825 402935808  4月 30 14:59 2015 #sql_2974_0.MYD
-rw-r----- 1 yoku0825 yoku0825      1024  4月 30 14:59 2015 #sql_2974_0.MYI
-rw-rw-r-- 1 yoku0825 yoku0825 408888897  4月 30 14:45 2015 md5
drwx------ 2 yoku0825 tmux         4096  4月 17 15:45 2015 tmux-3012

$ df -h
Filesystem            Size  Used Avail Use% Mounted on
/dev/mapper/vg_00-lv_root
                       42G   40G   33M 100% /


暗黙のテンポラリーテーブルがDiskを食いきってクエリーがアボートされるとストレージ容量は元に戻る。
internal_tmp_disk_storage_engine= MyISAMのとき(MySQL 5.7.5とそれ以前)はこんな動作だった。

ところがInnoDBになるとibtmp1にこのデータを書くし、ibtmp1はmysqldの再起動まで容量が空かないので、

mysql57> SELECT @@internal_tmp_disk_storage_engine;
+------------------------------------+
| @@internal_tmp_disk_storage_engine |
+------------------------------------+
| INNODB                             |
+------------------------------------+
1 row in set (0.03 sec)

mysql57> SELECT * FROM (SELECT * FROM t1 WHERE val LIKE 'abc%') AS t1, (SELECT * FROM t1 WHERE val LIKE 'def%') AS t2 ORDER BY t1.num;
ERROR 1114 (HY000): The table '/tmp/#sql_2974_0' is full

$ tail error.log
..
2015-04-30T15:04:22.549484+09:00 87 [ERROR] InnoDB: posix_fallocate(): Failed to preallocate data for file ./ibtmp1, desired size 67108864 bytes. Operating system error number 28. Check that the disk is not full or a disk quota exceeded. Make sure the file system supports this function. Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html
2015-04-30T15:04:22.590070+09:00 87 [Warning] InnoDB: 1048576 bytes should have been written. Only 794624 bytes written. Retrying again to write the rem

クエリーがアボートしても容量は開放されていない。


$ ll /usr/mysql/5.7.7/data/ibtmp1
-rw-r----- 1 yoku0825 yoku0825 485236736  4月 30 15:04 2015 /usr/mysql/5.7.7/data/ibtmp1

$ df -h
Filesystem            Size  Used Avail Use% Mounted on
/dev/mapper/vg_00-lv_root
                       42G   40G   17M 100% /


ベンチマーク取りながらうっかり100%突っ込んだ人とかならわかると思うんだけれど、DiskがFullな状態で更新かけるとbinlogに書き込もうとしたときにそこで詰まって

mysql57> INSERT INTO t1 VALUES (0, 'test');

何も言わずにmysqldは応答を返さない。


(gdb) bt
#0  0x00000038862aca3d in nanosleep () at ../sysdeps/unix/syscall-template.S:82
#1  0x00000038862ac8b0 in __sleep (seconds=0) at ../sysdeps/unix/sysv/linux/sleep.c:138
#2  0x0000000000e9a111 in wait_for_free_space (filename=0x7f3d6f428690 "./bin.000002", errors=)
    at /home/yoku0825/mysql-5.7.7-rc/mysys/errors.c:85
#3  0x0000000000e9147c in my_write (Filedes=19, Buffer=0x7f3d5772e0c2 "", Count=108, MyFlags=52)
    at /home/yoku0825/mysql-5.7.7-rc/mysys/my_write.c:90
#4  0x0000000000e7f579 in inline_mysql_file_write (info=0x1cfc0c8, need_append_buffer_lock=)
    at /home/yoku0825/mysql-5.7.7-rc/include/mysql/psi/mysql_file.h:1136
#5  my_b_flush_io_cache (info=0x1cfc0c8, need_append_buffer_lock=)
    at /home/yoku0825/mysql-5.7.7-rc/mysys/mf_iocache.c:1537
#6  0x0000000000e2a317 in MYSQL_BIN_LOG::flush_cache_to_file (this=0x1cfbdc0, end_pos_var=0x7f3d6fda9520)
    at /home/yoku0825/mysql-5.7.7-rc/sql/binlog.cc:8187
#7  0x0000000000e39a14 in MYSQL_BIN_LOG::ordered_commit (this=0x1cfbdc0, thd=0x7f3d55ffa000, all=,
    skip_commit=) at /home/yoku0825/mysql-5.7.7-rc/sql/binlog.cc:8467
#8  0x0000000000e39c62 in MYSQL_BIN_LOG::write_binlog_and_commit_engine (this=0x1cfbdc0, thd=0x7f3d55ffa000,
    all=) at /home/yoku0825/mysql-5.7.7-rc/sql/binlog.cc:7858
#9  0x0000000000e3a1d4 in MYSQL_BIN_LOG::commit (this=, thd=0x7f3d55ffa000, all=)
    at /home/yoku0825/mysql-5.7.7-rc/sql/binlog.cc:7643
#10 0x000000000079dc60 in ha_commit_trans (thd=0x7f3d55ffa000, all=,
    ignore_global_read_lock=) at /home/yoku0825/mysql-5.7.7-rc/sql/handler.cc:1615
#11 0x0000000000d1c0fe in trans_commit_stmt (thd=)
    at /home/yoku0825/mysql-5.7.7-rc/sql/transaction.cc:395
#12 0x0000000000c687ec in mysql_execute_command (thd=0x7f3d55ffa000) at /home/yoku0825/mysql-5.7.7-rc/sql/sql_parse.cc:4591
#13 0x0000000000c6acb0 in mysql_parse (thd=0x7f3d55ffa000, parser_state=)
    at /home/yoku0825/mysql-5.7.7-rc/sql/sql_parse.cc:5159
#14 0x0000000000c6c1c6 in dispatch_command (command=COM_QUERY, thd=0x7f3d55ffa000,
    packet=0x7f3d55c1b011 "INSERT INTO t1 VALUES (0, 'test')", packet_length=33)
    at /home/yoku0825/mysql-5.7.7-rc/sql/sql_parse.cc:1249
#15 0x0000000000d3a1dc in handle_connection (arg=)
    at /home/yoku0825/mysql-5.7.7-rc/sql/conn_handler/connection_handler_per_thread.cc:298
#16 0x0000000000f066b7 in pfs_spawn_thread (arg=0x7f3d693a2210)
    at /home/yoku0825/mysql-5.7.7-rc/storage/perfschema/pfs.cc:2147
#17 0x00000038866079d1 in start_thread (arg=0x7f3d6fdac700) at pthread_create.c:301
#18 0x00000038862e88fd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

$ tail error.log
2015-04-30T15:12:50.592458+09:00 87 [ERROR] Disk is full writing './bin.000002' (Errcode: 28 - No space left on device). Waiting for someone to free space...
2015-04-30T15:12:50.592539+09:00 87 [ERROR] Retry in 60 secs. Message reprinted in 600 secs
2015-04-30T15:22:50.705673+09:00 87 [ERROR] Disk is full writing './bin.000002' (Errcode: 28 - No space left on device). Waiting for someone to free space...
2015-04-30T15:22:50.705730+09:00 87 [ERROR] Retry in 60 secs. Message reprinted in 600 secs
2015-04-30T15:32:50.831917+09:00 87 [ERROR] Disk is full writing './bin.000002' (Errcode: 28 - No space left on device). Waiting for someone to free space...
2015-04-30T15:32:50.831991+09:00 87 [ERROR] Retry in 60 secs. Message reprinted in 600 secs
2015-04-30T15:42:50.963577+09:00 87 [ERROR] Disk is full writing './bin.000002' (Errcode: 28 - No space left on device). Waiting for someone to free space...
2015-04-30T15:42:50.963636+09:00 87 [ERROR] Retry in 60 secs. Message reprinted in 600 secs
2015-04-30T15:52:51.098086+09:00 87 [ERROR] Disk is full writing './bin.000002' (Errcode: 28 - No space left on device). Waiting for someone to free space...
2015-04-30T15:52:51.098142+09:00 87 [ERROR] Retry in 60 secs. Message reprinted in 600 secs

ああ、一応ちゃんとリトライアウトはあるのか、よかった。。 主人をibtmp1に殺されてからはや1時間くらいになりますが、リトライ *アウト* はしてなかった。まだクエリーはエラーになってくれない。たぶん、これからもなってくれない。

デフォルトのまま使うと間違ってでっかい暗黙のテンポラリーテーブル作るクエリー投げちゃった、てへ☆ が笑い事でなくなるので、

innodb_tmp_data_file_pathをautoextendじゃない形でサイズを決め打っておくか(innodb_data_file_pathと同じノリで記述できる。暗黙のデフォルトはibtmp1:12M:autoextend。コールドパラメーターなのでMySQLの再起動が必要) または internal_tmp_disk_storage_engineをMyISAMにセットしておくか(こっちはオンラインでOK)

秘伝のmy.cnfにinnodb_tmp_data_file_pathを足しておくか。。


【2020/06/19 14:53】
この記事はMySQL 5.7を対象としたもので、MySQL 8.0.13とそれ以降ではこれは発生しないっぽくなっている(瞬間的に容量を食うのは一緒だが、mysqldを再起動しなくても容量が解放できるようになっている)

日々の覚書: MySQL 8.0.13とそれ以降ではibtmp1は肥大化しない(あるいは、 /var/lib/mysql/#innodb_temp ディレクトリの正体)

2015/04/03

MySQL 5.7のEXPLAINでようやく変なUsing whereが消えた

や、EXPLAINの説明用の資料作ってて気付いたんですが、こんなサンプルテーブルに対して


mysql56> show create table cards\G
*************************** 1. row ***************************
       Table: cards
Create Table: CREATE TABLE `cards` (
  `seq` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  `suite` varchar(6) NOT NULL,
  `number` tinyint(3) unsigned NOT NULL,
  UNIQUE KEY `seq` (`seq`),
  KEY `suite` (`suite`)
) ENGINE=InnoDB AUTO_INCREMENT=101 DEFAULT CHARSET=utf8
1 row in set (0.00 sec)

mysql56> SELECT * FROM cards ORDER BY _rowid LIMIT 3;
+-----+--------------+--------+
| seq | suite        | number |
+-----+--------------+--------+
|   1 | ダイヤ       |      2 |
|   2 | クラブ       |      9 |
|   3 | スペード     |      3 |
+-----+--------------+--------+
3 rows in set (0.01 sec)

WHERE句だけをインデックスで解決するクエリーをEXPLAIN取ると

mysql56> explain extended SELECT * FROM cards WHERE suite= 'ハート' ORDER BY number;
+----+-------------+-------+------+---------------+-------+---------+-------+------+----------+----------------------------------------------------+
| id | select_type | table | type | possible_keys | key   | key_len | ref   | rows | filtered | Extra                                              |
+----+-------------+-------+------+---------------+-------+---------+-------+------+----------+----------------------------------------------------+
|  1 | SIMPLE      | cards | ref  | suite         | suite | 20      | const |   31 |   100.00 | Using index condition; Using where; Using filesort |
+----+-------------+-------+------+---------------+-------+---------+-------+------+----------+----------------------------------------------------+
1 row in set, 1 warning (0.00 sec)

mysql56> SELECT * FROM cards WHERE suite= 'ハート' ORDER BY number;
..
31 rows in set (0.00 sec)

mysql56> SHOW SESSION STATUS LIKE 'handler%';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| Handler_commit             | 1     |
| Handler_delete             | 0     |
| Handler_discover           | 0     |
| Handler_external_lock      | 2     |
| Handler_mrr_init           | 0     |
| Handler_prepare            | 0     |
| Handler_read_first         | 0     |
| Handler_read_key           | 1     |
| Handler_read_last          | 0     |
| Handler_read_next          | 31    |
| Handler_read_prev          | 0     |
| Handler_read_rnd           | 0     |
| Handler_read_rnd_next      | 0     |
| Handler_rollback           | 0     |
| Handler_savepoint          | 0     |
| Handler_savepoint_rollback | 0     |
| Handler_update             | 0     |
| Handler_write              | 0     |
+----------------------------+-------+
18 rows in set (0.00 sec)

こんな風になるじゃないですか。31行をインデックスからフェッチしてUsing filesort。

それはいいんですが、インデックスだけでWHERE句を解決しているにも関わらずUsing whereが出るし、filteredは100.00以外の値を見た記憶がない。これ5.5からずっとそうだったし、バグなのか仕様なのかよくわからない。

これが5.7では、


mysql57> explain extended SELECT * FROM cards WHERE suite= 'ハート' ORDER BY number;
+----+-------------+-------+------------+------+---------------+-----------+---------+-------+------+----------+---------------------------------------+
| id | select_type | table | partitions | type | possible_keys | key       | key_len | ref   | rows | filtered | Extra                                 |
+----+-------------+-------+------------+------+---------------+-----------+---------+-------+------+----------+---------------------------------------+
|  1 | SIMPLE      | cards | NULL       | ref  | idx_suite     | idx_suite | 17      | const |  100 |    31.00 | Using index condition; Using filesort |
+----+-------------+-------+------------+------+---------------+-----------+---------+-------+------+----------+---------------------------------------+
1 row in set, 2 warnings (0.00 sec)

mysql57> SELECT * FROM cards WHERE suite= 'ハート' ORDER BY number;
..
31 rows in set (0.00 sec)

mysql57> SHOW SESSION STATUS LIKE 'handler%';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| Handler_commit             | 1     |
| Handler_delete             | 0     |
| Handler_discover           | 0     |
| Handler_external_lock      | 2     |
| Handler_mrr_init           | 0     |
| Handler_prepare            | 0     |
| Handler_read_first         | 0     |
| Handler_read_key           | 1     |
| Handler_read_last          | 0     |
| Handler_read_next          | 31    |
| Handler_read_prev          | 0     |
| Handler_read_rnd           | 0     |
| Handler_read_rnd_next      | 0     |
| Handler_rollback           | 0     |
| Handler_savepoint          | 0     |
| Handler_savepoint_rollback | 0     |
| Handler_update             | 0     |
| Handler_write              | 0     |
+----------------------------+-------+
18 rows in set (0.00 sec)

こうなってました。
テーブル全体がrowsの100件で、31.00%がフィルターされてってことなんでしょうかね? 変なUsing whereは姿を見せなくなっています。


とはいえなんかこのfilteredカラム、ちょっと謎で、インデックスだけで解決できないクエリーにすると

mysql57> explain extended SELECT * FROM cards WHERE suite = 'ハート' AND number = 1 ORDER BY number;
+----+-------------+-------+------------+------+---------------+-----------+---------+-------+------+----------+-------------+
| id | select_type | table | partitions | type | possible_keys | key       | key_len | ref   | rows | filtered | Extra       |
+----+-------------+-------+------------+------+---------------+-----------+---------+-------+------+----------+-------------+
|  1 | SIMPLE      | cards | NULL       | ref  | idx_suite     | idx_suite | 17      | const |   31 |    10.00 | Using where |
+----+-------------+-------+------------+------+---------------+-----------+---------+-------+------+----------+-------------+
1 row in set, 2 warnings (0.00 sec)

mysql57> SELECT * FROM cards WHERE suite = 'ハート' AND number = 1 ORDER BY number;
+-----+-----------+--------+
| seq | suite     | number |
+-----+-----------+--------+
|  41 | ハート    |      1 |
|  47 | ハート    |      1 |
|  50 | ハート    |      1 |
|  59 | ハート    |      1 |
|  96 | ハート    |      1 |
+-----+-----------+--------+
5 rows in set (0.00 sec)

rows= インデックスで解決できた31件、filterd= 10.00%は31 * 10.00% < 5とちょっと誤差が大きすぎる気がします。どうやって計算してるんだろ。

2015/04/01

pt-online-schema-change(と、pt-table-checksumとかもろもろ)の--recursion-methodについて

pt-online-schema-change(以下、pt-osc)をはじめとするPercona Toolkitのツール群には、--recursion-methodというオプションがあります。

pt-online-schema-change — Percona Toolkit Documentation


暗黙のデフォルトは"processlist,hosts"で、なんとなくprocesslist(SHOW PROCESSLISTからBinlog Dump Threadのホスト名を引っ張り挙げる)とhosts(SHOW SLAVE HOSTSの結果からホスト名とポート番号を引っ張り挙げる)をよしなにミックスしてくれそうな雰囲気なれど。

これ残念ながら単にprocesslistだけ指定した時と同じ結果になります。

( ´-`).oO(全くトリアージされる気はしないけど、一応ばぐれぽも上げた
Bug #1438641 “Default value of --recursion-method, “processlist,...” : Bugs : Percona Toolkit

まあそれはいいとして、各--recursion-method個別の動作。動作環境は127.0.0.1:64057に5.7なマスター, 127.10.0.1:64056 に5.6なスレーブがぶら下がっている。


* processlist

$ PTDEBUG=1 pt-online-schema-change --execute --alter "Engine = InnoDB" h=127.10.0.1,D=d1,t=t1,u=root,P=64057 --recursion-method=processlist
..
# MasterSlave:4031 30199 Recursion methods: processlist
# MasterSlave:4041 30199 Connected to D=d1,P=64057,h=127.0.0.1,t=t1,u=root
# MasterSlave:4050 30199 SELECT @@SERVER_ID
# MasterSlave:4052 30199 Working on server ID 1057
# MasterSlave:4085 30199 Looking for slaves on D=d1,P=64057,h=127.0.0.1,t=t1,u=root using methods processlist
# MasterSlave:4092 30199 Finding slaves with _find_slaves_by_processlist
# MasterSlave:4154 30199 DBI::db=HASH(0x3051a08) SHOW GRANTS FOR CURRENT_USER()
# MasterSlave:4184 30199 DBI::db=HASH(0x3051a08) SHOW PROCESSLIST
..
# MasterSlave:4097 30199 Found 1 slaves
..
# MasterSlave:4041 30199 Connected to D=d1,P=64057,h=127.10.0.1,u=root
# MasterSlave:4050 30199 SELECT @@SERVER_ID
# MasterSlave:4052 30199 Working on server ID 1057
# MasterSlave:4058 30199 Server ID seen, or not what master said
..

mysql57> show processlist;
+----+------+------------------+------+------------------+------+----------------+------------------+
| Id | User | Host             | db   | Command          | Time | State          | Info             |
+----+------+------------------+------+------------------+------+----------------+------------------+
| 39 | root | 127.10.0.1:45008 | NULL | Binlog Dump GTID |  112 | Writing to net | NULL             |
| 46 | root | localhost        | NULL | Query            |    0 | starting       | show processlist |
+----+------+------------------+------+------------------+------+----------------+------------------+
2 rows in set (0.02 sec)

SHOW PROCESSLISTの結果からCommand =~ /Binlog Dump/なスレッドのHost部からホスト名を引いている。それ以外のパラメーターはもともとマスターに接続するために指定したDSN(h=127.0.0.1,D=d1,t=t1,u=root,P=64057)を流用するらしい。
なので、IPアドレスは127.10.0.1向きになっているけどポート番号がそのまま。

というわけで、
  * マスターに接続するDSNに明示的にポートを指定している場合で
    * スレーブでポート番号が違う場合
  * マスターに接続するDSNに明示的にポートを指定していない場合(S= でソケットを指定しているとか)で
    * スレーブが標準ポート(3306)以外を使っている場合
はprocesslistではスレーブの自動検出に失敗する。


* hosts

$ PTDEBUG=1 pt-online-schema-change --execute --alter "Engine = InnoDB" h=127.0.0.1,D=d1,t=t1,u=root,P=64057 --recursion-method=hosts
..
# MasterSlave:4031 30218 Recursion methods: hosts
# MasterSlave:4041 30218 Connected to D=d1,P=64057,h=127.0.0.1,t=t1,u=root
# MasterSlave:4050 30218 SELECT @@SERVER_ID
# MasterSlave:4052 30218 Working on server ID 1057
# MasterSlave:4085 30218 Looking for slaves on D=d1,P=64057,h=127.0.0.1,t=t1,u=root using methods hosts
# MasterSlave:4092 30218 Finding slaves with _find_slaves_by_hosts
# MasterSlave:4126 30218 DBI::db=HASH(0x3260a08) SHOW SLAVE HOSTS
# MasterSlave:4130 30218 Found some SHOW SLAVE HOSTS info
..
# MasterSlave:4097 30218 Found 1 slaves
# MasterSlave:4074 30218 Recursing from D=d1,P=64057,h=127.0.0.1,t=t1,u=root to D=d1,P=64056,h=,u=root
..
Cannot connect to D=d1,P=64056,h=,u=root
# pt_online_schema_change:8027 30218 0 slaves found
..

mysql57> show slave hosts;
+-----------+------+-------+-----------+--------------------------------------+
| Server_id | Host | Port  | Master_id | Slave_UUID                           |
+-----------+------+-------+-----------+--------------------------------------+
|      1056 |      | 64056 |      1057 | 5ceebb66-c191-11e4-b66a-001a4aa000e2 |
+-----------+------+-------+-----------+--------------------------------------+
1 row in set (0.00 sec)

SHOW SLAVE HOSTSの結果からHostとPortをパースして接続に行く。一見万能そうだが、--report-hostを指定していない場合は空欄になってしまって上手くパースできていない("Cannot connect to D=d1,P=64056,h=,u=root")
あと、MySQL 5.5.23からは--report-portを指定しなかった場合は暗黙のデフォルトとしてmysqldのポートが使われるのだが、それ以前の場合は3306が暗黙のデフォルトとして使われてしまうし、5.5.3より前のバージョンはそもそも--report-hostが設定されていない場合はSHOW SLAVE HOSTSに全く表示されない。

というわけで--report-hostと--report-portが正しく設定されている場合(5.5.23以降はreport-portは未指定でもいい)のみ使えるrecursion-methodで、これらはオンラインで変更できないオプションなので、pt-oscのためだけに変更するのはなんかコレジャナイ感しかしない。

MySQL :: MySQL 5.5 Reference Manual :: 13.7.5.34 SHOW SLAVE HOSTS Syntax


* dsn

というわけで、↑の条件を満たさない(非標準ポートで使っていて、--report-hostや--report-portが全てのmysqldに行き渡っているわけではない)場合に使えるrecursion-methodってこれしか残らないと思うんだけど、ぐぐっても(英語ですら)ほとんど情報がなかった。


mysql57> create table mysql.slave (id int, dsn varchar(255));
Query OK, 0 rows affected (0.67 sec)

mysql57> INSERT INTO mysql.slave VALUES (1, 'h=127.0.0.1,P=64056,u=root');
Query OK, 1 row affected (0.23 sec)

mysql57> SELECT * FROM mysql.slave;
+------+----------------------------+
| id   | dsn                        |
+------+----------------------------+
|    1 | h=127.0.0.1,P=64056,u=root |
+------+----------------------------+
1 row in set (0.12 sec)

ここは下準備。別にmysqlスキーマに作らなくてもいいし、テーブル名も何でもいい。pt-oscのオプションで任意の値を指定できる。
カラムも(マニュアルには色々書いてあるけど)`id`カラムと`dsn`カラムさえあればそれでいい。発行されるクエリーはSELECT dsn FROM .. ORDER BY idだったので、それが結果を返しさえすればOKだ。今のところは。


$ PTDEBUG=1 pt-online-schema-change --execute --alter "Engine = InnoDB" h=127.0.0.1,D=d1,t=t1,u=root,P=64057 --recursion-method="dsn=D=mysql,t=slave"
..
# MasterSlave:4598 30328 DSN table DSN: D=mysql,t=slave
..
# MasterSlave:4619 30328 SELECT dsn FROM `mysql`.`slave` ORDER BY id
# MasterSlave:4624 30328 DSN from DSN table: h=127.0.0.1,P=64056,u=root
..
# pt_online_schema_change:8027 30328 1 slaves found
# pt_online_schema_change:8052 30328 Will check slave lag on all slaves
# pt_online_schema_change:8070 30328 Checking slave replication filters
# MasterSlave:4268 30328 DBI::db=HASH(0x2a07458) SHOW MASTER STATUS
# MasterSlave:4272 30328 binlog_do_db= file=bin.000006 position=234290939 executed_gtid_set=5ceebb66-c191-11e4-b66a-001a4aa000e2:1-13,
# ecb991db-cb86-11e4-b75b-001a4aa000e2:1-613048 binlog_ignore_db=
# MasterSlave:4244 30328 DBI::db=HASH(0x2a07458) SHOW SLAVE STATUS
# MasterSlave:4570 30328 DBI::db=HASH(0x2a07458) SHOW VARIABLES LIKE 'slave_skip_errors'
..

この通り、--recursion-method="dsn=.."で指定したスキーマ, テーブルにクエリーを発行してそこからDSNを拾う。processlistの時と同じく、テーブルのdsnカラムに指定されていない部分はマスターに接続するときに使ったDSNをそのまま流用するらしい。ホスト名とポート番号だけでなくユーザーとパスワードも指定しておいた方がいい(や、rootでどのホストからでもアクセスできるならいいけど)

また、これをやっておくと多少遅延してもいいけど性能の悪いバックアップ用のスレーブのラグに引きずられて、pt-osc自体の進行が遅くなる…とかいうのも防げる。ビバ。

ちなみに接続先のDSNを間違えて、レプリケーションのつながっていないホストに接続してしまうと、

Waiting forever for new table `d1`.`_t1_new` to replicate to myhost...

( ´-`).oO(マスターで_t1_newをCREATE TABLEした後にスレーブで_t1_newが作られてるか確認してスリープしながら無限ループしてるだけ(なので、すさまじく遅延したレプリケーション環境では出うる)んだけど本当にforever待ってしまうという。。