mita2 database life

主にMySQLに関するメモです

Percona Playback で 本番 MySQLに流れているクエリを試験環境でリプレイする

MySQL

データベースのバージョンアップの際、アプリケーションの網羅的なテストが可能であれば良いのですが、どうしても難しいケースがあります。 そのような場合、リプレイツールで本番環境に流れているクエリを、試験環境でリプレイ（再現）し、動作確認を取る方法もあります。

リプレイツールを探す

MySQL の クエリ リプレイができるツールを探してみました。

Percona Tookit に pt-log-player というツールが含まれていたのですが、いつのまにか、なくなってました。。。 2013年にリリースされた、percona tookit 2.2 で削除されてしまったようです。

We removed pt-query-advisor, pt-tcp-model, pt-trend, and pt-log-player. Granted, no tool is ever really gone: if you need one of these tools, get it from 2.1. pt-log-player is now superseded by Percona Playback (http://www.percona.com/doc/percona-playback/). pt-query-advisor was removed so that we can focus our efforts on its online counterpart instead: https://tools.percona.com/query-advisor. The other tools were special projects that were not widely used.

https://www.percona.com/doc/percona-toolkit/LATEST/release_notes.html

pt-log-player is now superseded by Percona Playback とあるように Percona Playback が代替のツールとなるようです。 このツールも、最後のコミットが3年前と、メンテされてない雰囲気が漂っていますが・・・試してみます。

github.com

Percona Playback を インストールする

MySQL 8.0 環境でも問題なくビルドできました。セーフ。

$ git clone https://github.com/Percona-Lab/query-playback.git

$ sudo yum -y install tbb tbb-devel cmake boost boost-devel gcc gcc-c++ doxygen mysql-community-devel mysql-community-libs-compat

$ cd query-playback
$ mkdir build_dir
$ cd build_dir
$ cmake -DMYSQL_LIB=/usr/lib64/mysql/libmysqlclient.so -DCMAKE_BUILD_TYPE=RelWithDebInfo ..
$ make
$ make test
$ make install
$ ls /usr/local/bin/percona-playback
/usr/local/bin/percona-playback

動かしてみる

Percona Playback はスロークエリログか一般クエリログをもとにリプレイします。 とりあえず、クエリを１つだけ含んだ、スロークエリログを食わせてみます。

$ sudo cat /var/lib/mysql/localhost-slow.log
/usr/sbin/mysqld, Version: 8.0.21 (MySQL Community Server - GPL). started with:
Tcp port: 3306  Unix socket: /var/lib/mysql/mysql.sock
Time                 Id Command    Argument
# Time: 2020-08-30T08:15:17.706789Z
# User@Host: root[root] @ localhost []  Id:    16
# Query_time: 0.002868  Lock_time: 0.000708 Rows_sent: 1  Rows_examined: 559
SET timestamp=1598775317;
SELECT COUNT(*) FROM information_schema.tables;
# Time: 2020-08-30T08:15:18.795306Z
# User@Host: root[root] @ localhost []  Id:    16
# Query_time: 0.000009  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 559
SET timestamp=1598775318;
# administrator command: Quit;

リプレイ先とユーザ、パスワード等をシンプルに指定するだけです。

$ sudo /usr/local/bin/percona-playback --query-log-file /var/lib/mysql/localhost-slow.log --mysql-host 192.168.123.12 --mysql-user appuser --mysql-password Pass@123 --mysql-schema mysql --mysql-max-retries=0

Database Plugin: libmysqlclient
 Running...
 Finished reading log entries
 Start sorting log entries
 Finished sorting log entries
 Finished preprocessing - starting playback...
thread 16 slower query was run in  35623 microseconds instead of 2868
  <--
SELECT COUNT(*) FROM information_schema.tables;  -->
Error Report finished


Detailed Report
----------------
SELECTs  : 1 queries (0 faster, 1 slower)
INSERTs  : 0 queries (0 faster, 0 slower)
UPDATEs  : 0 queries (0 faster, 0 slower)
DELETEs  : 0 queries (0 faster, 0 slower)
REPLACEs : 0 queries (0 faster, 0 slower)
DROPs    : 0 queries (0 faster, 0 slower)


Report
------
Executed 1 queries
Spent 00:00:00.035623 executing queries versus an expected 00:00:00.002868 time.
0 queries were quicker than expected, 1 were slower
A total of 0 queries had errors.
Expected 1 rows, got 1 (a difference of 0)
Number of queries where number of rows differed: 0.

Average of 1.00 queries per connection (1 connections).

SELECTs : 1 queries (0 faster, 1 slower) とリプレイ先で遅くなったクエリの数をレポートしてくれます。 その他、Expected 1 rows, got 1 (a difference of 0) 結果セットの件数比較もあります。

わざとエラーにしてみる

リプレイ先でわざとエラーになるようなクエリを投げて、エラーが検知できることを確認してみます。 リプレイ先では sql_mode に ONLY_FULL_GROUP_BY を設定して、SQLがエラーになるようにしています。

$ sudo /usr/local/bin/percona-playback --query-log-file /var/lib/mysql/localhost-slow.log --mysql-host 192.168.123.12 --mysql-user appuser --mysql-password Pass@123 --mysql-schema mysql --mysql-max-retries=0
Database Plugin: libmysqlclient
 Running...
 Finished reading log entries
 Start sorting log entries
 Finished sorting log entries
 Finished preprocessing - starting playback...
Error during query: Expression #2 of SELECT list is not in GROUP BY clause and contains nonaggregated column 'tables.TABLE_NAME' which is not functionally dependent on columns in GROUP BY clause; this is incompatible with sql_mode=only_full_group_by, number of tries 1 of 1
thread 24 slower query was run in  60973 microseconds instead of 13559
  <--
SELECT COUNT(*), table_name FROM information_schema.tables GROUP BY table_schema;  -->
Error query: SELECT COUNT(*), table_name FROM information_schema.tables GROUP BY table_schema;
Connection 24 Rows Sent: 0 != expected 5 for query: SELECT COUNT(*), table_name FROM information_schema.tables GROUP BY table_schema;
Error Report finished


Detailed Report
----------------
SELECTs  : 1 queries (0 faster, 1 slower)
INSERTs  : 0 queries (0 faster, 0 slower)
UPDATEs  : 0 queries (0 faster, 0 slower)
DELETEs  : 0 queries (0 faster, 0 slower)
REPLACEs : 0 queries (0 faster, 0 slower)
DROPs    : 0 queries (0 faster, 0 slower)


Report
------
Executed 1 queries
Spent 00:00:00.060973 executing queries versus an expected 00:00:00.013559 time.
0 queries were quicker than expected, 1 were slower
A total of 1 queries had errors.
Expected 5 rows, got 0 (a difference of 5)
Number of queries where number of rows differed: 1.

Average of 1.00 queries per connection (1 connections).

A total of 1 queries had errors. としっかりエラーが補足できています。 デフォルトでは、10回リトライする設定になっています。エラーがたくさん出て、出力が見にくいので、--mysql-max-retries=0 で無効化したほうが良いです。

実行タイミングも考慮したリプレイ

相互に関係するクエリのロックの挙動やタイミング依存の問題も含めて、精度の高いリプレイをしたいと考えると、クエリの実行タイミングも可能な限り再現できるとベターです。

--query-log-accurate-mode を指定すれば、クエリの実行タイミングも含めて再現してくれそうです。 5秒間隔で INSERT INTO t (d) VALUES(NOW()) を実行し、それがリプレイ先で再現されるか確認してみます。タイミングも含めたリプレイが成功すれば、d の値の差が5秒あるレコードが再現されるはずです。

mysql> select * from test.t;
+----+---------------------+
| pk | d                   |
+----+---------------------+
|  1 | 2020-08-30 08:30:15 |
|  2 | 2020-08-30 08:30:20 |
+----+---------------------+
2 rows in set (0.01 sec)
$ sudo /usr/local/bin/percona-playback --query-log-file /var/lib/mysql/localhost-slow.log --mysql-host 192.168.123.12 --mysql-user appuser --mysql-password Pass@123 --mysql-schema mysql --mysql-max-retries=0 --query-log-accurate-mode
Database Plugin: libmysqlclient
 Running...
WARNING: did not find a timestamp for the first query. Disabling accurate mode.

WARNING: did not find a timestamp for the first query. Disabling accurate mode. とタイムスタンプがログに見つからないと言われてしまいました・・・ぐぬぬぬ。ログにはしっかりタイムスタンプが出力されています。

ソースコードを見ると、MySQL 8.0 のタイムスタンプの形式（# Time: 2020-08-30T08:29:48.563737Z） に対応できていない状態でした。

query_log/query_log.cc

static bool parse_time(boost::string_ref s, QueryLogData::TimePoint& start_time) {
  // Time can look like this
  //   # Time: 090402 9:23:36
  // or like this if microseconds granularity is configured.
  //   # Time: 090402 9:23:36.123456
  long long msecs = 0;
  std::tm td;
  memset(&td, 0, sizeof(td));
  std::string line(s.begin(), s.end());
  int num_read = sscanf(line.c_str(), "# Time: %02d%02d%02d %2d:%02d:%02d.%06lld",
                        &td.tm_year, &td.tm_mon, &td.tm_mday, &td.tm_hour, &td.tm_min, &td.tm_sec, &msecs);

MySQL 8.0のスロークエリログのタイムスタンプ形式にあわせて書き換えます。

  int num_read = sscanf(line.c_str(), "# Time: %04d-%02d-%02dT%2d:%02d:%02d.%06lld",
                        &td.tm_year, &td.tm_mon, &td.tm_mday, &td.tm_hour, &td.tm_min, &td.tm_sec, &msecs);

ソースを微修正すれば動きました。

リプレイ先に作られたレコード）

mysql> select * from test.t;
+----+---------------------+
| pk | d                   |
+----+---------------------+
|  1 | 2020-08-30 08:46:21 |
|  2 | 2020-08-30 08:46:26 |
+----+---------------------+
2 rows in set (0.00 sec)

当たり前ですが、このオプションを使うと、実際の時間と同じぐらいリプレイに時間がかかります。１時間分のスロークエリログを食わせたら、リプレイに１時間かかります。

Percona Playback まとめ

  • リプレイ先でのエラーの有無、性能劣化の有無のチェックが出来る
  • スロークエリログに記録されている結果セットの件数とリプレイ先での結果セットの件数に差異がないかチェック出来る
  • クエリの実行タイミングも再現したリプレイが可能

tombo さんの mysql-query-replayer も試したい

tombo さんが、リプレイツールを作っています。 大規模なリプレイが出来そうです。こちらも、いつか試してみたいと思います。

github.com

MySQL Shell で検証環境を作る

MySQL

日々、検証のためDBサーバを作っては捨て、作っては捨てる・・を繰り返しています。 そうすると、検証環境を作る手間を省きたくなってきます。

dbdeployer、docker-compose やchef など、いろいろなツールを試してきましたが、結局、白紙の仮装マシン（VM）を立てて、一から構築することが多いです。 それが一番慣れてますからね。。。

今回は、MySQL Shell の サンドボックス機能を試してみました。

MySQL Shell をインストールする

$ yum install -y https://dev.mysql.com/get/mysql80-community-release-el7-3.noarch.rpm
$ sudo yum install -y mysql-shell

MySQL Shell の Sandbox 関連のファンクション

検証環境（Sandbox）を作るファンクションが用意されています。ファンクション名を見れば、だいたい使い方の予想が付きます。 〜 on localhost という記述があり、（dbdeployer のような）ローカルに複数の mysqld を立ち上げる仕組みであることが想像できます。

 MySQL  127.0.0.1:3307 ssl  JS > dba.help()

NAME
      dba - InnoDB cluster and replicaset management functions.
<snip>

FUNCTIONS
<snip>

      deleteSandboxInstance(port[, options])
            Deletes an existing MySQL Server instance on localhost.

      deploySandboxInstance(port[, options])
            Creates a new MySQL Server instance on localhost.

<snip>

      killSandboxInstance(port[, options])
            Kills a running MySQL Server instance on localhost.

<snip>


      startSandboxInstance(port[, options])
            Starts an existing MySQL Server instance on localhost.

      stopSandboxInstance(port[, options])
            Stops a running MySQL Server instance on localhost.


<snip>

サンドボックスインスタンスを作成する

deploySandboxInstance でサンドボックスインスタンスを作成＋起動します。作成だけでなく、起動まで一緒にやってくれます。 引数にはポート番号を指定します。

 MySQL  localhost:33060+ ssl  JS > dba.deploySandboxInstance(3307)
A new MySQL sandbox instance will be created on this host in
/home/vagrant/mysql-sandboxes/3307

Warning: Sandbox instances are only suitable for deploying and
running on your local machine for testing purposes and are not
accessible from external networks.

Please enter a MySQL root password for the new instance: ********

Deploying new MySQL instance...

Instance localhost:3307 successfully deployed and started.
Use shell.connect('root@localhost:3307') to connect to the instance.

mysql-sandboxes ディレクトリ以下にポート番号でディレクトリが切られ、その中に設定ファイルやデータファイルが配置されていました。

$ ps au | grep mysqld
vagrant   2739  5.1 52.8 1252440 263732 pts/0  Sl   06:07   0:03 /home/vagrant/mysql-sandboxes/3307/bin/mysqld --defaults-file=/home/vagrant/mysql-sandboxes/3307/my.cnf
vagrant   2799  0.0  0.1  12500   688 pts/0    S+   06:08   0:00 grep --color=auto mysqld

my.cnf には最初からレプリケーションに必要な設定があらかじめ追記されています。

$ cat /home/vagrant/mysql-sandboxes/3307/my.cnf
[mysqld]
port = 3307
loose_mysqlx_port = 33070
server_id = 3057363809
socket = mysqld.sock
loose_mysqlx_socket = mysqlx.sock
basedir = /usr
datadir = /home/vagrant/mysql-sandboxes/3307/sandboxdata
loose_log_syslog = OFF
report_port = 3307
report_host = 127.0.0.1
log_error = /home/vagrant/mysql-sandboxes/3307/sandboxdata/error.log
relay_log_info_repository = TABLE
master_info_repository = TABLE
gtid_mode = ON
log_slave_updates = ON
transaction_write_set_extraction = XXHASH64
binlog_format = ROW
log_bin
enforce_gtid_consistency = ON
pid_file = /home/vagrant/mysql-sandboxes/3307/3307.pid
secure_file_priv = /home/vagrant/mysql-sandboxes/3307/mysql-files
[client]
port = 3307
user = root
protocol = TCP

レプリケーションを組んでみる

レプリカ用のインスタンスを追加します。

 MySQL  localhost:33060+ ssl  JS > dba.deploySandboxInstance(3308)
A new MySQL sandbox instance will be created on this host in
/home/vagrant/mysql-sandboxes/3307

createReplicaSet で ReplicaSet を作成します。createReplicaSet の引数には名前を指定します。今回は適当に、myCluster という名前を付けました。

 MySQL  localhost:33060+ ssl  JS > \connect root@localhost:3307
Creating a session to 'root@localhost:3307'
Please provide the password for 'root@localhost:3307': ********
Save password for 'root@localhost:3307'? [Y]es/[N]o/Ne[v]er (default No): Y
Fetching schema names for autocompletion... Press ^C to stop.
Closing old connection...
Your MySQL connection id is 14
Server version: 8.0.21 MySQL Community Server - GPL
No default schema selected; type \use <schema> to set one.

 MySQL  localhost:3307 ssl  JS > dba.createReplicaSet('myCluster')
A new replicaset with instance '127.0.0.1:3307' will be created.

* Checking MySQL instance at 127.0.0.1:3307

This instance reports its own address as 127.0.0.1:3307
127.0.0.1:3307: Instance configuration is suitable.

* Updating metadata...

ReplicaSet object successfully created for 127.0.0.1:3307.
Use rs.addInstance() to add more asynchronously replicated instances to this replicaset and rs.status() to check its status.

topology を見ると、まだ、127.0.0.1:3307 の１台構成であることがわかります。

 MySQL  localhost:3307 ssl  JS > rs = dba.getReplicaSet()
You are connected to a member of replicaset 'myCluster'.
<ReplicaSet:myCluster>

 MySQL  localhost:3307 ssl  JS > rs.status()
{
    "replicaSet": {
        "name": "myCluster",
        "primary": "127.0.0.1:3307",
        "status": "AVAILABLE",
        "statusText": "All instances available.",
        "topology": {
            "127.0.0.1:3307": {
                "address": "127.0.0.1:3307",
                "instanceRole": "PRIMARY",
                "mode": "R/W",
                "status": "ONLINE"
            }
        },
        "type": "ASYNC"
    }
}

addInstance で ReplicaSet にレプリカを追加します。

 MySQL  127.0.0.1:3307 ssl  JS > rs.addInstance('root@127.0.0.1:3308');
Adding instance to the replicaset...

* Performing validation checks

This instance reports its own address as 127.0.0.1:3308
127.0.0.1:3308: Instance configuration is suitable.

* Checking async replication topology...

* Checking transaction state of the instance...

NOTE: The target instance '127.0.0.1:3308' has not been pre-provisioned (GTID set is empty). The Shell is unable to decide whether replication can completely recover its state.
The safest and most convenient way to provision a new instance is through automatic clone provisioning, which will completely overwrite the state of '127.0.0.1:3308' with a physical snapshot from an existing replicaset member. To use this method by default, set the 'recoveryMethod' option to 'clone'.

このとき、レプリカのリカバリーをClone か Incremental recovery 、どちらの方法で行うか選択する必要があります。今回は、Cloneを選択し、ソース（マスター）をまるっとコピーしました。

WARNING: It should be safe to rely on replication to incrementally recover the state of the new instance if you are sure all updates ever executed in the replicaset were done with GTIDs enabled, there are no purged transactions and the new instance contains the same GTID set as the replicaset or a subset of it. To use this method by default, set the 'recoveryMethod' option to 'incremental'.


Please select a recovery method [C]lone/[I]ncremental recovery/[A]bort (default Clone): C
* Updating topology
Waiting for clone process of the new member to complete. Press ^C to abort the operation.
* Waiting for clone to finish...
NOTE: 127.0.0.1:3308 is being cloned from 127.0.0.1:3307
** Stage DROP DATA: Completed
** Clone Transfer
    FILE COPY  ############################################################  100%  Completed
    PAGE COPY  ############################################################  100%  Completed
    REDO COPY  ############################################################  100%  Completed

NOTE: 127.0.0.1:3308 is shutting down...

* Waiting for server restart... ready
* 127.0.0.1:3308 has restarted, waiting for clone to finish...
* Clone process has finished: 59.62 MB transferred in about 1 second (~59.62 MB/s)

** Configuring 127.0.0.1:3308 to replicate from 127.0.0.1:3307
** Waiting for new instance to synchronize with PRIMARY...

The instance '127.0.0.1:3308' was added to the replicaset and is replicating from 127.0.0.1:3307.

127.0.0.1:3308 がレプリカ（SECCONDARY）として追加されていることが確認できます。

 MySQL  127.0.0.1:3307 ssl  JS >  rs.status()
{
    "replicaSet": {
        "name": "myCluster",
        "primary": "127.0.0.1:3307",
        "status": "AVAILABLE",
        "statusText": "All instances available.",
        "topology": {
            "127.0.0.1:3307": {
                "address": "127.0.0.1:3307",
                "instanceRole": "PRIMARY",
                "mode": "R/W",
                "status": "ONLINE"
            },
            "127.0.0.1:3308": {
                "address": "127.0.0.1:3308",
                "instanceRole": "SECONDARY",
                "mode": "R/O",
                "replication": {
                    "applierStatus": "APPLIED_ALL",
                    "applierThreadState": "Slave has read all relay log; waiting for more updates",
                    "receiverStatus": "ON",
                    "receiverThreadState": "Waiting for master to send event",
                    "replicationLag": null
                },
                "status": "ONLINE"
            }
        },
        "type": "ASYNC"
    }
}

念のため、SHOW SLAVE STATUS を直接みてチェックしてみます。 3307 ポートのMySQLをソース（マスター）として参照していることが確認できました。

$ mysql -uroot -p -S mysql-sandboxes/3308/sandboxdata/mysqld.sock
mysql> SHOW SLAVE STATUS \G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 127.0.0.1
                  Master_User: mysql_innodb_rs_637839038
                  Master_Port: 3307
                Connect_Retry: 60
              Master_Log_File: localhost-bin.000002
          Read_Master_Log_Pos: 24939
               Relay_Log_File: localhost-relay-bin.000002
                Relay_Log_Pos: 2093
        Relay_Master_Log_File: localhost-bin.000002
             Slave_IO_Running: Yes
<snip>
               Last_SQL_Error:
  Replicate_Ignore_Server_Ids:
             Master_Server_Id: 3057363809
                  Master_UUID: d89032f1-e9bd-11ea-81a5-5254004d77d3
             Master_Info_File: mysql.slave_master_info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates
           Master_Retry_Count: 86400
                  Master_Bind:
      Last_IO_Error_Timestamp:
     Last_SQL_Error_Timestamp:
               Master_SSL_Crl:
           Master_SSL_Crlpath:
           Retrieved_Gtid_Set: d89032f1-e9bd-11ea-81a5-5254004d77d3:37-38
            Executed_Gtid_Set: d89032f1-e9bd-11ea-81a5-5254004d77d3:1-38
                Auto_Position: 1
         Replicate_Rewrite_DB:
                 Channel_Name:
           Master_TLS_Version:
       Master_public_key_path:
        Get_master_public_key: 1
            Network_Namespace:
1 row in set (0.01 sec)

所感

MySQL Shell に同梱されているのは良いですね。MySQL Shell を普段使いするようになれば、出番があるかも。

MySQL スロークエリログからやたら遅いクエリだけ取り出す

MySQL

日常的に、long_query_time をちょっと超えているクエリが流れていて、スロークエリログが多く出力されているDBってあったりしますよね？

そんなログからノイズとなってしまっている、ちょっと遅いクエリは除いて、非常に重症のクエリのログだけに絞って見たいときどうするか。

今まで、grep や awk でゴニョゴニョしてがんばってたんですが、pt-query-digest を使えば簡単にできました・・・

pt-query-digest でフィルタだけする

pt-query-digest はスロークエリログを集計し、「遅いクエリランキング」等のレポートを生成できるツールです。SQLチューニングする時によく使っています。

www.percona.com

pt-query-digest のレポート機能を無効にすることで、単なるログのフィルタツールとしても使えました（知らなかった！）

やたら遅いクエリだけ取り出す

--no-report でレポートを無効化し、出力形式を --output slowlog でスローログ形式にします。--filer に条件を指定します。

# 5秒以上のクエリだけを取り出す
$ pt-query-digest --type slowlog --output slowlog --no-report --filter '$event->{Query_time} > 5 '  localhost-slow.log

出力例）

$ pt-query-digest --type slowlog --output slowlog --no-report --filter '$event->{Query_time} > 5 '  localhost-slow.log
# Time: 2020-08-23T07:26:29
# User@Host: root[root] @ localhost []
# Thread_id: 13
# Query_time: 10.002385  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0
SELECT SLEEP(10);
# Time: 2020-08-23T07:30:25
# User@Host: root[root] @ localhost []
# Thread_id: 14
# Query_time: 5.004318  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0
SELECT SLEEP(5);
# Time: 2020-08-23T07:44:26
# User@Host: root[root] @ localhost []
# Thread_id: 15
# Query_time: 5.000435  Lock_time: 0.000163  Rows_sent: 1  Rows_examined: 4
SELECT *, SLEEP(5) FROM mysql.user WHERE User = 'root';

--output slowlog-secure とすると、バンド変数を ? に置き換えてマスキングしてくれます。

$ pt-query-digest --type slowlog --output secure-slowlog --no-report --filter ' $event->{Query_time} > 5 ' localhost-slow.log
<snip>
# Time: 2020-08-23T07:44:26
# User@Host: root[root] @ localhost []
# Thread_id: 15
# Query_time: 5.000435  Lock_time: 0.000163  Rows_sent: 1  Rows_examined: 4
select *, sleep(?) from mysql.user where user = ?;

特定のユーザのクエリだけ見る

pt-query-digest は perl で書かれてます。--filer には任意の perl のプログラムを書くことができます。

Userを正規表現でフィルタして、appuser で実行されたクエリだけ取り出す。

# pt-query-digest --type slowlog --output secure-slowlog --no-report --filter ' $event->{user} =~ /appuser/ ' /var/lib/mysql/localhost-slow.log
# Time: 2020-08-23T07:02:53
# User@Host: appuser[appuser] @ localhost []
# Thread_id: 8
# Query_time: 0.000066  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0
select @@version_comment limit ?;

MySQL ALTER TABLEとその影響まとめ

MySQL

MySQLの初期のALTER TABLEの実装は非常にシンプルな実装でした。 新しいテーブル定義で(内部的に)一時テーブルを作成し、そこに既存のデータをコピーして、コピーが終わったら入れ替えます。コピー中は更新をブロックします。

MySQL v5.6 で オンラインDDL がサポートされ、更新がブロックされなくなりました。 また、v8.0 では、INSTANT ADD COLUMN が登場し、カラム追加が一瞬できるようになりました。

このように MySQL の DDLは進化を続けてきたのですが、全ての ALTER TABLE で新機能が使えるわけではありません。 マニュアルには○×の記載があるのですが、早見表のようなものが欲しかったので、まとめてみました。

早見表

v5.7 のマニュアルをベースに、DDLの挙動をまとめました。v8.0でDDLまわりは大きく改善されているので、v8.0では違うかもしれないです。

dev.mysql.com

○×項目は4種類あります。単純に組み合わせると12パターンになるのですが、各項目はお互いに関連しているため、整理すると6パターンでした。

f:id:mita2db:20200821195517p:plain

各項目の解説

In Place

In Place が Yes の場合、既存のデータファイルに対して変更や追記を行うことで、定義変更を行います。 No の場合、上記で説明した初期実装の動きになり、対象のテーブルと同じ空き容量が ALTER TABLE するために必要になります。

Rebuilds Table

Rebuilds Table は データの再編を行うかどうかを表します。 Rebuilds Table が No の場合は、既存のデータブロックにはタッチせず、差分だけ既存のデータファイルに追記します。

  • In Place が Yes / Rebuilds Table が Yes
    • 既存のデータファイルを書き換えて再構築する
  • In Place が Yes / Rebuilds Table が No
    • 既存のデータファイルに追記する
  • In Place が No / Rebuilds Table が Yes
    • データを新定義のテーブルへコピーし、データを再編する
  • In Place が No / Rebullds Table が No
    • 該当なし（ファイルコピーの場合は必ず、データの再編となるため、ありえない）

Permits Concurrent DML

オンラインでDDLが実行できるかどうかです。Yes の場合、ALTER中に該当テーブルに対して更新を行うことができます。 No の場合、更新はブロックされ待たされます。

Only Modifies Metadata

この覧が Yes の場合、テーブルのデータにはタッチせず、メタデータの変更のみで ALTER TABLE が完結します。そのため、一瞬で、ALTER TABLE が完了します。 データファイル本体にはタッチしないため In Place と Rebuilds Table は必ず No です。また、 Permits Concurrent DML は必ず Yes です。

Only Modifies Metadata が Yes のものは、削除やリネームなど、既存のデータを書き換え・参照する必要のないオペレーションが該当しています。

AWS Aurora MySQL v5.6 から v5.7 へのアップグレードをちょっとだけ考えてみた

Aurora

Aurora MySQL v5.6 のサポート期限がいつかわからない

現在、Auroraでは、MySQL v5.6 (Engine 1.x) とv5.7互換 (Engine 2.x) のデータベースが利用できます。

Oracleが開発しているオリジナルのMySQL v5.6(以降 Vanilla MySQLと記載) は、2021/02 にサポートが切れます。 Aurora MySQL は Amazonが独自に開発している互換DBです。Vanilla MySQLのサポート期限はAuroraには関係ないのですが、互換DBであることを踏まえると、 「同じようなタイミングでサポート切れになる可能性もあるのでは・・・」と心配になってしまいます。

例えば、RHEL6互換のAmazon LinuxはRHEL6のサポート期限(2020/11末)と近しいタイミングでサポートが終了になっているようです。

aws.amazon.com

一方で、Aurora のMySQLの最新バージョン(8.0) へのキャッチアップは、まだされていません(RDS MySQLはMySQL v8.0利用可)。MySQL v8.0は2年以上前（2018/04）にリリースされています。

Amazon が Aurora を常に最新のMySQLにキャッチアップさせ続ける気があるのかどうか、よくわからないです。 v8.0へはキャッチアップせず、v5.6/v5.7 互換のバージョンをずっと継続していくのかもしれません。

ようするに、Aurora v5.6がいつまでサポートされるのか、いつかはサポートが切れるのか、よくわかりませんでした。

補足しておくと、Aurora には LTS(長期サポート)リリースのバージョンがあり、LTSに指定されたバージョンのリリースから最低でも１年はサポートが継続されると明記されています。 ある日突然サポートが打ち切られるということはないでしょう。 docs.aws.amazon.com

メリットが限られているアップグレード

MySQL v5.7 の新機能のうち、いくつかは Aurora の制限により使えないとされています。 これらは、「使えない」というよりは、Aurora 独自に解決策がすでにあるため、「使う必要がない」と言えるものが多くあります。 例えば、「起動時の InnoDB バッファープールのロード」は同じ役割をはたす機能が Aurora v5.6の時点 で既に実装されています。

docs.aws.amazon.com

Auroraのアーキテクチャや制限を踏まえると、v5.7にアップグレードして得られるメリットは主に以下でしょうか。 オンプレでのアップグレード体験と比較すると、ちょっと物足りなさを感じますね。。。(それだけ、Auroraが既に十分、賢いとも言える)

  • JSON型
  • Generated Column （生成列）
  • VARCHARの長さの拡張がオンラインDDLで対応可能

アップグレード方法

とはいえ、いつアップグレードすることになっても良いよう、方法を検討してみました。

インプレース

DBを停止し、現在利用しているサーバをそのままアップグレードする方法です。現時点ではAuroraではサポートされていないようです。

サポートされました！

dev.classmethod.jp

ダンプ・インポート

mysqldumpでデータを抜いて、v5.7へインポートする。 シンプルでわかりやすいやり方ですが、データ量が多いとすごく時間がかかります。

スナップショット復元

Aurora MySQL v5.6 のスナップショットから v5.7 の新規DBインスタンスを作成することができます。 DBへの書き込みを停止し→スナップショットの取得→新規DBインスタンスの作成→アプリからの接続先変更 という流れになります。

移行先を事前に作成しておけないので、当日、間接的な部分も含めて完了させないといけない点がデメリットでしょうか。例えば、監視設定とかセキュリティまわりなど。

v5.7のスナップショットからv5.6を作成すること(ダウングレード)はできないようです。 万が一の切り戻し時には他の手段を取る必要があります。

レプリケーション

v5.6/v5.7 のAuroraクラスタ間でレプリケーションをしておく。データを事前に連携しておくので、停止時間が短く済みます。 事前にv5.7側に参照を向けておいて実績を作れるというメリットもありますが、v5.6→v5.7間で普段発生しないレプリケーション遅延が発生する可能性があります。

まとめ

  • Amazonさん、Auroraのライフサイクルポリシーをハッキリしてほしいです（見落としてたらごめん）
  • アップグレード方法はスナップショットかレプリケーションが良さそうだが、実際に手を動かしてもうちょっと考えたい

MySQL Shell dumpInstance でバックアップ中はDDL が待機させられる

MySQL

MySQL Sever Blog に　MySQL Shell 8.0.21 の Dump / Import 機能についてエントリーが投稿されています。 並列化により非常に高速に Dump / Import 出来ることなどが示されてます。非常に強力なツールであることが感じられます。

https://mysqlserverteam.com/wp-content/uploads/2020/07/dump-1.png

MySQL Shell Dump & Load part 1: Demo! | MySQL Server Blog

とりあえず動かしてみる

\help util.dumpInstance で説明が見れます。 threads や maxRate オプションでパフォーマンスの調整ができそうです。

$ mysqlsh root@localhost
mysqlsh > \help util.dumpInstance
NAME
      dumpInstance - Dumps the whole database to files in the output directory.

SYNTAX
      util.dumpInstance(outputUrl[, options])

WHERE
      outputUrl: Target directory to store the dump files.
      options: Dictionary with the dump options.

DESCRIPTION
      The outputUrl specifies where the dump is going to be stored.

      By default, a local directory is used, and in this case outputUrl can be
      prefixed with file:// scheme. If a relative path is given, the absolute
      path is computed as relative to the current working directory. If the
      output directory does not exist but its parent does, it is created. If
      the output directory exists, it must be empty. All directories created
      during the dump will have the following access rights (on operating
      systems which support them): rwxr-x---. All files created during the dump
      will have the following access rights (on operating systems which support
      them): rw-r-----.

      The following options are supported:
      - excludeSchemas: list of strings (default: empty) - list of schemas to
        be excluded from the dump.
      - excludeTables: list of strings (default: empty) - List of tables to be
        excluded from the dump in the format of schema.table.
      - users: bool (default: true) - Include users, roles and grants in the
        dump file.
      - events: bool (default: true) - Include events from each dumped schema.
      - routines: bool (default: true) - Include functions and stored
        procedures for each dumped schema.
      - triggers: bool (default: true) - Include triggers for each dumped
        table.
      - tzUtc: bool (default: true) - Convert TMESTAMP data to UTC.
      - consistent: bool (default: true) - Enable or disable consistent data
        dumps.
      - ddlOnly: bool (default: false) - Only dump Data Definition Language
        (DDL) from the database.
      - dataOnly: bool (default: false) - Only dump data from the database.
      - dryRun: bool (default: false) - Print information about what would be
        dumped, but do not dump anything.
      - ocimds: bool (default: false) - Enable checks for compatibility with
        MySQL Database Service (MDS)
      - compatibility: list of strings (default: empty) - Apply MySQL Database
        Service compatibility modifications when writing dump files. Supported
        values: "force_innodb", "strip_definers", "strip_restricted_grants",
        "strip_role_admin", "strip_tablespaces".
      - chunking: bool (default: true) - Enable chunking of the tables.
      - bytesPerChunk: string (default: "32M") - Sets average estimated number
        of bytes to be written to each chunk file, enables chunking.
      - threads: int (default: 4) - Use N threads to dump data chunks from the
        server.
      - maxRate: string (default: "0") - Limit data read throughput to maximum
            - maxRate: string (default: "0") - Limit data read throughput to maximum
        rate, measured in bytes per second per thread. Use maxRate="0" to set
        no limit.
      - showProgress: bool (default: true if stdout is a TTY device, false
        otherwise) - Enable or disable dump progress information.
      - compression: string (default: "zstd") - Compression used when writing
        the data dump files, one of: "none", "gzip", "zstd".
      - defaultCharacterSet: string (default: "utf8mb4") - Character set used
        for the dump.
      - osBucketName: string (default: not set) - Use specified OCI bucket for
        the location of the dump.
      - osNamespace: string (default: not set) - Specify the OCI namespace
        (tenancy name) where the OCI bucket is located.
      - ociConfigFile: string (default: not set) - Use the specified OCI
        configuration file instead of the one in the default location.
      - ociProfile: string (default: not set) - Use the specified OCI profile
        instead of the default one.
<snip>

引数に出力先のディレクトリを指定して実行します。

$ mysqlsh root@localhost
mysqlsh> util.dumpInstance("/tmp/dumpdir")

dump時 はどんなSQLが流れるのか

一般クエリログを有効にし、ダンプ処理中に流れるSQLを観測してみました。テスト用に小さなテーブル（lockt）を１つ用意してます。

mysql> SHOW TABLES FROM test;
+----------------+
| Tables_in_test |
+----------------+
| lockt          |
+----------------+
1 row in set (0.01 sec)

一般クエリログに出力されたログの Id 列に注目すると、コネクションIDが17〜22の5本のコネクションにより並列にバックアップ処理が行われていることがわかります。

$ tail -n +3 general.log  | awk '{ print $2 }' | sort | uniq
17
18
19
20
21
22
Id

コネクションごとにログを分解するとこんな感じ。

  • コネクションID 17: ポート番号確認
$ grep '17 ' general.log
2020-08-15T04:03:37.955055Z    17 Query select schema()
2020-08-15T04:04:03.138587Z    17 Query SELECT @@GLOBAL.port
2020-08-15T04:04:04.708654Z    17 Quit
  • コネクションID 18: FLUSH TABLE WITH READ LOCK と LOCK INSTANCE FOR BACKUP でロックする
$ grep '18 ' general.log
2020-08-15T04:04:03.156406Z    18 Connect   root@localhost on  using SSL/TLS
2020-08-15T04:04:03.156714Z    18 Query SET SQL_MODE = ''
2020-08-15T04:04:03.156883Z    18 Query SET NAMES 'utf8mb4'
2020-08-15T04:04:03.157033Z    18 Query SET SESSION net_write_timeout = 300
2020-08-15T04:04:03.157150Z    18 Query SET TIME_ZONE = '+00:00'
2020-08-15T04:04:03.157338Z    18 Query SELECT SCHEMA_NAME FROM information_schema.schemata WHERE SCHEMA_NAME NOT IN ('information_schema', 'mysql', 'ndbinfo', 'performance_schema', 'sys')
2020-08-15T04:04:03.159080Z    18 Query SELECT TABLE_NAME FROM information_schema.tables WHERE TABLE_SCHEMA = 'test' AND TABLE_TYPE = 'BASE TABLE'
2020-08-15T04:04:03.160512Z    18 Query SELECT TABLE_NAME FROM information_schema.tables WHERE TABLE_SCHEMA = 'test' AND TABLE_TYPE = 'VIEW'
2020-08-15T04:04:03.161561Z    18 Query SELECT TABLE_ROWS FROM information_schema.tables WHERE TABLE_SCHEMA = 'test' AND TABLE_NAME = 'lockt'
2020-08-15T04:04:03.162400Z    18 Query SELECT @@GLOBAL.HOSTNAME
2020-08-15T04:04:03.162565Z    18 Query SELECT @@GLOBAL.VERSION
2020-08-15T04:04:03.162733Z    18 Query SELECT @@GLOBAL.GTID_EXECUTED
2020-08-15T04:04:03.163244Z    18 Query select * from (select distinct grantee, substr(grantee, 2, length(grantee)-locate('@', reverse(grantee))-2) as User, substr(grantee, length(grantee)-locate('@', reverse(grantee))+3, locate('@', reverse(grantee))-3) as host from information_schema.user_privileges order by user, host) as Users where Users.User not like 'mysql.infoschema' AND Users.User not like 'mysql.session' AND Users.User not like 'mysql.sys'
2020-08-15T04:04:03.164371Z    18 Query USE `test`
2020-08-15T04:04:03.164583Z    18 Query show events
2020-08-15T04:04:03.165572Z    18 Query USE `test`
2020-08-15T04:04:03.165755Z    18 Query SHOW FUNCTION STATUS WHERE Db = 'test'
2020-08-15T04:04:03.166877Z    18 Query USE `test`
2020-08-15T04:04:03.167059Z    18 Query SHOW PROCEDURE STATUS WHERE Db = 'test'
2020-08-15T04:04:03.168525Z    18 Query FLUSH TABLES WITH READ LOCK
2020-08-15T04:04:03.209360Z    18 Query /*!80000 LOCK INSTANCE FOR BACKUP */
2020-08-15T04:04:03.209530Z    18 Query UNLOCK TABLES
2020-08-15T04:04:03.210561Z    18 Query select * from (select distinct grantee, substr(grantee, 2, length(grantee)-locate('@', reverse(grantee))-2) as User, substr(grantee, length(grantee)-locate('@', reverse(grantee))+3, locate('@', reverse(grantee))-3) as host from information_schema.user_privileges order by user, host) as Users where Users.User not like 'mysql.infoschema' AND Users.User not like 'mysql.session' AND Users.User not like 'mysql.sys'
2020-08-15T04:04:03.211197Z    18 Query SHOW CREATE USER 'root'@'localhost'
2020-08-15T04:04:03.211977Z    18 Query SHOW GRANTS FOR 'root'@'localhost'
2020-08-15T04:04:03.212358Z    18 Query SELECT INDEX_NAME, COLUMN_NAME FROM information_schema.statistics WHERE NON_UNIQUE = 0 AND SEQ_IN_INDEX = 1 AND TABLE_SCHEMA = 'test' AND TABLE_NAME = 'lockt'
2020-08-15T04:04:03.240608Z    18 Quit
$ grep '19 ' general.log
2020-08-15T04:04:03.206269Z    19 Connect   root@localhost on  using SSL/TLS
2020-08-15T04:04:03.207182Z    19 Query SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ
2020-08-15T04:04:03.207402Z    19 Query START TRANSACTION WITH CONSISTENT SNAPSHOT
2020-08-15T04:04:03.207531Z    19 Query SET SQL_MODE = ''
2020-08-15T04:04:03.207673Z    19 Query SET NAMES 'utf8mb4'
2020-08-15T04:04:03.207802Z    19 Query SET SESSION net_write_timeout = 300
2020-08-15T04:04:03.208020Z    19 Query SET TIME_ZONE = '+00:00'
2020-08-15T04:04:03.215139Z    19 Query SHOW VARIABLES LIKE 'ndbinfo\_version'
2020-08-15T04:04:03.233438Z    19 Query USE `test`
2020-08-15T04:04:03.233704Z    19 Query show table status like 'lockt'
2020-08-15T04:04:03.235205Z    19 Query SET SQL_QUOTE_SHOW_CREATE=1
2020-08-15T04:04:03.235319Z    19 Query SET SESSION character_set_results = 'binary'
2020-08-15T04:04:03.235398Z    19 Query show create table `lockt`
2020-08-15T04:04:03.235584Z    19 Query SET SESSION character_set_results = 'utf8mb4'
2020-08-15T04:04:03.235685Z    19 Query show fields from `lockt`
2020-08-15T04:04:03.236751Z    19 Query select count(TRIGGER_NAME) from information_schema.triggers where TRIGGER_SCHEMA = 'test' and EVENT_OBJECT_TABLE = 'lockt'
2020-08-15T04:04:03.240935Z    19 Quit
  • コネクションID 20: SELECTでデータを抜き出す
SELECT SQL_NO_CACHE `pk`,`name`,`favorite`,`addr` FROM `test`.`lockt` WHERE `pk` BETWEEN 1 AND 4 OR `pk` IS NULL ORDER BY `pk` /* mysqlsh dumpInstance, dumping table `test`.`lockt`, chunk ID: 0 */

と BETWEEN を使って、データを分割して並列でバックアップする作りになっていることが読み取れます（今回はデータが小さすぎるので、データのダンプは並列されずこの１つのSELECTのみで終わってます）。

$ grep '20 ' general.log
2020-08-15T04:04:03.205716Z    20 Connect   root@localhost on  using SSL/TLS
2020-08-15T04:04:03.206984Z    20 Query SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ
2020-08-15T04:04:03.207611Z    20 Query START TRANSACTION WITH CONSISTENT SNAPSHOT
2020-08-15T04:04:03.207739Z    20 Query SET SQL_MODE = ''
2020-08-15T04:04:03.207950Z    20 Query SET NAMES 'utf8mb4'
2020-08-15T04:04:03.208088Z    20 Query SET SESSION net_write_timeout = 300
2020-08-15T04:04:03.208156Z    20 Query SET TIME_ZONE = '+00:00'
2020-08-15T04:04:03.219989Z    20 Query SELECT COLUMN_NAME, DATA_TYPE FROM information_schema.columns WHERE EXTRA <> 'VIRTUAL GENERATED' AND EXTRA <> 'STORED GENERATED' AND TABLE_SCHEMA = 'test' AND TABLE_NAME = 'lockt' ORDER BY ORDINAL_POSITION
2020-08-15T04:04:03.221376Z    20 Query USE `test`
2020-08-15T04:04:03.222424Z    20 Query SHOW TRIGGERS LIKE 'lockt'
2020-08-15T04:04:03.224205Z    20 Query SET SESSION character_set_results = 'binary'
2020-08-15T04:04:03.224505Z    20 Query SELECT COLUMN_NAME,                 JSON_EXTRACT(HISTOGRAM, '$."number-of-buckets-specified"')               FROM information_schema.COLUMN_STATISTICS               WHERE SCHEMA_NAME = 'test' AND TABLE_NAME = 'lockt'
2020-08-15T04:04:03.224985Z    20 Query SET SESSION character_set_results = 'utf8mb4'
2020-08-15T04:04:03.225329Z    20 Query SELECT SQL_NO_CACHE MIN(`pk`), MAX(`pk`) FROM `test`.`lockt`
2020-08-15T04:04:03.227138Z    20 Query SELECT AVG_ROW_LENGTH FROM information_schema.tables WHERE TABLE_SCHEMA = 'test' AND TABLE_NAME = 'lockt'
2020-08-15T04:04:03.230184Z    20 Query SELECT SQL_NO_CACHE `pk`,`name`,`favorite`,`addr` FROM `test`.`lockt` WHERE `pk` BETWEEN 1 AND 4 OR `pk` IS NULL ORDER BY `pk` /* mysqlsh dumpInstance, dumping table `test`.`lockt`, chunk ID: 0 */
2020-08-15T04:04:03.231534Z    20 Quit
  • コネクションID 21: ファンクションやプロシージャを抜き出す
$ grep '21 ' general.log
/usr/sbin/mysqld, Version: 8.0.21 (MySQL Community Server - GPL). started with:
2020-08-15T04:04:03.205102Z    21 Connect   root@localhost on  using SSL/TLS
2020-08-15T04:04:03.206485Z    21 Query SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ
2020-08-15T04:04:03.206782Z    21 Query START TRANSACTION WITH CONSISTENT SNAPSHOT
2020-08-15T04:04:03.207065Z    21 Query SET SQL_MODE = ''
2020-08-15T04:04:03.207263Z    21 Query SET NAMES 'utf8mb4'
2020-08-15T04:04:03.207343Z    21 Query SET SESSION net_write_timeout = 300
2020-08-15T04:04:03.207467Z    21 Query SET TIME_ZONE = '+00:00'
2020-08-15T04:04:03.214462Z    21 Query SHOW CREATE DATABASE IF NOT EXISTS test
2020-08-15T04:04:03.221139Z    21 Query USE `test`
2020-08-15T04:04:03.221476Z    21 Query show events
2020-08-15T04:04:03.223192Z    21 Query LOCK TABLES mysql.proc READ
2020-08-15T04:04:03.224379Z    21 Query use `test`
2020-08-15T04:04:03.224863Z    21 Query select @@collation_database
2020-08-15T04:04:03.225075Z    21 Query SET SESSION character_set_results = 'binary'
2020-08-15T04:04:03.225726Z    21 Query USE `test`
2020-08-15T04:04:03.225833Z    21 Query SHOW FUNCTION STATUS WHERE Db = 'test'
2020-08-15T04:04:03.229322Z    21 Query USE `test`
2020-08-15T04:04:03.229487Z    21 Query SHOW PROCEDURE STATUS WHERE Db = 'test'
2020-08-15T04:04:03.231929Z    21 Query SET SESSION character_set_results = 'utf8mb4'
2020-08-15T04:04:03.232081Z    21 Query UNLOCK TABLES
2020-08-15T04:04:03.233234Z    21 Quit
  • コネクションID 22: 何もしてない（おそらくデータ量が少なかったため）
$ grep '22 ' general.log
2020-08-15T04:04:03.208791Z    22 Connect   root@localhost on  using SSL/TLS
2020-08-15T04:04:03.208917Z    22 Query SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ
2020-08-15T04:04:03.208987Z    22 Query START TRANSACTION WITH CONSISTENT SNAPSHOT
2020-08-15T04:04:03.209066Z    22 Query SET SQL_MODE = ''
2020-08-15T04:04:03.209126Z    22 Query SET NAMES 'utf8mb4'
2020-08-15T04:04:03.209195Z    22 Query SET SESSION net_write_timeout = 300
2020-08-15T04:04:03.209252Z    22 Query SET TIME_ZONE = '+00:00'
2020-08-15T04:04:03.229120Z    22 Quit

どうやって一貫性を保ったバックアップを実現しているのか

\help util.dumpInstance で表示される説明には consistent オプションの記載があります（デフォルトは true）。dumpInstance では一貫性を持ったバックアップ*1が取れるようです。 複数のコネクション（スレッド）が一貫性を持ったバックアップを取るためにどのように連携しているのか確認してみました。

$ egrep 'Time|FLUSH|UNLOCK|LOCK|SELECT .* FROM `test`.`lockt`|START' general.log  | grep -v '21 '
Time                 Id Command    Argument
2020-08-15T04:04:03.168525Z        18 Query     FLUSH TABLES WITH READ LOCK

2020-08-15T04:04:03.207402Z        19 Query     START TRANSACTION WITH CONSISTENT SNAPSHOT
2020-08-15T04:04:03.207611Z        20 Query     START TRANSACTION WITH CONSISTENT SNAPSHOT
2020-08-15T04:04:03.208987Z        22 Query     START TRANSACTION WITH CONSISTENT SNAPSHOT

2020-08-15T04:04:03.209360Z        18 Query     /*!80000 LOCK INSTANCE FOR BACKUP */
2020-08-15T04:04:03.209530Z        18 Query     UNLOCK TABLES

2020-08-15T04:04:03.225329Z        20 Query     SELECT SQL_NO_CACHE MIN(`pk`), MAX(`pk`) FROM `test`.`lockt`
2020-08-15T04:04:03.230184Z        20 Query     SELECT SQL_NO_CACHE `pk`,`name`,`favorite`,`addr` FROM `test`.`lockt` WHERE `pk` BETWEEN 1 AND 4 OR `pk` IS NULL ORDER BY `pk` /* mysqlsh dumpInstance, dumping table `test`.`lockt`, chunk ID: 0 */

まず、FLUSH TABLES WITH READ LOCK (FTWRL) を使って、データベース全体の静止点を設けています（コネクションID: 18）。 各ダンプスレッド（コネクションID: 19-22）が、START TRANSACTION WITH CONSISTENT SNAPSHOT を実行し、静止点からトランザクションを開始します。 各ダンプスレッドがトランザクションを開始し、静止点からSELECTを実行する準備ができたら、FTWRLの役割は終わりです。UNLOCK TABLESで、全体ロックを開放します。

FTWRL から UNLOCK TABLES するまでの間、データベースに書き込むことはできませんが、通常は一瞬で終わります。 バックアップ中にデータベースの読み書きができるように工夫されてますね。

LOCK INSTANCE FOR BACKUP

見慣れない LOCK INSTANCE FOR BACKUP が出てきました。 これは、MySQL 8.0 から登場した機能です。バックアップ中にテーブル定義が変更されてしまうと、バックアップが失敗してしまうため、DDLの実行をブロックしてくれます。 LOCK INSTANCE FOR BACKUP されているデータベースに対して、DDLを実行すると Waiting for backup lock で待たされます。

mysql> SHOW PROCESSLIST;
+----+-----------------+<snip>-------------------------+------------------+
| Id | User            |<snip> State                   | Info             |
+----+-----------------+<snip>-------------------------+------------------+
|  5 | event_scheduler |<snip> Waiting on empty queue  | NULL             |
| 36 | root            |<snip> starting                | SHOW PROCESSLIST |
| 39 | root            |<snip>                         | NULL             |
| 40 | root            |<snip> Waiting for backup lock | truncate test.t2 |
+----+-----------------+<snip>-------------------------+------------------+
4 rows in set (0.00 sec)

DDLが待機している状態で、対象テーブルにDMLを実行することは可能でした。

mysql> INSERT INTO test.t2 VALUES();
Query OK, 1 row affected (0.01 sec)

metadata lock のようにDDLに続く後続のクエリが待機してしまう事はなさそうです（よかった！）。

まとめ

  • MySQL Shell の dump / load Utility は並列バックアップなど強力なツールっぽい
  • FLUSH TABLES WITH READ LOCK と LOCK INSTANCE FOR BACKUP を使って、一貫性の持ったバックアップを確実に取れるように工夫されてる
  • dump 中は DDLが待機させられるので注意

*1:すべてのテーブルで同じ時点のデータがダンプされているバックアップを「一貫性を持ったバックアップ」と呼んでいます

MySQL のロック範囲は実行計画で変わるという話

MySQL

最近、ANDPADでデータベース周りの技術顧問をさせて頂いています。ANDPADのエンジニアの皆さんから「データベースのロックまわりを詳しく知りたい！」というお話を受けて、先日、ロック周りの社内勉強会を開催しました。

SQLでは一般的なプログラミング言語と違って、ロックの制御を明示的に記述しません。ロックは暗黙的に（自動的に）データベースが必要なロックを獲得します。データベースのロックが　わかりにくい・むずかしい　と言われることが多いのはこういった背景があると思います。

MySQL のロック範囲は実行計画で変わる

更新対象の行がロックされるのは予測が付く方が多いと思います。 しかし、MySQL（InnoDB）では更新対象でなくても行がロックされることがあります。

このようなサンプルデータを使って説明します。

mysql> CREATE TABLE `lockt` (
    ->  `pk` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
    ->  `name` varchar(255) DEFAULT NULL,
    ->  `favorite` varchar(255) DEFAULT NULL,
    ->  `addr` varchar(255) DEFAULT NULL,
    -> PRIMARY KEY (`pk`)) ENGINE=InnoDB;
Query OK, 0 rows affected (0.01 sec)

mysql> SELECT * FROM lockt;
+----+-------+----------+---------+
| pk | name  | favorite | addr    |
+----+-------+----------+---------+
|  1 | Taro  | Apple    | Tokyo   |
|  2 | Jiro  | Orange   | Tokyo   |
|  3 | Alice | Orange   | London  |
|  4 | John  | Pine     | NewYork |
+----+-------+----------+---------+
4 rows in set (0.00 sec)

MySQL 8.0 で登場した、FOR UPDATE SKIP LOCKED を使って、どの行がロックしたのかを確かめます。FOR UPDATE SKIP LOCKED はロックされている行を除外して、SELECTすることが出来る機能です。

-- 何もロックがない状態ではすべてのレコードが取れる
mysql> SELECT * FROM lockt FOR UPDATE SKIP LOCKED;
+----+-------+----------+---------+
| pk | name  | favorite | addr    |
+----+-------+----------+---------+
|  1 | Taro  | Apple    | Tokyo   |
|  2 | Jiro  | Orange   | Tokyo   |
|  3 | Alice | Orange   | London  |
|  4 | John  | Pine     | NewYork |
+----+-------+----------+---------+
4 rows in set (0.00 sec)

favorite = 'Orange' and addr = 'Tokyo'の pk=2 の1行のみを更新してみます。

mysql> BEGIN;
Query OK, 0 rows affected (0.00 sec)

mysql> UPDATE lockt SET favorite = 'Banana' WHERE favorite = 'Orange' AND addr = 'Tokyo';
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0

上記のUPDATEがロックを取っている状態で、FOR UPDATE SKIP LOCKED で確認します。

mysql> SELECT * FROM lockt FOR UPDATE SKIP LOCKED;
Empty set (0.00 sec)

関係のない pk=1,3,4 の行も含めて、全部の行がロックされてしまいました！

インデックスを追加します

次に、favorite カラムにインデックスを追加して、ロック範囲がどう変化するか確認してみます。

mysql> CREATE INDEX idx_favorite ON lockt(favorite);
Query OK, 0 rows affected (0.02 sec)

今度は、favorite = 'Orange'の行がロックされました。まだ、関係のない pk = 3 の行がロックされてしまっています。

mysql> SELECT * FROM lockt FOR UPDATE SKIP LOCKED;
+----+------+----------+---------+
| pk | name | favorite | addr    |
+----+------+----------+---------+
|  1 | Taro | Apple    | Tokyo   |
|  4 | John | Pine     | NewYork |
+----+------+----------+---------+
2 rows in set (0.00 sec)

インデックスを favorite と addr の複合キーにします。

mysql> CREATE INDEX idx_favorite_addr ON lockt(favorite, addr);
Query OK, 0 rows affected (0.03 sec)

今度は、無事、pk = 2の行だけがロックされました！

mysql> SELECT * FROM lockt FOR UPDATE SKIP LOCKED;
+----+-------+----------+---------+
| pk | name  | favorite | addr    |
+----+-------+----------+---------+
|  1 | Taro  | Apple    | Tokyo   |
|  3 | Alice | Orange   | London  |
|  4 | John  | Pine     | NewYork |
+----+-------+----------+---------+
3 rows in set (0.00 sec)

実行計画を比べる

すべてロックされてしまったケースでは、インデックスでの絞り込みが行われてません。 更新対象の行を特定するためにテーブル全体をスキャン（type=index）してしまっています。

mysql> EXPLAIN UPDATE lockt SET favorite = 'Banana' WHERE favorite = 'Orange' AND addr = 'Tokyo' \G
*************************** 1. row ***************************
           id: 1
  select_type: UPDATE
        table: lockt
   partitions: NULL
         type: index
possible_keys: NULL
          key: PRIMARY
      key_len: 8
          ref: NULL
         rows: 4
     filtered: 100.00
        Extra: Using where

インデックスを追加した場合は、rangeスキャンになり、該当の行をインデックスを使って絞り込めていることがわかります。

mysql> EXPLAIN UPDATE lockt SET favorite = 'Banana' WHERE favorite = 'Orange' AND addr = 'Tokyo' \G
*************************** 1. row ***************************
           id: 1
  select_type: UPDATE
        table: lockt
   partitions: NULL
         type: range
possible_keys: idx_favorite,idx_favorite_addr
          key: idx_favorite_addr
      key_len: 2046
          ref: const,const
         rows: 1
     filtered: 100.00
        Extra: Using where; Using temporary
1 row in set, 1 warning (0.00 sec)

もっと詳しい内容はANDPADのTechblogで

という様に、MySQLでは実行計画がSQLのパフォーマンスだけでなくロック範囲にも影響を及ぼすことを説明しました。 より詳しい内容はANDPADのTechblogに掲載されています。

tech.andpad.co.jp