s_tajima:TechBlog

渋谷で働くインフラエンジニアのTechブログです。

MHA + HAproxyによるMySQLの冗長構成の検証 (フェイルオーバー編)

前回の記事で作成したMHA + HAproxyのMySQLクラスタで、フェイルオーバーの実験をしてみた。

想定する状況

フェイルオーバー時のレプリケーションの状態は、上のスライドの図1のような状態を想定。

  • master(mysqlserver-a), slave*2台の構成。
  • slv1(mysqlserver-b)はt1までをDBに反映済み。t3までのrelay-logを受信済み。
  • slv2(mysqlserver-c)はt0までをDBに反映済み。t2までのrelay-logを受信済み。

この状況でmasterが(物理障害などで)OSごと停止した状況を想定。
MHAがどのようにリカバリを行うかを調査する。

検証環境構築の準備

MySQLのレプリケーション構成、MHAの設定などは前回の記事の通り。
今回はレプリケーションの状況をt0 -> t5の状況にする手順を記載。

t0 -> t1

  1. masterに対して書き込みを行う。
    1. 正常にレプリケーションされているのでslv1, slv2にもその書き込みが反映される。

t1 -> t2

  1. slv2のSQLスレッドを停止
  2. masterに対して書き込みを行う。
    1. slv1: t0 -> t1と同様masterに書き込んだデータが反映される。
    2. slv2: SQLスレッドが停止しているので、relay-logの転送は行われるが、DBへの反映はされない。

t2 -> t3

  1. slv1のSQLスレッドを停止
  2. masterに対して書き込みを行う。
    1. slv1: SQLスレッドが停止しているので、relay-logの転送は行われるが、DBへの反映はされない。
    2. slv2: SQLスレッドが停止しているので、relay-logの転送は行われるが、DBへの反映はされない。

t3 -> t4

  1. slv2のIOスレッドを停止
  2. masterに対して書き込みを行う。
    1. slv1: SQLスレッドが停止しているので、relay-logの転送は行われるが、DBへの反映はされない。
    2. slv2: IOスレッドが停止しているので、relay-logの転送が行われない。

t4 -> t5

  1. slv1のIOスレッドを停止
  2. masterに対して書き込みを行う。
    1. slv1: IOスレッドが停止しているので、relay-logの転送が行われない。
    2. slv2: IOスレッドが停止しているので、relay-logの転送が行われない。

実行したコマンドやその時のステータスは こちら:https://gist.github.com/s-tajima/9483097

フェイルオーバー時の挙動検証

スライドに添って解説。

masterの停止, MHAによる検知(スライド:図2)

サーバーがOSごと停止した状況を擬似的に再現するために、以下のコマンドを実行。

mysqlserver-a# nohup sh -c "kill -9 <mysqldのpid>; kill -9 <mysqld_safeのpid>; /etc/init.d/sshd stop; sleep 300; /etc/init.d/sshd start" &

sshdとmysqldをほぼ同時に停止(kill)する。

数秒すると、manager.logに以下のようなログが流れる。

Mon Mar 10 17:41:08 2014 - [warning] Got error on MySQL ping: 2006 (MySQL server has gone away)
ssh: connect to host 10.0.0.1 port 22: Connection refused
Mon Mar 10 17:41:08 2014 - [warning] HealthCheck: SSH to mysqlserver-a is NOT reachable.
Mon Mar 10 17:41:11 2014 - [warning] Got error on MySQL connect: 2013 (Lost connection to MySQL server at 'reading initial communication packet', system error: 111)
Mon Mar 10 17:41:11 2014 - [warning] Connection failed 1 time(s)..
Mon Mar 10 17:41:14 2014 - [warning] Got error on MySQL connect: 2013 (Lost connection to MySQL server at 'reading initial communication packet', system error: 111)
Mon Mar 10 17:41:14 2014 - [warning] Connection failed 2 time(s)..
Mon Mar 10 17:41:17 2014 - [warning] Got error on MySQL connect: 2013 (Lost connection to MySQL server at 'reading initial communication packet', system error: 111)
Mon Mar 10 17:41:17 2014 - [warning] Connection failed 3 time(s)..
Mon Mar 10 17:41:17 2014 - [warning] Master is not reachable from health checker!
Mon Mar 10 17:41:17 2014 - [warning] Master mysqlserver-a(10.0.0.1:3306) is not reachable!
Mon Mar 10 17:41:17 2014 - [warning] SSH is NOT reachable.

最新のrelay-logを持つSlaveを特定(スライド:図3)

slv1が最新のrelay-logを持つslaveであることを特定。

Mon Mar 10 17:41:17 2014 - [info] The latest binary log file/position on all slaves is mysqld-bin.000007:24179
Mon Mar 10 17:41:17 2014 - [info] Latest slaves (Slaves that received relay log files to the latest):
Mon Mar 10 17:41:17 2014 - [info]   mysqlserver-b(10.0.0.2:3306)  Version=5.6.16-log (oldest major version between slaves) log-bin:enabled
Mon Mar 10 17:41:17 2014 - [info]     Replicating from 10.0.0.1(10.0.0.1:3306)

masterにSSHで接続。可能であればbinary logの回収を行う。(スライド:図4)

今回はmasterがOS毎落ちてしまった場合を想定しているため、
slv1に送信されていなかったbinary logは回収不可能。

Mon Mar 10 17:41:17 2014 - [warning] Dead Master is not SSH reachable. Could not save it's binlogs. Transactions that were not sent to the latest slave (Read_Master_Log_Pos to the tail of the dead master's binlog) were lost.

新masterの選定。relay-logの適用。(スライド:図5)

slv2が最新のrelay-logを持っていることが確認できたため、
新masterに選出される。

Mon Mar 10 17:41:18 2014 - [info] OK. mysqlserver-b has all relay logs.
Mon Mar 10 17:41:18 2014 - [info] HealthCheck: SSH to mysqlserver-c is reachable.
Mon Mar 10 17:41:19 2014 - [info] Searching new master from slaves..
Mon Mar 10 17:41:19 2014 - [info]  Candidate masters from the configuration file:
Mon Mar 10 17:41:19 2014 - [info]  Non-candidate masters:
Mon Mar 10 17:41:19 2014 - [info] New master is mysqlserver-b(10.0.0.2:3306)
Mon Mar 10 17:41:19 2014 - [info] Starting master failover..

新masterのrelay-logが、全て適用されるのを待つ。

Mon Mar 10 17:41:19 2014 - [info] Starting recovery on mysqlserver-b(10.0.0.2:3306)..
Mon Mar 10 17:41:19 2014 - [info]  This server has all relay logs. Waiting all logs to be applied..
Mon Mar 10 17:41:19 2014 - [info]   done.
Mon Mar 10 17:41:19 2014 - [info]  All relay logs were successfully applied.

slaveのデータ復旧(スライド:図6, 図7)

slv1とslv2のrelay-logを比較し、slv2が持っていない(relay-logがない)データを特定。
slv1のrelay-logから差分のbin-logを生成し、scpでslv2に送信する。

Mon Mar 10 17:41:19 2014 - [info] Server mysqlserver-c received relay logs up to: mysqld-bin.000007:23133
Mon Mar 10 17:41:19 2014 - [info] Need to get diffs from the latest slave(mysqlserver-b) up to: mysqld-bin.000007:24179 (using the latest slave's relay logs)
Mon Mar 10 17:41:19 2014 - [info] Connecting to the latest slave host mysqlserver-b, generating diff relay log files..
Mon Mar 10 17:41:19 2014 - [info] Executing command: apply_diff_relay_logs --command=generate_and_send --scp_user=root --scp_host=10.0.0.3 --latest_mlf=mysqld-bin.000007 --latest_rmlp=24179 --target_mlf=mysqld-bin.000007 --target_rmlp=23133 --server_id=2 --diff_file_readtolatest=/var/log/mha4mysql//relay_from_read_to_latest_mysqlserver-c_3306_20140310174117.binlog --workdir=/var/log/mha4mysql/ --timestamp=20140310174117 --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.52 --relay_log_info=/var/lib/mysql/relay-log.info
Mon Mar 10 17:41:20 2014 - [info]  Generating diff files succeeded.
Mon Mar 10 17:41:20 2014 - [info] End of log messages from mysqlserver-c.
Mon Mar 10 17:41:20 2014 - [info] -- Slave diff log generation on host mysqlserver-c(10.0.0.3:3306) succeeded.
Mon Mar 10 17:41:20 2014 - [info] Generating relay diff files from the latest slave succeeded.

slv2が持っていたrelay-logがすべて適用されるのを待ち、
続いてslv1から送信されたbin-logを適用する。

Mon Mar 10 17:41:20 2014 - [info] Starting recovery on mysqlserver-c(10.0.0.3:3306)..
Mon Mar 10 17:41:20 2014 - [info]  Generating diffs succeeded.
Mon Mar 10 17:41:20 2014 - [info] Waiting until all relay logs are applied.
Mon Mar 10 17:41:20 2014 - [info]  done.
Mon Mar 10 17:41:20 2014 - [info] Getting slave status..
Mon Mar 10 17:41:20 2014 - [info] This slave(mysqlserver-c)'s Exec_Master_Log_Pos equals to Read_Master_Log_Pos(mysqld-bin.000007:23133). No need to recover from Exec_Master_Log_Pos.
Mon Mar 10 17:41:20 2014 - [info] Connecting to the target slave host mysqlserver-c, running recover script..
Mon Mar 10 17:41:20 2014 - [info] Executing command: apply_diff_relay_logs --command=apply --slave_user=root --slave_host=mysqlserver-c --slave_ip=10.0.0.3  --slave_port=3306 --apply_files=/var/log/mha4mysql//relay_from_read_to_latest_mysqlserver-c_3306_20140310174117.binlog --workdir=/var/log/mha4mysql/ --target_version=5.6.16-log --timestamp=20140310174117 --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.52 --slave_pass=xxx
Mon Mar 10 17:41:20 2014 - [info]
Applying differential binary/relay log files /var/log/mha4mysql//relay_from_read_to_latest_mysqlserver-c_3306_20140310174117.binlog on mysqlserver-c:3306. This may take long time...
Applying log files succeeded.
Mon Mar 10 17:41:20 2014 - [info]  All relay logs were successfully applied.

レプリケーションの参照先の変更(スライド: 図8)

レプリケーションの参照先を、新masterに変更する。

Mon Mar 10 17:41:20 2014 - [info]  Resetting slave mysqlserver-c(10.0.0.3:3306) and starting replication from the new master mysqlserver-b(10.0.0.2:3306)..
Mon Mar 10 17:41:20 2014 - [info]  Executed CHANGE MASTER.
Mon Mar 10 17:41:20 2014 - [info]  Slave started.

以上がMHAによるフェイルオーバーの流れ。
manager.logの全文は こちら: https://gist.github.com/s-tajima/9481507