MySQLレプリケーション遅延と不整合を体験してみよう

本稿ではDockerを使って、MySQLのレプリケーションを手軽に試すことができる環境を構築します。そしてレプリケーション遅延と不整合を実際に起こしてみて、どのような状態になるかを確認していきます。

具体的には`SHOW SLAVE STATUS`クエリの下記の値を確認することで、レプリケーションの状態がどうなっているかを見ていきます。

- `Slave_IO_Running`、`Slave_SQL_Running`
- `Last_Error`
- `Seconds_Behind_Master`

ここ数年でクラウドサービスのフルマネージドデータベースが主流になってきており、そこでは特にレプリケーションの知識が無くても簡単にレプリカを作成することができます。手動でMySQLレプリケーションを構築しなければいけない機会は減ってきているかもしれません。しかし裏側で動いている仕組みを知っておくと、何かの役に立つかもしれません。

たとえば AWS RDS 公式ドキュメントでも、AWS 外部のデータベースにデータを移行する手段としてレプリケーションが紹介されています。
参考: [Aurora と MySQL との間、または Aurora と別の Aurora DB クラスターとの間のレプリケーション \- Amazon Aurora](https://docs.aws.amazon.com/ja_jp/AmazonRDS/latest/AuroraUserGuide/AuroraMySQL.Replication.MySQL.html)


また一方で、Dockerを使うことによって、MySQLレプリケーションの検証環境を構築するのも非常に楽になりました。実際にレプリケーション遅延も簡単に体験することができます。

## 環境
- Windows 10 Pro 1809
Windows Subsystem for Linux (Bash on windows) Ubuntu 16.04.4 LTS
    - たぶんMacでも同じです
- Docker version 18.09.1
- docker-compose version 1.18.0

### 前提知識
- MySQLで簡単なCLUDのSQLが書けること
- MySQLレプリケーションの基本について理解していること
    - 具体的には、下記用語についてなんとなくでも良いので理解していること
    - マスター(Master)サーバ
    - スレーブ(Slave)サーバ
    - バイナリログ(binlog)
        - [MySQL :: MySQL 5\.6 リファレンスマニュアル :: 5\.2\.4 バイナリログ](https://dev.mysql.com/doc/refman/5.6/ja/binary-log.html)

本稿ではDockerを利用しますが、環境構築に利用するだけのため特に知識は無くても使えると思います。

## 1: レプリケーション構成MySQLを構築してみる
作業用に適当なディレクトリを作成します。

```bash
$ mkdir mysql-repl-sample && cd $_
```

### 単一構成MySQLの構築
まずはレプリケーションを貼る前に、1台だけのMySQLを構築します。

`Dockerfile-master`というファイルを作成します。後にSlave用のDockerfileも作成するため、名前を分けておきます。

```dockerfile:Dockerfile-master
FROM mysql:5.6
ADD ./mysql-master.cnf /etc/mysql/my.cnf
RUN chmod 644 /etc/mysql/my.cnf
```

`mysql-master.cnf`というファイルを作成します。こちらもmy.cnfですが、Slave用のファイルと区別できる名前にしています。

```mysql-master.cnf
[mysqld]
log-bin
server-id=1
```
設定について詳しくは下記を参照してください。
[MySQL :: MySQL 5\.6 リファレンスマニュアル :: 5\.2\.4\.2 バイナリログ形式の設定](https://dev.mysql.com/doc/refman/5.6/ja/binary-log-setting.html)

次に、Dockerfileとmy.cnfを使ってMySQLを起動するための、docker-compose.ymlを作成します。

```docker-compose.yml
version: '2'
services:
  db-master:
    build:
      context: "./"
      dockerfile: "Dockerfile-master"
    ports:
      - "13306:3306"
    volumes:
      - mysql-master-data:/var/lib/mysql
    environment:
      MYSQL_ALLOW_EMPTY_PASSWORD: 1
volumes:
  mysql-master-data:
```

ファイルを作成し終えたら、下記コマンドでMySQLを起動できます。

```bash
$ docker-compose up -d
```

13306ポートを開けているため、下記コマンドで接続できます。

```bash
$ mysql -u root -h 127.0.0.1 -P 13306
```

接続できたら成功です。

### 2台のMySQLを構築
先程と同様に、Slave用のDockerfileとmy.cnfを作成します。

```Dockerfile:Dockerfile-slave
FROM mysql:5.6
ADD ./mysql-slave.cnf /etc/mysql/my.cnf
RUN chmod 644 /etc/mysql/my.cnf
```

```mysql-slave.cnf
[mysqld]
server-id=2
```

docker-compose.ymlは、下記のように書き換えます。

```docker-compose.yml
version: '2'
services:
  db-master:
    build:
      context: "./"
      dockerfile: "Dockerfile-master"
    ports:
      - "13306:3306"
    volumes:
      - mysql-master-data:/var/lib/mysql
    environment:
      MYSQL_ALLOW_EMPTY_PASSWORD: 1
  db-slave:
    build:
      context: "./"
      dockerfile: "Dockerfile-slave"
    ports:
      - '23306:3306'
    volumes:
      - mysql-slave-data:/var/lib/mysql
    environment:
      MYSQL_ALLOW_EMPTY_PASSWORD: 1
volumes:
  mysql-master-data:
  mysql-slave-data:
```

**Masterは13306、Slaveは23306ポート**に設定しています。これは覚えておいてください。

ファイルを作成したら、下記コマンドでDockerコンテナを作り直します。

```bash
$ docker-compose down
$ docker-compose up -d
```
### レプリケーションの開始

**Master(13306ポート)**に接続し、binlogの状態を確認します。

```bash
$ mysql -u root -h 127.0.0.1 -P 13306 -e "SHOW MASTER STATUS\G"
```

この時の「File」と「Position」の値をメモしておきます。

続いて **Slave(23306ポート)** に接続し、下記`CHANGE MASTER`と`START SLAVE`というクエリを実行します。

```bash
$ mysql -u root -h 127.0.0.1 -P 23306

> CHANGE MASTER TO
    MASTER_HOST='db-master',
    MASTER_PORT=3306,
    MASTER_USER='root',
    MASTER_PASSWORD='',
    MASTER_LOG_FILE='<MasterLogFile>',
    MASTER_LOG_POS=<MasterLogPosition>;

> START SLAVE;

> SHOW SLAVE STATUS\G
```

`<MasterLogFile>`と`<MasterLogPosition>`には、先ほど`SHOW MASTER STATUS`でメモした値を入れてください。


**Slave(23306ポート)**に接続し、`Slave_IO_Running`と`Slave_SQL_Running`がともに`Yes`になっていることを確認できたら、レプリケーション成功です。

```bash
$ mysql -u root -h 127.0.0.1 -P 23306 -e "SHOW SLAVE STATUS\G" | grep Running: 
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
```

### レプリケーションを使ってデータを2台のMySQLに反映させる
**Master(13306ポート)**に接続し、適当なデータを入れてみます。

```bash
$ mysql -u root -h 127.0.0.1 -P 13306
```

```sql
> CREATE DATABASE sushi_ya;
> USE sushi_ya;

> CREATE TABLE sushi(
    id   INT PRIMARY KEY AUTO_INCREMENT,
    name VARCHAR(20),
    INDEX(id)
);

> INSERT into sushi_ya.sushi (name) VALUES ('maguro');
> INSERT into sushi_ya.sushi (name) VALUES ('tamago');
```

つづいて **Slave(23306ポート)**に接続 し、データを確認してみましょう。

```bash
$ mysql -u root -h 127.0.0.1 -P 23306 -e "SELECT * FROM sushi_ya.sushi;" 
+----+--------+ 
| id | name   |
+----+--------+
|  1 | maguro | 
|  2 | tamago |
+----+--------+
```

SlaveにはINSERTクエリを実行していません。しかし、MasterにINSERTしたデータがSlaveにも入っていることを確認できました。これがレプリケーションです。

## 2: レプリケーション不整合を起こして、修復してみる
レプリケーション構成においてはデータの不整合が起きないようにするために、Masterに更新系クエリが実行される事が想定されています。Slaveにはロックをかけておいて更新を防ぐ事もあります。しかし何らかの理由でMasterとSlaveのデータに不整合が起きてしまった場合、レプリケーションが反映できず止まってしまう事があります。

実際にやってみましょう。

### MasterとSlaveに同じIDで異なるデータを入れて、レプリケーションを止める
**Slave(23306ポート)**に直接 、id=100のデータを追記してみます。

```bash
$ mysql -u root -h 127.0.0.1 -P 23306 -e "INSERT into sushi_ya.sushi (id, name) VALUES (100, 'ika');"
```

当然Slaveには追加されますが、Masterには反映されていません。

```bash
$ mysql -u root -h 127.0.0.1 -P 13306 -e "SELECT * FROM sushi_ya.sushi WHERE id = 100;" # Master
```

```bash
$ mysql -u root -h 127.0.0.1 -P 23306 -e "SELECT * FROM sushi_ya.sushi WHERE id = 100;" # Slave 
+-----+------+ 
| id  | name |
+-----+------+
| 100 | ika  |
+-----+------+
```

ここで **Master(13306ポート)**にもid=100を追加する と、どうなるでしょうか？

```bash
$ mysql -u root -h 127.0.0.1 -P 13306 -e "INSERT into sushi_ya.sushi (id, name) VALUES (100, 'tako');"
```

MasterとSlaveの様子を見てみます。

```bash
$ mysql -u root -h 127.0.0.1 -P 13306 -e "SELECT * FROM sushi_ya.sushi WHERE id = 100;" # Master 
+-----+------+ 
| id  | name |
+-----+------+
| 100 | tako |
+-----+------+
```

```bash
$ mysql -u root -h 127.0.0.1 -P 23306 -e "SELECT * FROM sushi_ya.sushi WHERE id = 100;" # Slave 
+-----+------+ 
| id  | name |
+-----+------+
| 100 | ika  |
+-----+------+
```
id=100なのに、異なるデータが入ってしまっており、データの不整合が起きています。

このときレプリケーションは止まってしまっています。
**Master(13306ポート)**にid=101のデータを追加しても、Slaveには反映されません。

```bash
$ mysql -u root -h 127.0.0.1 -P 13306 -e "INSERT into sushi_ya.sushi (id, name) VALUES (101, 'ebi');" # Master
$ mysql -u root -h 127.0.0.1 -P 13306 -e "SELECT * FROM sushi_ya.sushi WHERE id = 101;" # Master
$ mysql -u root -h 127.0.0.1 -P 23306 -e "SELECT * FROM sushi_ya.sushi WHERE id = 101;" # Slave
```

`SHOW SLAVE STATUS`を確認します。

```bash
$ mysql -u root -h 127.0.0.1 -P 23306 -e "SHOW SLAVE STATUS\G" | grep Last_Error 
                   Last_Error: Could not execute Write_rows event on table sushi_ya.sushi; Duplicate entry '100' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log f4e6386f510a-bin.000001, end_log_pos 1351
```
id=100のデータを反映させようとした時の`Duplicate entry`のエラーでレプリケーションが止まっています。

```bash
$ mysql -u root -h 127.0.0.1 -P 23306 -e "SHOW SLAVE STATUS\G" | grep Running: 
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
```
`Slave_SQL_Running: No`になっているのが確認できます。

### レプリケーションの再開
止まってしまったレプリケーションを再開するには、下記の方法があります

- エラーになっているクエリをスキップする (Slaveを採択)
- エラーを直してbinlogを通す (Masterを採択)

今回は、エラーを修正する方法を紹介します。

**Slave(23306ポート)**に入ってしまったid=100の不正なデータを削除し、Masterにあるid=100を反映できるようにします。そしｔ`START SLAVE`でレプリケーションを再開します。

```bash
$ mysql -u root -h 127.0.0.1 -P 23306 -e "DELETE FROM sushi_ya.sushi WHERE id = 100;"
$ mysql -u root -h 127.0.0.1 -P 23306 -e "START SLAVE;"
```
エラーが解消され、レプリケーションが再開され、`SHOW SLAVE STATUS`も`Slave_SQL_Running: Yes`になります。

```bash
$ mysql -u root -h 127.0.0.1 -P 23306 -e "SHOW SLAVE STATUS\G" | grep Last_Error 
                   Last_Error:
```

```bash
$ mysql -u root -h 127.0.0.1 -P 23306 -e "SHOW SLAVE STATUS\G" | grep Running: 
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
```
レプリケーションが止まっていた後のid=101のデータも、全て入っているのが確認できます。

```bash
$ mysql -u root -h 127.0.0.1 -P 23306 -e "SELECT * FROM sushi_ya.sushi;" 
+-----+--------+ 
| id  | name   |
+-----+--------+
|   1 | maguro |
|   2 | tamago |
| 100 | tako   |
| 101 | ebi    | 
+-----+--------+
```

今回とは逆にSlaveを採択する場合は、`SET GLOBAL sql_slave_skip_counter = 1`というクエリを実行しMasterのbinlogをスキップします。
[MySQL :: MySQL 5\.6 リファレンスマニュアル :: 13\.4\.2\.4 SET GLOBAL sql\_slave\_skip\_counter 構文](https://dev.mysql.com/doc/refman/5.6/ja/set-global-sql-slave-skip-counter.html)


## 3: レプリケーション遅延を体験する
Masterに対して非常に重いクエリが実行されたりすると、レプリケーションに遅延が発生し「Masterのクエリが完了してからSlaveに反映されるまでの間、**MasterにはレコードがあるのにSlaveには無い状態**」になってしまいます。Slaveに参照系のクエリを投げて負荷分散している場合、更新したはずのデータが取得できず不具合を起こしてしまうことがあります。

実際にレプリケーション遅延を起こしてみましょう。

しかし今回の検証用のたった数件のデータベースでは、どんなクエリも一瞬で返ってきてしまうと思います。そこでここではSLEEP関数を使って「30秒かかる超遅いINSERTクエリ」を擬似的に発生させます。

まず準備として、**Master**のバイナリログの形式をステートメントベースに変更しておきます。

```bash
$ mysql -u root -h 127.0.0.1 -P 13306 -e "SET GLOBAL binlog_format = 'STATEMENT';"
```
`SHOW VARIABLES`で確認できます。

```bash
$ mysql -u root -h 127.0.0.1 -P 13306 -e "SHOW VARIABLES LIKE 'binlog_format'\G"; 
*************************** 1. row *************************** 
Variable_name: binlog_format
        Value: STATEMENT
```
これは本稿においてはSLEEP関数を使ってレプリケーション遅延を発生させるためだけの設定であり、本質とは関係ありません。詳細は下記を確認してください。
[MySQL :: MySQL 5\.6 リファレンスマニュアル :: 5\.2\.4\.2 バイナリログ形式の設定](https://dev.mysql.com/doc/refman/5.6/ja/binary-log-setting.html)

これから1分間で、下記の順番でオペレーションをします。

1. Masterに「30秒かかるINSERT文」を実行する
1. 30秒待つ
1. Slaveに反映されるまでの30秒間に、下記を確認する
    1. Masterにデータが入っていること
    1. Slaveにデータが入っていないこと
    1. `SHOW SLAVE STATUS`で`Seconds_Behind_Master`の値が1以上になること

時間が限られているので、何が起きるか事前に頭に入れて準備した上で実行してみてください。

まず**Master(13306ポート)**に「30秒かかるクエリ」を実行します。

```bash
$ mysql -u root -h 127.0.0.1 -P 13306 -e "INSERT into sushi_ya.sushi (name) VALUES (CONCAT('wasabi', SLEEP(30)));" # 30秒待つ
```
MasterへのINSERTに30秒かかるのを待ったら、Slaveに反映される30秒の間に、下記クエリを実行してみましょう。

```bash
$ mysql -u root -h 127.0.0.1 -P 13306 -e "SELECT * FROM sushi_ya.sushi;" # Master
$ mysql -u root -h 127.0.0.1 -P 23306 -e "SELECT * FROM sushi_ya.sushi;" # Slave
$ mysql -u root -h 127.0.0.1 -P 23306 -e "SHOW SLAVE STATUS\G" | grep Seconds_Behind_Master
```

Masterに登録されたはずのデータが、Slaveに登録されていないのが分かります。

最後の`SHOW SLAVE STATUS`を何度も繰り返し実行していると、`Seconds_Behind_Master`の数値がどんどん増えていって、30になると一気にゼロになると思います。30秒経過すると、Slaveにもデータが入っている事が確認できると思います。

これが**レプリケーション遅延**です。レプリケーションが**非同期**のため起きる現象です。

このように`Seconds_Behind_Master`の値が大きくなっていると、MasterとSlaveとの間でデータに差異が生まれ、アプリケーションに不具合を引き起こす可能性があります。

## まとめ
MySQLレプリケーションの状態は、`SHOW SLAVE STATUS`クエリで確認することができます。その中でも不整合や遅延は、以下の値で確認できます。

- `Slave_IO_Running`、`Slave_SQL_Running` がYesになっているかどうか
- `Last_Error` があるかどうか
- `Seconds_Behind_Master` が1以上の値になっていないかどうか



なお今回使ったDockerでの検証環境構築プログラムは、下記リポジトリにもあります。
https://github.com/s2terminal/mysql-repl

### 参考
- [実践ハイパフォーマンスMySQL 第3版 \| Baron Schwartz, Peter Zaitsev, Vadim Tkachenko, 菊池 研自, 株式会社クイープ \|本 \| 通販 \| Amazon](https://www.amazon.co.jp/dp/4873116384)
- [docker\-composeでMaster/Slave構成のMySQLを手に入れる \- Qiita](https://qiita.com/takyam/items/f13bc4a1db0433ffb958)