MHA自动failover测试系列-master主机关机,MHA的切换

环境：
Master：192.168.100.50
Slave1：192.168.100.48
Slave2：192.168.100.141 （MHA管理节点）

[root@test11g ~]# masterha_check_status --conf=/etc/masterha/mha.cnf 
mha (pid:19234) is running(0:PING_OK), master:192.168.100.50

+++master上执行关机命令
[root@goolen ~]# init 0

[root@test11g log]# tail -f mha.log 
Fri Nov 21 16:44:18 2014 - [warning] Got timeout on MySQL Ping(SELECT) child process and killed it! at /usr/share/perl5/vendor_perl/MHA/HealthCheck.pm line 431.
Fri Nov 21 16:44:18 2014 - [info] Executing secondary network check script: /usr/bin/masterha_secondary_check -s coredb -s test11g --user=root --master_host=goolen --master_ip=192.168.100.50 --master_port=3306  --user=root  --master_host=192.168.100.50  --master_ip=192.168.100.50  --master_port=3306 --master_user=root --master_password=root --ping_type=SELECT
Fri Nov 21 16:44:18 2014 - [info] Executing SSH check script: save_binary_logs --command=test --start_pos=4 --binlog_dir=/tol/mysql/binlog --output_file=/tmp/save_binary_logs_test --manager_version=0.56 --binlog_prefix=mysql-bin
Fri Nov 21 16:44:19 2014 - [warning] Got error on MySQL connect: 2003 (Can't connect to MySQL server on '192.168.100.50' (4))
Fri Nov 21 16:44:19 2014 - [warning] Connection failed 2 time(s)..
Fri Nov 21 16:44:20 2014 - [warning] Got error on MySQL connect: 2003 (Can't connect to MySQL server on '192.168.100.50' (4))
Fri Nov 21 16:44:20 2014 - [warning] Connection failed 3 time(s)..
Fri Nov 21 16:44:21 2014 - [warning] Got error on MySQL connect: 2003 (Can't connect to MySQL server on '192.168.100.50' (4))
Fri Nov 21 16:44:21 2014 - [warning] Connection failed 4 time(s)..
Fri Nov 21 16:44:23 2014 - [warning] HealthCheck: Got timeout on checking SSH connection to 192.168.100.50! at /usr/share/perl5/vendor_perl/MHA/HealthCheck.pm line 342.
Monitoring server coredb is reachable, Master is not reachable from coredb. OK.
Monitoring server test11g is reachable, Master is not reachable from test11g. OK.
Fri Nov 21 16:44:29 2014 - [info] Master is not reachable from all other monitoring servers. Failover should start.
Fri Nov 21 16:44:29 2014 - [warning] Master is not reachable from health checker!
Fri Nov 21 16:44:29 2014 - [warning] Master 192.168.100.50(192.168.100.50:3306) is not reachable!
Fri Nov 21 16:44:29 2014 - [warning] SSH is NOT reachable.
Fri Nov 21 16:44:29 2014 - [info] Connecting to a master server failed. Reading configuration file /etc/masterha_default.cnf and /etc/masterha/mha.cnf again, and trying to connect to all servers to check server status..
Fri Nov 21 16:44:29 2014 - [warning] Global configuration file /etc/masterha_default.cnf not found. Skipping.
Fri Nov 21 16:44:29 2014 - [info] Reading application default configuration from /etc/masterha/mha.cnf..
Fri Nov 21 16:44:29 2014 - [info] Reading server configuration from /etc/masterha/mha.cnf..
Fri Nov 21 16:44:29 2014 - [info] GTID failover mode = 0
Fri Nov 21 16:44:29 2014 - [info] Dead Servers:
Fri Nov 21 16:44:29 2014 - [info]   192.168.100.50(192.168.100.50:3306)
Fri Nov 21 16:44:29 2014 - [info] Alive Servers:
Fri Nov 21 16:44:29 2014 - [info]   192.168.100.48(192.168.100.48:3306)
Fri Nov 21 16:44:29 2014 - [info]   192.168.100.141(192.168.100.141:3306)
Fri Nov 21 16:44:29 2014 - [info] Alive Slaves:
Fri Nov 21 16:44:29 2014 - [info]   192.168.100.48(192.168.100.48:3306)  Version=5.5.18-log (oldest major version between slaves) log-bin:enabled
Fri Nov 21 16:44:29 2014 - [info]     Replicating from 192.168.100.50(192.168.100.50:3306)
Fri Nov 21 16:44:29 2014 - [info]     Primary candidate for the new Master (candidate_master is set)
Fri Nov 21 16:44:29 2014 - [info]   192.168.100.141(192.168.100.141:3306)  Version=5.5.18-log (oldest major version between slaves) log-bin:enabled
Fri Nov 21 16:44:29 2014 - [info]     Replicating from 192.168.100.50(192.168.100.50:3306)
Fri Nov 21 16:44:29 2014 - [info] Checking slave configurations..
Fri Nov 21 16:44:29 2014 - [info]  read_only=1 is not set on slave 192.168.100.48(192.168.100.48:3306).
Fri Nov 21 16:44:29 2014 - [info] Checking replication filtering settings..
Fri Nov 21 16:44:29 2014 - [info]  Replication filtering check ok.
Fri Nov 21 16:44:29 2014 - [info] Master is down!
Fri Nov 21 16:44:29 2014 - [info] Terminating monitoring script.
Fri Nov 21 16:44:29 2014 - [info] Got exit code 20 (Master dead).
Fri Nov 21 16:44:29 2014 - [info] MHA::MasterFailover version 0.56.
Fri Nov 21 16:44:29 2014 - [info] Starting master failover.
Fri Nov 21 16:44:29 2014 - [info] 
Fri Nov 21 16:44:29 2014 - [info] * Phase 1: Configuration Check Phase..
Fri Nov 21 16:44:29 2014 - [info] 
Fri Nov 21 16:44:29 2014 - [info] GTID failover mode = 0
Fri Nov 21 16:44:29 2014 - [info] Dead Servers:
Fri Nov 21 16:44:29 2014 - [info]   192.168.100.50(192.168.100.50:3306)
Fri Nov 21 16:44:29 2014 - [info] Checking master reachability via MySQL(double check)...
Fri Nov 21 16:44:30 2014 - [info]  ok.
Fri Nov 21 16:44:30 2014 - [info] Alive Servers:
Fri Nov 21 16:44:30 2014 - [info]   192.168.100.48(192.168.100.48:3306)
Fri Nov 21 16:44:30 2014 - [info]   192.168.100.141(192.168.100.141:3306)
Fri Nov 21 16:44:30 2014 - [info] Alive Slaves:
Fri Nov 21 16:44:30 2014 - [info]   192.168.100.48(192.168.100.48:3306)  Version=5.5.18-log (oldest major version between slaves) log-bin:enabled
Fri Nov 21 16:44:30 2014 - [info]     Replicating from 192.168.100.50(192.168.100.50:3306)
Fri Nov 21 16:44:30 2014 - [info]     Primary candidate for the new Master (candidate_master is set)
Fri Nov 21 16:44:30 2014 - [info]   192.168.100.141(192.168.100.141:3306)  Version=5.5.18-log (oldest major version between slaves) log-bin:enabled
Fri Nov 21 16:44:30 2014 - [info]     Replicating from 192.168.100.50(192.168.100.50:3306)
Fri Nov 21 16:44:30 2014 - [info] Starting Non-GTID based failover.
Fri Nov 21 16:44:30 2014 - [info] 
Fri Nov 21 16:44:30 2014 - [info] ** Phase 1: Configuration Check Phase completed.
Fri Nov 21 16:44:30 2014 - [info] 
Fri Nov 21 16:44:30 2014 - [info] * Phase 2: Dead Master Shutdown Phase..
Fri Nov 21 16:44:30 2014 - [info] 
Fri Nov 21 16:44:30 2014 - [info] Forcing shutdown so that applications never connect to the current master..
Fri Nov 21 16:44:30 2014 - [info] Executing master IP deactivation script:
Fri Nov 21 16:44:30 2014 - [info]   /usr/bin/masterha_ip_failover --orig_master_host=192.168.100.50 --orig_master_ip=192.168.100.50 --orig_master_port=3306 --command=stop 
Disabling the VIP on old master: 192.168.100.50 
ssh: connect to host 192.168.100.50 port 22: No route to host
Fri Nov 21 16:45:04 2014 - [info]  done.
Fri Nov 21 16:45:04 2014 - [warning] shutdown_script is not set. Skipping explicit shutting down of the dead master.
Fri Nov 21 16:45:04 2014 - [info] * Phase 2: Dead Master Shutdown Phase completed.
Fri Nov 21 16:45:04 2014 - [info] 
Fri Nov 21 16:45:04 2014 - [info] * Phase 3: Master Recovery Phase..
Fri Nov 21 16:45:04 2014 - [info] 
Fri Nov 21 16:45:04 2014 - [info] * Phase 3.1: Getting Latest Slaves Phase..
Fri Nov 21 16:45:04 2014 - [info] 
Fri Nov 21 16:45:04 2014 - [info] The latest binary log file/position on all slaves is mysql-bin.000010:107
Fri Nov 21 16:45:04 2014 - [info] Latest slaves (Slaves that received relay log files to the latest):
Fri Nov 21 16:45:04 2014 - [info]   192.168.100.48(192.168.100.48:3306)  Version=5.5.18-log (oldest major version between slaves) log-bin:enabled
Fri Nov 21 16:45:04 2014 - [info]     Replicating from 192.168.100.50(192.168.100.50:3306)
Fri Nov 21 16:45:04 2014 - [info]     Primary candidate for the new Master (candidate_master is set)
Fri Nov 21 16:45:04 2014 - [info]   192.168.100.141(192.168.100.141:3306)  Version=5.5.18-log (oldest major version between slaves) log-bin:enabled
Fri Nov 21 16:45:04 2014 - [info]     Replicating from 192.168.100.50(192.168.100.50:3306)
Fri Nov 21 16:45:04 2014 - [info] The oldest binary log file/position on all slaves is mysql-bin.000010:107
Fri Nov 21 16:45:04 2014 - [info] Oldest slaves:
Fri Nov 21 16:45:04 2014 - [info]   192.168.100.48(192.168.100.48:3306)  Version=5.5.18-log (oldest major version between slaves) log-bin:enabled
Fri Nov 21 16:45:04 2014 - [info]     Replicating from 192.168.100.50(192.168.100.50:3306)
Fri Nov 21 16:45:04 2014 - [info]     Primary candidate for the new Master (candidate_master is set)
Fri Nov 21 16:45:04 2014 - [info]   192.168.100.141(192.168.100.141:3306)  Version=5.5.18-log (oldest major version between slaves) log-bin:enabled
Fri Nov 21 16:45:04 2014 - [info]     Replicating from 192.168.100.50(192.168.100.50:3306)
Fri Nov 21 16:45:04 2014 - [info] 
Fri Nov 21 16:45:04 2014 - [info] * Phase 3.2: Saving Dead Master's Binlog Phase..
Fri Nov 21 16:45:04 2014 - [info] 
Fri Nov 21 16:45:04 2014 - [warning] Dead Master is not SSH reachable. Could not save it's binlogs. Transactions that were not sent to the latest slave (Read_Master_Log_Pos to the tail of the dead master's binlog) were lost.
Fri Nov 21 16:45:04 2014 - [info] 
Fri Nov 21 16:45:04 2014 - [info] * Phase 3.3: Determining New Master Phase..
Fri Nov 21 16:45:04 2014 - [info] 
Fri Nov 21 16:45:04 2014 - [info] Finding the latest slave that has all relay logs for recovering other slaves..
Fri Nov 21 16:45:04 2014 - [info] All slaves received relay logs to the same position. No need to resync each other.
Fri Nov 21 16:45:04 2014 - [info] Searching new master from slaves..
Fri Nov 21 16:45:04 2014 - [info]  Candidate masters from the configuration file:
Fri Nov 21 16:45:04 2014 - [info]   192.168.100.48(192.168.100.48:3306)  Version=5.5.18-log (oldest major version between slaves) log-bin:enabled
Fri Nov 21 16:45:04 2014 - [info]     Replicating from 192.168.100.50(192.168.100.50:3306)
Fri Nov 21 16:45:04 2014 - [info]     Primary candidate for the new Master (candidate_master is set)
Fri Nov 21 16:45:04 2014 - [info]  Non-candidate masters:
Fri Nov 21 16:45:04 2014 - [info]  Searching from candidate_master slaves which have received the latest relay log events..
Fri Nov 21 16:45:04 2014 - [info] New master is 192.168.100.48(192.168.100.48:3306)
Fri Nov 21 16:45:04 2014 - [info] Starting master failover..
Fri Nov 21 16:45:04 2014 - [info] 
From:
192.168.100.50(192.168.100.50:3306) (current master)
 +--192.168.100.48(192.168.100.48:3306)
 +--192.168.100.141(192.168.100.141:3306)

To:
192.168.100.48(192.168.100.48:3306) (new master)
 +--192.168.100.141(192.168.100.141:3306)
Fri Nov 21 16:45:04 2014 - [info] 
Fri Nov 21 16:45:04 2014 - [info] * Phase 3.3: New Master Diff Log Generation Phase..
Fri Nov 21 16:45:04 2014 - [info] 
Fri Nov 21 16:45:04 2014 - [info]  This server has all relay logs. No need to generate diff files from the latest slave.
Fri Nov 21 16:45:04 2014 - [info] 
Fri Nov 21 16:45:04 2014 - [info] * Phase 3.4: Master Log Apply Phase..
Fri Nov 21 16:45:04 2014 - [info] 
Fri Nov 21 16:45:04 2014 - [info] *NOTICE: If any error happens from this phase, manual recovery is needed.
Fri Nov 21 16:45:04 2014 - [info] Starting recovery on 192.168.100.48(192.168.100.48:3306)..
Fri Nov 21 16:45:04 2014 - [info]  This server has all relay logs. Waiting all logs to be applied.. 
Fri Nov 21 16:45:04 2014 - [info]   done.
Fri Nov 21 16:45:04 2014 - [info]  All relay logs were successfully applied.
Fri Nov 21 16:45:04 2014 - [info] Getting new master's binlog name and position..
Fri Nov 21 16:45:04 2014 - [info]  mysql-bin.000005:2017
Fri Nov 21 16:45:04 2014 - [info]  All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST='192.168.100.48', MASTER_PORT=3306, MASTER_LOG_FILE='mysql-bin.000005', MASTER_LOG_POS=2017, MASTER_USER='backup', MASTER_PASSWORD='xxx';
Fri Nov 21 16:45:04 2014 - [info] Executing master IP activate script:
Fri Nov 21 16:45:04 2014 - [info]   /usr/bin/masterha_ip_failover --command=start --ssh_user=root --orig_master_host=192.168.100.50 --orig_master_ip=192.168.100.50 --orig_master_port=3306 --new_master_host=192.168.100.48 --new_master_ip=192.168.100.48 --new_master_port=3306 --new_master_user='root' --new_master_password='root'  
Unknown option: new_master_user
Unknown option: new_master_password
Enabling the VIP - 192.168.100.170 on the new master - 192.168.100.48 
Fri Nov 21 16:45:05 2014 - [info]  OK.
Fri Nov 21 16:45:05 2014 - [info] ** Finished master recovery successfully.
Fri Nov 21 16:45:05 2014 - [info] * Phase 3: Master Recovery Phase completed.
Fri Nov 21 16:45:05 2014 - [info] 
Fri Nov 21 16:45:05 2014 - [info] * Phase 4: Slaves Recovery Phase..
Fri Nov 21 16:45:05 2014 - [info] 
Fri Nov 21 16:45:05 2014 - [info] * Phase 4.1: Starting Parallel Slave Diff Log Generation Phase..
Fri Nov 21 16:45:05 2014 - [info] 
Fri Nov 21 16:45:05 2014 - [info] -- Slave diff file generation on host 192.168.100.141(192.168.100.141:3306) started, pid: 19525. Check tmp log /tol/mha//192.168.100.141_3306_20141121164429.log if it takes time..
Fri Nov 21 16:45:05 2014 - [info] 
Fri Nov 21 16:45:05 2014 - [info] Log messages from 192.168.100.141 ...
Fri Nov 21 16:45:05 2014 - [info] 
Fri Nov 21 16:45:05 2014 - [info]  This server has all relay logs. No need to generate diff files from the latest slave.
Fri Nov 21 16:45:05 2014 - [info] End of log messages from 192.168.100.141.
Fri Nov 21 16:45:05 2014 - [info] -- 192.168.100.141(192.168.100.141:3306) has the latest relay log events.
Fri Nov 21 16:45:05 2014 - [info] Generating relay diff files from the latest slave succeeded.
Fri Nov 21 16:45:05 2014 - [info] 
Fri Nov 21 16:45:05 2014 - [info] * Phase 4.2: Starting Parallel Slave Log Apply Phase..
Fri Nov 21 16:45:05 2014 - [info] 
Fri Nov 21 16:45:05 2014 - [info] -- Slave recovery on host 192.168.100.141(192.168.100.141:3306) started, pid: 19527. Check tmp log /tol/mha//192.168.100.141_3306_20141121164429.log if it takes time..
Fri Nov 21 16:45:05 2014 - [info] 
Fri Nov 21 16:45:05 2014 - [info] Log messages from 192.168.100.141 ...
Fri Nov 21 16:45:05 2014 - [info] 
Fri Nov 21 16:45:05 2014 - [info] Starting recovery on 192.168.100.141(192.168.100.141:3306)..
Fri Nov 21 16:45:05 2014 - [info]  This server has all relay logs. Waiting all logs to be applied.. 
Fri Nov 21 16:45:05 2014 - [info]   done.
Fri Nov 21 16:45:05 2014 - [info]  All relay logs were successfully applied.
Fri Nov 21 16:45:05 2014 - [info]  Resetting slave 192.168.100.141(192.168.100.141:3306) and starting replication from the new master 192.168.100.48(192.168.100.48:3306)..
Fri Nov 21 16:45:05 2014 - [info]  Executed CHANGE MASTER.
Fri Nov 21 16:45:05 2014 - [info]  Slave started.
Fri Nov 21 16:45:05 2014 - [info] End of log messages from 192.168.100.141.
Fri Nov 21 16:45:05 2014 - [info] -- Slave recovery on host 192.168.100.141(192.168.100.141:3306) succeeded.
Fri Nov 21 16:45:05 2014 - [info] All new slave servers recovered successfully.
Fri Nov 21 16:45:05 2014 - [info] 
Fri Nov 21 16:45:05 2014 - [info] * Phase 5: New master cleanup phase..
Fri Nov 21 16:45:05 2014 - [info] 
Fri Nov 21 16:45:05 2014 - [info] Resetting slave info on the new master..
Fri Nov 21 16:45:05 2014 - [info]  192.168.100.48: Resetting slave info succeeded.
Fri Nov 21 16:45:05 2014 - [info] Master failover to 192.168.100.48(192.168.100.48:3306) completed successfully.
Fri Nov 21 16:45:05 2014 - [info] Deleted server1 entry from /etc/masterha/mha.cnf .
Fri Nov 21 16:45:05 2014 - [info] 

----- Failover Report -----

mha: MySQL Master failover 192.168.100.50(192.168.100.50:3306) to 192.168.100.48(192.168.100.48:3306) succeeded

Master 192.168.100.50(192.168.100.50:3306) is down!

Check MHA Manager logs at test11g:/tol/mha/log/mha.log for details.

Started automated(non-interactive) failover.
Invalidated master IP address on 192.168.100.50(192.168.100.50:3306)
The latest slave 192.168.100.48(192.168.100.48:3306) has all relay logs for recovery.
Selected 192.168.100.48(192.168.100.48:3306) as a new master.
192.168.100.48(192.168.100.48:3306): OK: Applying all logs succeeded.
192.168.100.48(192.168.100.48:3306): OK: Activated master IP address.
192.168.100.141(192.168.100.141:3306): This host has the latest relay log events.
Generating relay diff files from the latest slave succeeded.
192.168.100.141(192.168.100.141:3306): OK: Applying all logs succeeded. Slave started, replicating from 192.168.100.48(192.168.100.48:3306)
192.168.100.48(192.168.100.48:3306): Resetting slave info succeeded.
Master failover to 192.168.100.48(192.168.100.48:3306) completed successfully.

+++通过以上日志看得出，主库master关机后，MHA检测到异常，并且进行切换

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/23249684/viewspace-1341814/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/23249684/viewspace-1341814/