tom__bo’s Blog

MySQL!! MySQL!! @tom__bo

SemisyncレプリケーションのFailoverでなぜデータがずれるのか

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


※ 従来MySQLレプリケーション構成ではMaster/Slaveという単語が使われてきましたが、現時点の最新バージョンである8.0.22からは、これらの単語がSource/Replicaと置き換えられ始めています。使い慣れた単語を使いたいところですが、ここではMaster->Source, Slave->Replicaという単語に統一します。
cf) https://mysqlhighavailability.com/mysql-terminology-updates/


MySQLレプリケーション構成には5.7.22バージョンからPaxosをベースとしたGroup Replicationが導入されましたが、運用方法の変化やパフォーマンスなどの理由から従来のレプリケーション方式、特にSemisynchronous(準同期,以降semisync)レプリケーションをベースに運用しているケースは多いでしょう。

非常に単純なケースとしては以下の図1のような構成があります。

図1 f:id:tom__bo:20201130230013p:plain

Instance-1(Source)とInstance-2(Replica)の2台からなる冗長構成でInstance-1でClientからのすべてのリクエストを受け、Instance-2はアクティブスタンバイとしてInstance-1の故障に備え、Insatance-1が故障したときにはInstance-2をSourceに昇格し、サービスのダウンタイムを最小化します。

Sourceのインスタンス(図1中のInstance-1)が稼働不能になり、フェイルオーバが発生する理由は様々ですが、一時的なmysqldの停止(メモリ故障など)が原因のフェイルオーバであっても、その前後で2つのインスタンス間のデータがずれてしまう可能性があります。

この記事ではSemisyncレプリケーションの仕組みと、この構成のサーバ間でSourceのMySQLの再起動を伴うFailoverが発生した際にSourceにしか存在しないデータが発生する理由を説明します。 また、ここではトランザクション処理に対応しているInnoDBストレージエンジンを使っていることを前提とします。

Semisync(準同期)レプリケーションとは

Semisyncレプリケーションrpl_semisync_master, repl_semisync_slaveプラグインによって提供される、Sourceでの更新ログ(binary log, 以降binlog)がReplicaに到達したことを確認することでデータの同期具合を強化したレプリケーション機能です。 Semi(準)という名のとおり完全な同期は保証していません(Replicaからのackが返ってこない場合はtimeoutして非同期モードに切り替えて動作します)。

Semisyncリプリケーションの仕組み

Clientからcommit要求を受け取るとまずInnoDBでデータを更新し、binlogに書き込みます。そしてReplicaへ更新分を転送し、これを受け取ったReplicaはackを返します。 ackを受け取ったSourceはInnoDBcommitを行いClientにOK packetを返します。 (これはafter_syncの仕組みをかなり単純に説明したものですが、本記事で説明したい内容を理解するには十分なので、この程度にしています)

図にすると以下のようになります。

図2 f:id:tom__bo:20201130230023p:plain

  1. Clientがcommit要求
  2. ストレージエンジン(InnoDB)で更新
  3. BinlogにWrite(commit eventも含む)
  4. Replicaにbinlog(のevent)送信
  5. Replicaはbinlogを受け取ってAckを返す
  6. Ackを受け取ってストレージエンジンでcommit
  7. ClientにOKを返す

MySQLリカバリ

MySQLのクラッシュリカバリでは、innodb_log(いわゆるredo log)とbinlogを使ったリカバリーが行われ、binlogでcommitされたトランザクションリカバリ時に ロールフォーワードされます。
またMySQLは起動シーケンスの中で自身のデータをチェックし、必要であれば自動的にクラッシュリカバリを行ってからクライアントからの接続を受け付けます。

binlogでcommitされたのトランザクションがロールフォーワードされる、という挙動を説明した公式ドキュメントは見つけられませんでしたが、MySQL徹底入門第4版のp.282にはInnoDBはクラッシュリカバリにもバイナリログを使用するため...とあり、詳解MySQL5.7のp.42でもinnodb_logとbinlogを使った2層コミットを内部的に行っていて、データの損失がないという内容が説明されています。
この後の実験でも見ていきますが、更新負荷の高いMySQLでクラッシュリカバリをされたことのある方にはよく知られた内容かと思います。

Failover後に不整合が起きる理由

SemisyncレプリケーションMySQLのクラッシュリカバリの仕組みを理解すると、図2の③(BinlogへのWrite)の直後で、④(Replicaへのbinlog送信)の前にクラッシュすると、Replicaに更新分を送っていないのでReplicaには伝わっていないが、Sourceではクラシュリカバリーによって復元されるデータができることがわかります。 Sourceのクラッシュリカバリを待ってレプリケーションが再開されれば最終的にデータは等しくなりますが、多くの場合はダウンタイムを最小限にするために、SourceのMySQLが利用不可能と検知されたらすぐに(数秒かそれ以下の時間内に)Replicaへフェイルオーバするでしょう。(これはシステムの設計や規模、クラッシュの原因によりますが、通常はクラッシュしたMySQLの復旧には数分から数時間かかります)

クラッシュリカバリで復元される更新分はSemisyncレプリケーションのafter_sync(default)の設定によって、ClientにOKを返していないのでこの差分が問題になることはないはずですが、Failover後に旧Sourceにしかない更新分が存在することになります。 また、クラッシュリカバリで復元された更新分は新SourceとなったMySQLに同期できる可能性はかなり低くなります(PKやUKへの変更がコンフリクトする可能性が高いため)。

以上が理論上、FailoverによってSourceとReplicaにデータの差分ができる理由になります。 ここからは実際に高負荷のinsertを行うスクリプトを使ってこの差分ができる例を見てみます。

実験

実験はvCPU: 4のMySQLインスタンス2台と同じvCPUのVMスクリプト実行用(client想定)として用意して行いました。

sample db

semisyncレプリケーション構成のMySQLを2台用意し、適当なテーブルを作成します。

CREATE TABLE `tbl1` (
  `id` int NOT NULL,
  PRIMARY KEY (`id`)
)

上記のテーブルに、ある程度の並列度でデータをinsertするスクリプトを用意します。

package main

import (
    "database/sql"
    "fmt"
    _ "github.com/go-sql-driver/mysql"
    "math/rand"
    "sync"
    "time"
)

var (
    db *sql.DB
    id int = 1
    mu sync.Mutex
)

func insertRandom(db *sql.DB) {
    rand.Seed(time.Now().UnixNano())
    var localId int
    for i := 0; i < 10000; i++ {
        mu.Lock()
        localId = id
        id++
        mu.Unlock()
        _, err := db.Exec("insert into tbl1 (id) value (?) ", localId)
        if err != nil {
            fmt.Printf("[Error] %s. LocalID: %d \n", err.Error(), localId)
            return
        }
    }
}

func main() {
    conn := "sysbench:sysbench@tcp({host}:{port})/sample?timeout=1s&interpolateParams=true"
    db, err := sql.Open("mysql", conn)
    if err != nil {
        fmt.Println(err.Error())
        return
    }
    db.SetMaxIdleConns(20)
    db.SetMaxOpenConns(20)

    var wg sync.WaitGroup
    para := 20
    wg.Add(para)

    start := time.Now()
    for i := 0; i < para; i++ {
        go func() {
            defer wg.Done()
            insertRandom(db)
        }()
    }

    wg.Wait()
    end := time.Now()
    fmt.Println(end.Sub(start))
}

20並列でそれぞれ10000レコード、合計20万recordをinsertします。
グローバル変数をmutexで保護して各goroutineがincrementしながらinsertしています。
正常に実行すると今回の環境では22秒くらいかかり、9000qpsくらいになりました。

Sourceの障害再現

上記のスクリプトをSourceに対して実行し、5秒後くらいにSourceのMySQLをkillします

  • pkill -9 mysqlでプロセスをkill
  • replicaでstop slave (レプリケーションが自動で再開されてしまうのを止める)
  • sourceで再起動
  • source/replicaでデータを確認

スクリプトの出力

上記のスクリプトでエラーハンドリングしているところの出力は以下のようになりました。 LocalIDのinsert中にerrorが発生したことがわかります。

$ ./sample
[Error] invalid connection. LocalID: 52246
[Error] invalid connection. LocalID: 52250
[Error] invalid connection. LocalID: 52242
[Error] invalid connection. LocalID: 52248
[Error] invalid connection. LocalID: 52235
[Error] invalid connection. LocalID: 52243
[Error] invalid connection. LocalID: 52241
[Error] invalid connection. LocalID: 52237
[Error] invalid connection. LocalID: 52244
[Error] invalid connection. LocalID: 52249
[Error] invalid connection. LocalID: 52232
[Error] invalid connection. LocalID: 52236
[Error] invalid connection. LocalID: 52238
[Error] invalid connection. LocalID: 52247
[Error] invalid connection. LocalID: 52239
[Error] invalid connection. LocalID: 52234
[Error] invalid connection. LocalID: 52231
[Error] invalid connection. LocalID: 52245
[Error] invalid connection. LocalID: 52240
[Error] invalid connection. LocalID: 52233

replicaの状況

Sourceを復旧する前にreplicaのtbl1の状況を確認します。
52231までinsertされていることがわかります。ここでstop slave;してレプリケーションが再開しないようにしておきます。

mysql> select count(*) from tbl1;
+----------+
| count(*) |
+----------+
|    52231 |
+----------+
1 row in set (0.01 sec)

mysql> select * from tbl1 order by id desc limit 20;
+-------+
| id    |
+-------+
| 52231 |
| 52230 |
| 52229 |
| 52228 |
| 52227 |
| 52226 |
| 52225 |
| 52224 |
| 52223 |
| 52222 |
| 52221 |
| 52220 |
| 52219 |
| 52218 |
| 52217 |
| 52216 |
| 52215 |
| 52214 |
| 52213 |
| 52212 |
+-------+
20 rows in set (0.00 sec)

再起動後のsourceの状況 (crash recovery含む)

killしたMySQLのプロセスを再起動して、クラッシュリカバリ後のデータを確認します。
52247までinsertされていることがわかります。

mysql> select count(*) from tbl1;
+----------+
| count(*) |
+----------+
|    52247 |
+----------+
1 row in set (0.01 sec)

mysql> select * from tbl1 order by id desc limit 20;
+-------+
| id    |
+-------+
| 52247 |
| 52246 |
| 52245 |
| 52244 |
| 52243 |
| 52242 |
| 52241 |
| 52240 |
| 52239 |
| 52238 |
| 52237 |
| 52236 |
| 52235 |
| 52234 |
| 52233 |
| 52232 |
| 52231 |
| 52230 |
| 52229 |
| 52228 |
+-------+
20 rows in set (0.00 sec)

結果

スクリプト側のエラー出力を見ると52231 ~ 52250までのinsertでSourceからのOKの応答までが完了しなかったことがわかります。 2つのMySQLでは、Replicaでは52231までがinsertされた状態、Sourceでは再起動(クラシュリカバリ含む)後に52247までinsertされた状態が確認できました。 Sourceでクラッシュリカバリした後にデータが存在することから以下のことが推測できます。

  • 52231 ~ 52247のデータはbinlogには書いたがReplicaへの転送が完了していない
  • 52248 ~ 52250のデータはbinlogに書くところまでも完了していない

この実験からある程度書き込みの負荷が高いSouceのMySQLで障害が起こるとクラッシュリカバリによって復元されるデータがあることがわかります。

まとめ

Semisynchronousレプリケーションの仕組みとMySQLの再起動によるcrash recoveryについて説明し、これらと冗長化のためのFailoverの仕組みが組み合わさることでFailover後にSourceにしかないデータが発生することを説明しました。 実際にはMySQLの設定やHA構成、レプリケーショントポロジなどによって状況は異なりますので、よくある構成(?)の一例として見ていただけると幸いです。 また、更新系のクエリのQPSが高い場合でしかこういったことが起こることはなく、必ず発生するというわけではありません。

このあとの復旧方法はポリシーによりますが、こういった状況を考慮できているか確認してみることをおすすめします。

参考