2019年12月13日金曜日

MySQL 8.0時代のSET GLOBALとかSET PERSISTに必要な権限

TL;DR

  • オンライン変更は SYSTEM_VARIABLES_ADMIN 権限。 SUPER は非推奨。
  • SET PERSIST_ONLYSYSTEM_VARIABLES_ADMIN 権限 && PERSIST_RO_VARIABLES_ADMIN 権限

ふとコードを読んでいる時に SET PERSIST_ONLY には SUPER 権限は絡んでなさそうなことに気が付いたので試してみる。
  /* for dynamic variables user needs SUPER_ACL or SYSTEM_VARIABLES_ADMIN */
  if (!static_variable) {
    if (!sctx->check_access(SUPER_ACL) &&
        !(sctx->has_global_grant(STRING_WITH_LEN("SYSTEM_VARIABLES_ADMIN"))
              .first)) {
      my_error(ER_SPECIFIC_ACCESS_DENIED_ERROR, MYF(0),
               "SUPER or SYSTEM_VARIABLES_ADMIN");
      return 1;
    }
  } else {
    /*
     for static variables user needs both SYSTEM_VARIABLES_ADMIN and
     PERSIST_RO_VARIABLES_ADMIN
    */
    if (!(sctx->has_global_grant(STRING_WITH_LEN("SYSTEM_VARIABLES_ADMIN"))
              .first &&
          sctx->has_global_grant(STRING_WITH_LEN("PERSIST_RO_VARIABLES_ADMIN"))
              .first)) {
      my_error(ER_PERSIST_ONLY_ACCESS_DENIED_ERROR, MYF(0),
               "SYSTEM_VARIABLES_ADMIN and PERSIST_RO_VARIABLES_ADMIN");
      return 1;
    }
  }
こういう「なんの権限が必要なの」系は、何も権限のついてないアカウント実際に叩くのが一番検証が楽。
mysql80 100> SHOW GRANTS;
+--------------------------------------+
| Grants for yoku0825@%                |
+--------------------------------------+
| GRANT USAGE ON *.* TO `yoku0825`@`%` |
+--------------------------------------+
1 row in set (0.00 sec)

mysql80 100> SET GLOBAL innodb_buffer_pool_size = 128 * 1024 * 1024;ERROR 1227 (42000): Access denied; you need (at least one of) the SUPER or SYSTEM_VARIABLES_ADMIN privilege(s) for this operation

mysql80 100> SET PERSIST innodb_buffer_pool_size = 128 * 1024 * 1024;ERROR 1227 (42000): Access denied; you need (at least one of) the SUPER or SYSTEM_VARIABLES_ADMIN privilege(s) for this operation

mysql80 100> SET PERSIST_ONLY innodb_buffer_pool_size = 128 * 1024 * 1024;
ERROR 3630 (42000): Access denied; you need SYSTEM_VARIABLES_ADMIN and PERSIST_RO_VARIABLES_ADMIN privileges for this operation
8.0導入の新しい権限の方は、権限違反の時にエラー1227じゃなくて3630になるのね。


コードのコメントには "static variables" とは書いてあるけど、ダイナミック変更可能なやつも PERSIST_ONLY ならこっちを通る。
mysql80 102> SHOW GRANTS;
+--------------------------------------+
| Grants for yoku0825@%                |
+--------------------------------------+
| GRANT SUPER ON *.* TO `yoku0825`@`%` |
+--------------------------------------+
1 row in set (0.00 sec)

mysql80 102> SET GLOBAL innodb_buffer_pool_size = 128 * 1024 * 1024;
Query OK, 0 rows affected (0.00 sec)

mysql80 102> SET PERSIST innodb_buffer_pool_size = 128 * 1024 * 1024;
Query OK, 0 rows affected (0.02 sec)

mysql80 102> SET PERSIST_ONLY innodb_buffer_pool_size = 128 * 1024 * 1024;
ERROR 3630 (42000): Access denied; you need SYSTEM_VARIABLES_ADMIN and PERSIST_RO_VARIABLES_ADMIN privileges for this operation

mysql80 104> SHOW GRANTS;
+-------------------------------------------------------+
| Grants for yoku0825@%                                 |
+-------------------------------------------------------+
| GRANT USAGE ON *.* TO `yoku0825`@`%`                  |
| GRANT SYSTEM_VARIABLES_ADMIN ON *.* TO `yoku0825`@`%` |
+-------------------------------------------------------+
2 rows in set (0.00 sec)

mysql80 104> SET GLOBAL innodb_buffer_pool_size = 128 * 1024 * 1024;
Query OK, 0 rows affected (0.00 sec)

mysql80 104> SET PERSIST innodb_buffer_pool_size = 128 * 1024 * 1024;
Query OK, 0 rows affected (0.00 sec)

mysql80 104> SET PERSIST_ONLY innodb_buffer_pool_size = 128 * 1024 * 1024;
ERROR 3630 (42000): Access denied; you need SYSTEM_VARIABLES_ADMIN and PERSIST_RO_VARIABLES_ADMIN privileges for this operation

mysql80 106> SHOW GRANTS;
+-----------------------------------------------------------+
| Grants for yoku0825@%                                     |
+-----------------------------------------------------------+
| GRANT USAGE ON *.* TO `yoku0825`@`%`                      |
| GRANT PERSIST_RO_VARIABLES_ADMIN ON *.* TO `yoku0825`@`%` |
+-----------------------------------------------------------+
2 rows in set (0.00 sec)

mysql80 106> SET GLOBAL innodb_buffer_pool_size = 128 * 1024 * 1024;
ERROR 1227 (42000): Access denied; you need (at least one of) the SUPER or SYSTEM_VARIABLES_ADMIN privilege(s) for this operation

mysql80 106> SET PERSIST innodb_buffer_pool_size = 128 * 1024 * 1024;
ERROR 1227 (42000): Access denied; you need (at least one of) the SUPER or SYSTEM_VARIABLES_ADMIN privilege(s) for this operation

mysql80 106> SET PERSIST_ONLY innodb_buffer_pool_size = 128 * 1024 * 1024;
ERROR 3630 (42000): Access denied; you need SYSTEM_VARIABLES_ADMIN and PERSIST_RO_VARIABLES_ADMIN privileges for this operation

mysql80 109> SHOW GRANTS;
+----------------------------------------------------------------------------------+
| Grants for yoku0825@%                                                            |
+----------------------------------------------------------------------------------+
| GRANT USAGE ON *.* TO `yoku0825`@`%`                                             |
| GRANT PERSIST_RO_VARIABLES_ADMIN,SYSTEM_VARIABLES_ADMIN ON *.* TO `yoku0825`@`%` |
+----------------------------------------------------------------------------------+
2 rows in set (0.00 sec)

mysql80 109> SET GLOBAL innodb_buffer_pool_size = 128 * 1024 * 1024;
Query OK, 0 rows affected (0.00 sec)

mysql80 109> SET PERSIST innodb_buffer_pool_size = 128 * 1024 * 1024;
Query OK, 0 rows affected (0.00 sec)

mysql80 109> SET PERSIST_ONLY innodb_buffer_pool_size = 128 * 1024 * 1024;
Query OK, 0 rows affected (0.00 sec)

mysql80 111> SHOW GRANTS;
+-----------------------------------------------------------+
| Grants for yoku0825@%                                     |
+-----------------------------------------------------------+
| GRANT SUPER ON *.* TO `yoku0825`@`%`                      |
| GRANT PERSIST_RO_VARIABLES_ADMIN ON *.* TO `yoku0825`@`%` |
+-----------------------------------------------------------+
2 rows in set (0.00 sec)

mysql80 111> SET GLOBAL innodb_buffer_pool_size = 128 * 1024 * 1024;
Query OK, 0 rows affected (0.00 sec)

mysql80 111> SET PERSIST innodb_buffer_pool_size = 128 * 1024 * 1024;
Query OK, 0 rows affected (0.00 sec)

mysql80 111> SET PERSIST_ONLY innodb_buffer_pool_size = 128 * 1024 * 1024;
ERROR 3630 (42000): Access denied; you need SYSTEM_VARIABLES_ADMIN and PERSIST_RO_VARIABLES_ADMIN privileges for this operation
確かにそうなった。
個人的には SET PERSIST_ONLY だけじゃなくて SET PERSISTSUPER だけでできないようにしてくれると嬉しかったりするけれども。
監視用アカウントに SUPER がついて運用しているとこういう権限分離は嬉しい…。

2019年12月9日月曜日

MySQL 8.0予約語問題にも使える、performance_schemaからエラーになったクエリーをたたき出す方法

TL;DR

  • events_statements_*テーブルmessage_text カラムにエラーメッセージが入っている
  • MySQL 5.6とそれ以降で使える
    • こんな便利なものに気が付いていなかった…

注意

  • MySQL 5.6では events_statements_history は enabled = ‘NO’ になっているので自分で UPDATE する必要がある
  • 動作自体は説明するより↓を見てもらった方が速いと思う。
    • errors > 0 にしてエラーを返さなかったクエリーは無視
    • warnings > 0 にはしたけど、ワーニングメッセージは mysql_errno にも message_text にも入ってこないのでダメだった。。
予約語を踏み抜いたり、 GROUP BY .. ASC みたいなのはパースエラー( mysql_errno = 1064) で出てくるので、それを知ってるとユニットテストとかと組み合わせて予約語対応も捗るかも知れない。
mysql80 48> SELECT * FROM d1.t1 GROUP BY num ASC;
ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'ASC' at line 1

mysql80 48> SELECT num AS rank FROM d1.t1 GROUP BY num ASC;
ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'rank FROM d1.t1 GROUP BY num ASC' at line 1

mysql80 48> SELECT thread_id, event_name, sql_text, current_schema, mysql_errno, message_text, errors, warnings FROM performance_schema.events_statements_history WHERE errors > 0 OR warnings > 0;
+-----------+---------------------+------------------------------------------------+----------------+-------------+----------------------------------------------------------------------------------------------------------------------------------+--------+----------+
| thread_id | event_name          | sql_text                                       | current_schema | mysql_errno | message_text                                                                                                                     | errors | warnings |
+-----------+---------------------+------------------------------------------------+----------------+-------------+----------------------------------------------------------------------------------------------------------------------------------+--------+----------+
|       111 | statement/sql/error | SELECT * FROM d1.t1 GROUP BY num ASC           | NULL           |        1064 | You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use |      1 |        0 |
|       111 | statement/sql/error | SELECT num AS rank FROM d1.t1 GROUP BY num ASC | NULL           |        1064 | You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use |      1 |        0 |
+-----------+---------------------+------------------------------------------------+----------------+-------------+----------------------------------------------------------------------------------------------------------------------------------+--------+----------+
2 rows in set (0.00 sec)

2019年12月7日土曜日

ConoHaの上でひたすらMySQLをビルドする簡単なおしごと in 2019年

この記事は ConoHa Advent Calendar 2019 の7日目の記事です。

去年一昨年三年前 とひたすらConoHa VPS 1GBプランでMySQLをビルドしています。
今年も変わらずビルドをするわけですが、去年と比べてMySQL 5.5系はMySQL 5.5.62のままだったので飛ばします。
MySQL 5.5は2018年12月でSustaining Support期間に入っているので、もう(Security Fixを含め)新しいリリースはないのでしょう。これがサポートが切れるということだ。
今年もサクッと新しいサーバーを立ち上げ…お、CentOSが8.0のがあるのでこれにしよう。
それではLet’s build.
$ wget https://dev.mysql.com/get/Downloads/MySQL-5.6/mysql-5.6.46.tar.gz
$ tar xf mysql-5.6.46.tar.gz
$ cd mysql-5.6.46/
$ cmake .
-bash: cmake: command not found
ウッ。8系では dnf でインストールするんですよねおれしってる。
$ sudo dnf install cmake
$ cmake .
..
-- Running cmake version 3.11.4
-- Could NOT find Git (missing: GIT_EXECUTABLE)
CMake Error: CMake was unable to find a build program corresponding to "Unix Makefiles".  CMAKE_MAKE_PROGRAM is not set.  You probably need to select a different build tool.
CMake Error: CMAKE_C_COMPILER not set, after EnableLanguage
CMake Error: CMAKE_CXX_COMPILER not set, after EnableLanguage
-- Configuring incomplete, errors occurred!
See also "/home/yoku0825/mysql-5.6.46/CMakeFiles/CMakeOutput.log".
ウッ、 git, make, gcc, g++ あたりがいないせいな気がする。
$ sudo dnf install git make gcc gcc-c++
$ cmake .
..
Cannot find appropriate system libraries for WITH_SSL=system.
Make sure you have specified a supported SSL version.
Valid options are :
system (use the OS openssl library),
yes (synonym for system),
</path/to/custom/openssl/installation>

CMake Error at cmake/ssl.cmake:66 (MESSAGE):
  Please install the appropriate openssl developer package.

Call Stack (most recent call first):
  cmake/ssl.cmake:260 (FATAL_SSL_NOT_FOUND_ERROR)
  CMakeLists.txt:482 (MYSQL_CHECK_SSL)

-- Configuring incomplete, errors occurred!
See also "/home/yoku0825/mysql-5.6.46/CMakeFiles/CMakeOutput.log".
See also "/home/yoku0825/mysql-5.6.46/CMakeFiles/CMakeError.log".
最近のMySQLはYaSSLバンドルをやめてOpenSSL一本になったので、 openssl-devel が入ってないとダメ、と。
$ sudo dnf install openssl-devel
$ cmake .
..
CMake Error at cmake/readline.cmake:92 (MESSAGE):
  Curses library not found.  Please install appropriate package,

      remove CMakeCache.txt and rerun cmake.On Debian/Ubuntu, package name is libncurses5-dev, on Redhat and derivates it is ncurses-devel.
Call Stack (most recent call first):
  cmake/readline.cmake:135 (FIND_CURSES)
  cmake/readline.cmake:225 (MYSQL_USE_BUNDLED_EDITLINE)
  CMakeLists.txt:484 (MYSQL_CHECK_EDITLINE)

-- Configuring incomplete, errors occurred!
See also "/home/yoku0825/mysql-5.6.46/CMakeFiles/CMakeOutput.log".
See also "/home/yoku0825/mysql-5.6.46/CMakeFiles/CMakeError.log".
今度は ncurses-devel (毎度転けさせてる気がするこれ)
$ sudo dnf install ncurses-devel
$ cmake .
..
-- Configuring done
-- Generating done
-- Build files have been written to: /home/yoku0825/mysql-5.6.46
よし cmake 終わったので make
$ time make
..
real    24m56.940s
user    21m53.985s
sys     2m38.626s
いやあgccのバージョンが新しくなったせいか、ワーニングいっぱい出る…。
とはいえ無事にビルドも終わった。
$ sudo make install
$ du -sh /usr/local/mysql
1.1G    /usr/local/mysql
これを5.7.28と8.0.18でもやるだけの簡単なおしごと。
$ wget https://dev.mysql.com/get/Downloads/MySQL-5.7/mysql-boost-5.7.28.tar.gz
$ tar xf mysql-boost-5.7.28.tar.gz
$ cd mysql-5.7.28/
$ cmake -DWITH_BOOST=./boost
..
-- Checking for module 'libtirpc'
--   Package 'libtirpc', required by 'virtual:world', not found
CMake Error at cmake/rpc.cmake:76 (MESSAGE):
  Could not find rpc/rpc.h in /usr/include or /usr/include/tirpc
Call Stack (most recent call first):
  rapid/plugin/group_replication/configure.cmake:60 (MYSQL_CHECK_RPC)
  rapid/plugin/group_replication/CMakeLists.txt:25 (INCLUDE)

-- Configuring incomplete, errors occurred!
See also "/home/yoku0825/mysql-5.7.28/CMakeFiles/CMakeOutput.log".
See also "/home/yoku0825/mysql-5.7.28/CMakeFiles/CMakeError.log".
MySQL 5.7とそれ以降はビルドにBoostライブラリの特定のバージョンを要求するので、面倒がないBoost同梱版のソースをダウンロードしてきて指定してやる。
あれ何だこれ、見たことないやつが出た。ライブラリの方を要求してるっぽく見えて、Ncursesと同じでdevelが必要なやつっぽい。
$ sudo dnf install libtirpc
Package libtirpc-1.1.4-3.el8.x86_64 is already installed.

$ sudo dnf install libtirpc-devel
$ cmake -DWITH_BOOST=./boost
..
CMake Error at rapid/plugin/group_replication/rpcgen.cmake:100 (MESSAGE):
  Could not find rpcgen
Call Stack (most recent call first):
  rapid/plugin/group_replication/CMakeLists.txt:36 (INCLUDE)

-- Configuring incomplete, errors occurred!
See also "/home/yoku0825/mysql-5.7.28/CMakeFiles/CMakeOutput.log".
See also "/home/yoku0825/mysql-5.7.28/CMakeFiles/CMakeError.log".
ん-。色々新しく必要になるものが増えたのか、CentOS 7と8の違いなのかよくわからん。
$ sudo dnf --enablerepo=PowerTools install rpcgen
$ cmake -DWITH_BOOST=./boost
..
-- Configuring done
-- Generating done
-- Build files have been written to: /home/yoku0825/mysql-5.7.28
cmakeできたのでmake。
$ time make
..
real    67m32.487s
user    50m14.800s
sys     6m39.203s

$ sudo make install
$ du -sh /usr/local/mysql
2.3G    /usr/local/mysql
最後はMySQL 8.0.18。
$ wget https://dev.mysql.com/get/Downloads/MySQL-8.0/mysql-boost-8.0.18.tar.gz
$ tar xf mysql-boost-8.0.18.tar.gz
$ cd mysql-8.0.18/
$ cmake -DWITH_BOOST=./boost
..
CMake Error at CMakeLists.txt:341 (MESSAGE):
  Please do not build in-source.  Out-of source builds are highly
  recommended: you can have multiple builds for the same source, and there is
  an easy way to do cleanup, simply remove the build directory (note that
  'make clean' or 'make distclean' does *not* work)

  You *can* force in-source build by invoking cmake with
  -DFORCE_INSOURCE_BUILD=1

-- Configuring incomplete, errors occurred!
See also "/home/yoku0825/mysql-8.0.18/CMakeFiles/CMakeOutput.log".
あ、そうか、8.0はソースディレクトリの外側でビルドしないといけないんだった。
$ cd ..
$ mkdir work
$ cd work
$ cmake -DWITH_BOOST=../mysql-8.0.18/boost ../mysql-8.0.18
..
CMake Error at CMakeLists.txt:341 (MESSAGE):
  Please do not build in-source.  Out-of source builds are highly
  recommended: you can have multiple builds for the same source, and there is
  an easy way to do cleanup, simply remove the build directory (note that
  'make clean' or 'make distclean' does *not* work)

  You *can* force in-source build by invoking cmake with
  -DFORCE_INSOURCE_BUILD=1
あれ、前と同じエラーが出る時はCMakeCache.txtかな。
$ rm ../mysql-8.0.18/CMakeCache.txt
$ cmake -DWITH_BOOST=../mysql-8.0.18/boost ../mysql-8.0.18
..
-- Configuring done
-- Generating done
-- Build files have been written to: /home/yoku0825/work
大正解。
$ time make
..
real    161m15.531s
user    110m1.582s
sys     15m43.989s

$ sudo make install
$ du -sh /usr/local/mysql
2.2G    /usr/local/mysql

8.0.18、更に時間がかかるようになっていた。。
明日は 8mitsu さんです。

2019年12月1日日曜日

手探りでマイエスキューエルシェる!

TL;DR

  • ドキュメントを読むのが面倒だから “TAB” 補完でがんばってみた
    • 優秀


この記事は MySQL Advent Calendar 2019 の1日目の記事です!

MySQL Shell は遊んでみたいけど、ドキュメントは読みたくない(面倒だから)
タブ補完だけでどんなメソッドがあるか探索しにいく!
$ mysqlsh
MySQL Shell 8.0.18

Copyright (c) 2016, 2019, Oracle and/or its affiliates. All rights reserved.
Oracle is a registered trademark of Oracle Corporation and/or its affiliates.
Other names may be trademarks of their respective owners.

Type '\help' or '\?' for help; '\quit' to exit.
 MySQL  JS > a^C
 MySQL  JS > break
break
 MySQL  JS > break^C
 MySQL  JS > c
case      catch     class     const     continue
 MySQL  JS > c^C
 MySQL  JS >
いかん、タブ補完だけで色々出てくるけど 俺にはそれがJS由来の何かなのか、MySQL Shellのなにかなのかがわからん…。
 MySQL  JS > d
db        dba       debugger  default   delete    dir()     do
 MySQL  JS > db
db   dba
 MySQL  JS > db.^C
 MySQL  JS > dba.
checkInstanceConfiguration()       deploySandboxInstance()            rebootClusterFromCompleteOutage()
configureInstance()                dropMetadataSchema()               startSandboxInstance()
configureLocalInstance()           getCluster()                       stopSandboxInstance()
createCluster()                    help()                             verbose
deleteSandboxInstance()            killSandboxInstance()
 MySQL  JS > dba.^C
さすがに dba はMySQL Shellだってわかるけどこれはしんどいかも知れない。
 MySQL  JS > db.help()
TypeError: Cannot read property 'help' of null

 MySQL  JS > dba.help()
NAME
      dba - Global variable for InnoDB cluster management.

DESCRIPTION
      The global variable dba is used to access the AdminAPI functionality and
      perform DBA operations. It is used for managing MySQL InnoDB clusters.

PROPERTIES
      verbose
            Enables verbose mode on the dba operations.

FUNCTIONS
      checkInstanceConfiguration(instance[, options])
            Validates an instance for MySQL InnoDB Cluster usage.
..
見分け方としてはこの、 help() メソッドが生えてればMySQL Shell側、生えてなければJS側だと思えばいいのかな…
 MySQL  JS > dba.checkInstanceConfiguration()
Dba.checkInstanceConfiguration: An open session is required to perform this operation. (RuntimeError)

 MySQL  JS > dba.help('checkInstanceConfiguration')
NAME
      checkInstanceConfiguration - Validates an instance for MySQL InnoDB
                                   Cluster usage.

SYNTAX
      dba.checkInstanceConfiguration(instance[, options])

WHERE
      instance: An instance definition.
      options: Data for the operation.
..
MySQL Shell由来のオブジェクトは help() メソッドに関数の名前をクォートして渡してやるとちゃんとドキュメントが生えてくる(?)っぽい。
あとは名前から何となく類推するくらいかなぁ…。
俺はドキュメント読みたくないけどこの手法でInnoDB Clusterサンドボックスの構築くらいはできるようになりました。タブ補完オススメ。

2019年11月26日火曜日

本番データ de CLONEプラグイン、そして思ったこと

TL;DR

  • みんなだいすきCLONEプラグインを使って本番のマスター(稼働中)から本番のスレーブ(諸事情により再構築が必要だった)を作った。
    • 何度かリトライはしたけど、ちゃんと動いているような気がする
  • CLONE INSTANCE FROM .. を実行するターミナルは tmux などで切断から保護しましょう…

CLONEプラグインって何的な人は先にこっちを読んでいただくと良いかも知れない。
取り敢えず
何も考えずにクローン用のアカウントをマスターに作成する。
mysql> CREATE USER cloner@xxx.xxx.xxx.xxx IDENTIFIED BY 'xxxx';
Query OK, 0 rows affected (0.00 sec)

mysql> GRANT BACKUP_ADMIN ON *.* TO cloner@xxx.xxx.xxx.xxx;
Query OK, 0 rows affected (0.00 sec)
スレーブ用地から CLONE INSTANCE FROM .. でクローンを開始しようとする。
mysql> SET GLOBAL SEESSION clone_valid_donor_list = 'yyy.yyy.yyy.yyy:3306';
Query OK, 0 rows affected (0.00 sec)

mysql> CLONE INSTANCE FROM cloner@yyy.yyy.yyy.yyy:3306 IDENTIFIED BY 'xxxx';
ERROR 3862 (HY000): Clone Donor Error: 1016 : Can't open file: './undo001' (errno: 2 - No such file or directory).
(つд⊂)ゴシゴシ
ERROR 3862は「ドナーからこんなエラーを受け取った」ためのエラーコードなので、ERROR 1016 Can’t open file .. がドナーから受け取った生のエラー。
クローンに関する進捗とかその他は全てドナーノード側のエラーログに出力される。 Note レベルなのでドナー側が log_error_verbosity= 3 でないと出力されないと思う。
こっちがドナー側のエラーログ。
2019-11-26T10:39:22.974397+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Acquired backup lock.'
2019-11-26T10:39:22.974459+09:00 34186 [Note] [MY-013457] [InnoDB] Clone Begin Master Task by cloner@172.21.160.132
2019-11-26T10:39:22.979792+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_INIT: Storage Initialize.'
2019-11-26T10:39:22.979825+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_RES_COMPLETE.'
2019-11-26T10:39:51.981458+09:00 34187 [Note] [MY-013458] [InnoDB] Clone set state change ACK: 1
2019-11-26T10:39:51.981516+09:00 34187 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_ACK: Storage Ack.'
2019-11-26T10:39:51.981544+09:00 34187 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_RES_COMPLETE.'
2019-11-26T10:39:52.081398+09:00 34186 [Note] [MY-013458] [InnoDB] Clone Master received state change ACK
2019-11-26T10:39:52.081463+09:00 34186 [Note] [MY-013458] [InnoDB] Clone State Change : Number of tasks = 1
2019-11-26T10:39:52.081483+09:00 34186 [Note] [MY-013458] [InnoDB] Clone State BEGIN FILE COPY
2019-11-26T10:39:52.087133+09:00 34186 [Note] [MY-011845] [InnoDB] Clone Start PAGE ARCH : start LSN : 1927678359668, checkpoint LSN : 1927629671670
2019-11-26T10:39:52.094897+09:00 34186 [Note] [MY-013458] [InnoDB] Clone Set Error code: 1815 Saved Error code: 0
2019-11-26T10:39:52.094936+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_EXECUTE: Storage Execute: error: 1815: Can't open file: './undo001' (errno: 2 - No such file or directory).'
2019-11-26T10:39:52.094954+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Before sending COM_RES_ERROR:  : error: 1815: Can't open file: './undo001' (errno: 2 - No such file or directory).'
2019-11-26T10:39:52.095022+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: After sending COM_RES_ERROR.'
2019-11-26T10:39:52.095295+09:00 34187 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_EXIT: Storage End.'
2019-11-26T10:39:52.095347+09:00 34187 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_RES_COMPLETE.'
2019-11-26T10:39:52.095375+09:00 34187 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Exiting clone protocol.'
2019-11-26T10:39:52.096028+09:00 34186 [Note] [MY-011846] [InnoDB] Clone Stop  PAGE ARCH : end   LSN : 1927629671670, log sys LSN : 1927678363098
2019-11-26T10:39:52.096207+09:00 34186 [Note] [MY-013457] [InnoDB] Clone End Master Task ID: 0 Passed, code: 0:
2019-11-26T10:39:52.096234+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_EXIT: Storage End.'
2019-11-26T10:39:52.096268+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_RES_COMPLETE.'
2019-11-26T10:39:52.096302+09:00 34186 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Exiting clone protocol.'
こっちがレシピエント側のエラーログ。
2019-11-26T10:39:22.963763+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Task Connect.'
2019-11-26T10:39:22.974258+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Master ACK Connect.'
2019-11-26T10:39:22.974323+09:00 139 [Note] [MY-013457] [InnoDB] Clone Apply Begin Master Version Check
2019-11-26T10:39:22.975340+09:00 139 [Note] [MY-013457] [InnoDB] Clone Apply Version End Master Task ID: 0 Passed, code: 0:
2019-11-26T10:39:22.975382+09:00 139 [Note] [MY-013457] [InnoDB] Clone Apply Begin Master Task
2019-11-26T10:39:22.976280+09:00 139 [Warning] [MY-013460] [InnoDB] Clone removing all user data for provisioning: Started
2019-11-26T10:39:22.976316+09:00 139 [Note] [MY-011977] [InnoDB] Clone Drop all user data
2019-11-26T10:39:24.122046+09:00 139 [Note] [MY-011977] [InnoDB] Clone: Fix Object count: 2314 task: 0
2019-11-26T10:39:51.598531+09:00 139 [Note] [MY-011977] [InnoDB] Clone Drop User schemas
2019-11-26T10:39:51.598901+09:00 139 [Note] [MY-011977] [InnoDB] Clone: Fix Object count: 14 task: 0
2019-11-26T10:39:51.623511+09:00 139 [Note] [MY-011977] [InnoDB] Clone Drop User tablespaces
2019-11-26T10:39:51.624095+09:00 139 [Note] [MY-011977] [InnoDB] Clone: Fix Object count: 6 task: 0
2019-11-26T10:39:51.625091+09:00 132 [Note] [MY-010596] [Repl] Error reading relay log event for channel '': slave SQL thread was killed
2019-11-26T10:39:51.625136+09:00 132 [Note] [MY-010587] [Repl] Slave SQL thread for channel '' exiting, replication stopped in log 'FIRST' at position 0
2019-11-26T10:39:51.742987+09:00 139 [Note] [MY-011977] [InnoDB] Clone Drop: finished successfully
2019-11-26T10:39:51.743073+09:00 139 [Warning] [MY-013460] [InnoDB] Clone removing all user data for provisioning: Finished
2019-11-26T10:39:51.981055+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Command COM_INIT.'
2019-11-26T10:39:52.095229+09:00 139 [Note] [MY-013458] [InnoDB] Clone Set Error code: 3862 Saved Error code: 0
2019-11-26T10:39:52.095271+09:00 139 [Note] [MY-013458] [InnoDB] Clone Apply set error code: 3862: Clone Donor Error: 1016 : Can't open file: './undo001' (errno: 2 - No such file or directory).
2019-11-26T10:39:52.095290+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Wait for remote after local issue: error: 3862: Clone Donor Error: 1016 : Can't open file: './undo001' (errno: 2 - No such file or directory)..'
2019-11-26T10:39:52.095305+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Command COM_EXECUTE: error: 3862: Clone Donor Error: 1016 : Can't open file: './undo001' (errno: 2 - No such file or directory)..'
2019-11-26T10:39:52.095552+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Master ACK COM_EXIT.'
2019-11-26T10:39:52.095941+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Master ACK Disconnect : abort: false.'
2019-11-26T10:39:52.096479+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Task COM_EXIT.'
2019-11-26T10:39:52.096798+09:00 139 [Note] [MY-013272] [Clone] Plugin Clone reported: 'Client: Task Disconnect : abort: false.'
2019-11-26T10:39:52.096858+09:00 139 [Note] [MY-013458] [InnoDB] Clone Set Error code: 3862 Saved Error code: 3862
2019-11-26T10:39:52.096890+09:00 139 [Note] [MY-013458] [InnoDB] Clone Apply set error code: 3862: Clone Donor Error: 1016 : Can't open file: './undo001' (errno: 2 - No such file or directory).
2019-11-26T10:39:52.096944+09:00 139 [Note] [MY-013458] [InnoDB] Clone Set Error code: 3862 Saved Error code: 3862
2019-11-26T10:39:52.097189+09:00 139 [Note] [MY-013457] [InnoDB] Clone Apply End Master Task ID: 0 Failed, code: 3862: Clone Donor Error: 1016 : Can't open file: './undo001' (errno: 2 - No such file or directory).
目をこらして良く見ていただくとわかるのだが、 [Warning] [MY-013460] [InnoDB] Clone removing all user data for provisioning: Finished なので、クローンが始まった時点でレシピエントのdatadirからは諸々が消える。

ちなみにドナー側の undo001 、ちゃんとあるんですけどねってすったもんだした後、レシピエントを再起動したりドナーの innodb_undo_log_truncate = ON にしてみたり色々したけれど、結局ドナー(= 稼働中のマスター)を再起動するまでクローンは同じエラーで転け続けた。
  • ひょっとしたら、ドナーを5.7から8.0にバージョンアップした時に、「自動で更新かかるから良いっしょー」ってアップグレード後に再起動してなかったのがいけないんじゃないかなと思っている( mysql_upgrade の時は自分で再起動してたけど、すっかり忘れていたんじゃないかなと)
mysql> CLONE INSTANCE FROM cloner@yyy.yyy.yyy.yyy:3306 IDENTIFIED BY 'xxxx';
Query OK, 0 rows affected (37 min 23.83 sec)
再起動後はすんなり通った。
レシピエントの方のエラーログには
2019-11-26T11:08:19.464385+09:00 7 [Note] [MY-011978] [InnoDB] Clone estimated size: 188.15 GiB Available space: 359.75 GiB
と書いてあったので、「何も設定しない(= ほぼ無制限にCLONEがリソースを欲しがる)状態」で85MB/sくらい。
m4.xlarge + 900IOPSなgp2のEBSなので「マスターでトラフィックを受けながらにしてはまあまあ?」みたいな感じはする。
ただしまあ dstat を見てたら結構iowait出てるしストレージもかなり読むし出ていくパケットも多いし…で、2台目やる時はちょっと制限しようかなとか思った(↓ はドナー側)
$ dstat -amrl
----total-cpu-usage---- -dsk/total- -net/total- ---paging-- ---system-- ------memory-usage----- --io/total- ---load-avg---
usr sys idl wai hiq siq| read  writ| recv  send|  in   out | int   csw | used  buff  cach  free| read  writ| 1m   5m  15m
 53   1  12  33   0   0|  90M  318k| 337k   90M|   0     0 |  20k 5285 |12.0G    0  1602M 1952M| 751   105 |5.57 6.21 5.83
 62   1   7  30   0   0|  90M  378k| 220k   90M|   0     0 |  16k 5335 |12.0G    0  1602M 1953M| 752   118 |5.57 6.21 5.83
 53   1  17  29   0   1|  89M  321k| 291k   89M|   0     0 |  18k 5428 |12.0G    0  1602M 1950M| 751   103 |5.57 6.21 5.83

2019-11-26T11:08:46.108105+09:00 112 [Note] [MY-013458] [InnoDB] Stage progress: 1% completed.
2019-11-26T11:10:31.546724+09:00 112 [Note] [MY-013458] [InnoDB] Stage progress: 11% completed.
制限するにはこの辺のパラメーターをいじるんだけれど、
複数個所いっぺんに変えるとわからなくなる(というか、なったので一度中断してやり直している)ので今回は clone_enable_compression = ONだけ変更して実行(↓もドナー側)
mysql> SET GLOBAL SEESSION clone_valid_donor_list = 'yyy.yyy.yyy.yyy:3306';
Query OK, 0 rows affected (0.00 sec)

mysql> SET GLOBAL clone_enable_compression = ON;
Query OK, 0 rows affected (0.00 sec)

mysql> CLONE INSTANCE FROM cloner@yyy.yyy.yyy.yyy:3306 IDENTIFIED BY 'xxxx';

----total-cpu-usage---- -dsk/total- -net/total- ---paging-- ---system-- ------memory-usage----- --io/total-
usr sys idl wai hiq siq| read  writ| recv  send|  in   out | int   csw | used  buff  cach  free| read  writ
 50   0  46   4   0   0|  14M 2675k|  47k 4043k|   0     0 |7780  6601 |12.0G    0  2152M 1425M| 143   277
 49   1  48   3   0   0|  16M  692k|  29k 4434k|   0     0 |5988  4010 |12.0G    0  2152M 1425M| 171  92.0
 50   1  47   3   0   0|  12M  843k|  35k 3330k|   0     0 |7091  5590 |12.0G    0  2152M 1425M| 127   141

2019-11-26T12:17:54.871875+09:00 474 [Note] [MY-013458] [InnoDB] Stage progress: 1% completed.
2019-11-26T12:27:37.153130+09:00 474 [Note] [MY-013458] [InnoDB] Stage progress: 11% completed.
( ゚д゚)
いやー、IOがぐっと下がったのは良いけど、遅い遅い。
読み出し速度が14MB/secしか出てなくて単純計算6倍近くかかるってことは3時間かー…ごはんでも食べてこようそうしよう。
_人人人人人_
> 時は流れた <
 ̄Y^Y^Y^Y^Y^ ̄
さーてクローンどうなったかな。
mysql> CLONE INSTANCE FROM cloner@yyy.yyy.yyy.yyy:3306 IDENTIFIED BY 'xxxx';
Timeout, server 192.168.211.58 not responding.
Σ(゚д゚lll) VPN切れてる!?
2019-11-26T15:31:25.203117+09:00 474 [Note] [MY-013458] [InnoDB] Stage progress: 96% completed.
2019-11-26T15:33:30.443342+09:00 475 [Note] [MY-013458] [InnoDB] Clone set error ACK: 1317
2019-11-26T15:33:30.443418+09:00 475 [Note] [MY-013458] [InnoDB] Clone Set Error code: 1317 Saved Error code: 0
2019-11-26T15:33:30.443440+09:00 475 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_ACK: Storage Ack.'
2019-11-26T15:33:30.443488+09:00 475 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_RES_COMPLETE.'
2019-11-26T15:33:30.443902+09:00 475 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_EXIT: Storage End.'
2019-11-26T15:33:30.443943+09:00 475 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_RES_COMPLETE.'
2019-11-26T15:33:30.443959+09:00 475 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Exiting clone protocol.'
2019-11-26T15:33:30.464396+09:00 474 [Note] [MY-013458] [InnoDB] Clone Set Error code: 1160 Saved Error code: 1317
2019-11-26T15:33:30.464443+09:00 474 [Note] [MY-013458] [InnoDB] Clone Set Error code: 1160 Saved Error code: 1317
2019-11-26T15:33:30.464465+09:00 474 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: COM_EXECUTE: Storage Execute: error: 1160: Got an error writing communication packets.'
2019-11-26T15:33:30.464491+09:00 474 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Before sending COM_RES_ERROR: network : error: 1160: Got an error writing communication packets.'
2019-11-26T15:33:30.464566+09:00 474 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: After sending COM_RES_ERROR: error: 1160: Got an error writing communication packets.'
2019-11-26T15:33:30.464646+09:00 474 [Note] [MY-013458] [InnoDB] Clone Set Error code: 1317 Saved Error code: 1317
2019-11-26T15:33:30.464687+09:00 474 [Note] [MY-011846] [InnoDB] Clone Stop  PAGE ARCH : end   LSN : 1928777840909, log sys LSN : 1928826565652
2019-11-26T15:33:30.464922+09:00 474 [Note] [MY-013457] [InnoDB] Clone End Master Task ID: 0 Failed, code: 1317: Got an error writing communication packets
2019-11-26T15:33:30.464955+09:00 474 [Note] [MY-013273] [Clone] Plugin Clone reported: 'Server: Exiting clone protocol: error: 1160: Got an error writing communication packets.'
Σ(゚д゚lll)
というわけで今、圧縮しない設定でCLONE取り直してます。ちゃんとtmux使って。
機会があれば他のパラメーターも試す。