2019年3月8日金曜日

ストレージエンジンをインストールしている環境でのリストアではまりがちなこと

TL;DR

  • plugin_dir に必要な .so ファイルを置いておくのは大前提
  • mysqldump から戻す時は、戻す前に自分で INSTALL PLUGIN
  • 物理バックアップから戻すときは基本的にそのまま戻して起動すればおk

周囲1mくらいで2回聞かれたのでメモしておく。
対象は ストレージエンジンプラグイン (デーモンプラグインである innodb_memcached とか mysqlx は対象外)かつサーバーデフォルトで有効になって いない もの( InnoDB, MyISAM などは対象外)、つまりだいたい Mroonga, TokuDB, RocksDB あたりをターゲットとして見ている。
ストレージエンジンプラグインが有効化されるタイミングは、 INSTALL PLUGIN または mysqldの起動時に mysql.plugin にレコードがある の2つ。
プラグインは plugin_dir$basedir/lib/plugin とか、 x86_64のrpm版だったら /usr/lib64/mysql/plugin とか)に置いてあるファイル以外は読めないので、 どちらの場合も plugin_dir に対応する .so ファイルが設置済である必要がある。
という訳で、リストア先の plugin_dir.so ファイルを置いていない場合は最初に置いておく。
TokuDB とか RocksDB とかのバンドルされている(= plugin_dir.so ファイルは置いてある)けど有効化されていないストレージエンジンであればこの前提は既に満たされている。
MySQLで Mroonga を使っている時に置き忘れるパターンがほぼほぼ(MariaDBの場合はMroongaは「バンドルされているけど有効化されていないストレージエンジン」なのでMariaDBの場合は当てはまらないと思うけど最近もまだバンドルされているのかよくわからない…)
次。
物理バックアップから mysql スキーマを含んだ完全な datadir を戻す場合、特に気にする必要はない。
何故ならその mysql.plugin テーブルには既にその .so ファイルを示すレコードがINSERTされているので(バックアップ元のサーバーで INSTALL PLUGIN をした時点で、プラグインが有効化されると同時に mysql.pluginINSERT が走る)、次に mysqld を起動した段階でそのストレージエンジンは有効化される。
物理バックアップでも、 mysql スキーマを 含まない datadir を戻す場合は、 mysql.plugin にレコードがないことが期待できるので、リストアする前にリストア先のインスタンスで INSTALL PLUGIN を実行する必要がある(なんなら INSERT INTO mysql.plugin VALUES (..) でもいいけど、わざわざSQLで叩く必要はないから INSTALL PLUGIN の方がいいと思う)
というか今日日こういう取り方することは少ないと思うけれども。
論理バックアップの場合、必ずリストア前に INSTALL PLUGIN が要る。
mysql スキーマを含んでいない場合は物理バックアップの時と同じくだが、全体をまるっとリストアする場合でも、 mysql.plugin への INSERT はプラグインを有効化 しない ので、 mysql スキーマのリストアまでは成功したとしても後続(単純にASCII順に並べる気もするから、前ってこともあり得る)のスキーマをリストアするどこかで失敗する( sql_modeのNO_ENGINE_SUBSTITUTION が設定されている場合はエラー、されていない場合はワーニングでデフォルトのストレージエンジン(たぶんInnoDB)に勝手に置き換えられる)
もしどうしても論理バックアップで INSTALL PLUGIN をせずにやるとしたら、
  1. mysql スキーマだけを先にリストアする
  2. mysqld 再起動(これにより mysql.plugin のレコードが読まれてプラグインが有効化)
  3. 残りのスキーマ、もしくは mysql スキーマも含めてもう一度リストアする
    という感じになる。敢えてやる必要はどこにもないと思うけれど。
というわけで、
  • 論理バックアップから戻す時は自分で INSTALL PLUGIN
  • 物理バックアップから戻す時はそのままでおk
    なのでしたん。

2019年3月4日月曜日

gh-ostを中断させたらどうなるのかの試み

gh-ost 3日目。
gh-ostを中断させたらどうなるのか確認してみる。
pt-osc はデフォルトでは中断する時に
  • テンポラリーテーブル(gh-ost的には「ゴーストテーブル」) が残存する
  • テンポラリーテーブルに対するトリガーも残存する
な訳だがgh-ostはいかがなものか。

取り敢えず Ctrl + Cで終了させてみる

$ gh-ost --database=mysqlslap --table=t1 --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=21800 --user=msandbox --password=msandbox --allow-on-master --execute
..
^C
  • *_ghc*_gho なテーブルが残った
master [localhost] {msandbox} (mysqlslap) > show tables;
+---------------------+
| Tables_in_mysqlslap |
+---------------------+
| _t1_ghc             |
| _t1_gho             |
| t1                  |
+---------------------+
3 rows in set (0.00 sec)
  • *_ghc の中身はハートビートだとかbinlog読んだ進捗だとか
master [localhost] {msandbox} (mysqlslap) > SELECT * FROM _t1_ghc;
+-----+---------------------+--------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| id  | last_update         | hint                           | value                                                                                                                                         |
+-----+---------------------+--------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
|   1 | 2019-03-04 18:29:35 | heartbeat                      | 2019-03-04T18:29:35.951427712+09:00                                                                                                           |
|   2 | 2019-03-04 18:29:34 | state                          | GhostTableMigrated                                                                                                                            |
| 256 | 2019-03-04 18:29:34 | state at 1551691774544903728   | GhostTableMigrated                                                                                                                            |
| 257 | 2019-03-04 18:29:34 | copy iteration 0 at 1551691774 | Copy: 0/19040 0.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000001:37853608; State: migrating; ETA: N/A   |
| 258 | 2019-03-04 18:29:35 | copy iteration 0 at 1551691775 | Copy: 0/19040 0.0%; Applied: 0; Backlog: 465/1000; Time: 1s(total), 1s(copy); streamer: mysql-bin.000001:38063743; State: migrating; ETA: N/A |
+-----+---------------------+--------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
5 rows in set (0.00 sec)
  • *_gho の中身は、最終的に RENAME TABLE で切り替える用のゴーストテーブル(のできかけ)
master [localhost] {msandbox} (mysqlslap) > SELECT * FROM _t1_gho;
+--------------------------------------+------------+--------------------------------------------------------------------------------------------------------------------------------+
| id                                   | intcol1    | charcol1                                                                                                                       |
+--------------------------------------+------------+--------------------------------------------------------------------------------------------------------------------------------+
| 05bc4dca-3e60-11e9-a036-0201a32caf75 |  364531492 | qMa5SuKo4M5OM7ldvisSc6WK9rsG9E8sSixocHdgfa5uiiNTGFxkDJ4EAwWC2e4NL1BpAgWiFRcp1zIH6F1BayPdmwphatwnmzdwgzWnQ6SRxmcvtd6JRYwEKdvuWr |
...
520 rows in set (0.00 sec)
  • 比較として。 pt-online-schema-change の場合はエラーメッセージで「こいつをDROPしたまえ」というのを教えてくれる。
$ pt-online-schema-change --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=21800 --user=msandbox --password=msandbox --execute D=mysqlslap,t=t1
...
Not dropping triggers because the tool was interrupted.  To drop the triggers, execute:
DROP TRIGGER IF EXISTS `mysqlslap`.`pt_osc_mysqlslap_t1_del`
DROP TRIGGER IF EXISTS `mysqlslap`.`pt_osc_mysqlslap_t1_upd`
DROP TRIGGER IF EXISTS `mysqlslap`.`pt_osc_mysqlslap_t1_ins`
Not dropping the new table `mysqlslap`.`_t1_new` because the tool was interrupted.  To drop the new table, execute:
DROP TABLE IF EXISTS `mysqlslap`.`_t1_new`;

そのままもう一度実行しようとする

$ gh-ost --database=mysqlslap --table=t1 --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=21800 --user=msandbox --password=msandbox --allow-on-master --execute
[2019/03/04 19:04:45] [info] binlogsyncer.go:133 create BinlogSyncer with config {99999 mysql 127.0.0.1 21800 msandbox    false false <nil> false UTC true 0 0s 0s 0 false}
[2019/03/04 19:04:45] [info] binlogsyncer.go:354 begin to sync binlog from position (mysql-bin.000001, 124526534)
[2019/03/04 19:04:45] [info] binlogsyncer.go:203 register slave for master server 127.0.0.1:21800
[2019/03/04 19:04:45] [info] binlogsyncer.go:723 rotate to (mysql-bin.000001, 124526534)
2019-03-04 19:04:45 FATAL Table `_t1_gho` already exists. Panicking. Use --initially-drop-ghost-table to force dropping it, though I really prefer that you drop it or rename it away
  • *_gho を消すか --initially-drop-ghost-table を使えって言われた。
master [localhost] {msandbox} (mysqlslap) > DROP TABLE _t1_gho;
Query OK, 0 rows affected (0.06 sec)

$ gh-ost --database=mysqlslap --table=t1 --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=21800 --user=msandbox --password=msandbox --allow-on-master --execute
..
[2019/03/04 19:05:39] [info] binlogsyncer.go:164 syncer is closing...
[2019/03/04 19:05:39] [error] binlogstreamer.go:77 close sync with err: sync is been closing...
[2019/03/04 19:05:39] [info] binlogsyncer.go:179 syncer is closed
# Done
  • *_ghc はどうでもいいらしい。できた。
$ pt-online-schema-change --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=21800 --user=msandbox --password=msandbox --execute D=mysqlslap,t=t1
..
The table `mysqlslap`.`t1` has triggers but --preserve-triggers was not specified.
Please read the documentation for --preserve-triggers.
  • ちなみに pt-osc は残ったトリガーを検出して —preserve-triggers を設定しろって言ってきた。
    • 今回は「中断したあとに残存したテーブル」なので、中断時のメッセージにあったステートメントでトリガーをDROPしてやればOK
    • pt-oscはゴーストテーブルの名前を動的に作り替えるので、古いゴーストテーブルが残っていてもそれは気にしない。

ロックを衝突させて止めてみる

  • タイムアウトは十分短めにしておく。
master [localhost] {msandbox} (mysqlslap) > SELECT @@lock_wait_timeout, @@innodb_lock_wait_timeout;
+---------------------+----------------------------+
| @@lock_wait_timeout | @@innodb_lock_wait_timeout |
+---------------------+----------------------------+
|                   1 |                          1 |
+---------------------+----------------------------+
1 row in set (0.00 sec)

master [localhost] {msandbox} (mysqlslap) > begin;
Query OK, 0 rows affected (0.00 sec)

master [localhost] {msandbox} (mysqlslap) > SELECT * FROM t1 FOR UPDATE;
..
2046 rows in set (0.01 sec)
  • gh-ost側のターミナルはしばらく流れ続けてから死んだ。
Copy: 0/2046 0.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000001:145576564; State: migrating; ETA: N/A
Copy: 0/2046 0.0%; Applied: 0; Backlog: 0/1000; Time: 1s(total), 1s(copy); streamer: mysql-bin.000001:145580965; State: migrating; ETA: N/A
Copy: 0/2046 0.0%; Applied: 0; Backlog: 0/1000; Time: 2s(total), 2s(copy); streamer: mysql-bin.000001:145585423; State: migrating; ETA: N/A
Copy: 0/2046 0.0%; Applied: 0; Backlog: 0/1000; Time: 3s(total), 3s(copy); streamer: mysql-bin.000001:145590287; State: migrating; ETA: N/A
..
Copy: 0/2046 0.0%; Applied: 0; Backlog: 0/1000; Time: 3m0s(total), 3m0s(copy); streamer: mysql-bin.000001:146329869; State: migrating; ETA: N/A
2019-03-04 19:15:29 ERROR Error 1205: Lock wait timeout exceeded; try restarting transaction
2019-03-04 19:15:29 ERROR Error 1205: Lock wait timeout exceeded; try restarting transaction
2019-03-04 19:15:29 FATAL Error 1205: Lock wait timeout exceeded; try restarting transaction
  • 内部では元のテーブルからゴーストテーブルにデータを移すクエリーがタイムアウトしてロールバックを繰り返している。
2019-03-04T10:13:02.759752Z       285 Query     START TRANSACTION
2019-03-04T10:13:02.760142Z       285 Query     SET
                        SESSION time_zone = 'SYSTEM',
                        sql_mode = CONCAT(@@session.sql_mode, ',STRICT_ALL_TABLES')
2019-03-04T10:13:02.760374Z       285 Query     insert /* gh-ost `mysqlslap`.`t1` */ ignore into `mysqlslap`.`_t1_gho` (`id`, `intcol1
`, `charcol1`)
      (select `id`, `intcol1`, `charcol1` from `mysqlslap`.`t1` force index (`PRIMARY`)
        where (((`id` > _binary'000037c7-3e66-11e9-a036-0201a32caf75') or ((`id` = _binary'000037c7-3e66-11e9-a036-0201a32caf75'))) an
d ((`id` < _binary'fedbd674-3e65-11e9-a036-0201a32caf75') or ((`id` = _binary'fedbd674-3e65-11e9-a036-0201a32caf75')))) lock in share
mode
      )
2019-03-04T10:13:07.762086Z       285 Query     ROLLBACK
2019-03-04T10:13:07.762260Z       285 Quit
  • この状態で gh-ost がAbortするとソケットファイルが残るので、そのままで gh-ost を起動できなくなる(このソケットファイルは対話的にghostプロセスをサスペンドさせたりするためのソケットファイルだと思う)
$ gh-ost --database=mysqlslap --table=t1 --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=21800 --user=msandbox --password=msandbox --allow-on-master --execute --initially-drop-ghost-table
[2019/03/04 19:21:02] [info] binlogsyncer.go:133 create BinlogSyncer with config {99999 mysql 127.0.0.1 21800 msandbox    false false <nil> false UTC true 0 0s 0s 0 false}
[2019/03/04 19:21:02] [info] binlogsyncer.go:354 begin to sync binlog from position (mysql-bin.000001, 147100612)
[2019/03/04 19:21:02] [info] binlogsyncer.go:203 register slave for master server 127.0.0.1:21800
[2019/03/04 19:21:02] [info] binlogsyncer.go:723 rotate to (mysql-bin.000001, 147100612)
2019-03-04 19:21:02 FATAL listen unix /tmp/gh-ost.mysqlslap.t1.sock: bind: address already in use
  • 掴んでいるプロセスが無ければ消しちゃって大丈夫だと思う。
$ ps auxww | grep gh-ost
yoku0825 31001  0.0  0.0 113512   964 pts/1    S+   19:22   0:00 grep --color=auto gh-ost
$ lsof /tmp/gh-ost.mysqlslap.t1.sock
$ rm /tmp/gh-ost.mysqlslap.t1.sock
  • pt-osc はロックを乱打した時点でトリガーを消しに走ってアボートしようとしてた。なかなか二次災害が起きそうな気配。
2019-03-04T19:27:08 Creating triggers...
2019-03-04T19:27:19 Created triggers OK.
2019-03-04T19:27:19 Copying approximately 2026 rows...
2019-03-04T19:27:42 Dropping triggers...
2019-03-04T19:28:27 Dropped triggers OK.
2019-03-04T19:28:27 Dropping new table...
2019-03-04T19:28:27 Dropped new table OK.
`mysqlslap`.`t1` was not altered.
2019-03-04T19:27:42 Error copying rows from `mysqlslap`.`t1` to `mysqlslap`.`_t1_new`: 2019-03-04T19:27:42 DBD::mysql::st execute failed: Lock wait timeout exceeded; try restarting transaction [for Statement "INSERT LOW_PRIORITY IGNORE INTO `mysqlslap`.`_t1_new` (`id`, `intcol1`, `charcol1`) SELECT `id`, `intcol1`, `charcol1` FROM `mysqlslap`.`t1` LOCK IN SHARE MODE /*pt-online-schema-change 31388 copy table*/"] at /usr/bin/pt-online-schema-change line 11444.
今日はここまで。

2019年2月26日火曜日

gho-stでスレーブからバイナリーログを食いながらインデックスを足してみる

TL;DR

  • マスターから食ってもスレーブから食っても動作が変わっているような気はしない
  • 能動的なスレーブの遅延監視を入れるなら --throttle-control-replicas を自分で入れないといけない

昨日 の続き。
昨日の時点では pt-online-schema-change っぽくマスターに接続してバイナリーログを吸いながらマスターに食わせたけれど、今日はデフォルトの「スレーブに接続してバイナリーログを吸ってマスターに食わせる」をやってみる。
早速。
$ master/my sqlslap --auto-generate-sql --auto-generate-sql-execute-number=100000 --auto-generate-sql-guid-primary

$ gh-ost --database=mysqlslap --table=t1 --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=21801 --user=msandbox --password=msandbox
2019-02-26 12:31:43 FATAL 127.0.0.1:21801 must have log_slave_updates enabled for executing migration
転けた。
log_slave_updates がONでないといけない(8.0からデフォルトでONになったんだけどそういえばこれは5.7.25でテストしている)
有効にしてから再起動。
( ´-`).oO( log_slave_updatesmysqld の再起動が必要だから、有効にしてない環境だとここで pt-online-schema-change--allow-on-master にするしかなくなるな…
$ gh-ost --database=mysqlslap --table=t1 --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=
21801 --user=msandbox --password=msandbox
[2019/02/26 12:39:08] [info] binlogsyncer.go:133 create BinlogSyncer with config {99999 mysql 127.0.0.1 21801 msandbox    false false
<nil> false UTC true 0 0s 0s 0 false}
[2019/02/26 12:39:08] [info] binlogsyncer.go:354 begin to sync binlog from position (mysql-bin.000002, 2215735)
[2019/02/26 12:39:08] [info] binlogsyncer.go:203 register slave for master server 127.0.0.1:21801
[2019/02/26 12:39:08] [info] binlogsyncer.go:723 rotate to (mysql-bin.000002, 2215735)
2019-02-26 12:39:08 ERROR parsing time "" as "2006-01-02T15:04:05.999999999Z07:00": cannot parse "" as "2006"
# Migrating `mysqlslap`.`t1`; Ghost table is `mysqlslap`.`_t1_gho`
[2019/02/26 12:39:08] [info] binlogsyncer.go:203 register slave for master server 127.0.0.1:21801
[2019/02/26 12:39:08] [info] binlogsyncer.go:723 rotate to (mysql-bin.000002, 2215735)
2019-02-26 12:39:08 ERROR parsing time "" as "2006-01-02T15:04:05.999999999Z07:00": cannot parse "" as "2006"
# Migrating `mysqlslap`.`t1`; Ghost table is `mysqlslap`.`_t1_gho`
# Migrating 163-44-175-117:21800; inspecting 163-44-175-117:21801; executing on 163-44-175-117
# Migration started at Tue Feb 26 12:39:07 +0900 2019
# chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000
# throttle-additional-flag-file: /tmp/gh-ost.throttle
# Serving on unix socket: /tmp/gh-ost.mysqlslap.t1.sock
# Migrating `mysqlslap`.`t1`; Ghost table is `mysqlslap`.`_t1_gho`
# Migrating 163-44-175-117:21800; inspecting 163-44-175-117:21801; executing on 163-44-175-117
# Migration started at Tue Feb 26 12:39:07 +0900 2019
# chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000
# throttle-additional-flag-file: /tmp/gh-ost.throttle
# Serving on unix socket: /tmp/gh-ost.mysqlslap.t1.sock
Copy: 0/5160 0.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000002:2226774; State: migrating; ETA: N/A
Copy: 0/0 100.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000002:2226774; State: migrating; ETA: due
CREATE TABLE `_t1_gho` (
  `id` varchar(36) NOT NULL,
  `intcol1` int(32) DEFAULT NULL,
  `charcol1` varchar(128) DEFAULT NULL,
  PRIMARY KEY (`id`),
  KEY `intcol1` (`intcol1`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1
[2019/02/26 12:39:08] [info] binlogsyncer.go:164 syncer is closing...
[2019/02/26 12:39:08] [error] binlogstreamer.go:77 close sync with err: sync is been closing...
[2019/02/26 12:39:08] [info] binlogsyncer.go:179 syncer is closed
# Done
なんか ERROR parsing time "" as "2006-01-02T15:04:05.999999999Z07:00": cannot parse "" as "2006" が気になるんだけどなにこれ……今度ソース読もう。
マスターへのクエリーは、 マスターに直接接続してバイナリーログを食った時 とほぼ変わらず。
バイナリーログを食うもとになったスレーブでも、指定していない方のスレーブでも特に SHOW SLAVE STATUS は叩かれていないので、やっぱり --throttle-control-replicas で指定しない限りはスレーブのラグは計算してくれない様子。
$ gh-ost --database=mysqlslap --table=t1 --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=
21801 --user=msandbox --password=msandbox --execute
[2019/02/26 14:14:36] [info] binlogsyncer.go:133 create BinlogSyncer with config {99999 mysql 127.0.0.1 21801 msandbox    false false
<nil> false UTC true 0 0s 0s 0 false}
[2019/02/26 14:14:36] [info] binlogsyncer.go:354 begin to sync binlog from position (mysql-bin.000003, 8755243)
[2019/02/26 14:14:36] [info] binlogsyncer.go:203 register slave for master server 127.0.0.1:21801
[2019/02/26 14:14:36] [info] binlogsyncer.go:723 rotate to (mysql-bin.000003, 8755243)
2019-02-26 14:14:36 ERROR parsing time "" as "2006-01-02T15:04:05.999999999Z07:00": cannot parse "" as "2006"
# Migrating `mysqlslap`.`t1`; Ghost table is `mysqlslap`.`_t1_gho`
# Migrating 163-44-175-117:21800; inspecting 163-44-175-117:21801; executing on 163-44-175-117
# Migration started at Tue Feb 26 14:14:36 +0900 2019
# chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000
# throttle-additional-flag-file: /tmp/gh-ost.throttle
# Serving on unix socket: /tmp/gh-ost.mysqlslap.t1.sock
Copy: 0/3316 0.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000003:8765344; State: migrating; ETA: N/A
Copy: 0/3316 0.0%; Applied: 0; Backlog: 415/1000; Time: 1s(total), 1s(copy); streamer: mysql-bin.000003:8947956; State: migrating; ET$: N/A
Copy: 3337/3337 100.0%; Applied: 529; Backlog: 0/1000; Time: 2s(total), 1s(copy); streamer: mysql-bin.000003:9305011; State: migratin$; ETA: due
Copy: 3337/3337 100.0%; Applied: 529; Backlog: 54/1000; Time: 2s(total), 1s(copy); streamer: mysql-bin.000003:9736765; State: migrati$g; ETA: due
# Migrating `mysqlslap`.`t1`; Ghost table is `mysqlslap`.`_t1_gho`
# Migrating 163-44-175-117:21800; inspecting 163-44-175-117:21801; executing on 163-44-175-117
# Migration started at Tue Feb 26 14:14:36 +0900 2019
# throttle-additional-flag-file: /tmp/gh-ost.throttle
# Serving on unix socket: /tmp/gh-ost.mysqlslap.t1.sock
Copy: 0/3316 0.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000003:8765344; State: migrating; ETA: N/A
Copy: 0/3316 0.0%; Applied: 0; Backlog: 415/1000; Time: 1s(total), 1s(copy); streamer: mysql-bin.000003:8947956; State: migrating; ETA: N/A
Copy: 3337/3337 100.0%; Applied: 529; Backlog: 0/1000; Time: 2s(total), 1s(copy); streamer: mysql-bin.000003:9305011; State: migrating; ETA: due
Copy: 3337/3337 100.0%; Applied: 529; Backlog: 54/1000; Time: 2s(total), 1s(copy); streamer: mysql-bin.000003:9736765; State: migrating; ETA: due
# Migrating `mysqlslap`.`t1`; Ghost table is `mysqlslap`.`_t1_gho`
# Migrating 163-44-175-117:21800; inspecting 163-44-175-117:21801; executing on 163-44-175-117
# Migration started at Tue Feb 26 14:14:36 +0900 2019
# chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000
# throttle-additional-flag-file: /tmp/gh-ost.throttle
# Serving on unix socket: /tmp/gh-ost.mysqlslap.t1.sock
Copy: 3337/3337 100.0%; Applied: 582; Backlog: 0/1000; Time: 3s(total), 1s(copy); streamer: mysql-bin.000003:9754093; State: migrating; ETA: due
[2019/02/26 14:14:39] [info] binlogsyncer.go:164 syncer is closing...
[2019/02/26 14:14:39] [error] binlogstreamer.go:77 close sync with err: sync is been closing...
[2019/02/26 14:14:39] [info] binlogsyncer.go:179 syncer is closed
# Done
今のところ雑に放置している # throttle-additional-flag-file: /tmp/gh-ost.throttle とか # Serving on unix socket: /tmp/gh-ost.mysqlslap.t1.sock とか、対話的にできるのがいいんだろうな、って気配は感じる。
あとやっぱり(ローカルで大した負荷かけてないとはいえ)トリガー使っている pt-online-schema-change より軽いような気がするのですよ、はふん。

2019年2月25日月曜日

第一印象 of gh-ost

TL;DR


インストール

  • releases にrpmパッケージもあるので yum でサクっと入れた。
    • コマンド1個だけが入っているとてもシンプルなパッケージ…
$ sudo yum install -y https://github.com/github/gh-ost/releases/download/v1.0.48/gh-ost-1.0.48-1.x86_64.rpm

$ rpm -ql gh-ost
/usr/bin/gh-ost

テスト

  • ドキュメント を一切合切読まずに試してみる。
  • MySQL::Sandboxmysqlslap でテキトーなテーブル定義にテキトーなクエリーを流させておく。 general_log はオンにしてみた。
$ make_replication_sandbox 5.7.25
$ cd ~/sandboxes/rsandbox_5_7_25/
$ ./m

master [localhost] {msandbox} ((none)) > SET GLOBAL general_log= 1;
Query OK, 0 rows affected (0.00 sec)

$ master/my sqlslap --auto-generate-sql --auto-generate-sql-execute-number=100000
  • 何もオプションを指定せずに打ってみた(何故)
$ gh-ost
2019-02-25 17:18:10 FATAL --database must be provided and database name must not be empty
  • --database が要ることは分かった。
$ gh-ost --database=mysqlslap
2019-02-25 17:18:45 FATAL --table must be provided and table name must not be empty
  • --table も要ることは分かった。
$ gh-ost --database=mysqlslap --table=t1
2019-02-25 17:19:10 FATAL --alter must be provided and statement must not be empty
  • --alter も要ることはわかった。これは pt-online-schema-change と一緒で、ALTERオペレーションの部分だけを書けばいいのかしらん。
$ gh-ost --database=mysqlslap --table=t1 --alter="ADD KEY (intcol1)"
2019-02-25 17:20:17 FATAL dial tcp 127.0.0.1:3306: connect: connection refused
  • ここで初めて接続エラーになった。たぶん --host--port--user--password でイケるだろ、と思う。
$ gh-ost --database=mysqlslap --table=t1 --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=21800 --user=msandbox --password=msandbox
2019-02-25 17:21:14 FATAL No PRIMARY nor UNIQUE key found in table! Bailing out
  • テーブルに PRIMARY KEY または UNIQUE KEY がないと適用できない。
  • 確かに binlog_format= ROW なバイナリログを食わせて、ALTER適用済のテンポラリーテーブル(gh-ost的には「ゴーストテーブル」というらしい)を作るにはないと具合が悪い。
2019-02-25T08:23:03.835939Z        11 Connect   msandbox@localhost on mysqlslap using TCP/IP
..
2019-02-25T08:23:03.838067Z        11 Query     show /* gh-ost */ grants for current_user()
2019-02-25T08:23:03.838364Z        11 Query     select @@global.log_bin, @@global.binlog_format
2019-02-25T08:23:03.838580Z        11 Query     select @@global.binlog_row_image
2019-02-25T08:23:03.839329Z        12 Connect   msandbox@localhost on information_schema using TCP/IP
2019-02-25T08:23:03.839500Z        12 Query     SELECT @@max_allowed_packet
2019-02-25T08:23:03.839623Z        12 Query     SET autocommit=true
2019-02-25T08:23:03.839737Z        12 Query     SET NAMES utf8mb4
2019-02-25T08:23:03.839966Z        12 Query     show slave status
2019-02-25T08:23:03.840312Z        12 Quit
2019-02-25T08:23:03.840475Z        11 Query     show /* gh-ost */ table status from `mysqlslap` like 't1'
2019-02-25T08:23:03.841162Z        11 Query     SELECT
..
                FROM INFORMATION_SCHEMA.KEY_COLUMN_USAGE
                WHERE
                                REFERENCED_TABLE_NAME IS NOT NULL
                                AND ((TABLE_SCHEMA='mysqlslap' AND TABLE_NAME='t1')
                                        OR (REFERENCED_TABLE_SCHEMA='mysqlslap' AND REFERENCED_TABLE_NAME='t1')
                                )
2019-02-25T08:23:03.851679Z        11 Query     SELECT
..
    FROM INFORMATION_SCHEMA.COLUMNS INNER JOIN (
      SELECT
..
      FROM INFORMATION_SCHEMA.STATISTICS
      WHERE
                                NON_UNIQUE=0
                                AND TABLE_SCHEMA = 'mysqlslap'
        AND TABLE_NAME = 't1'
      GROUP BY TABLE_SCHEMA, TABLE_NAME, INDEX_NAME
    ) AS UNIQUES
    ON (
      COLUMNS.COLUMN_NAME = UNIQUES.FIRST_COLUMN_NAME
    )
    WHERE
      COLUMNS.TABLE_SCHEMA = 'mysqlslap'
      AND COLUMNS.TABLE_NAME = 't1'
    ORDER BY
..
2019-02-25T08:23:03.853012Z        11 Quit
  • 外部キー制約がついてるとこの辺で判定されそうな感じ。
  • mysqlslapPRIMARY KEY を作るようにオプションを追加してやり直し。
$ master/my sqlslap --auto-generate-sql --auto-generate-sql-execute-number=100000 --auto-generate-sql-guid-primary

$ gh-ost --database=mysqlslap --table=t1 --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=21800 --user=msandbox --password=msandbox

2019-02-25 17:28:29 FATAL It seems like this migration attempt to run directly on master. Preferably it would be executed on a replica (and this reduces load from the master). To proceed please provide --allow-on-master. Inspector config=127.0.0.1:21800, user=msandbox, usingTLS=false, applier config=127.0.0.1:21800, user=msandbox, usingTLS=false
  • 直接マスターに接続するなら --allow-on-master 使えってことらしい。
  • バイナリーログはマスターから食ってもスレーブから食っても一緒なんでは? と思うけれど チートシート を見る感じ、デフォルトはスレーブでバイナリーログを食ってマスターにINSERT、のようだ。

$ gh-ost --database=mysqlslap --table=t1 --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=21800 --user=msandbox --password=msandbox --allow-on-master

[2019/02/25 17:32:48] [info] binlogsyncer.go:133 create BinlogSyncer with config {99999 mysql 127.0.0.1 21800 msandbox    false false <nil> false UTC true 0 0s 0s 0 false}

[2019/02/25 17:32:48] [info] binlogsyncer.go:354 begin to sync binlog from position (mysql-bin.000001, 34947374)

[2019/02/25 17:32:48] [info] binlogsyncer.go:203 register slave for master server 127.0.0.1:21800

[2019/02/25 17:32:48] [info] binlogsyncer.go:723 rotate to (mysql-bin.000001, 34947374)

# Migrating `mysqlslap`.`t1`; Ghost table is `mysqlslap`.`_t1_gho`

# Migrating 163-44-175-117:21800; inspecting 163-44-175-117:21800; executing on 163-44-175-117

# Migration started at Mon Feb 25 17:32:47 +0900 2019

# chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000

# throttle-additional-flag-file: /tmp/gh-ost.throttle

# Serving on unix socket: /tmp/gh-ost.mysqlslap.t1.sock

# Migrating `mysqlslap`.`t1`; Ghost table is `mysqlslap`.`_t1_gho`

# Migrating 163-44-175-117:21800; inspecting 163-44-175-117:21800; executing on 163-44-175-117

# Migration started at Mon Feb 25 17:32:47 +0900 2019

# chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000

# throttle-additional-flag-file: /tmp/gh-ost.throttle

# Serving on unix socket: /tmp/gh-ost.mysqlslap.t1.sock

Copy: 0/6772 0.0%; Applied: 0; Backlog: 1/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000001:34958571; State: migrating; ETA: N/A

Copy: 0/0 100.0%; Applied: 0; Backlog: 1/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000001:34958571; State: migrating; ETA: due

CREATE TABLE `_t1_gho` (

  `id` varchar(36) NOT NULL,

  `intcol1` int(32) DEFAULT NULL,

  `charcol1` varchar(128) DEFAULT NULL,

  PRIMARY KEY (`id`),

  KEY `intcol1` (`intcol1`)

) ENGINE=InnoDB DEFAULT CHARSET=latin1

[2019/02/25 17:32:48] [info] binlogsyncer.go:164 syncer is closing...

[2019/02/25 17:32:48] [error] binlogstreamer.go:77 close sync with err: sync is been closing...

[2019/02/25 17:32:48] [info] binlogsyncer.go:179 syncer is closed

# Done

master [localhost] {msandbox} (mysqlslap) > show create table t1\G

*************************** 1. row ***************************

       Table: t1

Create Table: CREATE TABLE `t1` (

  `id` varchar(36) NOT NULL,

  `intcol1` int(32) DEFAULT NULL,

  `charcol1` varchar(128) DEFAULT NULL,

  PRIMARY KEY (`id`)

) ENGINE=InnoDB DEFAULT CHARSET=latin1

1 row in set (0.00 sec)
  • 動いたっぽい。
  • この時点では dry-run で、実行はされていない(って出力してくれてもいいのに)
    • ちょくちょく pt-online-schema-change と動きが同じで嬉しい。
  • この時点では SHOW PROCESSLISTSHOW SLAVE HOSTS などマスターからスレーブを探せるようなSQLは叩いていない。
  • # chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000 あたりは、 --help を見た感じ負荷に合わせてよしなに指定するのであろう。
  • ちなみにこの時点で binlog_format <> ROW の場合はエラーが出る( FATAL You must be using ROW binlog format. I can switch it for you, provided --switch-to-rbr and that 127.0.0.1:21800 doesn't have replicas

$ gh-ost --database=mysqlslap --table=t1 --alter="ADD KEY (intcol1)" --host=127.0.0.1 --port=21800 --user=msandbox --password=msandbox --allow-on-master --execute

[2019/02/25 17:38:56] [info] binlogsyncer.go:133 create BinlogSyncer with config {99999 mysql 127.0.0.1 21800 msandbox    false false <nil> false UTC true 0 0s 0s 0 false}

[2019/02/25 17:38:56] [info] binlogsyncer.go:354 begin to sync binlog from position (mysql-bin.000001, 80752389)

[2019/02/25 17:38:56] [info] binlogsyncer.go:203 register slave for master server 127.0.0.1:21800

[2019/02/25 17:38:56] [info] binlogsyncer.go:723 rotate to (mysql-bin.000001, 80752389)

# Migrating `mysqlslap`.`t1`; Ghost table is `mysqlslap`.`_t1_gho`

# Migrating 163-44-175-117:21800; inspecting 163-44-175-117:21800; executing on 163-44-175-117

# Migration started at Mon Feb 25 17:38:56 +0900 2019

# chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000

# throttle-additional-flag-file: /tmp/gh-ost.throttle

# Serving on unix socket: /tmp/gh-ost.mysqlslap.t1.sock

Copy: 0/3346 0.0%; Applied: 0; Backlog: 1/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000001:80762720; State: migrating; ETA: N/A

Copy: 2000/3346 59.8%; Applied: 179; Backlog: 0/1000; Time: 1s(total), 1s(copy); streamer: mysql-bin.000001:81254459; State: migrating; ETA: 0s

Copy: 3365/3346 100.6%; Applied: 359; Backlog: 1/1000; Time: 2s(total), 2s(copy); streamer: mysql-bin.000001:81644106; State: migrating; ETA: due

Copy: 3365/3365 100.0%; Applied: 424; Backlog: 0/1000; Time: 2s(total), 2s(copy); streamer: mysql-bin.000001:81700141; State: migrating; ETA: due

Copy: 3365/3365 100.0%; Applied: 426; Backlog: 10/1000; Time: 3s(total), 2s(copy); streamer: mysql-bin.000001:81709653; State: migrating; ETA: due

# Migrating `mysqlslap`.`t1`; Ghost table is `mysqlslap`.`_t1_gho`

# Migrating 163-44-175-117:21800; inspecting 163-44-175-117:21800; executing on 163-44-175-117

# Migration started at Mon Feb 25 17:38:56 +0900 2019

# chunk-size: 1000; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000

# throttle-additional-flag-file: /tmp/gh-ost.throttle

# Serving on unix socket: /tmp/gh-ost.mysqlslap.t1.sock

Copy: 3365/3365 100.0%; Applied: 435; Backlog: 0/1000; Time: 3s(total), 2s(copy); streamer: mysql-bin.000001:81714074; State: migrating; ETA: due

[2019/02/25 17:39:00] [info] binlogsyncer.go:164 syncer is closing...

[2019/02/25 17:39:00] [error] binlogstreamer.go:77 close sync with err: sync is been closing...

[2019/02/25 17:39:00] [info] binlogsyncer.go:179 syncer is closed

# Done
  • 流れ終わりは、した。

master [localhost] {msandbox} (mysqlslap) > SHOW CREATE TABLE t1\G

*************************** 1. row ***************************

       Table: t1

Create Table: CREATE TABLE `t1` (

  `id` varchar(36) NOT NULL,

  `intcol1` int(32) DEFAULT NULL,

  `charcol1` varchar(128) DEFAULT NULL,

  PRIMARY KEY (`id`),

  KEY `intcol1` (`intcol1`)

) ENGINE=InnoDB DEFAULT CHARSET=latin1

1 row in set (0.00 sec)

slave1 [localhost] {msandbox} (mysqlslap) > SHOW CREATE TABLE t1\G

*************************** 1. row ***************************

       Table: t1

Create Table: CREATE TABLE `t1` (

  `id` varchar(36) NOT NULL,

  `intcol1` int(32) DEFAULT NULL,

  `charcol1` varchar(128) DEFAULT NULL,

  PRIMARY KEY (`id`),

  KEY `intcol1` (`intcol1`)

) ENGINE=InnoDB DEFAULT CHARSET=latin1

1 row in set (0.01 sec)

$ less ~/sandboxes/rsandbox_5_7_25/node1/data/163-44-175-117.log

..
  • マスターでもスレーブでもインデックスが足されているのはいいけれど、どうもgeneral_logを見る限り Seconds_Behind_Master を見に来ている気配はない。。
    • これはスレーブからバイナリーログを受け取る設定にしている時に、その接続先で SHOW SLAVE STATUS 叩いたり --throttle-control-replicas を指定した時にだけその先で叩いてくれるのかしらん。謎。

$ cat -v ~/sandboxes/rsandbox_5_7_25/master/data/163-44-175-117.log | grep "gh-ost"

..

2019-02-25T08:38:56.880696Z        41 Query     show /* gh-ost */ grants for current_user()

2019-02-25T08:38:56.882845Z        41 Query     show /* gh-ost */ table status from `mysqlslap` like 't1'

2019-02-25T08:38:56.902645Z        41 Query     explain select /* gh-ost */ * from `mysqlslap`.`t1` where 1=1

2019-02-25T08:38:56.907683Z        41 Query     show /* gh-ost readCurrentBinlogCoordinates */ master status

2019-02-25T08:38:56.917044Z        41 Query     show /* gh-ost */ table status from `mysqlslap` like '_t1_gho'

2019-02-25T08:38:56.917296Z        41 Query     show /* gh-ost */ table status from `mysqlslap` like '_t1_del'

2019-02-25T08:38:56.917506Z        41 Query     drop /* gh-ost */ table if exists `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:56.920110Z        41 Query     create /* gh-ost */ table `mysqlslap`.`_t1_ghc` (

2019-02-25T08:38:56.931295Z        41 Query     create /* gh-ost */ table `mysqlslap`.`_t1_gho` like `mysqlslap`.`t1`

2019-02-25T08:38:56.946308Z        41 Query     alter /* gh-ost */ table `mysqlslap`.`_t1_gho` ADD KEY (intcol1)

2019-02-25T08:38:56.959104Z        41 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:56.962483Z        41 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:56.965301Z        41 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:56.972091Z        41 Query     select /* gh-ost `mysqlslap`.`t1` */ `id`

2019-02-25T08:38:56.972536Z        47 Query     select /* gh-ost `mysqlslap`.`t1` */ `id`

2019-02-25T08:38:56.973362Z        47 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:56.973989Z        41 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:38:56.977606Z        47 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:38:56.982191Z        41 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:38:56.986080Z        47 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

...

2019-02-25T08:38:59.213685Z        66 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:38:59.221449Z        67 Query     select  /* gh-ost `mysqlslap`.`t1` iteration:4 */

2019-02-25T08:38:59.221871Z        66 Query     select /* gh-ost `mysqlslap`.`t1` iteration:4 */ `id`

2019-02-25T08:38:59.222528Z        67 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:38:59.222842Z        66 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:59.228316Z        67 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:38:59.241504Z        66 Query     select get_lock('gh-ost.66.lock', 0)

2019-02-25T08:38:59.242713Z        67 Query     show /* gh-ost */ table status from `mysqlslap` like '_t1_del'

2019-02-25T08:38:59.246396Z        67 Query     create /* gh-ost */ table `mysqlslap`.`_t1_del` (

2019-02-25T08:38:59.272465Z        69 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:59.272797Z        66 Query     lock /* gh-ost */ tables `mysqlslap`.`t1` write, `mysqlslap`.`_t1_del` write

2019-02-25T08:38:59.276302Z        67 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:59.279341Z        69 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:59.371523Z        67 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:59.471494Z        69 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:59.571439Z        67 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:59.671521Z        69 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:59.771526Z        67 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:59.871520Z        69 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:59.971540Z        67 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:38:59.976502Z        69 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:39:00.071569Z        67 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:39:00.171486Z        69 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:39:00.251211Z        67 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:39:00.251556Z        67 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:39:00.251754Z        67 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:39:00.251977Z        67 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:39:00.252143Z        67 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:39:00.252348Z        67 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:39:00.252505Z        67 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:39:00.252679Z        67 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:39:00.252847Z        67 Query     replace /* gh-ost `mysqlslap`.`_t1_gho` */ into

2019-02-25T08:39:00.264470Z        69 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:39:00.271783Z        67 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:39:00.285571Z        69 Query     rename /* gh-ost */ table `mysqlslap`.`t1` to `mysqlslap`.`_t1_del`, `mysqlslap`.`_t1_gho` to `mysqlslap`.`t1`

2019-02-25T08:39:00.297535Z        70 Query     select is_used_lock('gh-ost.66.lock')

2019-02-25T08:39:00.297781Z        66 Query     drop /* gh-ost */ table if exists `mysqlslap`.`_t1_del`

2019-02-25T08:39:00.361910Z        70 Query     show /* gh-ost */ table status from `mysqlslap` like '_t1_del'

2019-02-25T08:39:00.374467Z        67 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

2019-02-25T08:39:00.383095Z        69 Query     drop /* gh-ost */ table if exists `mysqlslap`.`_t1_ghc`
  • なんか *_ghc テーブルと *_gho テーブルを使ってる?

..

2019-02-25T08:39:00.264470Z        69 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

                                (id, hint, value)

                        values

                                (NULLIF(0, 0), 'copy iteration 4 at 1551083940', 'Copy: 3365/3365 100.0%; Applied: 435; Backlog: 0/100

0; Time: 3s(total), 2s(copy); streamer: mysql-bin.000001:81714074; State: migrating; ETA: due')

                        on duplicate key update

                                last_update=NOW(),

                                value=VALUES(value)

..

2019-02-25T08:39:00.374467Z        67 Query     insert /* gh-ost */ into `mysqlslap`.`_t1_ghc`

                                (id, hint, value)

                        values

                                (NULLIF(1, 0), 'heartbeat', '2019-02-25T17:39:00.374212828+09:00')

                        on duplicate key update

                                last_update=NOW(),

                                value=VALUES(value)

..
  • ghcの方は制御情報を書き込んでるっぽいのかな。

2019-02-25T08:38:59.221449Z        67 Query     select  /* gh-ost `mysqlslap`.`t1` iteration:4 */

                                                `id`

                                        from

                                                `mysqlslap`.`t1`

                                        where ((`id` > _binary'ca4dbc9a-38d8-11e9-98dc-0201a32caf75')) and ((`id` < _binary'ca4dbc9a-3

8d8-11e9-98dc-0201a32caf75') or ((`id` = _binary'ca4dbc9a-38d8-11e9-98dc-0201a32caf75')))

                                        order by

                                                `id` asc

                                        limit 1

                                        offset 999

2019-02-25T08:38:59.221871Z        66 Query     select /* gh-ost `mysqlslap`.`t1` iteration:4 */ `id`

                                from (

                                        select

                                                        `id`

                                                from

                                                        `mysqlslap`.`t1`

                                                where ((`id` > _binary'ca4dbc9a-38d8-11e9-98dc-0201a32caf75')) and ((`id` < _binary'ca

4dbc9a-38d8-11e9-98dc-0201a32caf75') or ((`id` = _binary'ca4dbc9a-38d8-11e9-98dc-0201a32caf75')))

                                                order by

                                                        `id` asc

                                                limit 1000

                                ) select_osc_chunk

                        order by

                                `id` desc

                        limit 1
  • --chunk-size ぶんの行を探している気配がする。
    • --concurrent-rowcount=true (デフォルト)の時は count rows after row-copy begins, concurrently, and adjust row estimate later on らしいのでその処理かしらん。
  • general_logを眺めていたら DROP が ghc なテーブルにしか流れてなかったことに気が付く。

master [localhost] {msandbox} (mysqlslap) > SHOW TABLES;

+---------------------+

| Tables_in_mysqlslap |

+---------------------+

| _t1_del             |

| t1                  |

+---------------------+

2 rows in set (0.00 sec)
  • デフォルトではスワップさせた旧テーブルはDROPしないっぽい。
    • pt-online-schema-change はデフォルトで旧テーブルをDROPするのでそれを知らないとたまにアイタタタタってなるけれど
    • 容量問題にぶち当たっている場合はこれを憶えておかないとアイタタタタってなると思うので憶えておこう
取り敢えず今日はここまで。