菜鸟小试之二：MHA failover切换

failovwer切换从192.168.1.34切换到192.168.1.35
把192.168.1.34上的master给down掉，模拟dead

下面通过手工切换：
[root@skfweb2 /mha/appl]masterha_master_switch --master_state=dead --conf=/etc/appl.cnf --dead_master_host=192.168.1.34
--dead_master_ip=<dead_master_ip> is not set. Using 192.168.1.34.
--dead_master_port=<dead_master_port> is not set. Using 3306.
Sat Aug 23 22:16:35 2014 - [info] Reading default configuratoins from /etc/masterha_default.cnf..
Sat Aug 23 22:16:35 2014 - [info] Reading application default configurations from /etc/appl.cnf..
Sat Aug 23 22:16:35 2014 - [info] Reading server configurations from /etc/appl.cnf..
Sat Aug 23 22:16:35 2014 - [info] MHA::MasterFailover version 0.53.
Sat Aug 23 22:16:35 2014 - [info] Starting master failover.
Sat Aug 23 22:16:35 2014 - [info]
Sat Aug 23 22:16:35 2014 - [info] * Phase 1: Configuration Check Phase..
Sat Aug 23 22:16:35 2014 - [info]
Sat Aug 23 22:16:35 2014 - [info] Dead Servers:
Sat Aug 23 22:16:35 2014 - [info]   192.168.1.34(192.168.1.34:3306)
Sat Aug 23 22:16:35 2014 - [info] Checking master reachability via mysql(double check)..
Sat Aug 23 22:16:35 2014 - [info]  ok.
Sat Aug 23 22:16:35 2014 - [info] Alive Servers:
Sat Aug 23 22:16:35 2014 - [info]   192.168.1.35(192.168.1.35:3306)
Sat Aug 23 22:16:35 2014 - [info] Alive Slaves:
Sat Aug 23 22:16:35 2014 - [info]   192.168.1.35(192.168.1.35:3306)  Version=5.5.15-log (oldest major version between slaves) log-bin:enabled
Sat Aug 23 22:16:35 2014 - [info]     Replicating from 192.168.1.34(192.168.1.34:3306)
Sat Aug 23 22:16:35 2014 - [info]     Primary candidate for the new Master (candidate_master is set)
Master 192.168.1.34 is dead. Proceed? (yes/NO):
yes
Sat Aug 23 22:17:19 2014 - [info] ** Phase 1: Configuration Check Phase completed.
Sat Aug 23 22:17:19 2014 - [info]
Sat Aug 23 22:17:19 2014 - [info] * Phase 2: Dead Master Shutdown Phase..
Sat Aug 23 22:17:19 2014 - [info]
Sat Aug 23 22:17:19 2014 - [info] HealthCheck: SSH to 192.168.1.34 is reachable.
Sat Aug 23 22:17:19 2014 - [info] Forcing shutdown so that applications never connect to the current master..
Sat Aug 23 22:17:19 2014 - [warning] master_ip_failover_script is not set. Skipping invalidating dead master ip address.
Sat Aug 23 22:17:19 2014 - [warning] shutdown_script is not set. Skipping explicit shutting down of the dead master.
Sat Aug 23 22:17:19 2014 - [info] * Phase 2: Dead Master Shutdown Phase completed.
Sat Aug 23 22:17:19 2014 - [info]
Sat Aug 23 22:17:19 2014 - [info] * Phase 3: Master Recovery Phase..
Sat Aug 23 22:17:19 2014 - [info]
Sat Aug 23 22:17:19 2014 - [info] * Phase 3.1: Getting Latest Slaves Phase..
Sat Aug 23 22:17:19 2014 - [info]
Sat Aug 23 22:17:19 2014 - [info] The latest binary log file/position on all slaves is mysql-bin.000004:6357
Sat Aug 23 22:17:19 2014 - [info] Latest slaves (Slaves that received relay log files to the latest):
Sat Aug 23 22:17:19 2014 - [info]   192.168.1.35(192.168.1.35:3306)  Version=5.5.15-log (oldest major version between slaves) log-bin:enabled
Sat Aug 23 22:17:19 2014 - [info]     Replicating from 192.168.1.34(192.168.1.34:3306)
Sat Aug 23 22:17:19 2014 - [info]     Primary candidate for the new Master (candidate_master is set)
Sat Aug 23 22:17:19 2014 - [info] The oldest binary log file/position on all slaves is mysql-bin.000004:6357
Sat Aug 23 22:17:19 2014 - [info] Oldest slaves:
Sat Aug 23 22:17:19 2014 - [info]   192.168.1.35(192.168.1.35:3306)  Version=5.5.15-log (oldest major version between slaves) log-bin:enabled
Sat Aug 23 22:17:19 2014 - [info]     Replicating from 192.168.1.34(192.168.1.34:3306)
Sat Aug 23 22:17:19 2014 - [info]     Primary candidate for the new Master (candidate_master is set)
Sat Aug 23 22:17:19 2014 - [info]
Sat Aug 23 22:17:19 2014 - [info] * Phase 3.2: Saving Dead Master's Binlog Phase..
Sat Aug 23 22:17:19 2014 - [info]
Sat Aug 23 22:17:20 2014 - [info] Fetching dead master's binary logs..
Sat Aug 23 22:17:20 2014 - [info] Executing command on the dead master 192.168.1.34(192.168.1.34:3306): save_binary_logs --command=save --start_file=mysql-bin.000004  --start_pos=6357 --binlog_dir=/mysql/mysql1/data --output_file=/mha/appl/saved_master_binlog_from_192.168.1.34_3306_20140823221635.binlog --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.53
  Creating /mha/appl if not exists..    ok.
 Concat binary/relay logs from mysql-bin.000004 pos 6357 to mysql-bin.000004 EOF into /mha/appl/saved_master_binlog_from_192.168.1.34_3306_20140823221635.binlog ..
  Dumping binlog format description event, from position 0 to 107.. ok.
  Dumping effective binlog data from /mysql/mysql1/data/mysql-bin.000004 position 6357 to tail(6376).. ok.
sh: mysqlbinlog: command not found
Failed to save binary log: /mha/appl/saved_master_binlog_from_192.168.1.34_3306_20140823221635.binlog is broken!
 at /usr/bin/save_binary_logs line 170
Sat Aug 23 22:17:20 2014 - [error][/usr/share/perl5/vendor_perl/MHA/MasterFailover.pm, ln575] Failed to save binary log events from the orig master. Maybe disks on binary logs are not accessible or binary log itself is corrupt?
Sat Aug 23 22:17:20 2014 - [info]
Sat Aug 23 22:17:20 2014 - [info] * Phase 3.3: Determining New Master Phase..
Sat Aug 23 22:17:20 2014 - [info]
Sat Aug 23 22:17:20 2014 - [info] Finding the latest slave that has all relay logs for recovering other slaves..
Sat Aug 23 22:17:20 2014 - [info] All slaves received relay logs to the same position. No need to resync each other.
Sat Aug 23 22:17:20 2014 - [info] Searching new master from slaves..
Sat Aug 23 22:17:20 2014 - [info]  Candidate masters from the configuration file:
Sat Aug 23 22:17:20 2014 - [info]   192.168.1.35(192.168.1.35:3306)  Version=5.5.15-log (oldest major version between slaves) log-bin:enabled
Sat Aug 23 22:17:20 2014 - [info]     Replicating from 192.168.1.34(192.168.1.34:3306)
Sat Aug 23 22:17:20 2014 - [info]     Primary candidate for the new Master (candidate_master is set)
Sat Aug 23 22:17:20 2014 - [info]  Non-candidate masters:
Sat Aug 23 22:17:20 2014 - [info]  Searching from candidate_master slaves which have received the latest relay log events..
Sat Aug 23 22:17:20 2014 - [info] New master is 192.168.1.35(192.168.1.35:3306)
Sat Aug 23 22:17:20 2014 - [info] Starting master failover..
Sat Aug 23 22:17:20 2014 - [info]
From:
192.168.1.34 (current master)
 +--192.168.1.35

To:
192.168.1.35 (new master)

Starting master switch from 192.168.1.34(192.168.1.34:3306) to 192.168.1.35(192.168.1.35:3306)? (yes/NO): yes
Sat Aug 23 22:17:53 2014 - [info] New master decided manually is 192.168.1.35(192.168.1.35:3306)
Sat Aug 23 22:17:53 2014 - [info]
Sat Aug 23 22:17:53 2014 - [info] * Phase 3.3: New Master Diff Log Generation Phase..
Sat Aug 23 22:17:53 2014 - [info]
Sat Aug 23 22:17:53 2014 - [info]  This server has all relay logs. No need to generate diff files from the latest slave.
Sat Aug 23 22:17:53 2014 - [info]
Sat Aug 23 22:17:53 2014 - [info] * Phase 3.4: Master Log Apply Phase..
Sat Aug 23 22:17:53 2014 - [info]
Sat Aug 23 22:17:53 2014 - [info] *NOTICE: If any error happens from this phase, manual recovery is needed.
Sat Aug 23 22:17:53 2014 - [info] Starting recovery on 192.168.1.35(192.168.1.35:3306)..
Sat Aug 23 22:17:53 2014 - [info]  This server has all relay logs. Waiting all logs to be applied..
Sat Aug 23 22:17:53 2014 - [info]   done.
Sat Aug 23 22:17:53 2014 - [info]  All relay logs were successfully applied.
Sat Aug 23 22:17:53 2014 - [info] Getting new master's binlog name and position..
Sat Aug 23 22:17:53 2014 - [info]  mysql-bin.000003:674
Sat Aug 23 22:17:53 2014 - [info]  All other slaves should start replication from here. Statement should be: CHANGE MASTER TO MASTER_HOST='192.168.1.35', MASTER_PORT=3306, MASTER_LOG_FILE='mysql-bin.000003', MASTER_LOG_POS=674, MASTER_USER='repl', MASTER_PASSWORD='xxx';
Sat Aug 23 22:17:53 2014 - [warning] master_ip_failover_script is not set. Skipping taking over new master ip address.
Sat Aug 23 22:17:53 2014 - [info] ** Finished master recovery successfully.
Sat Aug 23 22:17:53 2014 - [info] * Phase 3: Master Recovery Phase completed.
Sat Aug 23 22:17:53 2014 - [info]
Sat Aug 23 22:17:53 2014 - [info] * Phase 4: Slaves Recovery Phase..
Sat Aug 23 22:17:53 2014 - [info]
Sat Aug 23 22:17:53 2014 - [info] * Phase 4.1: Starting Parallel Slave Diff Log Generation Phase..
Sat Aug 23 22:17:53 2014 - [info]
Sat Aug 23 22:17:53 2014 - [info] Generating relay diff files from the latest slave succeeded.
Sat Aug 23 22:17:53 2014 - [info]
Sat Aug 23 22:17:53 2014 - [info] * Phase 4.2: Starting Parallel Slave Log Apply Phase..
Sat Aug 23 22:17:53 2014 - [info]
Sat Aug 23 22:17:53 2014 - [info] All new slave servers recovered successfully.
Sat Aug 23 22:17:53 2014 - [info]
Sat Aug 23 22:17:53 2014 - [info] * Phase 5: New master cleanup phease..
Sat Aug 23 22:17:53 2014 - [info]
Sat Aug 23 22:17:53 2014 - [info] Resetting slave info on the new master..
Sat Aug 23 22:17:53 2014 - [info]  192.168.1.35: Resetting slave info succeeded.
Sat Aug 23 22:17:53 2014 - [info] Master failover to 192.168.1.35(192.168.1.35:3306) completed successfully.
Sat Aug 23 22:17:53 2014 - [info]

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

appl: MySQL Master failover 192.168.1.34 to 192.168.1.35 succeeded

Master 192.168.1.34 is down!

Check MHA Manager logs at skfweb2 for details.

Started manual(interactive) failover.
The latest slave 192.168.1.35(192.168.1.35:3306) has all relay logs for recovery.
Selected 192.168.1.35 as a new master.
192.168.1.35: OK: Applying all logs succeeded.
Generating relay diff files from the latest slave succeeded.
192.168.1.35: Resetting slave info succeeded.
Master failover to 192.168.1.35(192.168.1.35:3306) completed successfully.
[root@skfweb2 /mh