Tue Aug 28 17:40:16 2018 - [info] Phase 4.1: Starting Parallel Slave Diff Log Generation Phase..
Tue Aug 28 17:40:16 2018 - [info]
Tue Aug 28 17:40:16 2018 - [info] -- Slave diff file generation on host 192.168.10.208(192.168.10.208:3306) started, pid: 13785. Check tmp log /opt/mha/app1/192.168.10.208_3306_20180828174008.log if it takes time..
Tue Aug 28 17:40:17 2018 - [info]
Tue Aug 28 17:40:17 2018 - [info] Log messages from 192.168.10.208 ...
Tue Aug 28 17:40:17 2018 - [info]
Tue Aug 28 17:40:16 2018 - [info] This server has all relay logs. No need to generate diff files from the latest slave.
Tue Aug 28 17:40:17 2018 - [info] End of log messages from 192.168.10.208.
Tue Aug 28 17:40:17 2018 - [info] -- 192.168.10.208(192.168.10.208:3306) has the latest relay log events.
Tue Aug 28 17:40:17 2018 - [info] Generating relay diff files from the latest slave succeeded.
Tue Aug 28 17:40:17 2018 - [info]
Tue Aug 28 17:40:17 2018 - [info] Phase 4.2: Starting Parallel Slave Log Apply Phase..
Tue Aug 28 17:40:17 2018 - [info]
Tue Aug 28 17:40:17 2018 - [info] -- Slave recovery on host 192.168.10.208(192.168.10.208:3306) started, pid: 13787. Check tmp log /opt/mha/app1/192.168.10.208_3306_20180828174008.log if it takes time..
Tue Aug 28 17:50:32 2018 - [error][/usr/local/share/perl5/MHA/Server.pm, ln789] Slave could not be started on 192.168.10.208(192.168.10.208:3306)! Check slave status.
Tue Aug 28 17:50:33 2018 - [info]
Tue Aug 28 17:50:33 2018 - [info] Log messages from 192.168.10.208 ...
Tue Aug 28 17:50:33 2018 - [info]
Tue Aug 28 17:40:17 2018 - [info] Sending binlog..
Tue Aug 28 17:40:18 2018 - [info] scp from local:/opt/mha/app1/saved_master_binlog_from_192.168.10.210_3306_20180828174008.binlog to root@192.168.10.208:/opt/mha/app1/saved_master_binlog_from_192.168.10.210_3306_20180828174008.binlog succeeded.
Tue Aug 28 17:40:19 2018 - [info] Starting recovery on 192.168.10.208(192.168.10.208:3306)..
Tue Aug 28 17:40:19 2018 - [info] Generating diffs succeeded.
Tue Aug 28 17:40:19 2018 - [info] Waiting until all relay logs are applied.
Tue Aug 28 17:40:19 2018 - [info] done.
Tue Aug 28 17:40:19 2018 - [info] Getting slave status..
Tue Aug 28 17:40:19 2018 - [info] This slave(192.168.10.208)'s Exec_Master_Log_Pos equals to Read_Master_Log_Pos(binlog.000002:154). No need to recover from Exec_Master_Log_Pos.
Tue Aug 28 17:40:19 2018 - [info] Connecting to the target slave host 192.168.10.208, running recover script..
Tue Aug 28 17:40:19 2018 - [info] Executing command: apply_diff_relay_logs --command=apply --slave_user='mha' --slave_host=192.168.10.208 --slave_ip=192.168.10.208 --slave_port=3306 --apply_files=/opt/mha/app1/saved_master_binlog_from_192.168.10.210_3306_20180828174008.binlog --workdir=/opt/mha/app1 --target_version=5.7.22-log --timestamp=20180828174008 --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.58 --slave_pass=xxx
Tue Aug 28 17:40:19 2018 - [info]
MySQL client version is 5.7.22. Using --binary-mode.
Applying differential binary/relay log files /opt/mha/app1/saved_master_binlog_from_192.168.10.210_3306_20180828174008.binlog on 192.168.10.208:3306. This may take long time...
Applying log files succeeded.
Tue Aug 28 17:40:19 2018 - [info] All relay logs were successfully applied.
Tue Aug 28 17:40:19 2018 - [info] Resetting slave 192.168.10.208(192.168.10.208:3306) and starting replication from the new master 192.168.10.207(192.168.10.207:3306)..
Tue Aug 28 17:40:20 2018 - [info] Executed CHANGE MASTER.
Tue Aug 28 17:50:32 2018 - [error][/usr/local/share/perl5/MHA/Server.pm, ln867] Starting slave IO/SQL thread on 192.168.10.208(192.168.10.208:3306) failed!
Tue Aug 28 17:50:33 2018 - [info] End of log messages from 192.168.10.208.
Tue Aug 28 17:50:33 2018 - [error][/usr/local/share/perl5/MHA/MasterFailover.pm, ln2045] Master failover to 192.168.10.207(192.168.10.207:3306) done, but recovery on slave partially failed.
Tue Aug 28 17:50:33 2018 - [info]
----- Failover Report -----
app1: MySQL Master failover 192.168.10.210(192.168.10.210:3306) to 192.168.10.207(192.168.10.207:3306)
Master 192.168.10.210(192.168.10.210:3306) is down!
Check MHA Manager logs at mysqldb1:/opt/mha/app1/app1.log for details.
Started automated(non-interactive) failover.
Invalidated master IP address on 192.168.10.210(192.168.10.210:3306)
The latest slave 192.168.10.207(192.168.10.207:3306) has all relay logs for recovery.
Selected 192.168.10.207(192.168.10.207:3306) as a new master.
192.168.10.207(192.168.10.207:3306): OK: Applying all logs succeeded.
192.168.10.207(192.168.10.207:3306): OK: Activated master IP address.
192.168.10.208(192.168.10.208:3306): This host has the latest relay log events.
Generating relay diff files from the latest slave succeeded.
192.168.10.208(192.168.10.208:3306): WARN: Applying all logs succeeded. But starting slave failed.
Master failover to 192.168.10.207(192.168.10.207:3306) done, but recovery on slave partially failed.
Tue Aug 28 17:50:33 2018 - [info] Sending mail..
Aug 28 17:50:34 mysqldb1 sendemail[13832]: Email was sent successfully!
大家好,我在进行MHA故障切换时,并没有成功,报错信息如下,请大师指点,谢谢!
Tue Aug 28 17:40:16 2018 - [info] Phase 4.1: Starting Parallel Slave Diff Log Generation Phase.. Tue Aug 28 17:40:16 2018 - [info] Tue Aug 28 17:40:16 2018 - [info] -- Slave diff file generation on host 192.168.10.208(192.168.10.208:3306) started, pid: 13785. Check tmp log /opt/mha/app1/192.168.10.208_3306_20180828174008.log if it takes time.. Tue Aug 28 17:40:17 2018 - [info] Tue Aug 28 17:40:17 2018 - [info] Log messages from 192.168.10.208 ... Tue Aug 28 17:40:17 2018 - [info] Tue Aug 28 17:40:16 2018 - [info] This server has all relay logs. No need to generate diff files from the latest slave. Tue Aug 28 17:40:17 2018 - [info] End of log messages from 192.168.10.208. Tue Aug 28 17:40:17 2018 - [info] -- 192.168.10.208(192.168.10.208:3306) has the latest relay log events. Tue Aug 28 17:40:17 2018 - [info] Generating relay diff files from the latest slave succeeded. Tue Aug 28 17:40:17 2018 - [info] Tue Aug 28 17:40:17 2018 - [info] Phase 4.2: Starting Parallel Slave Log Apply Phase.. Tue Aug 28 17:40:17 2018 - [info] Tue Aug 28 17:40:17 2018 - [info] -- Slave recovery on host 192.168.10.208(192.168.10.208:3306) started, pid: 13787. Check tmp log /opt/mha/app1/192.168.10.208_3306_20180828174008.log if it takes time..
Tue Aug 28 17:50:32 2018 - [error][/usr/local/share/perl5/MHA/Server.pm, ln789] Slave could not be started on 192.168.10.208(192.168.10.208:3306)! Check slave status. Tue Aug 28 17:50:33 2018 - [info] Tue Aug 28 17:50:33 2018 - [info] Log messages from 192.168.10.208 ... Tue Aug 28 17:50:33 2018 - [info] Tue Aug 28 17:40:17 2018 - [info] Sending binlog.. Tue Aug 28 17:40:18 2018 - [info] scp from local:/opt/mha/app1/saved_master_binlog_from_192.168.10.210_3306_20180828174008.binlog to root@192.168.10.208:/opt/mha/app1/saved_master_binlog_from_192.168.10.210_3306_20180828174008.binlog succeeded. Tue Aug 28 17:40:19 2018 - [info] Starting recovery on 192.168.10.208(192.168.10.208:3306).. Tue Aug 28 17:40:19 2018 - [info] Generating diffs succeeded. Tue Aug 28 17:40:19 2018 - [info] Waiting until all relay logs are applied. Tue Aug 28 17:40:19 2018 - [info] done. Tue Aug 28 17:40:19 2018 - [info] Getting slave status.. Tue Aug 28 17:40:19 2018 - [info] This slave(192.168.10.208)'s Exec_Master_Log_Pos equals to Read_Master_Log_Pos(binlog.000002:154). No need to recover from Exec_Master_Log_Pos. Tue Aug 28 17:40:19 2018 - [info] Connecting to the target slave host 192.168.10.208, running recover script.. Tue Aug 28 17:40:19 2018 - [info] Executing command: apply_diff_relay_logs --command=apply --slave_user='mha' --slave_host=192.168.10.208 --slave_ip=192.168.10.208 --slave_port=3306 --apply_files=/opt/mha/app1/saved_master_binlog_from_192.168.10.210_3306_20180828174008.binlog --workdir=/opt/mha/app1 --target_version=5.7.22-log --timestamp=20180828174008 --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.58 --slave_pass=xxx Tue Aug 28 17:40:19 2018 - [info] MySQL client version is 5.7.22. Using --binary-mode. Applying differential binary/relay log files /opt/mha/app1/saved_master_binlog_from_192.168.10.210_3306_20180828174008.binlog on 192.168.10.208:3306. This may take long time... Applying log files succeeded. Tue Aug 28 17:40:19 2018 - [info] All relay logs were successfully applied. Tue Aug 28 17:40:19 2018 - [info] Resetting slave 192.168.10.208(192.168.10.208:3306) and starting replication from the new master 192.168.10.207(192.168.10.207:3306).. Tue Aug 28 17:40:20 2018 - [info] Executed CHANGE MASTER. Tue Aug 28 17:50:32 2018 - [error][/usr/local/share/perl5/MHA/Server.pm, ln867] Starting slave IO/SQL thread on 192.168.10.208(192.168.10.208:3306) failed! Tue Aug 28 17:50:33 2018 - [info] End of log messages from 192.168.10.208. Tue Aug 28 17:50:33 2018 - [error][/usr/local/share/perl5/MHA/MasterFailover.pm, ln2045] Master failover to 192.168.10.207(192.168.10.207:3306) done, but recovery on slave partially failed. Tue Aug 28 17:50:33 2018 - [info]
----- Failover Report -----
app1: MySQL Master failover 192.168.10.210(192.168.10.210:3306) to 192.168.10.207(192.168.10.207:3306)
Master 192.168.10.210(192.168.10.210:3306) is down!
Check MHA Manager logs at mysqldb1:/opt/mha/app1/app1.log for details.
Started automated(non-interactive) failover. Invalidated master IP address on 192.168.10.210(192.168.10.210:3306) The latest slave 192.168.10.207(192.168.10.207:3306) has all relay logs for recovery. Selected 192.168.10.207(192.168.10.207:3306) as a new master. 192.168.10.207(192.168.10.207:3306): OK: Applying all logs succeeded. 192.168.10.207(192.168.10.207:3306): OK: Activated master IP address. 192.168.10.208(192.168.10.208:3306): This host has the latest relay log events. Generating relay diff files from the latest slave succeeded. 192.168.10.208(192.168.10.208:3306): WARN: Applying all logs succeeded. But starting slave failed. Master failover to 192.168.10.207(192.168.10.207:3306) done, but recovery on slave partially failed. Tue Aug 28 17:50:33 2018 - [info] Sending mail.. Aug 28 17:50:34 mysqldb1 sendemail[13832]: Email was sent successfully!