MHA failover GTID 专题

https://yq.aliyun.com/articles/238882?spm=5176.8067842.tagmain.18.73PjU3

摘要： MHA failover GTID 专题 这里以masterha_master_switch为背景详解各种可能遇到的场景 假定环境(经典三节点) host_1(host_1:3306) (current master) +--host_2(host_2:3306 slave[candidat...

MHA failover GTID 专题

这里以masterha_master_switch为背景详解各种可能遇到的场景

假定环境(经典三节点)

host_1(host_1:3306) (current master)
 +--host_2(host_2:3306 slave[candidate master])
 +--host_3(host_3:3306 etl)

一、Master : MySQL down

1.1 etl 延迟8小时

配置文件中加上no_check_delay=0 即可忽略报错

1.2 slave(候选master)比etl还要落后更多

• 1.2.1 当master的部分日志还没传递两个slave，这时候master 上的MySQL挂了

### 模拟现场，现场的3台DB gtid状态

* master host_2

dba:lc> show master status;
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| File                | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                                                                        |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| host_1.000002 |     2885 |              |                  | 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-16,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446362 |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)


* slave (candidate master) host_1

           Retrieved_Gtid_Set: ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:446353
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-16,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446353
                Auto_Position: 1

* etl (other slave) host_3

           Retrieved_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:4-16,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:446353-446356
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-16,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446356
                Auto_Position: 1



### 切换日志
masterha_master_switch --global_conf=/data/online/agent/MHA/conf/masterha_default.cnf --conf=/data/online/agent/MHA/conf/bak_mha_test.cnf  --dead_master_host=host_2  --dead_master_port=3306 --master_state=dead --interactive=0 --ignore_last_failover --ignore_binlog_server_error

Thu Nov  9 10:43:49 2017 - [info] MHA::MasterFailover version 0.56.
Thu Nov  9 10:43:49 2017 - [info] Starting master failover.
Thu Nov  9 10:43:49 2017 - [info]
Thu Nov  9 10:43:49 2017 - [info] * Phase 1: Configuration Check Phase..
Thu Nov  9 10:43:49 2017 - [info]
Thu Nov  9 10:43:50 2017 - [info] HealthCheck: SSH to host_2 is reachable.
Thu Nov  9 10:43:50 2017 - [info] Binlog server host_2 is reachable.
Thu Nov  9 10:43:50 2017 - [info] HealthCheck: SSH to host_1 is reachable.
Thu Nov  9 10:43:50 2017 - [info] Binlog server host_1 is reachable.
Thu Nov  9 10:43:50 2017 - [info] HealthCheck: SSH to host_3 is reachable.
Thu Nov  9 10:43:50 2017 - [info] Binlog server host_3 is reachable.
Thu Nov  9 10:43:51 2017 - [warning] SQL Thread is stopped(no error) on host_1(host_1:3306)
Thu Nov  9 10:43:51 2017 - [warning] SQL Thread is stopped(no error) on host_3(host_3:3306)
Thu Nov  9 10:43:51 2017 - [info] GTID failover mode = 1
Thu Nov  9 10:43:51 2017 - [info] Dead Servers:
Thu Nov  9 10:43:51 2017 - [info]   host_2(host_2:3306)
Thu Nov  9 10:43:51 2017 - [info] Checking master reachability via MySQL(double check)...
Thu Nov  9 10:43:51 2017 - [info]  ok.
Thu Nov  9 10:43:51 2017 - [info] Alive Servers:
Thu Nov  9 10:43:51 2017 - [info]   host_1(host_1:3306)
Thu Nov  9 10:43:51 2017 - [info]   host_3(host_3:3306)
Thu Nov  9 10:43:51 2017 - [info] Alive Slaves:
Thu Nov  9 10:43:51 2017 - [info]   host_1(host_1:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 10:43:51 2017 - [info]     GTID ON
Thu Nov  9 10:43:51 2017 - [info]     Replicating from host_2(host_2:3306)
Thu Nov  9 10:43:51 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Thu Nov  9 10:43:51 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 10:43:51 2017 - [info]     GTID ON
Thu Nov  9 10:43:51 2017 - [info]     Replicating from host_2(host_2:3306)
Thu Nov  9 10:43:51 2017 - [info]     Not candidate for the new Master (no_master is set)
Thu Nov  9 10:43:51 2017 - [info]  Starting SQL thread on host_1(host_1:3306) ..
Thu Nov  9 10:43:51 2017 - [info]   done.
Thu Nov  9 10:43:51 2017 - [info]  Starting SQL thread on host_3(host_3:3306) ..
Thu Nov  9 10:43:51 2017 - [info]   done.
Thu Nov  9 10:43:51 2017 - [info] Starting GTID based failover.
Thu Nov  9 10:43:51 2017 - [info]
Thu Nov  9 10:43:51 2017 - [info] ** Phase 1: Configuration Check Phase completed.
Thu Nov  9 10:43:51 2017 - [info]
Thu Nov  9 10:43:51 2017 - [info] * Phase 2: Dead Master Shutdown Phase..
Thu Nov  9 10:43:51 2017 - [info]
Thu Nov  9 10:43:51 2017 - [info] HealthCheck: SSH to host_2 is reachable.
Thu Nov  9 10:43:51 2017 - [info] Forcing shutdown so that applications never connect to the current master..
Thu Nov  9 10:43:51 2017 - [info] Executing master IP deactivation script:
Thu Nov  9 10:43:51 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --orig_master_host=host_2 --orig_master_ip=host_2 --orig_master_port=3306 --command=stopssh --ssh_user=root
Thu Nov  9 10:43:53 2017 - [info]  done.
Thu Nov  9 10:43:53 2017 - [warning] shutdown_script is not set. Skipping explicit shutting down of the dead master.
Thu Nov  9 10:43:53 2017 - [info] * Phase 2: Dead Master Shutdown Phase completed.
Thu Nov  9 10:43:53 2017 - [info]
Thu Nov  9 10:43:53 2017 - [info] * Phase 3: Master Recovery Phase..
Thu Nov  9 10:43:53 2017 - [info]
Thu Nov  9 10:43:53 2017 - [info] * Phase 3.1: Getting Latest Slaves Phase..
Thu Nov  9 10:43:53 2017 - [info]
Thu Nov  9 10:43:53 2017 - [info] The latest binary log file/position on all slaves is host_1.000002:1115
Thu Nov  9 10:43:53 2017 - [info] Retrieved Gtid Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:4-16,
Thu Nov  9 10:43:53 2017 - [info] Latest slaves (Slaves that received relay log files to the latest):
Thu Nov  9 10:43:53 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 10:43:53 2017 - [info]     GTID ON
Thu Nov  9 10:43:53 2017 - [info]     Replicating from host_2(host_2:3306)
Thu Nov  9 10:43:53 2017 - [info]     Not candidate for the new Master (no_master is set)
Thu Nov  9 10:43:53 2017 - [info] The oldest binary log file/position on all slaves is host_1.000002:230
Thu Nov  9 10:43:53 2017 - [info] Retrieved Gtid Set: ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:446353
Thu Nov  9 10:43:53 2017 - [info] Oldest slaves:
Thu Nov  9 10:43:53 2017 - [info]   host_1(host_1:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 10:43:53 2017 - [info]     GTID ON
Thu Nov  9 10:43:53 2017 - [info]     Replicating from host_2(host_2:3306)
Thu Nov  9 10:43:53 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Thu Nov  9 10:43:53 2017 - [info]
Thu Nov  9 10:43:53 2017 - [info] * Phase 3.3: Determining New Master Phase..
Thu Nov  9 10:43:53 2017 - [info]
Thu Nov  9 10:43:53 2017 - [info] Searching new master from slaves..
Thu Nov  9 10:43:53 2017 - [info]  Candidate masters from the configuration file:
Thu Nov  9 10:43:53 2017 - [info]   host_1(host_1:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 10:43:53 2017 - [info]     GTID ON
Thu Nov  9 10:43:53 2017 - [info]     Replicating from host_2(host_2:3306)
Thu Nov  9 10:43:53 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Thu Nov  9 10:43:53 2017 - [info]  Non-candidate masters:
Thu Nov  9 10:43:53 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 10:43:53 2017 - [info]     GTID ON
Thu Nov  9 10:43:53 2017 - [info]     Replicating from host_2(host_2:3306)
Thu Nov  9 10:43:53 2017 - [info]     Not candidate for the new Master (no_master is set)
Thu Nov  9 10:43:53 2017 - [info]  Searching from candidate_master slaves which have received the latest relay log events..
Thu Nov  9 10:43:53 2017 - [info]   Not found.
Thu Nov  9 10:43:53 2017 - [info]  Searching from all candidate_master slaves..
Thu Nov  9 10:43:53 2017 - [info] New master is host_1(host_1:3306)
Thu Nov  9 10:43:53 2017 - [info] Starting master failover..
Thu Nov  9 10:43:53 2017 - [info]
Thu Nov  9 10:43:53 2017 - [info]
Thu Nov  9 10:43:53 2017 - [info] * Phase 3.3: New Master Recovery Phase..
Thu Nov  9 10:43:53 2017 - [info]
Thu Nov  9 10:43:53 2017 - [info]  Waiting all logs to be applied..
Thu Nov  9 10:43:53 2017 - [info]   done.
Thu Nov  9 10:43:53 2017 - [info]  Replicating from the latest slave host_3(host_3:3306) and waiting to apply..
Thu Nov  9 10:43:53 2017 - [info]  Waiting all logs to be applied on the latest slave..
Thu Nov  9 10:43:53 2017 - [info]  Resetting slave host_1(host_1:3306) and starting replication from the new master host_3(host_3:3306)..
Thu Nov  9 10:43:53 2017 - [info]  Executed CHANGE MASTER.
Thu Nov  9 10:43:54 2017 - [info]  Slave started.
Thu Nov  9 10:43:54 2017 - [info]  Waiting to execute all relay logs on host_1(host_1:3306)..
Thu Nov  9 10:43:54 2017 - [info]  master_pos_wait(host_3.000049:18041) completed on host_1(host_1:3306). Executed 0 events.
Thu Nov  9 10:43:54 2017 - [info]   done.
Thu Nov  9 10:43:54 2017 - [info]   done.
Thu Nov  9 10:43:54 2017 - [info] -- Saving binlog from host host_2 started, pid: 150294
Thu Nov  9 10:43:54 2017 - [info] -- Saving binlog from host host_1 started, pid: 150295
Thu Nov  9 10:43:54 2017 - [info] -- Saving binlog from host host_3 started, pid: 150297
Thu Nov  9 10:43:54 2017 - [info]
Thu Nov  9 10:43:54 2017 - [info] Log messages from host_1 ...
Thu Nov  9 10:43:54 2017 - [info]
Thu Nov  9 10:43:54 2017 - [info] Fetching binary logs from binlog server host_1..
Thu Nov  9 10:43:54 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=host_1.000002  --start_pos=1115 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog2_20171109104349.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Thu Nov  9 10:43:54 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Thu Nov  9 10:43:54 2017 - [info] End of log messages from host_1.
Thu Nov  9 10:43:54 2017 - [warning] Got error from host_1.
Thu Nov  9 10:43:54 2017 - [info]
Thu Nov  9 10:43:54 2017 - [info] Log messages from host_3 ...
Thu Nov  9 10:43:54 2017 - [info]
Thu Nov  9 10:43:54 2017 - [info] Fetching binary logs from binlog server host_3..
Thu Nov  9 10:43:54 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=host_1.000002  --start_pos=1115 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog3_20171109104349.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Thu Nov  9 10:43:54 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Thu Nov  9 10:43:54 2017 - [info] End of log messages from host_3.
Thu Nov  9 10:43:54 2017 - [warning] Got error from host_3.
Thu Nov  9 10:43:55 2017 - [info]
Thu Nov  9 10:43:55 2017 - [info] Log messages from host_2 ...
Thu Nov  9 10:43:55 2017 - [info]
Thu Nov  9 10:43:54 2017 - [info] Fetching binary logs from binlog server host_2..
Thu Nov  9 10:43:54 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=host_1.000002  --start_pos=1115 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog1_20171109104349.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Thu Nov  9 10:43:55 2017 - [info] scp from root@host_2:/var/log/masterha/mha_test/saved_binlog_binlog1_20171109104349.binlog to local:/var/log/masterha/mha_test/saved_binlog_host_2_binlog1_20171109104349.binlog succeeded.
Thu Nov  9 10:43:55 2017 - [info] End of log messages from host_2.
Thu Nov  9 10:43:55 2017 - [info] Saved mysqlbinlog size from host_2 is 6047 bytes.
Thu Nov  9 10:43:55 2017 - [info] Applying differential binlog /var/log/masterha/mha_test/saved_binlog_host_2_binlog1_20171109104349.binlog ..
Thu Nov  9 10:43:55 2017 - [info] Differential log apply from binlog server succeeded.
Thu Nov  9 10:43:55 2017 - [info] Getting new master's binlog name and position..
Thu Nov  9 10:43:55 2017 - [info]  tjtx-126-164.000053:3624
Thu Nov  9 10:43:55 2017 - [info]  All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST='host_1', MASTER_PORT=3306, MASTER_AUTO_POSITION=1, MASTER_USER='repl', MASTER_PASSWORD='xxx';
Thu Nov  9 10:43:55 2017 - [info] Master Recovery succeeded. File:Pos:Exec_Gtid_Set: tjtx-126-164.000053, 3624, 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-16,
Thu Nov  9 10:43:55 2017 - [info] Executing master IP activate script:
Thu Nov  9 10:43:55 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --command=start --ssh_user=root --orig_master_host=host_2 --orig_master_ip=host_2 --orig_master_port=3306 --new_master_host=host_1 --new_master_ip=host_1 --new_master_port=3306 --new_master_user='xxx' --new_master_password='xxx'
Thu Nov  9 10:43:57 2017 - [info]  OK.
Thu Nov  9 10:43:57 2017 - [info] Setting read_only=0 on host_1(host_1:3306)..
Thu Nov  9 10:43:57 2017 - [info]  ok.
Thu Nov  9 10:43:57 2017 - [info] ** Finished master recovery successfully.
Thu Nov  9 10:43:57 2017 - [info] * Phase 3: Master Recovery Phase completed.
Thu Nov  9 10:43:57 2017 - [info]
Thu Nov  9 10:43:57 2017 - [info] * Phase 4: Slaves Recovery Phase..
Thu Nov  9 10:43:57 2017 - [info]
Thu Nov  9 10:43:57 2017 - [info]
Thu Nov  9 10:43:57 2017 - [info] * Phase 4.1: Starting Slaves in parallel..
Thu Nov  9 10:43:57 2017 - [info]
Thu Nov  9 10:43:57 2017 - [info] -- Slave recovery on host host_3(host_3:3306) started, pid: 155162. Check tmp log /var/log/masterha/mha_test/host_3_3306_20171109104349.log if it takes time..
Thu Nov  9 10:43:58 2017 - [info]
Thu Nov  9 10:43:58 2017 - [info] Log messages from host_3 ...
Thu Nov  9 10:43:58 2017 - [info]
Thu Nov  9 10:43:57 2017 - [info]  Resetting slave host_3(host_3:3306) and starting replication from the new master host_1(host_1:3306)..
Thu Nov  9 10:43:57 2017 - [info]  Executed CHANGE MASTER.
Thu Nov  9 10:43:58 2017 - [info]  Slave started.
Thu Nov  9 10:43:58 2017 - [info]  gtid_wait(0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-16,
Thu Nov  9 10:43:58 2017 - [info] End of log messages from host_3.
Thu Nov  9 10:43:58 2017 - [info] -- Slave on host host_3(host_3:3306) started.
Thu Nov  9 10:43:58 2017 - [info] All new slave servers recovered successfully.
Thu Nov  9 10:43:58 2017 - [info]
Thu Nov  9 10:43:58 2017 - [info] * Phase 5: New master cleanup phase..
Thu Nov  9 10:43:58 2017 - [info]
Thu Nov  9 10:43:58 2017 - [info] Resetting slave info on the new master..
Thu Nov  9 10:43:58 2017 - [info]  host_1: Resetting slave info succeeded.
Thu Nov  9 10:43:58 2017 - [info] Master failover to host_1(host_1:3306) completed successfully.
Thu Nov  9 10:43:58 2017 - [info]
Thu Nov  9 10:43:58 2017 - [info] Sending mail..

• 1.2.2 当master的所有日志已经传递到1个etl，这时候master 上的MySQL挂了

### 模拟现场，现场的3台DB gtid状态

* master host_1

dba:lc> show master status;
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| File                | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                                                                        |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| tjtx-126-164.000053 |     5229 |              |                  | 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-21,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446362 |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)



* slave (candidate master) host_2

           Retrieved_Gtid_Set:
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-16,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446362
                Auto_Position: 1

* etl (other slave) host_3

           Retrieved_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:17-21,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:446357-446362
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-21,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446362
                Auto_Position: 1


### 切换日志

masterha_master_switch --global_conf=/data/online/agent/MHA/conf/masterha_default.cnf --conf=/data/online/agent/MHA/conf/bak_mha_test.cnf  --dead_master_host=host_1  --dead_master_port=3306 --master_state=dead --interactive=0 --ignore_last_failover --ignore_binlog_server_error

Thu Nov  9 10:59:14 2017 - [info] MHA::MasterFailover version 0.56.
Thu Nov  9 10:59:14 2017 - [info] Starting master failover.
Thu Nov  9 10:59:14 2017 - [info]
Thu Nov  9 10:59:14 2017 - [info] * Phase 1: Configuration Check Phase..
Thu Nov  9 10:59:14 2017 - [info]
Thu Nov  9 10:59:15 2017 - [info] HealthCheck: SSH to host_2 is reachable.
Thu Nov  9 10:59:15 2017 - [info] Binlog server host_2 is reachable.
Thu Nov  9 10:59:15 2017 - [info] HealthCheck: SSH to host_1 is reachable.
Thu Nov  9 10:59:15 2017 - [info] Binlog server host_1 is reachable.
Thu Nov  9 10:59:15 2017 - [info] HealthCheck: SSH to host_3 is reachable.
Thu Nov  9 10:59:16 2017 - [info] Binlog server host_3 is reachable.
Thu Nov  9 10:59:16 2017 - [warning] SQL Thread is stopped(no error) on host_2(host_2:3306)
Thu Nov  9 10:59:16 2017 - [info] GTID failover mode = 1
Thu Nov  9 10:59:16 2017 - [info] Dead Servers:
Thu Nov  9 10:59:16 2017 - [info]   host_1(host_1:3306)
Thu Nov  9 10:59:16 2017 - [info] Checking master reachability via MySQL(double check)...
Thu Nov  9 10:59:16 2017 - [info]  ok.
Thu Nov  9 10:59:16 2017 - [info] Alive Servers:
Thu Nov  9 10:59:16 2017 - [info]   host_2(host_2:3306)
Thu Nov  9 10:59:16 2017 - [info]   host_3(host_3:3306)
Thu Nov  9 10:59:16 2017 - [info] Alive Slaves:
Thu Nov  9 10:59:16 2017 - [info]   host_2(host_2:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 10:59:16 2017 - [info]     GTID ON
Thu Nov  9 10:59:16 2017 - [info]     Replicating from host_1(host_1:3306)
Thu Nov  9 10:59:16 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Thu Nov  9 10:59:16 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 10:59:16 2017 - [info]     GTID ON
Thu Nov  9 10:59:16 2017 - [info]     Replicating from host_1(host_1:3306)
Thu Nov  9 10:59:16 2017 - [info]     Not candidate for the new Master (no_master is set)
Thu Nov  9 10:59:16 2017 - [info]  Starting SQL thread on host_2(host_2:3306) ..
Thu Nov  9 10:59:16 2017 - [info]   done.
Thu Nov  9 10:59:16 2017 - [info] Starting GTID based failover.
Thu Nov  9 10:59:16 2017 - [info]
Thu Nov  9 10:59:16 2017 - [info] ** Phase 1: Configuration Check Phase completed.
Thu Nov  9 10:59:16 2017 - [info]
Thu Nov  9 10:59:16 2017 - [info] * Phase 2: Dead Master Shutdown Phase..
Thu Nov  9 10:59:16 2017 - [info]
Thu Nov  9 10:59:16 2017 - [info] HealthCheck: SSH to host_1 is reachable.
Thu Nov  9 10:59:16 2017 - [info] Forcing shutdown so that applications never connect to the current master..
Thu Nov  9 10:59:16 2017 - [info] Executing master IP deactivation script:
Thu Nov  9 10:59:16 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --orig_master_host=host_1 --orig_master_ip=host_1 --orig_master_port=3306 --command=stopssh --ssh_user=root
Thu Nov  9 10:59:20 2017 - [info]  done.
Thu Nov  9 10:59:20 2017 - [warning] shutdown_script is not set. Skipping explicit shutting down of the dead master.
Thu Nov  9 10:59:20 2017 - [info] * Phase 2: Dead Master Shutdown Phase completed.
Thu Nov  9 10:59:20 2017 - [info]
Thu Nov  9 10:59:20 2017 - [info] * Phase 3: Master Recovery Phase..
Thu Nov  9 10:59:20 2017 - [info]
Thu Nov  9 10:59:20 2017 - [info] * Phase 3.1: Getting Latest Slaves Phase..
Thu Nov  9 10:59:20 2017 - [info]
Thu Nov  9 10:59:20 2017 - [info] The latest binary log file/position on all slaves is tjtx-126-164.000053:5229
Thu Nov  9 10:59:20 2017 - [info] Retrieved Gtid Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:17-21,
Thu Nov  9 10:59:20 2017 - [info] Latest slaves (Slaves that received relay log files to the latest):
Thu Nov  9 10:59:20 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 10:59:20 2017 - [info]     GTID ON
Thu Nov  9 10:59:20 2017 - [info]     Replicating from host_1(host_1:3306)
Thu Nov  9 10:59:20 2017 - [info]     Not candidate for the new Master (no_master is set)
Thu Nov  9 10:59:20 2017 - [info] The oldest binary log file/position on all slaves is tjtx-126-164.000053:3624
Thu Nov  9 10:59:20 2017 - [info] Oldest slaves:
Thu Nov  9 10:59:20 2017 - [info]   host_2(host_2:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 10:59:20 2017 - [info]     GTID ON
Thu Nov  9 10:59:20 2017 - [info]     Replicating from host_1(host_1:3306)
Thu Nov  9 10:59:20 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Thu Nov  9 10:59:20 2017 - [info]
Thu Nov  9 10:59:20 2017 - [info] * Phase 3.3: Determining New Master Phase..
Thu Nov  9 10:59:20 2017 - [info]
Thu Nov  9 10:59:20 2017 - [info] Searching new master from slaves..
Thu Nov  9 10:59:20 2017 - [info]  Candidate masters from the configuration file:
Thu Nov  9 10:59:20 2017 - [info]   host_2(host_2:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 10:59:20 2017 - [info]     GTID ON
Thu Nov  9 10:59:20 2017 - [info]     Replicating from host_1(host_1:3306)
Thu Nov  9 10:59:20 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Thu Nov  9 10:59:20 2017 - [info]  Non-candidate masters:
Thu Nov  9 10:59:20 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 10:59:20 2017 - [info]     GTID ON
Thu Nov  9 10:59:20 2017 - [info]     Replicating from host_1(host_1:3306)
Thu Nov  9 10:59:20 2017 - [info]     Not candidate for the new Master (no_master is set)
Thu Nov  9 10:59:20 2017 - [info]  Searching from candidate_master slaves which have received the latest relay log events..
Thu Nov  9 10:59:20 2017 - [info]   Not found.
Thu Nov  9 10:59:20 2017 - [info]  Searching from all candidate_master slaves..
Thu Nov  9 10:59:20 2017 - [info] New master is host_2(host_2:3306)
Thu Nov  9 10:59:20 2017 - [info] Starting master failover..
Thu Nov  9 10:59:20 2017 - [info]
Thu Nov  9 10:59:20 2017 - [info]
Thu Nov  9 10:59:20 2017 - [info] * Phase 3.3: New Master Recovery Phase..
Thu Nov  9 10:59:20 2017 - [info]
Thu Nov  9 10:59:20 2017 - [info]  Waiting all logs to be applied..
Thu Nov  9 10:59:20 2017 - [info]   done.
Thu Nov  9 10:59:20 2017 - [info]  Replicating from the latest slave host_3(host_3:3306) and waiting to apply..
Thu Nov  9 10:59:20 2017 - [info]  Waiting all logs to be applied on the latest slave..
Thu Nov  9 10:59:20 2017 - [info]  Resetting slave host_2(host_2:3306) and starting replication from the new master host_3(host_3:3306)..
Thu Nov  9 10:59:20 2017 - [info]  Executed CHANGE MASTER.
Thu Nov  9 10:59:21 2017 - [info]  Slave started.
Thu Nov  9 10:59:21 2017 - [info]  Waiting to execute all relay logs on host_2(host_2:3306)..
Thu Nov  9 10:59:21 2017 - [info]  master_pos_wait(host_3.000049:22035) completed on host_2(host_2:3306). Executed 0 events.
Thu Nov  9 10:59:21 2017 - [info]   done.
Thu Nov  9 10:59:21 2017 - [info]   done.
Thu Nov  9 10:59:21 2017 - [info] -- Saving binlog from host host_2 started, pid: 184482
Thu Nov  9 10:59:21 2017 - [info] -- Saving binlog from host host_1 started, pid: 184483
Thu Nov  9 10:59:21 2017 - [info] -- Saving binlog from host host_3 started, pid: 184487
Thu Nov  9 10:59:21 2017 - [info]
Thu Nov  9 10:59:21 2017 - [info] Log messages from host_2 ...
Thu Nov  9 10:59:21 2017 - [info]
Thu Nov  9 10:59:21 2017 - [info] Fetching binary logs from binlog server host_2..
Thu Nov  9 10:59:21 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=tjtx-126-164.000053  --start_pos=5229 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog1_20171109105914.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Thu Nov  9 10:59:21 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Thu Nov  9 10:59:21 2017 - [info] End of log messages from host_2.
Thu Nov  9 10:59:21 2017 - [warning] Got error from host_2.
Thu Nov  9 10:59:21 2017 - [info]
Thu Nov  9 10:59:21 2017 - [info] Log messages from host_3 ...
Thu Nov  9 10:59:21 2017 - [info]
Thu Nov  9 10:59:21 2017 - [info] Fetching binary logs from binlog server host_3..
Thu Nov  9 10:59:21 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=tjtx-126-164.000053  --start_pos=5229 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog3_20171109105914.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Thu Nov  9 10:59:21 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Thu Nov  9 10:59:21 2017 - [info] End of log messages from host_3.
Thu Nov  9 10:59:21 2017 - [warning] Got error from host_3.
Thu Nov  9 10:59:22 2017 - [info]
Thu Nov  9 10:59:22 2017 - [info] Log messages from host_1 ...
Thu Nov  9 10:59:22 2017 - [info]
Thu Nov  9 10:59:21 2017 - [info] Fetching binary logs from binlog server host_1..
Thu Nov  9 10:59:21 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=tjtx-126-164.000053  --start_pos=5229 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog2_20171109105914.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Thu Nov  9 10:59:22 2017 - [info] scp from root@host_1:/var/log/masterha/mha_test/saved_binlog_binlog2_20171109105914.binlog to local:/var/log/masterha/mha_test/saved_binlog_host_1_binlog2_20171109105914.binlog succeeded.
Thu Nov  9 10:59:22 2017 - [info] End of log messages from host_1.
Thu Nov  9 10:59:22 2017 - [info] Saved mysqlbinlog size from host_1 is 800 bytes.
Thu Nov  9 10:59:22 2017 - [info] Applying differential binlog /var/log/masterha/mha_test/saved_binlog_host_1_binlog2_20171109105914.binlog ..
Thu Nov  9 10:59:22 2017 - [info] Differential log apply from binlog server succeeded.
Thu Nov  9 10:59:22 2017 - [info] Getting new master's binlog name and position..
Thu Nov  9 10:59:22 2017 - [info]  host_1.000003:1680
Thu Nov  9 10:59:22 2017 - [info]  All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST='host_2', MASTER_PORT=3306, MASTER_AUTO_POSITION=1, MASTER_USER='repl', MASTER_PASSWORD='xxx';
Thu Nov  9 10:59:22 2017 - [info] Master Recovery succeeded. File:Pos:Exec_Gtid_Set: host_1.000003, 1680, 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-21,
Thu Nov  9 10:59:22 2017 - [info] Executing master IP activate script:
Thu Nov  9 10:59:22 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --command=start --ssh_user=root --orig_master_host=host_1 --orig_master_ip=host_1 --orig_master_port=3306 --new_master_host=host_2 --new_master_ip=host_2 --new_master_port=3306 --new_master_user='xxx' --new_master_password='xxx'
Thu Nov  9 10:59:24 2017 - [info]  OK.
Thu Nov  9 10:59:24 2017 - [info] Setting read_only=0 on host_2(host_2:3306)..
Thu Nov  9 10:59:24 2017 - [info]  ok.
Thu Nov  9 10:59:24 2017 - [info] ** Finished master recovery successfully.
Thu Nov  9 10:59:24 2017 - [info] * Phase 3: Master Recovery Phase completed.
Thu Nov  9 10:59:24 2017 - [info]
Thu Nov  9 10:59:24 2017 - [info] * Phase 4: Slaves Recovery Phase..
Thu Nov  9 10:59:24 2017 - [info]
Thu Nov  9 10:59:24 2017 - [info]
Thu Nov  9 10:59:24 2017 - [info] * Phase 4.1: Starting Slaves in parallel..
Thu Nov  9 10:59:24 2017 - [info]
Thu Nov  9 10:59:24 2017 - [info] -- Slave recovery on host host_3(host_3:3306) started, pid: 189393. Check tmp log /var/log/masterha/mha_test/host_3_3306_20171109105914.log if it takes time..
Thu Nov  9 10:59:25 2017 - [info]
Thu Nov  9 10:59:25 2017 - [info] Log messages from host_3 ...
Thu Nov  9 10:59:25 2017 - [info]
Thu Nov  9 10:59:24 2017 - [info]  Resetting slave host_3(host_3:3306) and starting replication from the new master host_2(host_2:3306)..
Thu Nov  9 10:59:24 2017 - [info]  Executed CHANGE MASTER.
Thu Nov  9 10:59:25 2017 - [info]  Slave started.
Thu Nov  9 10:59:25 2017 - [info]  gtid_wait(0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-21,
Thu Nov  9 10:59:25 2017 - [info] End of log messages from host_3.
Thu Nov  9 10:59:25 2017 - [info] -- Slave on host host_3(host_3:3306) started.
Thu Nov  9 10:59:25 2017 - [info] All new slave servers recovered successfully.
Thu Nov  9 10:59:25 2017 - [info]
Thu Nov  9 10:59:25 2017 - [info] * Phase 5: New master cleanup phase..
Thu Nov  9 10:59:25 2017 - [info]
Thu Nov  9 10:59:25 2017 - [info] Resetting slave info on the new master..
Thu Nov  9 10:59:25 2017 - [info]  host_2: Resetting slave info succeeded.
Thu Nov  9 10:59:25 2017 - [info] Master failover to host_2(host_2:3306) completed successfully.
Thu Nov  9 10:59:25 2017 - [info]
Thu Nov  9 10:59:25 2017 - [info] Sending mail..

1.3 slave(候选master)的日志是最新的，比etl要多

• 1.3.1 当master的部分日志还没传递两个slave，这时候master 上的MySQL挂了

masterha_master_switch --global_conf=/data/online/agent/MHA/conf/masterha_default.cnf --conf=/data/online/agent/MHA/conf/bak_mha_test.cnf  --dead_master_host=host_1  --dead_master_port=3306 --master_state=dead --interactive=0 --ignore_last_failover --ignore_binlog_server_error


Tue Nov  7 17:11:29 2017 - [info] MHA::MasterFailover version 0.56.
Tue Nov  7 17:11:29 2017 - [info] Starting master failover.
Tue Nov  7 17:11:29 2017 - [info]
Tue Nov  7 17:11:29 2017 - [info] * Phase 1: Configuration Check Phase..
Tue Nov  7 17:11:29 2017 - [info]
Tue Nov  7 17:11:29 2017 - [info] HealthCheck: SSH to host_2 is reachable.
Tue Nov  7 17:11:29 2017 - [info] Binlog server host_2 is reachable.
Tue Nov  7 17:11:29 2017 - [info] HealthCheck: SSH to host_1 is reachable.
Tue Nov  7 17:11:30 2017 - [info] Binlog server host_1 is reachable.
Tue Nov  7 17:11:30 2017 - [info] HealthCheck: SSH to host_3 is reachable.
Tue Nov  7 17:11:30 2017 - [info] Binlog server host_3 is reachable.
Tue Nov  7 17:11:30 2017 - [warning] SQL Thread is stopped(no error) on host_2(host_2:3306)
Tue Nov  7 17:11:30 2017 - [warning] SQL Thread is stopped(no error) on host_3(host_3:3306)
Tue Nov  7 17:11:30 2017 - [info] GTID failover mode = 1
Tue Nov  7 17:11:30 2017 - [info] Dead Servers:
Tue Nov  7 17:11:30 2017 - [info]   host_1(host_1:3306)
Tue Nov  7 17:11:30 2017 - [info] Checking master reachability via MySQL(double check)...
Tue Nov  7 17:11:30 2017 - [info]  ok.
Tue Nov  7 17:11:30 2017 - [info] Alive Servers:
Tue Nov  7 17:11:30 2017 - [info]   host_2(host_2:3306)
Tue Nov  7 17:11:30 2017 - [info]   host_3(host_3:3306)
Tue Nov  7 17:11:30 2017 - [info] Alive Slaves:
Tue Nov  7 17:11:30 2017 - [info]   host_2(host_2:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Tue Nov  7 17:11:30 2017 - [info]     GTID ON
Tue Nov  7 17:11:30 2017 - [info]     Replicating from host_1(host_1:3306)
Tue Nov  7 17:11:30 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Tue Nov  7 17:11:30 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Tue Nov  7 17:11:30 2017 - [info]     GTID ON
Tue Nov  7 17:11:30 2017 - [info]     Replicating from host_1(host_1:3306)
Tue Nov  7 17:11:30 2017 - [info]     Not candidate for the new Master (no_master is set)
Tue Nov  7 17:11:30 2017 - [info]  Starting SQL thread on host_2(host_2:3306) ..
Tue Nov  7 17:11:30 2017 - [info]   done.
Tue Nov  7 17:11:30 2017 - [info]  Starting SQL thread on host_3(host_3:3306) ..
Tue Nov  7 17:11:30 2017 - [info]   done.
Tue Nov  7 17:11:30 2017 - [info] Starting GTID based failover.
Tue Nov  7 17:11:30 2017 - [info]
Tue Nov  7 17:11:30 2017 - [info] ** Phase 1: Configuration Check Phase completed.
Tue Nov  7 17:11:30 2017 - [info]
Tue Nov  7 17:11:30 2017 - [info] * Phase 2: Dead Master Shutdown Phase..
Tue Nov  7 17:11:30 2017 - [info]
Tue Nov  7 17:11:30 2017 - [info] HealthCheck: SSH to host_1 is reachable.
Tue Nov  7 17:11:31 2017 - [info] Forcing shutdown so that applications never connect to the current master..
Tue Nov  7 17:11:31 2017 - [info] Executing master IP deactivation script:
Tue Nov  7 17:11:31 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --orig_master_host=host_1 --orig_master_ip=host_1 --orig_master_port=3306 --command=stopssh --ssh_user=root
Tue Nov  7 17:11:33 2017 - [info]  done.
Tue Nov  7 17:11:33 2017 - [warning] shutdown_script is not set. Skipping explicit shutting down of the dead master.
Tue Nov  7 17:11:33 2017 - [info] * Phase 2: Dead Master Shutdown Phase completed.
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info] * Phase 3: Master Recovery Phase..
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info] * Phase 3.1: Getting Latest Slaves Phase..
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info] The latest binary log file/position on all slaves is tjtx-126-164.000051:13508
Tue Nov  7 17:11:33 2017 - [info] Retrieved Gtid Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:3-8
Tue Nov  7 17:11:33 2017 - [info] Latest slaves (Slaves that received relay log files to the latest):
Tue Nov  7 17:11:33 2017 - [info]   host_2(host_2:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Tue Nov  7 17:11:33 2017 - [info]     GTID ON
Tue Nov  7 17:11:33 2017 - [info]     Replicating from host_1(host_1:3306)
Tue Nov  7 17:11:33 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Tue Nov  7 17:11:33 2017 - [info] The oldest binary log file/position on all slaves is tjtx-126-164.000051:11918
Tue Nov  7 17:11:33 2017 - [info] Retrieved Gtid Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:2-3,
Tue Nov  7 17:11:33 2017 - [info] Oldest slaves:
Tue Nov  7 17:11:33 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Tue Nov  7 17:11:33 2017 - [info]     GTID ON
Tue Nov  7 17:11:33 2017 - [info]     Replicating from host_1(host_1:3306)
Tue Nov  7 17:11:33 2017 - [info]     Not candidate for the new Master (no_master is set)
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info] * Phase 3.3: Determining New Master Phase..
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info] Searching new master from slaves..
Tue Nov  7 17:11:33 2017 - [info]  Candidate masters from the configuration file:
Tue Nov  7 17:11:33 2017 - [info]   host_2(host_2:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Tue Nov  7 17:11:33 2017 - [info]     GTID ON
Tue Nov  7 17:11:33 2017 - [info]     Replicating from host_1(host_1:3306)
Tue Nov  7 17:11:33 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Tue Nov  7 17:11:33 2017 - [info]  Non-candidate masters:
Tue Nov  7 17:11:33 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Tue Nov  7 17:11:33 2017 - [info]     GTID ON
Tue Nov  7 17:11:33 2017 - [info]     Replicating from host_1(host_1:3306)
Tue Nov  7 17:11:33 2017 - [info]     Not candidate for the new Master (no_master is set)
Tue Nov  7 17:11:33 2017 - [info]  Searching from candidate_master slaves which have received the latest relay log events..
Tue Nov  7 17:11:33 2017 - [info] New master is host_2(host_2:3306)
Tue Nov  7 17:11:33 2017 - [info] Starting master failover..
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info] * Phase 3.3: New Master Recovery Phase..
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info]  Waiting all logs to be applied..
Tue Nov  7 17:11:33 2017 - [info]   done.
Tue Nov  7 17:11:33 2017 - [info] -- Saving binlog from host host_2 started, pid: 54677
Tue Nov  7 17:11:33 2017 - [info] -- Saving binlog from host host_1 started, pid: 54681
Tue Nov  7 17:11:33 2017 - [info] -- Saving binlog from host host_3 started, pid: 54683
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info] Log messages from host_3 ...
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info] Fetching binary logs from binlog server host_3..
Tue Nov  7 17:11:33 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=tjtx-126-164.000051  --start_pos=13508 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog3_20171107171129.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Tue Nov  7 17:11:33 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Tue Nov  7 17:11:33 2017 - [info] End of log messages from host_3.
Tue Nov  7 17:11:33 2017 - [warning] Got error from host_3.
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info] Log messages from host_2 ...
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info] Fetching binary logs from binlog server host_2..
Tue Nov  7 17:11:33 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=tjtx-126-164.000051  --start_pos=13508 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog1_20171107171129.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Tue Nov  7 17:11:33 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Tue Nov  7 17:11:33 2017 - [info] End of log messages from host_2.
Tue Nov  7 17:11:33 2017 - [warning] Got error from host_2.
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info] Log messages from host_1 ...
Tue Nov  7 17:11:33 2017 - [info]
Tue Nov  7 17:11:33 2017 - [info] Fetching binary logs from binlog server host_1..
Tue Nov  7 17:11:33 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=tjtx-126-164.000051  --start_pos=13508 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog2_20171107171129.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Tue Nov  7 17:11:33 2017 - [info] scp from root@host_1:/var/log/masterha/mha_test/saved_binlog_binlog2_20171107171129.binlog to local:/var/log/masterha/mha_test/saved_binlog_host_1_binlog2_20171107171129.binlog succeeded.
Tue Nov  7 17:11:33 2017 - [info] End of log messages from host_1.
Tue Nov  7 17:11:33 2017 - [info] Saved mysqlbinlog size from host_1 is 8578 bytes.
Tue Nov  7 17:11:33 2017 - [info] Applying differential binlog /var/log/masterha/mha_test/saved_binlog_host_1_binlog2_20171107171129.binlog ..
Tue Nov  7 17:11:33 2017 - [info] Differential log apply from binlog server succeeded.
Tue Nov  7 17:11:33 2017 - [info] Getting new master's binlog name and position..
Tue Nov  7 17:11:33 2017 - [info]  host_1.000001:5048
Tue Nov  7 17:11:33 2017 - [info]  All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST='host_2', MASTER_PORT=3306, MASTER_AUTO_POSITION=1, MASTER_USER='repl', MASTER_PASSWORD='xxx';
Tue Nov  7 17:11:33 2017 - [info] Master Recovery succeeded. File:Pos:Exec_Gtid_Set: host_1.000001, 5048, 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-16,
Tue Nov  7 17:11:33 2017 - [info] Executing master IP activate script:
Tue Nov  7 17:11:33 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --command=start --ssh_user=root --orig_master_host=host_1 --orig_master_ip=host_1 --orig_master_port=3306 --new_master_host=host_2 --new_master_ip=host_2 --new_master_port=3306 --new_master_user='xxx' --new_master_password='xxx'
Tue Nov  7 17:11:36 2017 - [info]  OK.
Tue Nov  7 17:11:36 2017 - [info] Setting read_only=0 on host_2(host_2:3306)..
Tue Nov  7 17:11:36 2017 - [info]  ok.
Tue Nov  7 17:11:36 2017 - [info] ** Finished master recovery successfully.
Tue Nov  7 17:11:36 2017 - [info] * Phase 3: Master Recovery Phase completed.
Tue Nov  7 17:11:36 2017 - [info]
Tue Nov  7 17:11:36 2017 - [info] * Phase 4: Slaves Recovery Phase..
Tue Nov  7 17:11:36 2017 - [info]
Tue Nov  7 17:11:36 2017 - [info]
Tue Nov  7 17:11:36 2017 - [info] * Phase 4.1: Starting Slaves in parallel..
Tue Nov  7 17:11:36 2017 - [info]
Tue Nov  7 17:11:36 2017 - [info] -- Slave recovery on host host_3(host_3:3306) started, pid: 58422. Check tmp log /var/log/masterha/mha_test/host_3_3306_20171107171129.log if it takes time..
Tue Nov  7 17:11:37 2017 - [info]
Tue Nov  7 17:11:37 2017 - [info] Log messages from host_3 ...
Tue Nov  7 17:11:37 2017 - [info]
Tue Nov  7 17:11:36 2017 - [info]  Resetting slave host_3(host_3:3306) and starting replication from the new master host_2(host_2:3306)..
Tue Nov  7 17:11:36 2017 - [info]  Executed CHANGE MASTER.
Tue Nov  7 17:11:37 2017 - [info]  Slave started.
Tue Nov  7 17:11:37 2017 - [info]  gtid_wait(0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-16,
Tue Nov  7 17:11:37 2017 - [info] End of log messages from host_3.
Tue Nov  7 17:11:37 2017 - [info] -- Slave on host host_3(host_3:3306) started.
Tue Nov  7 17:11:37 2017 - [info] All new slave servers recovered successfully.
Tue Nov  7 17:11:37 2017 - [info]
Tue Nov  7 17:11:37 2017 - [info] * Phase 5: New master cleanup phase..
Tue Nov  7 17:11:37 2017 - [info]
Tue Nov  7 17:11:37 2017 - [info] Resetting slave info on the new master..
Tue Nov  7 17:11:37 2017 - [info]  host_2: Resetting slave info succeeded.
Tue Nov  7 17:11:37 2017 - [info] Master failover to host_2(host_2:3306) completed successfully.
Tue Nov  7 17:11:37 2017 - [info]
Tue Nov  7 17:11:37 2017 - [info] Sending mail..

• 1.3.2 当master的所有日志已经传递slave，这时候master 上的MySQL挂了

masterha_master_switch --global_conf=/data/online/agent/MHA/conf/masterha_default.cnf --conf=/data/online/agent/MHA/conf/bak_mha_test.cnf  --dead_master_host=host_2  --dead_master_port=3306 --master_state=dead --interactive=0 --ignore_last_failover --ignore_binlog_server_error


Tue Nov  7 15:56:11 2017 - [info] MHA::MasterFailover version 0.56.
Tue Nov  7 15:56:11 2017 - [info] Starting master failover.
Tue Nov  7 15:56:11 2017 - [info]
Tue Nov  7 15:56:11 2017 - [info] * Phase 1: Configuration Check Phase..
Tue Nov  7 15:56:11 2017 - [info]
Tue Nov  7 15:56:11 2017 - [info] HealthCheck: SSH to host_2 is reachable.
Tue Nov  7 15:56:12 2017 - [info] Binlog server host_2 is reachable.
Tue Nov  7 15:56:12 2017 - [info] HealthCheck: SSH to host_1 is reachable.
Tue Nov  7 15:56:12 2017 - [info] Binlog server host_1 is reachable.
Tue Nov  7 15:56:12 2017 - [info] HealthCheck: SSH to host_3 is reachable.
Tue Nov  7 15:56:13 2017 - [info] Binlog server host_3 is reachable.
Tue Nov  7 15:56:13 2017 - [warning] SQL Thread is stopped(no error) on host_1(host_1:3306)
Tue Nov  7 15:56:13 2017 - [warning] SQL Thread is stopped(no error) on host_3(host_3:3306)
Tue Nov  7 15:56:13 2017 - [info] GTID failover mode = 1
Tue Nov  7 15:56:13 2017 - [info] Dead Servers:
Tue Nov  7 15:56:13 2017 - [info]   host_2(host_2:3306)
Tue Nov  7 15:56:13 2017 - [info] Checking master reachability via MySQL(double check)...
Tue Nov  7 15:56:13 2017 - [info]  ok.
Tue Nov  7 15:56:13 2017 - [info] Alive Servers:
Tue Nov  7 15:56:13 2017 - [info]   host_1(host_1:3306)
Tue Nov  7 15:56:13 2017 - [info]   host_3(host_3:3306)
Tue Nov  7 15:56:13 2017 - [info] Alive Slaves:
Tue Nov  7 15:56:13 2017 - [info]   host_1(host_1:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Tue Nov  7 15:56:13 2017 - [info]     GTID ON
Tue Nov  7 15:56:13 2017 - [info]     Replicating from host_2(host_2:3306)
Tue Nov  7 15:56:13 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Tue Nov  7 15:56:13 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Tue Nov  7 15:56:13 2017 - [info]     GTID ON
Tue Nov  7 15:56:13 2017 - [info]     Replicating from host_2(host_2:3306)
Tue Nov  7 15:56:13 2017 - [info]     Not candidate for the new Master (no_master is set)
Tue Nov  7 15:56:13 2017 - [info]  Starting SQL thread on host_1(host_1:3306) ..
Tue Nov  7 15:56:13 2017 - [info]   done.
Tue Nov  7 15:56:13 2017 - [info]  Starting SQL thread on host_3(host_3:3306) ..
Tue Nov  7 15:56:13 2017 - [info]   done.
Tue Nov  7 15:56:13 2017 - [info] Starting GTID based failover.
Tue Nov  7 15:56:13 2017 - [info]
Tue Nov  7 15:56:13 2017 - [info] ** Phase 1: Configuration Check Phase completed.
Tue Nov  7 15:56:13 2017 - [info]
Tue Nov  7 15:56:13 2017 - [info] * Phase 2: Dead Master Shutdown Phase..
Tue Nov  7 15:56:13 2017 - [info]
Tue Nov  7 15:56:13 2017 - [info] HealthCheck: SSH to host_2 is reachable.
Tue Nov  7 15:56:13 2017 - [info] Forcing shutdown so that applications never connect to the current master..
Tue Nov  7 15:56:13 2017 - [info] Executing master IP deactivation script:
Tue Nov  7 15:56:13 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --orig_master_host=host_2 --orig_master_ip=host_2 --orig_master_port=3306 --command=stopssh --ssh_user=root
Tue Nov  7 15:56:16 2017 - [info]  done.
Tue Nov  7 15:56:16 2017 - [warning] shutdown_script is not set. Skipping explicit shutting down of the dead master.
Tue Nov  7 15:56:16 2017 - [info] * Phase 2: Dead Master Shutdown Phase completed.
Tue Nov  7 15:56:16 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info] * Phase 3: Master Recovery Phase..
Tue Nov  7 15:56:16 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info] * Phase 3.1: Getting Latest Slaves Phase..
Tue Nov  7 15:56:16 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info] The latest binary log file/position on all slaves is host_1.000049:11291
Tue Nov  7 15:56:16 2017 - [info] Retrieved Gtid Set: ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:3-446352
Tue Nov  7 15:56:16 2017 - [info] Latest slaves (Slaves that received relay log files to the latest):
Tue Nov  7 15:56:16 2017 - [info]   host_1(host_1:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Tue Nov  7 15:56:16 2017 - [info]     GTID ON
Tue Nov  7 15:56:16 2017 - [info]     Replicating from host_2(host_2:3306)
Tue Nov  7 15:56:16 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Tue Nov  7 15:56:16 2017 - [info] The oldest binary log file/position on all slaves is host_1.000049:10703
Tue Nov  7 15:56:16 2017 - [info] Retrieved Gtid Set: ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:3-446350
Tue Nov  7 15:56:16 2017 - [info] Oldest slaves:
Tue Nov  7 15:56:16 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Tue Nov  7 15:56:16 2017 - [info]     GTID ON
Tue Nov  7 15:56:16 2017 - [info]     Replicating from host_2(host_2:3306)
Tue Nov  7 15:56:16 2017 - [info]     Not candidate for the new Master (no_master is set)
Tue Nov  7 15:56:16 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info] * Phase 3.3: Determining New Master Phase..
Tue Nov  7 15:56:16 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info] Searching new master from slaves..
Tue Nov  7 15:56:16 2017 - [info]  Candidate masters from the configuration file:
Tue Nov  7 15:56:16 2017 - [info]   host_1(host_1:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Tue Nov  7 15:56:16 2017 - [info]     GTID ON
Tue Nov  7 15:56:16 2017 - [info]     Replicating from host_2(host_2:3306)
Tue Nov  7 15:56:16 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Tue Nov  7 15:56:16 2017 - [info]  Non-candidate masters:
Tue Nov  7 15:56:16 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Tue Nov  7 15:56:16 2017 - [info]     GTID ON
Tue Nov  7 15:56:16 2017 - [info]     Replicating from host_2(host_2:3306)
Tue Nov  7 15:56:16 2017 - [info]     Not candidate for the new Master (no_master is set)
Tue Nov  7 15:56:16 2017 - [info]  Searching from candidate_master slaves which have received the latest relay log events..
Tue Nov  7 15:56:16 2017 - [info] New master is host_1(host_1:3306)
Tue Nov  7 15:56:16 2017 - [info] Starting master failover..
Tue Nov  7 15:56:16 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info] * Phase 3.3: New Master Recovery Phase..
Tue Nov  7 15:56:16 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info]  Waiting all logs to be applied..
Tue Nov  7 15:56:16 2017 - [info]   done.
Tue Nov  7 15:56:16 2017 - [info] -- Saving binlog from host host_2 started, pid: 79759
Tue Nov  7 15:56:16 2017 - [info] -- Saving binlog from host host_1 started, pid: 79768
Tue Nov  7 15:56:16 2017 - [info] -- Saving binlog from host host_3 started, pid: 79770
Tue Nov  7 15:56:17 2017 - [info]
Tue Nov  7 15:56:17 2017 - [info] Log messages from host_1 ...
Tue Nov  7 15:56:17 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info] Fetching binary logs from binlog server host_1..
Tue Nov  7 15:56:16 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=host_1.000049  --start_pos=11291 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog2_20171107155611.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Tue Nov  7 15:56:17 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Tue Nov  7 15:56:17 2017 - [info] End of log messages from host_1.
Tue Nov  7 15:56:17 2017 - [warning] Got error from host_1.
Tue Nov  7 15:56:17 2017 - [info]
Tue Nov  7 15:56:17 2017 - [info] Log messages from host_3 ...
Tue Nov  7 15:56:17 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info] Fetching binary logs from binlog server host_3..
Tue Nov  7 15:56:16 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=host_1.000049  --start_pos=11291 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog3_20171107155611.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Tue Nov  7 15:56:17 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Tue Nov  7 15:56:17 2017 - [info] End of log messages from host_3.
Tue Nov  7 15:56:17 2017 - [warning] Got error from host_3.
Tue Nov  7 15:56:17 2017 - [info]
Tue Nov  7 15:56:17 2017 - [info] Log messages from host_2 ...
Tue Nov  7 15:56:17 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info] Fetching binary logs from binlog server host_2..
Tue Nov  7 15:56:16 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=host_1.000049  --start_pos=11291 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog1_20171107155611.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Tue Nov  7 15:56:17 2017 - [info] scp from root@host_2:/var/log/masterha/mha_test/saved_binlog_binlog1_20171107155611.binlog to local:/var/log/masterha/mha_test/saved_binlog_host_2_binlog1_20171107155611.binlog succeeded.
Tue Nov  7 15:56:17 2017 - [info] End of log messages from host_2.
Tue Nov  7 15:56:17 2017 - [info] Saved mysqlbinlog size from host_2 is 768 bytes.
Tue Nov  7 15:56:17 2017 - [info] Applying differential binlog /var/log/masterha/mha_test/saved_binlog_host_2_binlog1_20171107155611.binlog ..
Tue Nov  7 15:56:17 2017 - [info] Differential log apply from binlog server succeeded.
Tue Nov  7 15:56:17 2017 - [info] Getting new master's binlog name and position..
Tue Nov  7 15:56:17 2017 - [info]  tjtx-126-164.000051:11449
Tue Nov  7 15:56:17 2017 - [info]  All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST='host_1', MASTER_PORT=3306, MASTER_AUTO_POSITION=1, MASTER_USER='repl', MASTER_PASSWORD='xxx';
Tue Nov  7 15:56:17 2017 - [info] Master Recovery succeeded. File:Pos:Exec_Gtid_Set: tjtx-126-164.000051, 11449, 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1,
Tue Nov  7 15:56:17 2017 - [info] Executing master IP activate script:
Tue Nov  7 15:56:17 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --command=start --ssh_user=root --orig_master_host=host_2 --orig_master_ip=host_2 --orig_master_port=3306 --new_master_host=host_1 --new_master_ip=host_1 --new_master_port=3306 --new_master_user='xxx' --new_master_password='xxx'
Tue Nov  7 15:56:20 2017 - [info]  OK.
Tue Nov  7 15:56:20 2017 - [info] Setting read_only=0 on host_1(host_1:3306)..
Tue Nov  7 15:56:20 2017 - [info]  ok.
Tue Nov  7 15:56:20 2017 - [info] ** Finished master recovery successfully.
Tue Nov  7 15:56:20 2017 - [info] * Phase 3: Master Recovery Phase completed.
Tue Nov  7 15:56:20 2017 - [info]
Tue Nov  7 15:56:20 2017 - [info] * Phase 4: Slaves Recovery Phase..
Tue Nov  7 15:56:20 2017 - [info]
Tue Nov  7 15:56:20 2017 - [info]
Tue Nov  7 15:56:20 2017 - [info] * Phase 4.1: Starting Slaves in parallel..
Tue Nov  7 15:56:20 2017 - [info]
Tue Nov  7 15:56:20 2017 - [info] -- Slave recovery on host host_3(host_3:3306) started, pid: 85941. Check tmp log /var/log/masterha/mha_test/host_3_3306_20171107155611.log if it takes time..
Tue Nov  7 15:56:21 2017 - [info]
Tue Nov  7 15:56:21 2017 - [info] Log messages from host_3 ...
Tue Nov  7 15:56:21 2017 - [info]
Tue Nov  7 15:56:20 2017 - [info]  Resetting slave host_3(host_3:3306) and starting replication from the new master host_1(host_1:3306)..
Tue Nov  7 15:56:20 2017 - [info]  Executed CHANGE MASTER.
Tue Nov  7 15:56:21 2017 - [info]  Slave started.
Tue Nov  7 15:56:21 2017 - [info]  gtid_wait(0923e916-3c36-11e6-82a5-ecf4bbf1f518:1,
Tue Nov  7 15:56:21 2017 - [info] End of log messages from host_3.
Tue Nov  7 15:56:21 2017 - [info] -- Slave on host host_3(host_3:3306) started.
Tue Nov  7 15:56:21 2017 - [info] All new slave servers recovered successfully.
Tue Nov  7 15:56:21 2017 - [info]
Tue Nov  7 15:56:21 2017 - [info] * Phase 5: New master cleanup phase..
Tue Nov  7 15:56:21 2017 - [info]
Tue Nov  7 15:56:21 2017 - [info] Resetting slave info on the new master..
Tue Nov  7 15:56:21 2017 - [info]  host_1: Resetting slave info succeeded.
Tue Nov  7 15:56:21 2017 - [info] Master failover to host_1(host_1:3306) completed successfully.
Tue Nov  7 15:56:21 2017 - [info]
Tue Nov  7 15:56:21 2017 - [info] Sending mail..

1.4 slave(候选master）上面有大事务在跑

• 1000s的大查询

无影响，正常切换

• flush tables with readlock

无影响，正常切换

1.5 binlog server 不同场景的测试

dead_master上的最后部分日志没有传递到slave和etl的情况, 然而slave的日志也落后etl （这是最严苛的情况）

• binlog server 写3台

masterha_master_switch --global_conf=/data/online/agent/MHA/conf/masterha_default.cnf --conf=/data/online/agent/MHA/conf/bak_mha_test.cnf  --dead_master_host=host_1  --dead_master_port=3306 --master_state=dead --interactive=0 --ignore_last_failover --ignore_binlog_server_error


Tue Nov  7 15:56:17 2017 - [info] Log messages from host_1 ...
Tue Nov  7 15:56:17 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info] Fetching binary logs from binlog server host_1..
Tue Nov  7 15:56:16 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=host_1.000049  --start_pos=11291 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog2_20171107155611.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Tue Nov  7 15:56:17 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Tue Nov  7 15:56:17 2017 - [info] End of log messages from host_1.
Tue Nov  7 15:56:17 2017 - [warning] Got error from host_1.
Tue Nov  7 15:56:17 2017 - [info]
Tue Nov  7 15:56:17 2017 - [info] Log messages from host_3 ...
Tue Nov  7 15:56:17 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info] Fetching binary logs from binlog server host_3..
Tue Nov  7 15:56:16 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=host_1.000049  --start_pos=11291 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog3_20171107155611.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Tue Nov  7 15:56:17 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Tue Nov  7 15:56:17 2017 - [info] End of log messages from host_3.
Tue Nov  7 15:56:17 2017 - [warning] Got error from host_3.
Tue Nov  7 15:56:17 2017 - [info]
Tue Nov  7 15:56:17 2017 - [info] Log messages from host_2 ...
Tue Nov  7 15:56:17 2017 - [info]
Tue Nov  7 15:56:16 2017 - [info] Fetching binary logs from binlog server host_2..
Tue Nov  7 15:56:16 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=host_1.000049  --start_pos=11291 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog1_20171107155611.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Tue Nov  7 15:56:17 2017 - [info] scp from root@host_2:/var/log/masterha/mha_test/saved_binlog_binlog1_20171107155611.binlog to local:/var/log/masterha/mha_test/saved_binlog_host_2_binlog1_20171107155611.binlog succeeded.
Tue Nov  7 15:56:17 2017 - [info] End of log messages from host_2.
Tue Nov  7 15:56:17 2017 - [info] Saved mysqlbinlog size from host_2 is 768 bytes.
Tue Nov  7 15:56:17 2017 - [info] Applying differential binlog /var/log/masterha/mha_test/saved_binlog_host_2_binlog1_20171107155611.binlog ..
Tue Nov  7 15:56:17 2017 - [info] Differential log apply from binlog server succeeded.

• binlog server 只写master

masterha_master_switch --global_conf=/data/online/agent/MHA/conf/masterha_default.cnf --conf=/data/online/agent/MHA/conf/bak_mha_test.cnf  --dead_master_host=host_2  --dead_master_port=3306 --master_state=dead --interactive=0 --ignore_last_failover --ignore_binlog_server_error


Thu Nov  9 11:20:04 2017 - [info] -- Saving binlog from host host_2 started, pid: 117389
Thu Nov  9 11:20:05 2017 - [info]
Thu Nov  9 11:20:05 2017 - [info] Log messages from host_2 ...
Thu Nov  9 11:20:05 2017 - [info]
Thu Nov  9 11:20:04 2017 - [info] Fetching binary logs from binlog server host_2..
Thu Nov  9 11:20:04 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=host_1.000004  --start_pos=1115 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog1_20171109111957.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Thu Nov  9 11:20:05 2017 - [info] scp from root@host_2:/var/log/masterha/mha_test/saved_binlog_binlog1_20171109111957.binlog to local:/var/log/masterha/mha_test/saved_binlog_host_2_binlog1_20171109111957.binlog succeeded.
Thu Nov  9 11:20:05 2017 - [info] End of log messages from host_2.
Thu Nov  9 11:20:05 2017 - [info] Saved mysqlbinlog size from host_2 is 4444 bytes.
Thu Nov  9 11:20:05 2017 - [info] Applying differential binlog /var/log/masterha/mha_test/saved_binlog_host_2_binlog1_20171109111957.binlog ..
Thu Nov  9 11:20:05 2017 - [info] Differential log apply from binlog server succeeded.

• binlog server 只写slave

### 3台服务器的GTID状态

* master  host_1

dba:lc> show master status;
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| File                | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                                                                        |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| tjtx-126-164.000055 |     6016 |              |                  | 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-31,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446369 |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

* slave host_2


            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-21,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446369
                Auto_Position: 1


* etl host_3

           Retrieved_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:22-25,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:446366-446369
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-25,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446369
                Auto_Position: 1


### 切换日志

masterha_master_switch --global_conf=/data/online/agent/MHA/conf/masterha_default.cnf --conf=/data/online/agent/MHA/conf/bak_mha_test.cnf  --dead_master_host=host_1  --dead_master_port=3306 --master_state=dead --interactive=0 --ignore_last_failover --ignore_binlog_server_error

Thu Nov  9 15:00:09 2017 - [info] MHA::MasterFailover version 0.56.
Thu Nov  9 15:00:09 2017 - [info] Starting master failover.
Thu Nov  9 15:00:09 2017 - [info]
Thu Nov  9 15:00:09 2017 - [info] * Phase 1: Configuration Check Phase..
Thu Nov  9 15:00:09 2017 - [info]
Thu Nov  9 15:00:09 2017 - [info] HealthCheck: SSH to host_2 is reachable.
Thu Nov  9 15:00:09 2017 - [info] Binlog server host_2 is reachable.
Thu Nov  9 15:00:10 2017 - [warning] SQL Thread is stopped(no error) on host_2(host_2:3306)
Thu Nov  9 15:00:10 2017 - [warning] SQL Thread is stopped(no error) on host_3(host_3:3306)
Thu Nov  9 15:00:10 2017 - [info] GTID failover mode = 1
Thu Nov  9 15:00:10 2017 - [info] Dead Servers:
Thu Nov  9 15:00:10 2017 - [info]   host_1(host_1:3306)
Thu Nov  9 15:00:10 2017 - [info] Checking master reachability via MySQL(double check)...
Thu Nov  9 15:00:10 2017 - [info]  ok.
Thu Nov  9 15:00:10 2017 - [info] Alive Servers:
Thu Nov  9 15:00:10 2017 - [info]   host_2(host_2:3306)
Thu Nov  9 15:00:10 2017 - [info]   host_3(host_3:3306)
Thu Nov  9 15:00:10 2017 - [info] Alive Slaves:
Thu Nov  9 15:00:10 2017 - [info]   host_2(host_2:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 15:00:10 2017 - [info]     GTID ON
Thu Nov  9 15:00:10 2017 - [info]     Replicating from host_1(host_1:3306)
Thu Nov  9 15:00:10 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Thu Nov  9 15:00:10 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 15:00:10 2017 - [info]     GTID ON
Thu Nov  9 15:00:10 2017 - [info]     Replicating from host_1(host_1:3306)
Thu Nov  9 15:00:10 2017 - [info]     Not candidate for the new Master (no_master is set)
Thu Nov  9 15:00:10 2017 - [info]  Starting SQL thread on host_2(host_2:3306) ..
Thu Nov  9 15:00:10 2017 - [info]   done.
Thu Nov  9 15:00:10 2017 - [info]  Starting SQL thread on host_3(host_3:3306) ..
Thu Nov  9 15:00:10 2017 - [info]   done.
Thu Nov  9 15:00:10 2017 - [info] Starting GTID based failover.
Thu Nov  9 15:00:10 2017 - [info]
Thu Nov  9 15:00:10 2017 - [info] ** Phase 1: Configuration Check Phase completed.
Thu Nov  9 15:00:10 2017 - [info]
Thu Nov  9 15:00:10 2017 - [info] * Phase 2: Dead Master Shutdown Phase..
Thu Nov  9 15:00:10 2017 - [info]
Thu Nov  9 15:00:10 2017 - [info] HealthCheck: SSH to host_1 is reachable.
Thu Nov  9 15:00:10 2017 - [info] Forcing shutdown so that applications never connect to the current master..
Thu Nov  9 15:00:10 2017 - [info] Executing master IP deactivation script:
Thu Nov  9 15:00:10 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --orig_master_host=host_1 --orig_master_ip=host_1 --orig_master_port=3306 --command=stopssh --ssh_user=root
Thu Nov  9 15:00:17 2017 - [info]  done.
Thu Nov  9 15:00:17 2017 - [warning] shutdown_script is not set. Skipping explicit shutting down of the dead master.
Thu Nov  9 15:00:17 2017 - [info] * Phase 2: Dead Master Shutdown Phase completed.
Thu Nov  9 15:00:17 2017 - [info]
Thu Nov  9 15:00:17 2017 - [info] * Phase 3: Master Recovery Phase..
Thu Nov  9 15:00:17 2017 - [info]
Thu Nov  9 15:00:17 2017 - [info] * Phase 3.1: Getting Latest Slaves Phase..
Thu Nov  9 15:00:17 2017 - [info]
Thu Nov  9 15:00:17 2017 - [info] The latest binary log file/position on all slaves is tjtx-126-164.000055:4090
Thu Nov  9 15:00:17 2017 - [info] Retrieved Gtid Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:22-25,
Thu Nov  9 15:00:17 2017 - [info] Latest slaves (Slaves that received relay log files to the latest):
Thu Nov  9 15:00:17 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 15:00:17 2017 - [info]     GTID ON
Thu Nov  9 15:00:17 2017 - [info]     Replicating from host_1(host_1:3306)
Thu Nov  9 15:00:17 2017 - [info]     Not candidate for the new Master (no_master is set)
Thu Nov  9 15:00:17 2017 - [info] The oldest binary log file/position on all slaves is tjtx-126-164.000055:2806
Thu Nov  9 15:00:17 2017 - [info] Oldest slaves:
Thu Nov  9 15:00:17 2017 - [info]   host_2(host_2:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 15:00:17 2017 - [info]     GTID ON
Thu Nov  9 15:00:17 2017 - [info]     Replicating from host_1(host_1:3306)
Thu Nov  9 15:00:17 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Thu Nov  9 15:00:17 2017 - [info]
Thu Nov  9 15:00:17 2017 - [info] * Phase 3.3: Determining New Master Phase..
Thu Nov  9 15:00:17 2017 - [info]
Thu Nov  9 15:00:17 2017 - [info] Searching new master from slaves..
Thu Nov  9 15:00:17 2017 - [info]  Candidate masters from the configuration file:
Thu Nov  9 15:00:17 2017 - [info]   host_2(host_2:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 15:00:17 2017 - [info]     GTID ON
Thu Nov  9 15:00:17 2017 - [info]     Replicating from host_1(host_1:3306)
Thu Nov  9 15:00:17 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Thu Nov  9 15:00:17 2017 - [info]  Non-candidate masters:
Thu Nov  9 15:00:17 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 15:00:17 2017 - [info]     GTID ON
Thu Nov  9 15:00:17 2017 - [info]     Replicating from host_1(host_1:3306)
Thu Nov  9 15:00:17 2017 - [info]     Not candidate for the new Master (no_master is set)
Thu Nov  9 15:00:17 2017 - [info]  Searching from candidate_master slaves which have received the latest relay log events..
Thu Nov  9 15:00:17 2017 - [info]   Not found.
Thu Nov  9 15:00:17 2017 - [info]  Searching from all candidate_master slaves..
Thu Nov  9 15:00:17 2017 - [info] New master is host_2(host_2:3306)
Thu Nov  9 15:00:17 2017 - [info] Starting master failover..
Thu Nov  9 15:00:17 2017 - [info]
Thu Nov  9 15:00:17 2017 - [info]
Thu Nov  9 15:00:17 2017 - [info] * Phase 3.3: New Master Recovery Phase..
Thu Nov  9 15:00:17 2017 - [info]
Thu Nov  9 15:00:17 2017 - [info]  Waiting all logs to be applied..
Thu Nov  9 15:00:17 2017 - [info]   done.
Thu Nov  9 15:00:17 2017 - [info]  Replicating from the latest slave host_3(host_3:3306) and waiting to apply..
Thu Nov  9 15:00:17 2017 - [info]  Waiting all logs to be applied on the latest slave..
Thu Nov  9 15:00:17 2017 - [info]  Resetting slave host_2(host_2:3306) and starting replication from the new master host_3(host_3:3306)..
Thu Nov  9 15:00:17 2017 - [info]  Executed CHANGE MASTER.
Thu Nov  9 15:00:18 2017 - [info]  Slave started.
Thu Nov  9 15:00:18 2017 - [info]  Waiting to execute all relay logs on host_2(host_2:3306)..
Thu Nov  9 15:00:18 2017 - [info]  master_pos_wait(host_3.000049:25843) completed on host_2(host_2:3306). Executed 0 events.
Thu Nov  9 15:00:18 2017 - [info]   done.
Thu Nov  9 15:00:18 2017 - [info]   done.
Thu Nov  9 15:00:18 2017 - [info] -- Saving binlog from host host_2 started, pid: 175683
Thu Nov  9 15:00:18 2017 - [info]
Thu Nov  9 15:00:18 2017 - [info] Log messages from host_2 ...
Thu Nov  9 15:00:18 2017 - [info]
Thu Nov  9 15:00:18 2017 - [info] Fetching binary logs from binlog server host_2..
Thu Nov  9 15:00:18 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=tjtx-126-164.000055  --start_pos=4090 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog1_20171109150009.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Thu Nov  9 15:00:18 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Thu Nov  9 15:00:18 2017 - [info] End of log messages from host_2.
Thu Nov  9 15:00:18 2017 - [warning] Got error from host_2.
Thu Nov  9 15:00:18 2017 - [info] Getting new master's binlog name and position..
Thu Nov  9 15:00:18 2017 - [info]  host_1.000005:1390
Thu Nov  9 15:00:18 2017 - [info]  All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST='host_2', MASTER_PORT=3306, MASTER_AUTO_POSITION=1, MASTER_USER='repl', MASTER_PASSWORD='xxx';
Thu Nov  9 15:00:18 2017 - [info] Master Recovery succeeded. File:Pos:Exec_Gtid_Set: host_1.000005, 1390, 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-25,
Thu Nov  9 15:00:18 2017 - [info] Executing master IP activate script:
Thu Nov  9 15:00:18 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --command=start --ssh_user=root --orig_master_host=host_1 --orig_master_ip=host_1 --orig_master_port=3306 --new_master_host=host_2 --new_master_ip=host_2 --new_master_port=3306 --new_master_user='xxx' --new_master_password='xxx'
Thu Nov  9 15:00:22 2017 - [info]  OK.
Thu Nov  9 15:00:22 2017 - [info] Setting read_only=0 on host_2(host_2:3306)..
Thu Nov  9 15:00:22 2017 - [info]  ok.
Thu Nov  9 15:00:22 2017 - [info] ** Finished master recovery successfully.
Thu Nov  9 15:00:22 2017 - [info] * Phase 3: Master Recovery Phase completed.
Thu Nov  9 15:00:22 2017 - [info]
Thu Nov  9 15:00:22 2017 - [info] * Phase 4: Slaves Recovery Phase..
Thu Nov  9 15:00:22 2017 - [info]
Thu Nov  9 15:00:22 2017 - [info]
Thu Nov  9 15:00:22 2017 - [info] * Phase 4.1: Starting Slaves in parallel..
Thu Nov  9 15:00:22 2017 - [info]
Thu Nov  9 15:00:22 2017 - [info] -- Slave recovery on host host_3(host_3:3306) started, pid: 180681. Check tmp log /var/log/masterha/mha_test/host_3_3306_20171109150009.log if it takes time..
Thu Nov  9 15:00:23 2017 - [info]
Thu Nov  9 15:00:23 2017 - [info] Log messages from host_3 ...
Thu Nov  9 15:00:23 2017 - [info]
Thu Nov  9 15:00:22 2017 - [info]  Resetting slave host_3(host_3:3306) and starting replication from the new master host_2(host_2:3306)..
Thu Nov  9 15:00:22 2017 - [info]  Executed CHANGE MASTER.
Thu Nov  9 15:00:23 2017 - [info]  Slave started.
Thu Nov  9 15:00:23 2017 - [info]  gtid_wait(0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-25,
Thu Nov  9 15:00:23 2017 - [info] End of log messages from host_3.
Thu Nov  9 15:00:23 2017 - [info] -- Slave on host host_3(host_3:3306) started.
Thu Nov  9 15:00:23 2017 - [info] All new slave servers recovered successfully.
Thu Nov  9 15:00:23 2017 - [info]
Thu Nov  9 15:00:23 2017 - [info] * Phase 5: New master cleanup phase..
Thu Nov  9 15:00:23 2017 - [info]
Thu Nov  9 15:00:23 2017 - [info] Resetting slave info on the new master..
Thu Nov  9 15:00:23 2017 - [info]  host_2: Resetting slave info succeeded.
Thu Nov  9 15:00:23 2017 - [info] Master failover to host_2(host_2:3306) completed successfully.
Thu Nov  9 15:00:23 2017 - [info]
Thu Nov  9 15:00:23 2017 - [info] Sending mail..

结论： 由于binlog server没有配置master，所以会丢失master没有传递过来的事务日志
好在，slave和etl之间会互相change master，所以尽管slave（candidate master）的日志落后，最终也还是用etl的日志补齐了slave缺失的日志。

• binlog server 啥都不写

### 3台DB的GTID状态

* master host_2

dba:lc> show master status;
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| File                | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                                                                        |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| host_1.000005 |     5785 |              |                  | 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-31,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446378 |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)


* slave host_1

           Retrieved_Gtid_Set:
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-31,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446369
                Auto_Position: 1

* etl host_3


           Retrieved_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:26-31,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:446370-446372
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-31,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446372
                Auto_Position: 1


### 切换日志

Thu Nov  9 16:22:41 2017 - [info] MHA::MasterFailover version 0.56.
Thu Nov  9 16:22:41 2017 - [info] Starting master failover.
Thu Nov  9 16:22:41 2017 - [info]
Thu Nov  9 16:22:41 2017 - [info] * Phase 1: Configuration Check Phase..
Thu Nov  9 16:22:41 2017 - [info]
Thu Nov  9 16:22:41 2017 - [warning] SQL Thread is stopped(no error) on host_1(host_1:3306)
Thu Nov  9 16:22:41 2017 - [warning] SQL Thread is stopped(no error) on host_3(host_3:3306)
Thu Nov  9 16:22:41 2017 - [info] GTID failover mode = 1
Thu Nov  9 16:22:41 2017 - [info] Dead Servers:
Thu Nov  9 16:22:41 2017 - [info]   host_2(host_2:3306)
Thu Nov  9 16:22:41 2017 - [info] Checking master reachability via MySQL(double check)...
Thu Nov  9 16:22:41 2017 - [info]  ok.
Thu Nov  9 16:22:41 2017 - [info] Alive Servers:
Thu Nov  9 16:22:41 2017 - [info]   host_1(host_1:3306)
Thu Nov  9 16:22:41 2017 - [info]   host_3(host_3:3306)
Thu Nov  9 16:22:41 2017 - [info] Alive Slaves:
Thu Nov  9 16:22:41 2017 - [info]   host_1(host_1:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 16:22:41 2017 - [info]     GTID ON
Thu Nov  9 16:22:41 2017 - [info]     Replicating from host_2(host_2:3306)
Thu Nov  9 16:22:41 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Thu Nov  9 16:22:41 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 16:22:41 2017 - [info]     GTID ON
Thu Nov  9 16:22:41 2017 - [info]     Replicating from host_2(host_2:3306)
Thu Nov  9 16:22:41 2017 - [info]     Not candidate for the new Master (no_master is set)
Thu Nov  9 16:22:41 2017 - [info]  Starting SQL thread on host_1(host_1:3306) ..
Thu Nov  9 16:22:41 2017 - [info]   done.
Thu Nov  9 16:22:41 2017 - [info]  Starting SQL thread on host_3(host_3:3306) ..
Thu Nov  9 16:22:41 2017 - [info]   done.
Thu Nov  9 16:22:41 2017 - [info] Starting GTID based failover.
Thu Nov  9 16:22:41 2017 - [info]
Thu Nov  9 16:22:41 2017 - [info] ** Phase 1: Configuration Check Phase completed.
Thu Nov  9 16:22:41 2017 - [info]
Thu Nov  9 16:22:41 2017 - [info] * Phase 2: Dead Master Shutdown Phase..
Thu Nov  9 16:22:41 2017 - [info]
Thu Nov  9 16:22:42 2017 - [info] HealthCheck: SSH to host_2 is reachable.
Thu Nov  9 16:22:42 2017 - [info] Forcing shutdown so that applications never connect to the current master..
Thu Nov  9 16:22:42 2017 - [info] Executing master IP deactivation script:
Thu Nov  9 16:22:42 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --orig_master_host=host_2 --orig_master_ip=host_2 --orig_master_port=3306 --command=stopssh --ssh_user=root
===================    swift vip :  vip from host_2 is deleted  ==============================


--2017-11-09 16:22:42--  http://tgw_server/cgi-bin/fun_logic/bin/public_api/op_rs.cgi
正在连接 tgw_server:80... 已连接。
已发出 HTTP 请求，正在等待回应... 200 OK
长度：未指定 [text/html]
正在保存至: “STDOUT”

     0K                                                        9.79M=0s

2017-11-09 16:22:44 (9.79 MB/s) - 已写入标准输出 [38]

Thu Nov  9 16:22:44 2017 - [info]  done.
Thu Nov  9 16:22:44 2017 - [warning] shutdown_script is not set. Skipping explicit shutting down of the dead master.
Thu Nov  9 16:22:44 2017 - [info] * Phase 2: Dead Master Shutdown Phase completed.
Thu Nov  9 16:22:44 2017 - [info]
Thu Nov  9 16:22:44 2017 - [info] * Phase 3: Master Recovery Phase..
Thu Nov  9 16:22:44 2017 - [info]
Thu Nov  9 16:22:44 2017 - [info] * Phase 3.1: Getting Latest Slaves Phase..
Thu Nov  9 16:22:44 2017 - [info]
Thu Nov  9 16:22:44 2017 - [info] The latest binary log file/position on all slaves is host_1.000005:4015
Thu Nov  9 16:22:44 2017 - [info] Retrieved Gtid Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:26-31,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:446370-446372
Thu Nov  9 16:22:44 2017 - [info] Latest slaves (Slaves that received relay log files to the latest):
Thu Nov  9 16:22:44 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 16:22:44 2017 - [info]     GTID ON
Thu Nov  9 16:22:44 2017 - [info]     Replicating from host_2(host_2:3306)
Thu Nov  9 16:22:44 2017 - [info]     Not candidate for the new Master (no_master is set)
Thu Nov  9 16:22:44 2017 - [info] The oldest binary log file/position on all slaves is host_1.000005:3130
Thu Nov  9 16:22:44 2017 - [info] Oldest slaves:
Thu Nov  9 16:22:44 2017 - [info]   host_1(host_1:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 16:22:44 2017 - [info]     GTID ON
Thu Nov  9 16:22:44 2017 - [info]     Replicating from host_2(host_2:3306)
Thu Nov  9 16:22:44 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Thu Nov  9 16:22:44 2017 - [info]
Thu Nov  9 16:22:44 2017 - [info] * Phase 3.3: Determining New Master Phase..
Thu Nov  9 16:22:44 2017 - [info]
Thu Nov  9 16:22:44 2017 - [info] Searching new master from slaves..
Thu Nov  9 16:22:44 2017 - [info]  Candidate masters from the configuration file:
Thu Nov  9 16:22:44 2017 - [info]   host_1(host_1:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 16:22:44 2017 - [info]     GTID ON
Thu Nov  9 16:22:44 2017 - [info]     Replicating from host_2(host_2:3306)
Thu Nov  9 16:22:44 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Thu Nov  9 16:22:44 2017 - [info]  Non-candidate masters:
Thu Nov  9 16:22:44 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Thu Nov  9 16:22:44 2017 - [info]     GTID ON
Thu Nov  9 16:22:44 2017 - [info]     Replicating from host_2(host_2:3306)
Thu Nov  9 16:22:44 2017 - [info]     Not candidate for the new Master (no_master is set)
Thu Nov  9 16:22:44 2017 - [info]  Searching from candidate_master slaves which have received the latest relay log events..
Thu Nov  9 16:22:44 2017 - [info]   Not found.
Thu Nov  9 16:22:44 2017 - [info]  Searching from all candidate_master slaves..
Thu Nov  9 16:22:44 2017 - [info] New master is host_1(host_1:3306)
Thu Nov  9 16:22:44 2017 - [info] Starting master failover..
Thu Nov  9 16:22:44 2017 - [info]
From:
host_2(host_2:3306) (current master)
 +--host_1(host_1:3306)
 +--host_3(host_3:3306)

To:
host_1(host_1:3306) (new master)
 +--host_3(host_3:3306)
Thu Nov  9 16:22:44 2017 - [info]
Thu Nov  9 16:22:44 2017 - [info] * Phase 3.3: New Master Recovery Phase..
Thu Nov  9 16:22:44 2017 - [info]
Thu Nov  9 16:22:44 2017 - [info]  Waiting all logs to be applied..
Thu Nov  9 16:22:44 2017 - [info]   done.
Thu Nov  9 16:22:44 2017 - [info]  Replicating from the latest slave host_3(host_3:3306) and waiting to apply..
Thu Nov  9 16:22:44 2017 - [info]  Waiting all logs to be applied on the latest slave..
Thu Nov  9 16:22:44 2017 - [info]  Resetting slave host_1(host_1:3306) and starting replication from the new master host_3(host_3:3306)..
Thu Nov  9 16:22:44 2017 - [info]  Executed CHANGE MASTER.
Thu Nov  9 16:22:45 2017 - [info]  Slave started.
Thu Nov  9 16:22:45 2017 - [info]  Waiting to execute all relay logs on host_1(host_1:3306)..
Thu Nov  9 16:22:45 2017 - [info]  master_pos_wait(host_3.000049:28663) completed on host_1(host_1:3306). Executed 0 events.
Thu Nov  9 16:22:45 2017 - [info]   done.
Thu Nov  9 16:22:45 2017 - [info]   done.
Thu Nov  9 16:22:45 2017 - [info] Getting new master's binlog name and position..
Thu Nov  9 16:22:45 2017 - [info]  tjtx-126-164.000056:1170
Thu Nov  9 16:22:45 2017 - [info]  All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST='host_1', MASTER_PORT=3306, MASTER_AUTO_POSITION=1, MASTER_USER='repl', MASTER_PASSWORD='xxx';
Thu Nov  9 16:22:45 2017 - [info] Master Recovery succeeded. File:Pos:Exec_Gtid_Set: tjtx-126-164.000056, 1170, 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-31,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446372
Thu Nov  9 16:22:45 2017 - [info] Executing master IP activate script:
Thu Nov  9 16:22:45 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --command=start --ssh_user=root --orig_master_host=host_2 --orig_master_ip=host_2 --orig_master_port=3306 --new_master_host=host_1 --new_master_ip=host_1 --new_master_port=3306 --new_master_user='xxx' --new_master_password='xxx'
Unknown option: new_master_user
Unknown option: new_master_password
===================    swift vip :  vip to host_1  is added  ==============================


Thu Nov  9 16:22:47 2017 - [info]  OK.
Thu Nov  9 16:22:47 2017 - [info] Setting read_only=0 on host_1(host_1:3306)..
Thu Nov  9 16:22:47 2017 - [info]  ok.
Thu Nov  9 16:22:47 2017 - [info] ** Finished master recovery successfully.
Thu Nov  9 16:22:47 2017 - [info] * Phase 3: Master Recovery Phase completed.
Thu Nov  9 16:22:47 2017 - [info]
Thu Nov  9 16:22:47 2017 - [info] * Phase 4: Slaves Recovery Phase..
Thu Nov  9 16:22:47 2017 - [info]
Thu Nov  9 16:22:47 2017 - [info]
Thu Nov  9 16:22:47 2017 - [info] * Phase 4.1: Starting Slaves in parallel..
Thu Nov  9 16:22:47 2017 - [info]
Thu Nov  9 16:22:47 2017 - [info] -- Slave recovery on host host_3(host_3:3306) started, pid: 112317. Check tmp log /var/log/masterha/mha_test/host_3_3306_20171109162241.log if it takes time..
Thu Nov  9 16:22:48 2017 - [info]
Thu Nov  9 16:22:48 2017 - [info] Log messages from host_3 ...
Thu Nov  9 16:22:48 2017 - [info]
Thu Nov  9 16:22:47 2017 - [info]  Resetting slave host_3(host_3:3306) and starting replication from the new master host_1(host_1:3306)..
Thu Nov  9 16:22:47 2017 - [info]  Executed CHANGE MASTER.
Thu Nov  9 16:22:48 2017 - [info]  Slave started.
Thu Nov  9 16:22:48 2017 - [info]  gtid_wait(0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-31,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446372) completed on host_3(host_3:3306). Executed 0 events.
Thu Nov  9 16:22:48 2017 - [info] End of log messages from host_3.
Thu Nov  9 16:22:48 2017 - [info] -- Slave on host host_3(host_3:3306) started.
Thu Nov  9 16:22:48 2017 - [info] All new slave servers recovered successfully.
Thu Nov  9 16:22:48 2017 - [info]
Thu Nov  9 16:22:48 2017 - [info] * Phase 5: New master cleanup phase..
Thu Nov  9 16:22:48 2017 - [info]
Thu Nov  9 16:22:48 2017 - [info] Resetting slave info on the new master..
Thu Nov  9 16:22:49 2017 - [info]  host_1: Resetting slave info succeeded.
Thu Nov  9 16:22:49 2017 - [info] Master failover to host_1(host_1:3306) completed successfully.
Thu Nov  9 16:22:49 2017 - [info]

----- Failover Report -----

bak_mha_test: MySQL Master failover host_2(host_2:3306) to host_1(host_1:3306) succeeded

Master host_2(host_2:3306) is down!

Check MHA Manager logs at tjtx135-2-217.58os.org:/var/log/masterha/mha_test/mha_test.log for details.

Started automated(non-interactive) failover.
Invalidated master IP address on host_2(host_2:3306)
Selected host_1(host_1:3306) as a new master.
host_1(host_1:3306): OK: Applying all logs succeeded.
host_1(host_1:3306): OK: Activated master IP address.
host_3(host_3:3306): OK: Slave started, replicating from host_1(host_1:3306)
host_1(host_1:3306): Resetting slave info succeeded.
Master failover to host_1(host_1:3306) completed successfully.

结论： 由于binlog server没有配置master，所以会丢失master没有传递过来的事务日志
好在，slave和etl之间会互相change master，所以尽管slave（candidate master）的日志落后，最终也还是用etl的日志补齐了slave缺失的日志。

1.6 如果MHA过程中失败，是否可以重新执行MHA的failover呢？

• 99%的场景都是可以重新执行的

• 1%的场景不能再次执行，执行会报错

一般这种场景就是：已经failover到最后的change master阶段，这样主从结构已经变更，MHA无法重新走一遍。
不过，即便到这步骤失败了，表示master的日志已经补完，由于是gtid模式，自己再让slave change master到最新的master即可，最后ACTIVE new ip和readonly=1就好了

Thu Nov  9 16:49:39 2017 - [info] MHA::MasterFailover version 0.56.
Thu Nov  9 16:49:39 2017 - [info] Starting master failover.
Thu Nov  9 16:49:39 2017 - [info]
Thu Nov  9 16:49:39 2017 - [info] * Phase 1: Configuration Check Phase..
Thu Nov  9 16:49:39 2017 - [info]
Thu Nov  9 16:49:39 2017 - [info] GTID failover mode = 1
Thu Nov  9 16:49:39 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln169] Detected dead master host_1(host_1:3306) does not match with specified dead master host_2(host_2:3306)!
Thu Nov  9 16:49:39 2017 - [error][/usr/share/perl5/vendor_perl/MHA/ManagerUtil.pm, ln177] Got ERROR:  at /usr/bin/masterha_master_switch line 53

1.7 Master：MySQL down小结

1. failover最终命令

masterha_master_switch --global_conf=/data/online/agent/MHA/conf/masterha_default.cnf --conf=/data/online/agent/MHA/conf/bak_mha_test.cnf  --dead_master_host=host_2  --dead_master_port=3306 --master_state=dead --interactive=0 --ignore_last_failover --ignore_binlog_server_error


2. binlog server建议

配置master就可以了
[binlog1]
$master_ip

只配置slave，或者没有配置，会导致丢失部分没有从master传递过来的日志事务

二、Master : Server down

2.1 etl 延迟8小时

 同1.1 结论

2.2 slave(候选master)比etl还要落后更多

• 2.2.1 当master的部分日志还没传递两个slave，这时候master server挂了

### 3台DB的GTID状态

* master host_2

dba:lc> show master status;
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| File                | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                                                                        |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| host_1.000008 |     5445 |              |                  | 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-50,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446392 |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

* slave host_1

           Retrieved_Gtid_Set:
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-50,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446385
                Auto_Position: 1



* etl host_3

           Retrieved_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:46-50,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:446386-446388
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-50,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446388
                Auto_Position: 1




### 模拟故障场景

* 隔离master的网络，让其等同于down机

master> iptables -A INPUT -p tcp -s monitor_ip --dport 22 -j ACCEPT
master> iptables -A INPUT -p tcp -s 0.0.0.0/0 -j DROP

### 切换日志


masterha_master_switch --global_conf=/data/online/agent/MHA/conf/masterha_default.cnf --conf=/data/online/agent/MHA/conf/bak_mha_test.cnf  --dead_master_host=host_2  --dead_master_port=3306 --master_state=dead --interactive=0 --ignore_last_failover --ignore_binlog_server_error


Fri Nov 10 11:12:38 2017 - [info] MHA::MasterFailover version 0.56.
Fri Nov 10 11:12:38 2017 - [info] Starting master failover.
Fri Nov 10 11:12:38 2017 - [info]
Fri Nov 10 11:12:38 2017 - [info] * Phase 1: Configuration Check Phase..
Fri Nov 10 11:12:38 2017 - [info]
Fri Nov 10 11:13:28 2017 - [warning] HealthCheck: Got timeout on checking SSH connection to host_2! at /usr/share/perl5/vendor_perl/MHA/HealthCheck.pm line 342.
Fri Nov 10 11:13:28 2017 - [warning] Failed to SSH to binlog server host_2
Fri Nov 10 11:13:29 2017 - [info] HealthCheck: SSH to host_1 is reachable.
Fri Nov 10 11:13:29 2017 - [info] Binlog server host_1 is reachable.
Fri Nov 10 11:13:29 2017 - [info] HealthCheck: SSH to host_3 is reachable.
Fri Nov 10 11:13:29 2017 - [info] Binlog server host_3 is reachable.
Fri Nov 10 11:13:29 2017 - [warning] SQL Thread is stopped(no error) on host_1(host_1:3306)
Fri Nov 10 11:13:29 2017 - [warning] SQL Thread is stopped(no error) on host_3(host_3:3306)
Fri Nov 10 11:13:29 2017 - [info] GTID failover mode = 1
Fri Nov 10 11:13:29 2017 - [info] Dead Servers:
Fri Nov 10 11:13:29 2017 - [info]   host_2(host_2:3306)
Fri Nov 10 11:13:29 2017 - [info] Checking master reachability via MySQL(double check)...
Fri Nov 10 11:13:30 2017 - [info]  ok.
Fri Nov 10 11:13:30 2017 - [info] Alive Servers:
Fri Nov 10 11:13:30 2017 - [info]   host_1(host_1:3306)
Fri Nov 10 11:13:30 2017 - [info]   host_3(host_3:3306)
Fri Nov 10 11:13:30 2017 - [info] Alive Slaves:
Fri Nov 10 11:13:30 2017 - [info]   host_1(host_1:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Fri Nov 10 11:13:30 2017 - [info]     GTID ON
Fri Nov 10 11:13:30 2017 - [info]     Replicating from host_2(host_2:3306)
Fri Nov 10 11:13:30 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Fri Nov 10 11:13:30 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Fri Nov 10 11:13:30 2017 - [info]     GTID ON
Fri Nov 10 11:13:30 2017 - [info]     Replicating from host_2(host_2:3306)
Fri Nov 10 11:13:30 2017 - [info]     Not candidate for the new Master (no_master is set)
Fri Nov 10 11:13:30 2017 - [info]  Starting SQL thread on host_1(host_1:3306) ..
Fri Nov 10 11:13:30 2017 - [info]   done.
Fri Nov 10 11:13:30 2017 - [info]  Starting SQL thread on host_3(host_3:3306) ..
Fri Nov 10 11:13:30 2017 - [info]   done.
Fri Nov 10 11:13:30 2017 - [info] Starting GTID based failover.
Fri Nov 10 11:13:30 2017 - [info]
Fri Nov 10 11:13:30 2017 - [info] ** Phase 1: Configuration Check Phase completed.
Fri Nov 10 11:13:30 2017 - [info]
Fri Nov 10 11:13:30 2017 - [info] * Phase 2: Dead Master Shutdown Phase..
Fri Nov 10 11:13:30 2017 - [info]
Fri Nov 10 11:14:20 2017 - [warning] HealthCheck: Got timeout on checking SSH connection to host_2! at /usr/share/perl5/vendor_perl/MHA/HealthCheck.pm line 342.
Fri Nov 10 11:14:20 2017 - [info] Forcing shutdown so that applications never connect to the current master..
Fri Nov 10 11:14:20 2017 - [info] Executing master IP deactivation script:
Fri Nov 10 11:14:20 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --orig_master_host=host_2 --orig_master_ip=host_2 --orig_master_port=3306 --command=stop
ssh: connect to host host_2 port 22: Connection timed out
===================    swift vip :  vip from host_2 is deleted  ==============================


--2017-11-10 11:14:27--  http://tgw_server/cgi-bin/fun_logic/bin/public_api/op_rs.cgi
正在连接 tgw_server:80... 已连接。
已发出 HTTP 请求，正在等待回应... 200 OK
长度：未指定 [text/html]
正在保存至: “STDOUT”

     0K                                                        11.4M=0s

2017-11-10 11:16:27 (11.4 MB/s) - 已写入标准输出 [38]

Fri Nov 10 11:16:27 2017 - [info]  done.
Fri Nov 10 11:16:27 2017 - [warning] shutdown_script is not set. Skipping explicit shutting down of the dead master.
Fri Nov 10 11:16:27 2017 - [info] * Phase 2: Dead Master Shutdown Phase completed.
Fri Nov 10 11:16:27 2017 - [info]
Fri Nov 10 11:16:27 2017 - [info] * Phase 3: Master Recovery Phase..
Fri Nov 10 11:16:27 2017 - [info]
Fri Nov 10 11:16:27 2017 - [info] * Phase 3.1: Getting Latest Slaves Phase..
Fri Nov 10 11:16:27 2017 - [info]
Fri Nov 10 11:16:27 2017 - [info] The latest binary log file/position on all slaves is host_1.000008:4265
Fri Nov 10 11:16:27 2017 - [info] Retrieved Gtid Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:46-50,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:446386-446388
Fri Nov 10 11:16:27 2017 - [info] Latest slaves (Slaves that received relay log files to the latest):
Fri Nov 10 11:16:27 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Fri Nov 10 11:16:27 2017 - [info]     GTID ON
Fri Nov 10 11:16:27 2017 - [info]     Replicating from host_2(host_2:3306)
Fri Nov 10 11:16:27 2017 - [info]     Not candidate for the new Master (no_master is set)
Fri Nov 10 11:16:27 2017 - [info] The oldest binary log file/position on all slaves is host_1.000008:3380
Fri Nov 10 11:16:27 2017 - [info] Oldest slaves:
Fri Nov 10 11:16:27 2017 - [info]   host_1(host_1:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Fri Nov 10 11:16:27 2017 - [info]     GTID ON
Fri Nov 10 11:16:27 2017 - [info]     Replicating from host_2(host_2:3306)
Fri Nov 10 11:16:27 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Fri Nov 10 11:16:27 2017 - [info]
Fri Nov 10 11:16:27 2017 - [info] * Phase 3.3: Determining New Master Phase..
Fri Nov 10 11:16:27 2017 - [info]
Fri Nov 10 11:16:27 2017 - [info] Searching new master from slaves..
Fri Nov 10 11:16:27 2017 - [info]  Candidate masters from the configuration file:
Fri Nov 10 11:16:27 2017 - [info]   host_1(host_1:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Fri Nov 10 11:16:27 2017 - [info]     GTID ON
Fri Nov 10 11:16:27 2017 - [info]     Replicating from host_2(host_2:3306)
Fri Nov 10 11:16:27 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Fri Nov 10 11:16:27 2017 - [info]  Non-candidate masters:
Fri Nov 10 11:16:27 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Fri Nov 10 11:16:27 2017 - [info]     GTID ON
Fri Nov 10 11:16:27 2017 - [info]     Replicating from host_2(host_2:3306)
Fri Nov 10 11:16:27 2017 - [info]     Not candidate for the new Master (no_master is set)
Fri Nov 10 11:16:27 2017 - [info]  Searching from candidate_master slaves which have received the latest relay log events..
Fri Nov 10 11:16:27 2017 - [info]   Not found.
Fri Nov 10 11:16:27 2017 - [info]  Searching from all candidate_master slaves..
Fri Nov 10 11:16:27 2017 - [info] New master is host_1(host_1:3306)
Fri Nov 10 11:16:27 2017 - [info] Starting master failover..
Fri Nov 10 11:16:27 2017 - [info]
From:
host_2(host_2:3306) (current master)
 +--host_1(host_1:3306)
 +--host_3(host_3:3306)

To:
host_1(host_1:3306) (new master)
 +--host_3(host_3:3306)
Fri Nov 10 11:16:27 2017 - [info]
Fri Nov 10 11:16:27 2017 - [info] * Phase 3.3: New Master Recovery Phase..
Fri Nov 10 11:16:27 2017 - [info]
Fri Nov 10 11:16:27 2017 - [info]  Waiting all logs to be applied..
Fri Nov 10 11:16:27 2017 - [info]   done.
Fri Nov 10 11:16:27 2017 - [info]  Replicating from the latest slave host_3(host_3:3306) and waiting to apply..
Fri Nov 10 11:16:27 2017 - [info]  Waiting all logs to be applied on the latest slave..
Fri Nov 10 11:16:27 2017 - [info]  Resetting slave host_1(host_1:3306) and starting replication from the new master host_3(host_3:3306)..
Fri Nov 10 11:16:27 2017 - [info]  Executed CHANGE MASTER.
Fri Nov 10 11:16:28 2017 - [info]  Slave started.
Fri Nov 10 11:16:28 2017 - [info]  Waiting to execute all relay logs on host_1(host_1:3306)..
Fri Nov 10 11:16:28 2017 - [info]  master_pos_wait(host_3.000049:40136) completed on host_1(host_1:3306). Executed 0 events.
Fri Nov 10 11:16:28 2017 - [info]   done.
Fri Nov 10 11:16:28 2017 - [info]   done.
Fri Nov 10 11:16:28 2017 - [info] -- Saving binlog from host host_2 started, pid: 43038
Fri Nov 10 11:16:28 2017 - [info] -- Saving binlog from host host_1 started, pid: 43039
Fri Nov 10 11:16:28 2017 - [info] -- Saving binlog from host host_3 started, pid: 43041
Fri Nov 10 11:16:28 2017 - [info]
Fri Nov 10 11:16:28 2017 - [info] Log messages from host_2 ...
Fri Nov 10 11:16:28 2017 - [info] End of log messages from host_2.
Fri Nov 10 11:16:28 2017 - [warning] SSH is not reachable on host_2. Skipping
Fri Nov 10 11:16:28 2017 - [info]
Fri Nov 10 11:16:28 2017 - [info] Log messages from host_1 ...
Fri Nov 10 11:16:28 2017 - [info]
Fri Nov 10 11:16:28 2017 - [info] Fetching binary logs from binlog server host_1..
Fri Nov 10 11:16:28 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=host_1.000008  --start_pos=4265 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog2_20171110111238.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Failed to save binary log: Binlog not found from /data/mysql.bin! If you got this error at MHA Manager, please set "master_binlog_dir=/path/to/binlog_directory_of_the_master" correctly in the MHA Manager's configuration file and try again.
 at /usr/bin/save_binary_logs line 123
    eval {...} called at /usr/bin/save_binary_logs line 70
    main::main() called at /usr/bin/save_binary_logs line 66
Fri Nov 10 11:16:28 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Fri Nov 10 11:16:28 2017 - [info] End of log messages from host_1.
Fri Nov 10 11:16:28 2017 - [warning] Got error from host_1.
Fri Nov 10 11:16:28 2017 - [info]
Fri Nov 10 11:16:28 2017 - [info] Log messages from host_3 ...
Fri Nov 10 11:16:28 2017 - [info]
Fri Nov 10 11:16:28 2017 - [info] Fetching binary logs from binlog server host_3..
Fri Nov 10 11:16:28 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=host_1.000008  --start_pos=4265 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog3_20171110111238.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Failed to save binary log: Binlog not found from /data/mysql.bin! If you got this error at MHA Manager, please set "master_binlog_dir=/path/to/binlog_directory_of_the_master" correctly in the MHA Manager's configuration file and try again.
 at /usr/bin/save_binary_logs line 123
    eval {...} called at /usr/bin/save_binary_logs line 70
    main::main() called at /usr/bin/save_binary_logs line 66
Fri Nov 10 11:16:28 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Fri Nov 10 11:16:28 2017 - [info] End of log messages from host_3.
Fri Nov 10 11:16:28 2017 - [warning] Got error from host_3.
Fri Nov 10 11:16:28 2017 - [info] Getting new master's binlog name and position..
Fri Nov 10 11:16:28 2017 - [info]  tjtx-126-164.000058:4059
Fri Nov 10 11:16:28 2017 - [info]  All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST='host_1', MASTER_PORT=3306, MASTER_AUTO_POSITION=1, MASTER_USER='repl', MASTER_PASSWORD='xxx';
Fri Nov 10 11:16:28 2017 - [info] Master Recovery succeeded. File:Pos:Exec_Gtid_Set: tjtx-126-164.000058, 4059, 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-50,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446388
Fri Nov 10 11:16:28 2017 - [info] Executing master IP activate script:
Fri Nov 10 11:16:28 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --command=start --ssh_user=root --orig_master_host=host_2 --orig_master_ip=host_2 --orig_master_port=3306 --new_master_host=host_1 --new_master_ip=host_1 --new_master_port=3306 --new_master_user='xxx' --new_master_password='xxx'
Unknown option: new_master_user
Unknown option: new_master_password
===================    swift vip :  vip to host_1  is added  ==============================


Fri Nov 10 11:16:30 2017 - [info]  OK.
Fri Nov 10 11:16:30 2017 - [info] ** Finished master recovery successfully.
Fri Nov 10 11:16:30 2017 - [info] * Phase 3: Master Recovery Phase completed.
Fri Nov 10 11:16:30 2017 - [info]
Fri Nov 10 11:16:30 2017 - [info] * Phase 4: Slaves Recovery Phase..
Fri Nov 10 11:16:30 2017 - [info]
Fri Nov 10 11:16:30 2017 - [info]
Fri Nov 10 11:16:30 2017 - [info] * Phase 4.1: Starting Slaves in parallel..
Fri Nov 10 11:16:30 2017 - [info]
Fri Nov 10 11:16:30 2017 - [info] -- Slave recovery on host host_3(host_3:3306) started, pid: 46878. Check tmp log /var/log/masterha/mha_test/host_3_3306_20171110111238.log if it takes time..
Fri Nov 10 11:16:31 2017 - [info]
Fri Nov 10 11:16:31 2017 - [info] Log messages from host_3 ...
Fri Nov 10 11:16:31 2017 - [info]
Fri Nov 10 11:16:30 2017 - [info]  Resetting slave host_3(host_3:3306) and starting replication from the new master host_1(host_1:3306)..
Fri Nov 10 11:16:30 2017 - [info]  Executed CHANGE MASTER.
Fri Nov 10 11:16:31 2017 - [info]  Slave started.
Fri Nov 10 11:16:31 2017 - [info]  gtid_wait(0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-50,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446388) completed on host_3(host_3:3306). Executed 0 events.
Fri Nov 10 11:16:31 2017 - [info] End of log messages from host_3.
Fri Nov 10 11:16:31 2017 - [info] -- Slave on host host_3(host_3:3306) started.
Fri Nov 10 11:16:31 2017 - [info] All new slave servers recovered successfully.
Fri Nov 10 11:16:31 2017 - [info]
Fri Nov 10 11:16:31 2017 - [info] * Phase 5: New master cleanup phase..
Fri Nov 10 11:16:31 2017 - [info]
Fri Nov 10 11:16:31 2017 - [info] Resetting slave info on the new master..
Fri Nov 10 11:16:31 2017 - [info]  host_1: Resetting slave info succeeded.
Fri Nov 10 11:16:31 2017 - [info] Master failover to host_1(host_1:3306) completed successfully.
Fri Nov 10 11:16:31 2017 - [info]

----- Failover Report -----

bak_mha_test: MySQL Master failover host_2(host_2:3306) to host_1(host_1:3306) succeeded

Master host_2(host_2:3306) is down!

Check MHA Manager logs at tjtx135-2-217.58os.org:/var/log/masterha/mha_test/mha_test.log for details.

Started automated(non-interactive) failover.
Invalidated master IP address on host_2(host_2:3306)
Selected host_1(host_1:3306) as a new master.
host_1(host_1:3306): OK: Applying all logs succeeded.
host_1(host_1:3306): OK: Activated master IP address.
host_3(host_3:3306): OK: Slave started, replicating from host_1(host_1:3306)
host_1(host_1:3306): Resetting slave info succeeded.
Master failover to host_1(host_1:3306) completed successfully.
Fri Nov 10 11:16:31 2017 - [info] Sending mail..


### 最后一步很重要

如果dead master之后又活过来了，那么这一步要做

dead_master> /usr/local/realserver/RS_TUNL0/etc/setup_rs.sh -c

http://gitlab.corp.anjuke.com/_dba/architecture/blob/master/personal/Keithlan/other/share/tools/always_used_command.md  ==》 tgw章节详细描述

结论： 由于master 已挂，然而最后的日志没有传递到其他服务器，所以会丢失master没有传递过来的事务日志
好在，slave和etl之间会互相change master，所以尽管slave（candidate master）的日志落后，最终也还是用etl的日志补齐了slave缺失的日志。

• 2.2.2 当master的所有日志已经传递到1个etl，这时候master server挂了

测试省略，和2.2.1基本一样

结论：由于master上的所有日志全部传递到etl，所以最后是不会丢失master上任何数据的。

2.3 slave(候选master)的日志是最新的，比etl要多

• 2.3.1 当master的部分日志还没传递两个slave，这时候master server挂了

测试省略，和2.2.1基本一样

结论： 由于master 已挂，然而最后的日志没有传递到其他服务器，所以会丢失master没有传递过来的事务日志
好在，slave和etl之间会互相change master，所以尽管slave（candidate master）的日志落后，最终也还是用etl的日志补齐了slave缺失的日志。

• 2.3.2 当master的所有日志已经传递slave，这时候master server挂了

测试省略，和2.2.1基本一样

结论：由于master上的所有日志全部传递到slave，所以最后是不会丢失master上任何数据的。

2.4 slave(候选master）上面有大事务在跑

• 1000s的大查询

同1.4结论

• flush tables with readlock

同1.4结论

2.5 binlog server 不同场景的测试

dead_master上的最后部分日志没有传递到slave和etl的情况, 然而slave的日志也落后etl （这是最严苛的情况）

• binlog server 写3台

2.2.1 测试的就是这种情况，详细日志切换请看2.2.1

结论： 由于binlog server配置了3台，但是由于master server已经挂掉，无法从master的binlog server上获取日志，所以会丢失master上没有传递的日志事务

• binlog server 只写master

### 3台DB的gtid 状态

* master host_1

dba:lc> show master status;
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| File                | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                                                                        |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| tjtx-126-164.000058 |     8517 |              |                  | 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-60,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446392 |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)


* slave host_2

           Retrieved_Gtid_Set:
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-50,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446392
                Auto_Position: 1


* etl host_3

           Retrieved_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:51-55,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:446389-446392
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-55,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446392
                Auto_Position: 1



### 模拟故障

master> iptables -A INPUT -p tcp -s monitor_ip --dport 22 -j ACCEPT
master> iptables -A INPUT -p tcp -s 0.0.0.0/0 -j DROP


### 故障切换

masterha_master_switch --global_conf=/data/online/agent/MHA/conf/masterha_default.cnf --conf=/data/online/agent/MHA/conf/bak_mha_test.cnf  --dead_master_host=host_1  --dead_master_port=3306 --master_state=dead --interactive=0 --ignore_last_failover --ignore_binlog_server_error

Fri Nov 10 14:15:51 2017 - [info] MHA::MasterFailover version 0.56.
Fri Nov 10 14:15:51 2017 - [info] Starting master failover.
Fri Nov 10 14:15:51 2017 - [info]
Fri Nov 10 14:15:51 2017 - [info] * Phase 1: Configuration Check Phase..
Fri Nov 10 14:15:51 2017 - [info]
Fri Nov 10 14:16:41 2017 - [warning] HealthCheck: Got timeout on checking SSH connection to host_1! at /usr/share/perl5/vendor_perl/MHA/HealthCheck.pm line 342.
Fri Nov 10 14:16:41 2017 - [warning] Failed to SSH to binlog server host_1
Fri Nov 10 14:16:41 2017 - [error][/usr/share/perl5/vendor_perl/MHA/ServerManager.pm, ln239] Binlog Server is defined but there is no alive server.
Fri Nov 10 14:16:41 2017 - [error][/usr/share/perl5/vendor_perl/MHA/ManagerUtil.pm, ln177] Got ERROR:  at /usr/share/perl5/vendor_perl/MHA/MasterFailover.pm line 2082

结论： binlog server 必须要配置一个活的 server，如果只配置master，如果master挂了，那么就等于一个都没有，MHA不会切换

• binlog server 只写slave

### 3台DB的gtid 状态

* master host_1

dba:lc> show master status;
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| File                | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                                                                        |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
| tjtx-126-164.000058 |     8517 |              |                  | 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-60,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446392 |
+---------------------+----------+--------------+------------------+------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)


* slave host_2

           Retrieved_Gtid_Set:
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-50,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446392
                Auto_Position: 1


* etl host_3

           Retrieved_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:51-55,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:446389-446392
            Executed_Gtid_Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-55,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446392
                Auto_Position: 1



### 模拟故障

master> iptables -A INPUT -p tcp -s monitor_ip --dport 22 -j ACCEPT
master> iptables -A INPUT -p tcp -s 0.0.0.0/0 -j DROP


### 故障切换

Fri Nov 10 14:29:50 2017 - [info] MHA::MasterFailover version 0.56.
Fri Nov 10 14:29:50 2017 - [info] Starting master failover.
Fri Nov 10 14:29:50 2017 - [info]
Fri Nov 10 14:29:50 2017 - [info] * Phase 1: Configuration Check Phase..
Fri Nov 10 14:29:50 2017 - [info]
Fri Nov 10 14:29:50 2017 - [info] HealthCheck: SSH to host_2 is reachable.
Fri Nov 10 14:29:50 2017 - [info] Binlog server host_2 is reachable.
Fri Nov 10 14:29:50 2017 - [info] HealthCheck: SSH to host_3 is reachable.
Fri Nov 10 14:29:50 2017 - [info] Binlog server host_3 is reachable.
Fri Nov 10 14:29:50 2017 - [warning] SQL Thread is stopped(no error) on host_2(host_2:3306)
Fri Nov 10 14:29:50 2017 - [warning] SQL Thread is stopped(no error) on host_3(host_3:3306)
Fri Nov 10 14:29:50 2017 - [info] GTID failover mode = 1
Fri Nov 10 14:29:50 2017 - [info] Dead Servers:
Fri Nov 10 14:29:50 2017 - [info]   host_1(host_1:3306)
Fri Nov 10 14:29:50 2017 - [info] Checking master reachability via MySQL(double check)...
Fri Nov 10 14:29:51 2017 - [info]  ok.
Fri Nov 10 14:29:51 2017 - [info] Alive Servers:
Fri Nov 10 14:29:51 2017 - [info]   host_2(host_2:3306)
Fri Nov 10 14:29:51 2017 - [info]   host_3(host_3:3306)
Fri Nov 10 14:29:51 2017 - [info] Alive Slaves:
Fri Nov 10 14:29:51 2017 - [info]   host_2(host_2:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Fri Nov 10 14:29:51 2017 - [info]     GTID ON
Fri Nov 10 14:29:51 2017 - [info]     Replicating from host_1(host_1:3306)
Fri Nov 10 14:29:51 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Fri Nov 10 14:29:51 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Fri Nov 10 14:29:51 2017 - [info]     GTID ON
Fri Nov 10 14:29:51 2017 - [info]     Replicating from host_1(host_1:3306)
Fri Nov 10 14:29:51 2017 - [info]     Not candidate for the new Master (no_master is set)
Fri Nov 10 14:29:51 2017 - [info]  Starting SQL thread on host_2(host_2:3306) ..
Fri Nov 10 14:29:51 2017 - [info]   done.
Fri Nov 10 14:29:51 2017 - [info]  Starting SQL thread on host_3(host_3:3306) ..
Fri Nov 10 14:29:52 2017 - [info]   done.
Fri Nov 10 14:29:52 2017 - [info] Starting GTID based failover.
Fri Nov 10 14:29:52 2017 - [info]
Fri Nov 10 14:29:52 2017 - [info] ** Phase 1: Configuration Check Phase completed.
Fri Nov 10 14:29:52 2017 - [info]
Fri Nov 10 14:29:52 2017 - [info] * Phase 2: Dead Master Shutdown Phase..
Fri Nov 10 14:29:52 2017 - [info]
Fri Nov 10 14:30:42 2017 - [warning] HealthCheck: Got timeout on checking SSH connection to host_1! at /usr/share/perl5/vendor_perl/MHA/HealthCheck.pm line 342.
Fri Nov 10 14:30:42 2017 - [info] Forcing shutdown so that applications never connect to the current master..
Fri Nov 10 14:30:42 2017 - [info] Executing master IP deactivation script:
Fri Nov 10 14:30:42 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --orig_master_host=host_1 --orig_master_ip=host_1 --orig_master_port=3306 --command=stop
ssh: connect to host host_1 port 22: Connection timed out
===================    swift vip :  vip from host_1 is deleted  ==============================


--2017-11-10 14:30:49--  http://tgw_server/cgi-bin/fun_logic/bin/public_api/op_rs.cgi
正在连接 tgw_server:80... 已连接。
已发出 HTTP 请求，正在等待回应... 200 OK
长度：未指定 [text/html]
正在保存至: “STDOUT”

     0K                                                        12.1M=0s

2017-11-10 14:32:47 (12.1 MB/s) - 已写入标准输出 [38]

Fri Nov 10 14:32:47 2017 - [info]  done.
Fri Nov 10 14:32:47 2017 - [warning] shutdown_script is not set. Skipping explicit shutting down of the dead master.
Fri Nov 10 14:32:47 2017 - [info] * Phase 2: Dead Master Shutdown Phase completed.
Fri Nov 10 14:32:47 2017 - [info]
Fri Nov 10 14:32:47 2017 - [info] * Phase 3: Master Recovery Phase..
Fri Nov 10 14:32:47 2017 - [info]
Fri Nov 10 14:32:47 2017 - [info] * Phase 3.1: Getting Latest Slaves Phase..
Fri Nov 10 14:32:47 2017 - [info]
Fri Nov 10 14:32:47 2017 - [info] The latest binary log file/position on all slaves is tjtx-126-164.000058:6912
Fri Nov 10 14:32:47 2017 - [info] Retrieved Gtid Set: 0923e916-3c36-11e6-82a5-ecf4bbf1f518:51-55,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:446389-446392
Fri Nov 10 14:32:47 2017 - [info] Latest slaves (Slaves that received relay log files to the latest):
Fri Nov 10 14:32:47 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Fri Nov 10 14:32:47 2017 - [info]     GTID ON
Fri Nov 10 14:32:47 2017 - [info]     Replicating from host_1(host_1:3306)
Fri Nov 10 14:32:47 2017 - [info]     Not candidate for the new Master (no_master is set)
Fri Nov 10 14:32:47 2017 - [info] The oldest binary log file/position on all slaves is tjtx-126-164.000058:5307
Fri Nov 10 14:32:47 2017 - [info] Oldest slaves:
Fri Nov 10 14:32:47 2017 - [info]   host_2(host_2:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Fri Nov 10 14:32:47 2017 - [info]     GTID ON
Fri Nov 10 14:32:47 2017 - [info]     Replicating from host_1(host_1:3306)
Fri Nov 10 14:32:47 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Fri Nov 10 14:32:47 2017 - [info]
Fri Nov 10 14:32:47 2017 - [info] * Phase 3.3: Determining New Master Phase..
Fri Nov 10 14:32:47 2017 - [info]
Fri Nov 10 14:32:47 2017 - [info] Searching new master from slaves..
Fri Nov 10 14:32:47 2017 - [info]  Candidate masters from the configuration file:
Fri Nov 10 14:32:47 2017 - [info]   host_2(host_2:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Fri Nov 10 14:32:47 2017 - [info]     GTID ON
Fri Nov 10 14:32:47 2017 - [info]     Replicating from host_1(host_1:3306)
Fri Nov 10 14:32:47 2017 - [info]     Primary candidate for the new Master (candidate_master is set)
Fri Nov 10 14:32:47 2017 - [info]  Non-candidate masters:
Fri Nov 10 14:32:47 2017 - [info]   host_3(host_3:3306)  Version=5.7.13-log (oldest major version between slaves) log-bin:enabled
Fri Nov 10 14:32:47 2017 - [info]     GTID ON
Fri Nov 10 14:32:47 2017 - [info]     Replicating from host_1(host_1:3306)
Fri Nov 10 14:32:47 2017 - [info]     Not candidate for the new Master (no_master is set)
Fri Nov 10 14:32:47 2017 - [info]  Searching from candidate_master slaves which have received the latest relay log events..
Fri Nov 10 14:32:47 2017 - [info]   Not found.
Fri Nov 10 14:32:47 2017 - [info]  Searching from all candidate_master slaves..
Fri Nov 10 14:32:47 2017 - [info] New master is host_2(host_2:3306)
Fri Nov 10 14:32:47 2017 - [info] Starting master failover..
Fri Nov 10 14:32:47 2017 - [info]
From:
host_1(host_1:3306) (current master)
 +--host_2(host_2:3306)
 +--host_3(host_3:3306)

To:
host_2(host_2:3306) (new master)
 +--host_3(host_3:3306)
Fri Nov 10 14:32:47 2017 - [info]
Fri Nov 10 14:32:47 2017 - [info] * Phase 3.3: New Master Recovery Phase..
Fri Nov 10 14:32:47 2017 - [info]
Fri Nov 10 14:32:47 2017 - [info]  Waiting all logs to be applied..
Fri Nov 10 14:32:47 2017 - [info]   done.
Fri Nov 10 14:32:47 2017 - [info]  Replicating from the latest slave host_3(host_3:3306) and waiting to apply..
Fri Nov 10 14:32:47 2017 - [info]  Waiting all logs to be applied on the latest slave..
Fri Nov 10 14:32:47 2017 - [info]  Resetting slave host_2(host_2:3306) and starting replication from the new master host_3(host_3:3306)..
Fri Nov 10 14:32:47 2017 - [info]  Executed CHANGE MASTER.
Fri Nov 10 14:32:48 2017 - [info]  Slave started.
Fri Nov 10 14:32:48 2017 - [info]  Waiting to execute all relay logs on host_2(host_2:3306)..
Fri Nov 10 14:32:48 2017 - [info]  master_pos_wait(host_3.000049:42954) completed on host_2(host_2:3306). Executed 0 events.
Fri Nov 10 14:32:48 2017 - [info]   done.
Fri Nov 10 14:32:48 2017 - [info]   done.
Fri Nov 10 14:32:48 2017 - [info] -- Saving binlog from host host_2 started, pid: 76664
Fri Nov 10 14:32:48 2017 - [info] -- Saving binlog from host host_3 started, pid: 76665
Fri Nov 10 14:32:48 2017 - [info]
Fri Nov 10 14:32:48 2017 - [info] Log messages from host_2 ...
Fri Nov 10 14:32:48 2017 - [info]
Fri Nov 10 14:32:48 2017 - [info] Fetching binary logs from binlog server host_2..
Fri Nov 10 14:32:48 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=tjtx-126-164.000058  --start_pos=6912 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog1_20171110142950.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Failed to save binary log: Binlog not found from /data/mysql.bin! If you got this error at MHA Manager, please set "master_binlog_dir=/path/to/binlog_directory_of_the_master" correctly in the MHA Manager's configuration file and try again.
 at /usr/bin/save_binary_logs line 123
    eval {...} called at /usr/bin/save_binary_logs line 70
    main::main() called at /usr/bin/save_binary_logs line 66
Fri Nov 10 14:32:48 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Fri Nov 10 14:32:48 2017 - [info] End of log messages from host_2.
Fri Nov 10 14:32:48 2017 - [warning] Got error from host_2.
Fri Nov 10 14:32:48 2017 - [info]
Fri Nov 10 14:32:48 2017 - [info] Log messages from host_3 ...
Fri Nov 10 14:32:48 2017 - [info]
Fri Nov 10 14:32:48 2017 - [info] Fetching binary logs from binlog server host_3..
Fri Nov 10 14:32:48 2017 - [info] Executing binlog save command: save_binary_logs --command=save --start_file=tjtx-126-164.000058  --start_pos=6912 --output_file=/var/log/masterha/mha_test/saved_binlog_binlog3_20171110142950.binlog --handle_raw_binlog=0 --skip_filter=1 --disable_log_bin=0 --manager_version=0.56 --oldest_version=5.7.13-log  --binlog_dir=/data/mysql.bin
Failed to save binary log: Binlog not found from /data/mysql.bin! If you got this error at MHA Manager, please set "master_binlog_dir=/path/to/binlog_directory_of_the_master" correctly in the MHA Manager's configuration file and try again.
 at /usr/bin/save_binary_logs line 123
    eval {...} called at /usr/bin/save_binary_logs line 70
    main::main() called at /usr/bin/save_binary_logs line 66
Fri Nov 10 14:32:48 2017 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln660] Failed to save binary log events from the binlog server. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Fri Nov 10 14:32:48 2017 - [info] End of log messages from host_3.
Fri Nov 10 14:32:48 2017 - [warning] Got error from host_3.
Fri Nov 10 14:32:48 2017 - [info] Getting new master's binlog name and position..
Fri Nov 10 14:32:48 2017 - [info]  host_1.000008:6895
Fri Nov 10 14:32:48 2017 - [info]  All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST='host_2', MASTER_PORT=3306, MASTER_AUTO_POSITION=1, MASTER_USER='repl', MASTER_PASSWORD='xxx';
Fri Nov 10 14:32:48 2017 - [info] Master Recovery succeeded. File:Pos:Exec_Gtid_Set: host_1.000008, 6895, 0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-55,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446392
Fri Nov 10 14:32:48 2017 - [info] Executing master IP activate script:
Fri Nov 10 14:32:48 2017 - [info]   /data/online/agent/MHA/masterha/bak_mha_test/master_ip_failover_mha_test --command=start --ssh_user=root --orig_master_host=host_1 --orig_master_ip=host_1 --orig_master_port=3306 --new_master_host=host_2 --new_master_ip=host_2 --new_master_port=3306 --new_master_user='xxx' --new_master_password='xxx'
Unknown option: new_master_user
Unknown option: new_master_password
===================    swift vip :  vip to host_2  is added  ==============================


Fri Nov 10 14:32:51 2017 - [info]  OK.
Fri Nov 10 14:32:51 2017 - [info] ** Finished master recovery successfully.
Fri Nov 10 14:32:51 2017 - [info] * Phase 3: Master Recovery Phase completed.
Fri Nov 10 14:32:51 2017 - [info]
Fri Nov 10 14:32:51 2017 - [info] * Phase 4: Slaves Recovery Phase..
Fri Nov 10 14:32:51 2017 - [info]
Fri Nov 10 14:32:51 2017 - [info]
Fri Nov 10 14:32:51 2017 - [info] * Phase 4.1: Starting Slaves in parallel..
Fri Nov 10 14:32:51 2017 - [info]
Fri Nov 10 14:32:51 2017 - [info] -- Slave recovery on host host_3(host_3:3306) started, pid: 80398. Check tmp log /var/log/masterha/mha_test/host_3_3306_20171110142950.log if it takes time..
Fri Nov 10 14:32:52 2017 - [info]
Fri Nov 10 14:32:52 2017 - [info] Log messages from host_3 ...
Fri Nov 10 14:32:52 2017 - [info]
Fri Nov 10 14:32:51 2017 - [info]  Resetting slave host_3(host_3:3306) and starting replication from the new master host_2(host_2:3306)..
Fri Nov 10 14:32:51 2017 - [info]  Executed CHANGE MASTER.
Fri Nov 10 14:32:52 2017 - [info]  Slave started.
Fri Nov 10 14:32:52 2017 - [info]  gtid_wait(0923e916-3c36-11e6-82a5-ecf4bbf1f518:1-55,
ebd9ff93-c5b2-11e6-b21d-ecf4bbf1f42c:1-446392) completed on host_3(host_3:3306). Executed 0 events.
Fri Nov 10 14:32:52 2017 - [info] End of log messages from host_3.
Fri Nov 10 14:32:52 2017 - [info] -- Slave on host host_3(host_3:3306) started.
Fri Nov 10 14:32:52 2017 - [info] All new slave servers recovered successfully.
Fri Nov 10 14:32:52 2017 - [info]
Fri Nov 10 14:32:52 2017 - [info] * Phase 5: New master cleanup phase..
Fri Nov 10 14:32:52 2017 - [info]
Fri Nov 10 14:32:52 2017 - [info] Resetting slave info on the new master..
Fri Nov 10 14:32:52 2017 - [info]  host_2: Resetting slave info succeeded.
Fri Nov 10 14:32:52 2017 - [info] Master failover to host_2(host_2:3306) completed successfully.
Fri Nov 10 14:32:52 2017 - [info]

----- Failover Report -----

bak_mha_test: MySQL Master failover host_1(host_1:3306) to host_2(host_2:3306) succeeded

Master host_1(host_1:3306) is down!

Check MHA Manager logs at tjtx135-2-217.58os.org:/var/log/masterha/mha_test/mha_test.log for details.

Started automated(non-interactive) failover.
Invalidated master IP address on host_1(host_1:3306)
Selected host_2(host_2:3306) as a new master.
host_2(host_2:3306): OK: Applying all logs succeeded.
host_2(host_2:3306): OK: Activated master IP address.
host_3(host_3:3306): OK: Slave started, replicating from host_2(host_2:3306)
host_2(host_2:3306): Resetting slave info succeeded.
Master failover to host_2(host_2:3306) completed successfully.
Fri Nov 10 14:32:52 2017 - [info] Sending mail..

结论： binlog server 配置成多台slave，这是正确的方案。 由于master 挂了，master没有传递过来的binlog会丢失，这是没办法的. 好在，其余slave自动补齐现有日志

• binlog server 啥都不写

会切换成功，由于master 挂了，master没有传递过来的binlog会丢失

好在，其余slave自动补齐现有日志

2.6 如果MHA过程中失败，是否可以重新执行MHA的failover呢？

同1.6结论

三、遇到的坑

3.1 交互模式下，如果没有及时敲'YES'，则终止切换

四、总结

MHA + GTID 模式，重点配置和用法如下：

1. command
masterha_master_switch --global_conf=/data/online/agent/MHA/conf/masterha_default.cnf --conf=/data/online/agent/MHA/conf/bak_mha_test.cnf  --dead_master_host=host_1  --dead_master_port=3306 --master_state=dead --interactive=0 --ignore_last_failover --ignore_binlog_server_error


2. binlog server

在配置文件中对 master，slave，etl 都写在binlog server中。对MySQL down 和 DB server down  综合考虑下，建议这样配置。


3. tgw 清理

dead master 如果还可以起来，那么必须在上面执行： /usr/local/realserver/RS_TUNL0/etc/setup_rs.sh -c

原因可参看：http://gitlab.corp.anjuke.com/_dba/architecture/blob/master/personal/Keithlan/other/share/tools/always_used_command.md ==> TGW 章节

本文为云栖社区原创内容，未经允许不得转载，如需转载请发送邮件至yqeditor@list.alibaba-inc.com；如果您发现本社区中有涉嫌抄袭的内容，欢迎发送邮件至：yqgroup@service.aliyun.com 进行举报，并提供相关证据，一经查实，本社区将立刻删除涉嫌侵权内容