MHA 主从切换过程及日志分析

本文主要在MHA 切换日志的角度分析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 root@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 root@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 root@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.

 

上一篇:补充实验6:tftp


下一篇:Jun