本文主要在MHA 切换日志的角度分析MHA切换的过。MHA故障切换过程如下图所示
第一部分：开启MHA 监控
通过分析日志，得到以下步骤：
1、读取MHA manager 节点的配置文件，并检查配置文件中参数设置的正确性。
Sat Jun :: - [warning] Global configuration file /etc/masterha_default.cnf not found. Skipping.
Sat Jun :: - [info] Reading application default configuration from /etc/masterha/app1.conf..
Sat Jun :: - [info] Reading server configuration from /etc/masterha/app1.conf.. #找到manager的 配置文件
Creating /tmp if not exists.. ok.
Checking output directory is accessible or not..
ok.
Binlog found at /usr/local/mysql/data, up to mysql_bin.000024 #根据配置文件，找到主库binlog
Sat Jun :: - [warning] Global configuration file /etc/masterha_default.cnf not found. Skipping.
Sat Jun :: - [info] Reading application default configuration from /etc/masterha/app1.conf..
Sat Jun :: - [info] Reading server configuration from /etc/masterha/app1.conf.. #通过配置文件找到当前的主从架构
Sat Jun :: - [info] 172.16.13.15(172.16.13.15:) Version=5.7.-log (oldest major version between slaves) log-bin:enabled
Sat Jun :: - [info] Replicating from 172.16.15.3(172.16.15.3:)
Sat Jun :: - [info] Primary candidate for the new Master (candidate_master is set)
Sat Jun :: - [info] 172.16.15.2(172.16.15.2:) Version=5.7.-log (oldest major version between slaves) log-bin:enabled
Sat Jun :: - [info] Replicating from 172.16.15.3(172.16.15.3:)
Sat Jun :: - [info] Current Alive Master: 172.16.15.3(172.16.15.3:) #找到当前的主库
2、检查从库的配置，判断 slave 是否对某些数据库或表进行过滤
Sat Jun :: - [info] Checking slave configurations..
Sat Jun :: - [info] Checking replication filtering(过滤) settings..
Sat Jun :: - [info] binlog_do_db= , binlog_ignore_db=
Sat Jun :: - [info] Replication filtering check ok.
3、检查是否支持GTID主从，MHA Node版本，SSH连接测试，测试主库上的恢复脚本
Sat Jun :: - [info] GTID (with auto-pos) is not supported
Sat Jun :: - [info] Starting SSH connection tests..
Sat Jun :: - [info] All SSH connection tests passed successfully. Sat Jun :: - [info] Checking MHA Node version..
Sat Jun :: - [info] Version check ok. Sat Jun :: - [info] Checking SSH publickey authentication settings on the current master..
Sat Jun :: - [info] HealthCheck: SSH to 172.16.15.3 is reachable.
Sat Jun :: - [info] Master MHA Node version is 0.56.
Sat Jun :: - [info] Checking recovery script configurations on 172.16.15.3(172.16.15.3:)..
Sat Jun :: - [info] Executing command: save_binary_logs --command=test --start_pos= --binlog_dir=/usr/local/mysql/data --output_file=/tmp/save_binary_logs_test --manager_version=0.56 --start_file=mysql_bin.
4、分别通过SSH连接到主库和从库，检查binlog和relay log，测试应用差异日志的脚本是否正常，测试MySQL连接和权限
Sat Jun :: - [info] Connecting to root@172.16.15.3(172.16.15.3:)..
Creating /tmp if not exists.. ok.
Checking output directory is accessible or not..
ok.
Binlog found at /usr/local/mysql/data, up to mysql_bin.
Sat Jun :: - [info] Binlog setting check done.
Sat Jun :: - [info] Checking SSH publickey authentication and checking recovery script configurations on all alive slave servers..
Sat Jun :: - [info] Executing command : apply_diff_relay_logs --command=test --slave_user='root' --slave_host=172.16.13.15 --slave_ip=172.16.13.15 --slave_port= --workdir=/tmp --target_version=5.7.-log --manager_version=0.56 --relay_log_info=/usr/local/mysql/data/relay-log.info --relay_dir=/usr/local/mysql/data/ --slave_pass=xxx Sat Jun :: - [info] Connecting to root@172.16.13.15(172.16.13.15:)..
Checking slave recovery environment settings..
Opening /usr/local/mysql/data/relay-log.info ... ok.
Relay log found at /usr/local/mysql/data, up to mysqlserver-relay-bin.
Temporary relay log file is /usr/local/mysql/data/mysqlserver-relay-bin.
Testing mysql connection and privileges.. done.
Testing mysqlbinlog output.. done.
Cleaning up test file(s).. done.
Sat Jun :: - [info] Executing command : apply_diff_relay_logs --command=test --slave_user='root' --slave_host=172.16.15.2 --slave_ip=172.16.15.2 --slave_port= --workdir=/tmp --target_version=5.7.-log --manager_version=0.56 --relay_log_info=/usr/local/mysql/data/relay-log.info --relay_dir=/usr/local/mysql/data/ --slave_pass=xxx Sat Jun :: - [info] Connecting to root@172.16.15.2(172.16.15.2:)..
Checking slave recovery environment settings..
Opening /usr/local/mysql/data/relay-log.info ... ok.
Relay log found at /usr/local/mysql/data, up to A2-relay-bin.
Temporary relay log file is /usr/local/mysql/data/A2-relay-bin.
Testing mysql connection and privileges.. done.
Testing mysqlbinlog output.. done.
Cleaning up test file(s).. done.
Sat Jun :: - [info] Slaves settings check done.
5、得到主从架构信息，检查 master_ip_failover_script脚本是否正常。开始监控主库master 的运行情况
Sat Jun :: - [info]
172.16.15.3(172.16.15.3:) (current master)
+--172.16.13.15(172.16.13.15:)
+--172.16.15.2(172.16.15.2:) Sat Jun :: - [info] Checking master_ip_failover_script status:
Sat Jun :: - [info] /var/log/masterha/scripts/master_ip_failover --command=status --ssh_user=root --orig_master_host=172.16.15.3 --orig_master_ip=172.16.15.3 --orig_master_port=
Checking the Status of the script.. OK
Sat Jun :: - [info] OK.
Sat Jun :: - [warning] shutdown_script is not defined.
Sat Jun :: - [info] Set master ping interval seconds.
Sat Jun :: - [warning] secondary_check_script is not defined. It is highly recommended setting it to check master reachability from two or more routes.
Sat Jun :: - [info] Starting ping health check on 172.16.15.3(172.16.15.3:)..
Sat Jun :: - [info] Ping(SELECT) succeeded, waiting until MySQL doesn't respond..
第二部分：故障切换分析
1、发现主库故障，测试和主库的SSH连接，连续多次确认主库状态。根据配置文件信息，检查所有主机的状态
Sat Jun :: - [warning] Got error on MySQL select ping: (MySQL server has gone away)
Sat Jun :: - [info] Executing SSH check script: save_binary_logs --command=test --start_pos= --binlog_dir=/usr/local/mysql/data --output_file=/tmp/save_binary_logs_test --manager_version=0.56 --binlog_prefix=mysql_bin
Sat Jun :: - [info] HealthCheck: SSH to 172.16.15.3 is reachable.
Sat Jun :: - [warning] Got error on MySQL connect: (Lost connection to MySQL server at 'reading initial communication packet', system error: )
Sat Jun :: - [warning] Connection failed time(s)..
Sat Jun :: - [warning] Got error on MySQL connect: (Lost connection to MySQL server at 'reading initial communication packet', system error: )
Sat Jun :: - [warning] Connection failed time(s)..
Sat Jun :: - [warning] Got error on MySQL connect: (Lost connection to MySQL server at 'reading initial communication packet', system error: )
Sat Jun :: - [warning] Connection failed time(s)..
Sat Jun :: - [warning] Master is not reachable from health checker!
Sat Jun :: - [warning] Master 172.16.15.3(172.16.15.3:) is not reachable!
Sat Jun :: - [warning] SSH is reachable. Sat Jun :: - [info] Connecting to a master server failed. Reading configuration file /etc/masterha_default.cnf and /etc/masterha/app1.conf again, and trying to connect to all servers to check server status..
Sat Jun :: - [warning] Global configuration file /etc/masterha_default.cnf not found. Skipping.
Sat Jun :: - [info] Reading application default configuration from /etc/masterha/app1.conf..
Sat Jun :: - [info] Reading server configuration from /etc/masterha/app1.conf..
Sat Jun :: - [info] GTID failover mode =
Sat Jun :: - [info] Dead Servers:
Sat Jun :: - [info] 172.16.15.3(172.16.15.3:)
Sat Jun :: - [info] Alive Servers:
Sat Jun :: - [info] 172.16.13.15(172.16.13.15:)
Sat Jun :: - [info] 172.16.15.2(172.16.15.2:)
Sat Jun :: - [info] Alive Slaves:
Sat Jun :: - [info] 172.16.13.15(172.16.13.15:) Version=5.7.-log (oldest major version between slaves) log-bin:enabled
Sat Jun :: - [info] Replicating from 172.16.15.3(172.16.15.3:)
Sat Jun :: - [info] Primary candidate for the new Master (candidate_master is set)
Sat Jun :: - [info] 172.16.15.2(172.16.15.2:) Version=5.7.-log (oldest major version between slaves) log-bin:enabled
Sat Jun :: - [info] Replicating from 172.16.15.3(172.16.15.3:)
2、检查从库配置，MHA Node版本，再次确认Master 不可用
Sat Jun :: - [info] Checking slave configurations..
Sat Jun :: - [info] Checking replication filtering settings..
Sat Jun :: - [info] Replication filtering check ok. Sat Jun :: - [info] Master is down!
Sat Jun :: - [info] Terminating monitoring script.
Sat Jun :: - [info] Got exit code (Master dead).
Sat Jun :: - [info] MHA::MasterFailover version 0.56.
3、开始故障切换 Starting master failover
Phase 1: Configuration Check Phase..配置检查（得到当前主机状态）
Sat Jun :: - [info] Starting master failover.
Sat Jun :: - [info]
Sat Jun :: - [info] * Phase : Configuration Check Phase..
Sat Jun :: - [info]
Sat Jun :: - [info] GTID failover mode =
Sat Jun :: - [info] Dead Servers:
Sat Jun :: - [info] 172.16.15.3(172.16.15.3:)
Sat Jun :: - [info] Checking master reachability via MySQL(double check)...
Sat Jun :: - [info] ok.
Sat Jun :: - [info] Alive Servers:
Sat Jun :: - [info] 172.16.13.15(172.16.13.15:)
Sat Jun :: - [info] 172.16.15.2(172.16.15.2:)
Sat Jun :: - [info] Alive Slaves:
Sat Jun :: - [info] 172.16.13.15(172.16.13.15:) Version=5.7.-log (oldest major version between slaves) log-bin:enabled
Sat Jun :: - [info] Replicating from 172.16.15.3(172.16.15.3:)
Sat Jun :: - [info] Primary candidate for the new Master (candidate_master is set)
Sat Jun :: - [info] 172.16.15.2(172.16.15.2:) Version=5.7.-log (oldest major version between slaves) log-bin:enabled
Sat Jun :: - [info] Replicating from 172.16.15.3(172.16.15.3:)
Sat Jun :: - [info] Starting Non-GTID based failover.
Sat Jun :: - [info]
Sat Jun :: - [info] ** Phase : Configuration Check Phase completed.
Sat Jun :: - [info]
Phase 2: Dead Master Shutdown Phase..尝试关闭从库（将虚拟IP关掉，并尝试启动shutdown脚本）
Sat Jun :: - [info] * Phase : Dead Master Shutdown Phase..
Sat Jun :: - [info]
Sat Jun :: - [info] Forcing shutdown so that applications never connect to the current master..
Sat Jun :: - [info] Executing master IP deactivation script:
Sat Jun :: - [info] /var/log/masterha/scripts/master_ip_failover --orig_master_host=172.16.15.3 --orig_master_ip=172.16.15.3 --orig_master_port= --command=stopssh --ssh_user=root ***************************************************************
Disabling the VIP - 172.16.13.141/ on old master: 172.16.15.3
*************************************************************** Sat Jun :: - [info] done.
Sat Jun :: - [warning] shutdown_script is not set. Skipping explicit shutting down of the dead master.
Sat Jun :: - [info] * Phase : Dead Master Shutdown Phase completed.
Sat Jun :: - [info]
Phase 3: Master Recovery Phase..
Phase 3.1: Getting Latest Slaves Phase..得到距离旧主binlog最近（least slave）和最远的binlog位置
Sat Jun :: - [info] * Phase : Master Recovery Phase..
Sat Jun :: - [info]
Sat Jun :: - [info] * Phase 3.1: Getting Latest Slaves Phase..
Sat Jun :: - [info]
Sat Jun :: - [info] The latest binary log file/position on all slaves is mysql_bin.:
Sat Jun :: - [info] Latest slaves (Slaves that received relay log files to the latest):
Sat Jun :: - [info] 172.16.13.15(172.16.13.15:) Version=5.7.-log (oldest major version between slaves) log-bin:enabled
Sat Jun :: - [info] Replicating from 172.16.15.3(172.16.15.3:)
Sat Jun :: - [info] Primary candidate for the new Master (candidate_master is set)
Sat Jun :: - [info] 172.16.15.2(172.16.15.2:) Version=5.7.-log (oldest major version between slaves) log-bin:enabled
Sat Jun :: - [info] Replicating from 172.16.15.3(172.16.15.3:)
Sat Jun :: - [info] The oldest binary log file/position on all slaves is mysql_bin.:
Sat Jun :: - [info] Oldest slaves:
Sat Jun :: - [info] 172.16.13.15(172.16.13.15:) Version=5.7.-log (oldest major version between slaves) log-bin:enabled
Sat Jun :: - [info] Replicating from 172.16.15.3(172.16.15.3:)
Sat Jun :: - [info] Primary candidate for the new Master (candidate_master is set)
Sat Jun :: - [info] 172.16.15.2(172.16.15.2:) Version=5.7.-log (oldest major version between slaves) log-bin:enabled
Sat Jun :: - [info] Replicating from 172.16.15.3(172.16.15.3:)
Sat Jun :: - [info]
Phase 3.2: Saving Dead Master's Binlog Phase..保存（截取）旧主库的binlog和从库最接近（least slave）的这段 binlog，保存到 tmp目录
Sat Jun :: - [info] * Phase 3.2: Saving Dead Master's Binlog Phase..
Sat Jun :: - [info]
Sat Jun :: - [info] Fetching dead master's binary logs..
Sat Jun :: - [info] Executing command on the dead master 172.16.15.3(172.16.15.3:): save_binary_logs --command=save --start_file=mysql_bin. --start_pos= --binlog_dir=/usr/local/mysql/data --output_file=/tmp/saved_master_binlog_from_172.16.15.3_3306_20190622201810.binlog --handle_raw_binlog= --disable_log_bin= --manager_version=0.56
Creating /tmp if not exists.. ok.
Concat binary/relay logs from mysql_bin. pos to mysql_bin. EOF into /tmp/saved_master_binlog_from_172.16.15.3_3306_20190622201810.binlog ..
Binlog Checksum enabled
Dumping binlog format description event, from position to .. ok.
No need to dump effective binlog data from /usr/local/mysql/data/mysql_bin. (pos starts , filesize ). Skipping.
Binlog Checksum enabled
/tmp/saved_master_binlog_from_172.16.15.3_3306_20190622201810.binlog has no effective data events.
Event not exists.
Sat Jun :: - [info] Additional events were not found from the orig master. No need to save.
Phase 3.3: Determining New Master Phase..决定提升新的主库
Phase 3.3: New Master Diff Log Generation Phase..生成新主和最新least binlog 之间的差异日志文件
Sat Jun :: - [info] * Phase 3.3: Determining New Master Phase..
Sat Jun :: - [info]
Sat Jun :: - [info] Finding the latest slave that has all relay logs for recovering other slaves..
Sat Jun :: - [info] All slaves received relay logs to the same position. No need to resync each other.
Sat Jun :: - [info] Searching new master from slaves..
Sat Jun :: - [info] Candidate masters from the configuration file:
Sat Jun :: - [info] 172.16.13.15(172.16.13.15:) Version=5.7.-log (oldest major version between slaves) log-bin:enabled
Sat Jun :: - [info] Replicating from 172.16.15.3(172.16.15.3:)
Sat Jun :: - [info] Primary candidate for the new Master (candidate_master is set)
Sat Jun :: - [info] Non-candidate masters:
Sat Jun :: - [info] Searching from candidate_master slaves which have received the latest relay log events..
Sat Jun :: - [info] New master is 172.16.13.15(172.16.13.15:)
Sat Jun :: - [info] Starting master failover..
Sat Jun :: - [info]
From:
172.16.15.3(172.16.15.3:) (current master)
+--172.16.13.15(172.16.13.15:)
+--172.16.15.2(172.16.15.2:) To:
172.16.13.15(172.16.13.15:) (new master)
+--172.16.15.2(172.16.15.2:)
Sat Jun :: - [info]
Sat Jun :: - [info] * Phase 3.3: New Master Diff Log Generation Phase..
Sat Jun :: - [info]
Sat Jun :: - [info] This server has all relay logs. No need to generate diff files from the latest slave.
Sat Jun :: - [info]
Phase 3.4: Master Log Apply Phase..新的主库应用日志（包括新主与least slave之间的差异日志和least slave与旧主之间的日志），使新主到达和旧主一致的状态，得到新的主库的binlog name和position，用于后面在新的从库上执行 change master to，指向新的主库
在新的主库上面开启虚拟IP
Sat Jun :: - [info] * Phase 3.4: Master Log Apply Phase..
Sat Jun :: - [info]
Sat Jun :: - [info] *NOTICE: If any error happens from this phase, manual recovery is needed.
Sat Jun :: - [info] Starting recovery on 172.16.13.15(172.16.13.15:)..
Sat Jun :: - [info] This server has all relay logs. Waiting all logs to be applied..
Sat Jun :: - [info] done.
Sat Jun :: - [info] All relay logs were successfully applied.
Sat Jun :: - [info] Getting new master's binlog name and position..
Sat Jun :: - [info] mysql_bin.:
Sat Jun :: - [info] All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST='172.16.13.15', MASTER_PORT=, MASTER_LOG_FILE='mysql_bin.000056', MASTER_LOG_POS=, MASTER_USER='root', MASTER_PASSWORD='xxx';
Sat Jun :: - [info] Executing master IP activate script:
Sat Jun :: - [info] /var/log/masterha/scripts/master_ip_failover --command=start --ssh_user=root --orig_master_host=172.16.15.3 --orig_master_ip=172.16.15.3 --orig_master_port= --new_master_host=172.16.13.15 --new_master_ip=172.16.13.15 --new_master_port= --new_master_user='root' --new_master_password=''
Unknown option: new_master_user
Unknown option: new_master_password ***************************************************************
Enabling the VIP - 172.16.13.141/ on new master: 172.16.13.15
*************************************************************** Sat Jun :: - [info] OK.
Sat Jun :: - [info] Setting read_only= on 172.16.13.15(172.16.13.15:)..
Sat Jun :: - [info] ok.
Sat Jun :: - [info] ** Finished master recovery successfully.
Sat Jun :: - [info] * Phase : Master Recovery Phase completed.
Sat Jun :: - [info]
至此，新的主库恢复完成
Phase 4: Slaves Recovery Phase..开始进行从库的恢复
Phase 4.1: Starting Parallel Slave Diff Log Generation Phase..并行生成各个从库和least slave之间的差异日志
Sat Jun :: - [info] * Phase : Slaves Recovery Phase..
Sat Jun :: - [info]
Sat Jun :: - [info] * Phase 4.1: Starting Parallel Slave Diff Log Generation Phase..
Sat Jun :: - [info]
Sat Jun :: - [info] -- Slave diff file generation on host 172.16.15.2(172.16.15.2:) started, pid: . Check tmp log /var/log/masterha/app1/172.16..2_3306_20190622201810.log if it takes time..
Sat Jun :: - [info]
Sat Jun :: - [info] Log messages from 172.16.15.2 ...
Sat Jun :: - [info]
Sat Jun :: - [info] This server has all relay logs. No need to generate diff files from the latest slave.
Sat Jun :: - [info] End of log messages from 172.16.15.2.
Sat Jun :: - [info] -- 172.16.15.2(172.16.15.2:) has the latest relay log events.
Sat Jun :: - [info] Generating relay diff files from the latest slave succeeded.
Sat Jun :: - [info]
Phase 4.2: Starting Parallel Slave Log Apply Phase..从库并行应用日志（包括从库与least slave之间的差异日志和least slave与旧主之间的差异日志）
执行change master to，使新从库指向新的主库
Sat Jun :: - [info] * Phase 4.2: Starting Parallel Slave Log Apply Phase..
Sat Jun :: - [info]
Sat Jun :: - [info] -- Slave recovery on host 172.16.15.2(172.16.15.2:) started, pid: . Check tmp log /var/log/masterha/app1/172.16..2_3306_20190622201810.log if it takes time..
Sat Jun :: - [info]
Sat Jun :: - [info] Log messages from 172.16.15.2 ...
Sat Jun :: - [info]
Sat Jun :: - [info] Starting recovery on 172.16.15.2(172.16.15.2:)..
Sat Jun :: - [info] This server has all relay logs. Waiting all logs to be applied..
Sat Jun :: - [info] done.
Sat Jun :: - [info] All relay logs were successfully applied.
Sat Jun :: - [info] Resetting slave 172.16.15.2(172.16.15.2:) and starting replication from the new master 172.16.13.15(172.16.13.15:)..
Sat Jun :: - [info] Executed CHANGE MASTER.
Sat Jun :: - [info] Slave started.
Sat Jun :: - [info] End of log messages from 172.16.15.2.
Sat Jun :: - [info] -- Slave recovery on host 172.16.15.2(172.16.15.2:) succeeded.
Sat Jun :: - [info] All new slave servers recovered successfully.
Phase 5: New master cleanup phase..在新的主库上重新设置slave信息
Sat Jun :: - [info] * Phase : New master cleanup phase..
Sat Jun :: - [info]
Sat Jun :: - [info] Resetting slave info on the new master..
Sat Jun :: - [info] 172.16.13.15: Resetting slave info succeeded.
Sat Jun :: - [info] Master failover to 172.16.13.15(172.16.13.15:) completed successfully.
Sat Jun :: - [info]
生成故障切换报告
----- Failover Report ----- app1: MySQL Master failover 172.16.15.3(172.16.15.3:) to 172.16.13.15(172.16.13.15:) succeeded Master 172.16.15.3(172.16.15.3:) is down! Check MHA Manager logs at A2:/var/log/masterha/app1/manager.log for details. Started automated(non-interactive) failover.
Invalidated master IP address on 172.16.15.3(172.16.15.3:)
The latest slave 172.16.13.15(172.16.13.15:) has all relay logs for recovery.
Selected 172.16.13.15(172.16.13.15:) as a new master.
172.16.13.15(172.16.13.15:): OK: Applying all logs succeeded.
172.16.13.15(172.16.13.15:): OK: Activated master IP address.
172.16.15.2(172.16.15.2:): This host has the latest relay log events.
Generating relay diff files from the latest slave succeeded.
172.16.15.2(172.16.15.2:): OK: Applying all logs succeeded. Slave started, replicating from 172.16.13.15(172.16.13.15:)
172.16.13.15(172.16.13.15:): Resetting slave info succeeded.
Master failover to 172.16.13.15(172.16.13.15:) completed successfully.