Sun Mar 15 14:01:19 2020 - [info] Connecting to a master server failed. Reading configuration file /etc/masterha_default.cnf and /etc/mha/mha.conf again, and trying to connect to all servers to check server status..
Sun Mar 15 14:01:19 2020 - [warning] Global configuration file /etc/masterha_default.cnf not found. Skipping.
Sun Mar 15 14:01:19 2020 - [info] Reading application default configuration from /etc/mha/mha.conf..
Sun Mar 15 14:01:19 2020 - [info] Reading server configuration from /etc/mha/mha.conf..
Sun Mar 15 14:01:20 2020 - [info] GTID failover mode = 0
Sun Mar 15 14:01:20 2020 - [info] Dead Servers:
Sun Mar 15 14:01:20 2020 - [info] rac1(192.168.2.187:3306)
Sun Mar 15 14:01:20 2020 - [info] Alive Servers:
Sun Mar 15 14:01:20 2020 - [info] rac2(192.168.2.188:3306)
Sun Mar 15 14:01:20 2020 - [info] rac3(192.168.2.223:3306)
Sun Mar 15 14:01:20 2020 - [info] Alive Slaves:
Sun Mar 15 14:01:20 2020 - [info] rac2(192.168.2.188:3306) Version=5.7.28-log (oldest major version between slaves) log-bin:enabled
Sun Mar 15 14:01:20 2020 - [info] Replicating from 192.168.2.187(192.168.2.187:3306)
Sun Mar 15 14:01:20 2020 - [info] Primary candidate for the new Master (candidate_master is set)
Sun Mar 15 14:01:20 2020 - [info] rac3(192.168.2.223:3306) Version=5.7.28-log (oldest major version between slaves) log-bin:enabled
Sun Mar 15 14:01:20 2020 - [info] Replicating from 192.168.2.187(192.168.2.187:3306)
Sun Mar 15 14:01:20 2020 - [info] Not candidate for the new Master (no_master is set)
Sun Mar 15 14:01:20 2020 - [info] Checking slave configurations..
Sun Mar 15 14:01:20 2020 - [warning] relay_log_purge=0 is not set on slave rac2(192.168.2.188:3306).
Sun Mar 15 14:01:20 2020 - [warning] relay_log_purge=0 is not set on slave rac3(192.168.2.223:3306).
Sun Mar 15 14:01:20 2020 - [info] Checking replication filtering settings..
Sun Mar 15 14:01:20 2020 - [info] Replication filtering check ok.
Sun Mar 15 14:01:20 2020 - [info] Master is down!
Sun Mar 15 14:01:20 2020 - [info] Terminating monitoring script.
Sun Mar 15 14:01:20 2020 - [info] Got exit code 20 (Master dead).
---(3) MasterFailover配置文件确认
Sun Mar 15 14:01:20 2020 - [info] MHA::MasterFailover version 0.56.
Sun Mar 15 14:01:20 2020 - [info] Starting master failover.
Sun Mar 15 14:01:20 2020 - [info]
Sun Mar 15 14:01:20 2020 - [info] * Phase 1: Configuration Check Phase..
Sun Mar 15 14:01:20 2020 - [info]
Sun Mar 15 14:01:22 2020 - [info] GTID failover mode = 0
Sun Mar 15 14:01:22 2020 - [info] Dead Servers:
Sun Mar 15 14:01:22 2020 - [info] rac1(192.168.2.187:3306)
Sun Mar 15 14:01:22 2020 - [info] Checking master reachability via MySQL(double check)...
Sun Mar 15 14:01:22 2020 - [info] ok.
Sun Mar 15 14:01:22 2020 - [info] Alive Servers:
Sun Mar 15 14:01:22 2020 - [info] rac2(192.168.2.188:3306)
Sun Mar 15 14:01:22 2020 - [info] rac3(192.168.2.223:3306)
Sun Mar 15 14:01:22 2020 - [info] Alive Slaves:
Sun Mar 15 14:01:22 2020 - [info] rac2(192.168.2.188:3306) Version=5.7.28-log (oldest major version between slaves) log-bin:enabled
Sun Mar 15 14:01:22 2020 - [info] Replicating from 192.168.2.187(192.168.2.187:3306)
Sun Mar 15 14:01:22 2020 - [info] Primary candidate for the new Master (candidate_master is set)
Sun Mar 15 14:01:22 2020 - [info] rac3(192.168.2.223:3306) Version=5.7.28-log (oldest major version between slaves) log-bin:enabled
Sun Mar 15 14:01:22 2020 - [info] Replicating from 192.168.2.187(192.168.2.187:3306)
Sun Mar 15 14:01:22 2020 - [info] Not candidate for the new Master (no_master is set)
Sun Mar 15 14:01:22 2020 - [info] Starting Non-GTID based failover.
Sun Mar 15 14:01:22 2020 - [info]
---(4) 禁用rac1上的VIP,停止rac1
没有定义shutdown_script，所以没有调用
Sun Mar 15 14:01:22 2020 - [info] ** Phase 1: Configuration Check Phase completed.
Sun Mar 15 14:01:22 2020 - [info]
Sun Mar 15 14:01:22 2020 - [info] * Phase 2: Dead Master Shutdown Phase..
Sun Mar 15 14:01:22 2020 - [info]
Sun Mar 15 14:01:22 2020 - [info] Forcing shutdown so that applications never connect to the current master..
Sun Mar 15 14:01:22 2020 - [info] Executing master IP deactivation script:
Sun Mar 15 14:01:22 2020 - [info] /etc/mha/script/master_ip_failover --orig_master_host=rac1 --orig_master_ip=192.168.2.187 --orig_master_port=3306 --command=stopssh --ssh_user=root
Disabling the VIP an old master: rac1
---禁用VIP失败了(估计是网卡设置有问题)
SIOCSIFFLAGS: Cannot assign requested address
Sun Mar 15 14:01:22 2020 - [info] done.
Sun Mar 15 14:01:22 2020 - [warning] shutdown_script is not set. Skipping explicit shutting down of the dead master.
Sun Mar 15 14:01:22 2020 - [info] * Phase 2: Dead Master Shutdown Phase completed.
Sun Mar 15 14:01:22 2020 - [info]
---(5)主库恢复获取最新的slave
Sun Mar 15 14:01:22 2020 - [info] * Phase 3: Master Recovery Phase..
Sun Mar 15 14:01:22 2020 - [info]
Sun Mar 15 14:01:22 2020 - [info] * Phase 3.1: Getting Latest Slaves Phase..
Sun Mar 15 14:01:22 2020 - [info]
Sun Mar 15 14:01:22 2020 - [info] The latest binary log file/position on all slaves is mysql-bin.000015:250
Sun Mar 15 14:01:22 2020 - [info] Latest slaves (Slaves that received relay log files to the latest):
Sun Mar 15 14:01:22 2020 - [info] rac2(192.168.2.188:3306) Version=5.7.28-log (oldest major version between slaves) log-bin:enabled
Sun Mar 15 14:01:22 2020 - [info] Replicating from 192.168.2.187(192.168.2.187:3306)
Sun Mar 15 14:01:22 2020 - [info] Primary candidate for the new Master (candidate_master is set)
Sun Mar 15 14:01:22 2020 - [info] rac3(192.168.2.223:3306) Version=5.7.28-log (oldest major version between slaves) log-bin:enabled
Sun Mar 15 14:01:22 2020 - [info] Replicating from 192.168.2.187(192.168.2.187:3306)
Sun Mar 15 14:01:22 2020 - [info] Not candidate for the new Master (no_master is set)
Sun Mar 15 14:01:22 2020 - [info] The oldest binary log file/position on all slaves is mysql-bin.000015:250
Sun Mar 15 14:01:22 2020 - [info] Oldest slaves:
Sun Mar 15 14:01:22 2020 - [info] rac2(192.168.2.188:3306) Version=5.7.28-log (oldest major version between slaves) log-bin:enabled
Sun Mar 15 14:01:22 2020 - [info] Replicating from 192.168.2.187(192.168.2.187:3306)
Sun Mar 15 14:01:22 2020 - [info] Primary candidate for the new Master (candidate_master is set)
Sun Mar 15 14:01:22 2020 - [info] rac3(192.168.2.223:3306) Version=5.7.28-log (oldest major version between slaves) log-bin:enabled
Sun Mar 15 14:01:22 2020 - [info] Replicating from 192.168.2.187(192.168.2.187:3306)
Sun Mar 15 14:01:22 2020 - [info] Not candidate for the new Master (no_master is set)
Sun Mar 15 14:01:22 2020 - [info]
Sun Mar 15 14:01:22 2020 - [info] * Phase 3.2: Saving Dead Master's Binlog Phase..
Sun Mar 15 14:01:22 2020 - [info]
Sun Mar 15 14:01:22 2020 - [info] Fetching dead master's binary logs..
Sun Mar 15 14:01:22 2020 - [info] Executing command on the dead master rac1(192.168.2.187:3306): save_binary_logs --command=save --start_file=mysql-bin.000015 --start_pos=250 --binlog_dir=/datalog/mysql/binlog --output_file=/etc/mha/node/saved_master_binlog_from_rac1_3306_20200315140120.binlog --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.56
Creating /etc/mha/node if not exists.. ok.
Concat binary/relay logs from mysql-bin.000015 pos 250 to mysql-bin.000015 EOF into /etc/mha/node/saved_master_binlog_from_rac1_3306_20200315140120.binlog ..
Binlog Checksum enabled
Dumping binlog format description event, from position 0 to 250.. ok.
No need to dump effective binlog data from /datalog/mysql/binlog/mysql-bin.000015 (pos starts 250, filesize 250). Skipping.
ERROR: Error in Log_event::read_log_event(): 'Found invalid event in binary log', data_len: 127, event_type: 35
Binlog Checksum enabled
/etc/mha/node/saved_master_binlog_from_rac1_3306_20200315140120.binlog has no effective data events.
Event not exists.
Sun Mar 15 14:01:23 2020 - [info] Additional events were not found from the orig master. No need to save.
Sun Mar 15 14:01:23 2020 - [info]
---(6)决定新的主库188
Sun Mar 15 14:01:23 2020 - [info] * Phase 3.3: Determining New Master Phase..
Sun Mar 15 14:01:23 2020 - [info]
Sun Mar 15 14:01:23 2020 - [info] Finding the latest slave that has all relay logs for recovering other slaves..
Sun Mar 15 14:01:23 2020 - [info] All slaves received relay logs to the same position. No need to resync each other.
Sun Mar 15 14:01:23 2020 - [info] Searching new master from slaves..
Sun Mar 15 14:01:23 2020 - [info] Candidate masters from the configuration file:
Sun Mar 15 14:01:23 2020 - [info] rac2(192.168.2.188:3306) Version=5.7.28-log (oldest major version between slaves) log-bin:enabled
Sun Mar 15 14:01:23 2020 - [info] Replicating from 192.168.2.187(192.168.2.187:3306)
Sun Mar 15 14:01:23 2020 - [info] Primary candidate for the new Master (candidate_master is set)
Sun Mar 15 14:01:23 2020 - [info] Non-candidate masters:
Sun Mar 15 14:01:23 2020 - [info] rac3(192.168.2.223:3306) Version=5.7.28-log (oldest major version between slaves) log-bin:enabled
Sun Mar 15 14:01:23 2020 - [info] Replicating from 192.168.2.187(192.168.2.187:3306)
Sun Mar 15 14:01:23 2020 - [info] Not candidate for the new Master (no_master is set)
Sun Mar 15 14:01:23 2020 - [info] Searching from candidate_master slaves which have received the latest relay log events..
Sun Mar 15 14:01:23 2020 - [info] New master is rac2(192.168.2.188:3306)
Sun Mar 15 14:01:23 2020 - [info] Starting master failover..
Sun Mar 15 14:01:23 2020 - [info]
From:
rac1(192.168.2.187:3306) (current master)
+--rac2(192.168.2.188:3306)
+--rac3(192.168.2.223:3306)
To:
rac2(192.168.2.188:3306) (new master)
+--rac3(192.168.2.223:3306)
Sun Mar 15 14:01:23 2020 - [info]
Sun Mar 15 14:01:23 2020 - [info] * Phase 3.3: New Master Diff Log Generation Phase..
Sun Mar 15 14:01:23 2020 - [info]
Sun Mar 15 14:01:23 2020 - [info] This server has all relay logs. No need to generate diff files from the latest slave.
Sun Mar 15 14:01:23 2020 - [info]
Sun Mar 15 14:01:23 2020 - [info] * Phase 3.4: Master Log Apply Phase..
Sun Mar 15 14:01:23 2020 - [info]
Sun Mar 15 14:01:23 2020 - [info] *NOTICE: If any error happens from this phase, manual recovery is needed.
Sun Mar 15 14:01:23 2020 - [info] Starting recovery on rac2(192.168.2.188:3306)..
Sun Mar 15 14:01:23 2020 - [info] This server has all relay logs. Waiting all logs to be applied..
Sun Mar 15 14:01:23 2020 - [info] done.
Sun Mar 15 14:01:23 2020 - [info] All relay logs were successfully applied.
Sun Mar 15 14:01:23 2020 - [info] Getting new master's binlog name and position..
Sun Mar 15 14:01:23 2020 - [info] mysql-bin.000012:234
Sun Mar 15 14:01:23 2020 - [info] All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST='rac2 or 192.168.2.188', MASTER_PORT=3306, MASTER_LOG_FILE='mysql-bin.000012', MASTER_LOG_POS=234, MASTER_USER='repl', MASTER_PASSWORD='xxx';
Sun Mar 15 14:01:23 2020 - [info] Executing master IP activate script:
Sun Mar 15 14:01:23 2020 - [info] /etc/mha/script/master_ip_failover --command=start --ssh_user=root --orig_master_host=rac1 --orig_master_ip=192.168.2.187 --orig_master_port=3306 --new_master_host=rac2 --new_master_ip=192.168.2.188 --new_master_port=3306 --new_master_user='monitor' --new_master_password='123456'
Set read_only=0 on the new master.
Enabling the VIP 192.168.2.189 on the new master: rac2
Sun Mar 15 14:01:23 2020 - [info] OK.
Sun Mar 15 14:01:23 2020 - [info] ** Finished master recovery successfully.
Sun Mar 15 14:01:23 2020 - [info] * Phase 3: Master Recovery Phase completed.
Sun Mar 15 14:01:23 2020 - [info]
Sun Mar 15 14:01:23 2020 - [info] * Phase 4: Slaves Recovery Phase..
Sun Mar 15 14:01:23 2020 - [info]
Sun Mar 15 14:01:23 2020 - [info] * Phase 4.1: Starting Parallel Slave Diff Log Generation Phase..
Sun Mar 15 14:01:23 2020 - [info]
Sun Mar 15 14:01:23 2020 - [info] -- Slave diff file generation on host rac3(192.168.2.223:3306) started, pid: 10164. Check tmp log /etc/mha/manager/rac3_3306_20200315140120.log if it takes time..
Sun Mar 15 14:01:24 2020 - [info]
Sun Mar 15 14:01:24 2020 - [info] Log messages from rac3 ...
Sun Mar 15 14:01:24 2020 - [info]
Sun Mar 15 14:01:23 2020 - [info] This server has all relay logs. No need to generate diff files from the latest slave.
Sun Mar 15 14:01:24 2020 - [info] End of log messages from rac3.
Sun Mar 15 14:01:24 2020 - [info] -- rac3(192.168.2.223:3306) has the latest relay log events.
Sun Mar 15 14:01:24 2020 - [info] Generating relay diff files from the latest slave succeeded.
Sun Mar 15 14:01:24 2020 - [info]
Sun Mar 15 14:01:24 2020 - [info] * Phase 4.2: Starting Parallel Slave Log Apply Phase..
Sun Mar 15 14:01:24 2020 - [info]
Sun Mar 15 14:01:24 2020 - [info] -- Slave recovery on host rac3(192.168.2.223:3306) started, pid: 10166. Check tmp log /etc/mha/manager/rac3_3306_20200315140120.log if it takes time..
Sun Mar 15 14:01:25 2020 - [info]
Sun Mar 15 14:01:25 2020 - [info] Log messages from rac3 ...
Sun Mar 15 14:01:25 2020 - [info]
Sun Mar 15 14:01:24 2020 - [info] Starting recovery on rac3(192.168.2.223:3306)..
Sun Mar 15 14:01:24 2020 - [info] This server has all relay logs. Waiting all logs to be applied..
Sun Mar 15 14:01:24 2020 - [info] done.
Sun Mar 15 14:01:24 2020 - [info] All relay logs were successfully applied.
Sun Mar 15 14:01:24 2020 - [info] Resetting slave rac3(192.168.2.223:3306) and starting replication from the new master rac2(192.168.2.188:3306)..
Sun Mar 15 14:01:24 2020 - [info] Executed CHANGE MASTER.
Sun Mar 15 14:01:24 2020 - [info] Slave started.
Sun Mar 15 14:01:25 2020 - [info] End of log messages from rac3.
Sun Mar 15 14:01:25 2020 - [info] -- Slave recovery on host rac3(192.168.2.223:3306) succeeded.
Sun Mar 15 14:01:25 2020 - [info] All new slave servers recovered successfully.
Sun Mar 15 14:01:25 2020 - [info]
---(7) 清理阶段
Sun Mar 15 14:01:25 2020 - [info] * Phase 5: New master cleanup phase..
Sun Mar 15 14:01:25 2020 - [info]
Sun Mar 15 14:01:25 2020 - [info] Resetting slave info on the new master..
Sun Mar 15 14:01:25 2020 - [info] rac2: Resetting slave info succeeded.
Sun Mar 15 14:01:25 2020 - [info] Master failover to rac2(192.168.2.188:3306) completed successfully.
Sun Mar 15 14:01:25 2020 - [info] Deleted server1 entry from /etc/mha/mha.conf .
Sun Mar 15 14:01:25 2020 - [info]
---(8) failover报告
----- Failover Report -----
mha: MySQL Master failover rac1(192.168.2.187:3306) to rac2(192.168.2.188:3306) succeeded
Master rac1(192.168.2.187:3306) is down!
Check MHA Manager logs at rac4:/etc/mha/manager/mha.log for details.
Started automated(non-interactive) failover.
Invalidated master IP address on rac1(192.168.2.187:3306)
The latest slave rac2(192.168.2.188:3306) has all relay logs for recovery.
Selected rac2(192.168.2.188:3306) as a new master.
rac2(192.168.2.188:3306): OK: Applying all logs succeeded.
rac2(192.168.2.188:3306): OK: Activated master IP address.
rac3(192.168.2.223:3306): This host has the latest relay log events.
Generating relay diff files from the latest slave succeeded.
rac3(192.168.2.223:3306): OK: Applying all logs succeeded. Slave started, replicating from rac2(192.168.2.188:3306)
rac2(192.168.2.188:3306): Resetting slave info succeeded.
Master failover to rac2(192.168.2.188:3306) completed successfully.
