GA

2019/03/04

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.
今日はここまで。

0 件のコメント :

コメントを投稿