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