集群信息
角色 ip地址 serverid 类型
master 192.168.244.10 1 写入
candicate master 192.168.244.20 2 读
slave 192.168.244.30 3 读
monitor host 192.168.244.40 监控集群组
mha具体的搭建步骤和原理，可参考另外一篇博客：
mysql高可用方案mha的部署和原理
自动failover
为了通过mha的日志清晰判断mha自动failover的实现原理，需模拟如下场景：
当主库发生故障时，master中还有一部分binlog日志没有传输到candicate master和slave上，且slave上的二进制日志多于candicate master上。
尝试了几种方案，总算如愿以偿。
方案一：
1. 关闭candicate master和slave的主从复制。
2. 通过存储过程生成测试数据
3. 开启candicate master和slave的主从复制并kill掉master的mysqld进程，模拟主库发生故障，进行自动failover操作
为此，还特意写了个脚本，可惜的是，效果并不理想，在自动failover的过程中，显示mha manager到master的“ssh is not reachable”。
方案二：
通过tc命令对candicate master和slave的网卡分别设置不同的传输速率，确保发送到candicate master的日志量小于slave上的。
很可惜，效果同方案一一样。
方案三：
在主从复制中，直接关闭master的mysqld数据库。
但是，通过这样方式，并不会实现slave上的二进制日志多于candicate master的效果。
方案四：
通过截取relay log，在关掉slave的情况下，修改master.info和relay-log.info的位置点来人为制造candicate master的日志量小于slave的。
事后想想，其实这样的方法就等同于先关闭candicate master的主从复制，再在master上执行一段操作，再关闭slave上的主从复制，再在master上执行一段操作。
这样不就实现了master的binlog > slave 的relay log > candicate master的relay log。
方案四总算如愿以偿
下面通过方案四看看mha的实现原理
1. 创建测试表，并插入测试数据
mysql> create table sbtest.b(id int,name varchar(10));
query ok, 0 rows affected (0.12 sec)
mysql> insert into sbtest.b values(1,'a');
query ok, 1 row affected (0.00 sec)
mysql> insert into sbtest.b values(2,'b');
query ok, 1 row affected (0.01 sec)
mysql> insert into sbtest.b values(3,'c');
query ok, 1 row affected (0.00 sec)
mysql> insert into sbtest.b values(4,'d');
query ok, 1 row affected (0.00 sec)
mysql> insert into sbtest.b values(5,'e');
query ok, 1 row affected (0.01 sec)
2. 分别查看master上binlog的内容，slave上relay log的内容
master
mysql> show binlog events;+------------------+------+-------------+-----------+-------------+------------------------------------------------+| log_name | pos | event_type | server_id | end_log_pos | info |+------------------+------+-------------+-----------+-------------+------------------------------------------------+| mysql-bin.000001 | 4 | format_desc | 1 | 120 | server ver: 5.6.31-log, binlog ver: 4 || mysql-bin.000001 | 120 | query | 1 | 238 | create table sbtest.b(id int,name varchar(10)) || mysql-bin.000001 | 238 | query | 1 | 315 | begin || mysql-bin.000001 | 315 | query | 1 | 421 | insert into sbtest.b values(1,'a') || mysql-bin.000001 | 421 | xid | 1 | 452 | commit /* xid=102 */ || mysql-bin.000001 | 452 | query | 1 | 529 | begin || mysql-bin.000001 | 529 | query | 1 | 635 | insert into sbtest.b values(2,'b') || mysql-bin.000001 | 635 | xid | 1 | 666 | commit /* xid=103 */ || mysql-bin.000001 | 666 | query | 1 | 743 | begin || mysql-bin.000001 | 743 | query | 1 | 849 | insert into sbtest.b values(3,'c') || mysql-bin.000001 | 849 | xid | 1 | 880 | commit /* xid=104 */ || mysql-bin.000001 | 880 | query | 1 | 957 | begin || mysql-bin.000001 | 957 | query | 1 | 1063 | insert into sbtest.b values(4,'d') || mysql-bin.000001 | 1063 | xid | 1 | 1094 | commit /* xid=105 */ || mysql-bin.000001 | 1094 | query | 1 | 1171 | begin || mysql-bin.000001 | 1171 | query | 1 | 1277 | insert into sbtest.b values(5,'e') || mysql-bin.000001 | 1277 | xid | 1 | 1308 | commit /* xid=106 */ |+------------------+------+-------------+-----------+-------------+------------------------------------------------+17 rows in set (0.01 sec)
slave
mysql> show relaylog events in 'mysqld-relay-bin.000002';+-------------------------+------+-------------+-----------+-------------+------------------------------------------------+| log_name | pos | event_type | server_id | end_log_pos | info |+-------------------------+------+-------------+-----------+-------------+------------------------------------------------+| mysqld-relay-bin.000002 | 4 | format_desc | 2 | 120 | server ver: 5.6.31-log, binlog ver: 4 || mysqld-relay-bin.000002 | 120 | rotate | 1 | 0 | mysql-bin.000001;pos=120 || mysqld-relay-bin.000002 | 167 | format_desc | 1 | 0 | server ver: 5.6.31-log, binlog ver: 4 || mysqld-relay-bin.000002 | 283 | query | 1 | 238 | create table sbtest.b(id int,name varchar(10)) || mysqld-relay-bin.000002 | 401 | query | 1 | 315 | begin || mysqld-relay-bin.000002 | 478 | query | 1 | 421 | insert into sbtest.b values(1,'a') || mysqld-relay-bin.000002 | 584 | xid | 1 | 452 | commit /* xid=102 */ || mysqld-relay-bin.000002 | 615 | query | 1 | 529 | begin || mysqld-relay-bin.000002 | 692 | query | 1 | 635 | insert into sbtest.b values(2,'b') || mysqld-relay-bin.000002 | 798 | xid | 1 | 666 | commit /* xid=103 */ || mysqld-relay-bin.000002 | 829 | query | 1 | 743 | begin || mysqld-relay-bin.000002 | 906 | query | 1 | 849 | insert into sbtest.b values(3,'c') || mysqld-relay-bin.000002 | 1012 | xid | 1 | 880 | commit /* xid=104 */ || mysqld-relay-bin.000002 | 1043 | query | 1 | 957 | begin || mysqld-relay-bin.000002 | 1120 | query | 1 | 1063 | insert into sbtest.b values(4,'d') || mysqld-relay-bin.000002 | 1226 | xid | 1 | 1094 | commit /* xid=105 */ || mysqld-relay-bin.000002 | 1257 | query | 1 | 1171 | begin || mysqld-relay-bin.000002 | 1334 | query | 1 | 1277 | insert into sbtest.b values(5,'e') || mysqld-relay-bin.000002 | 1440 | xid | 1 | 1308 | commit /* xid=106 */ |+-------------------------+------+-------------+-----------+-------------+------------------------------------------------+19 rows in set (0.00 sec)
通过对比master中的binlog event，可以看到show relaylog events中的end_log_pos实际上指的是对应的二进制事件在binlog的位置。
再来查看candicate master中对应的relay log的内容
[root@node2 mysql]# mysqlbinlog mysqld-relay-bin.000002
[root@node2 mysql]# mysqlbinlog mysqld-relay-bin.000002/*!50530 set @@session.pseudo_slave_mode=1*/;/*!40019 set @@session.max_insert_delayed_threads=0*/;/*!50003 set @old_completion_type=@@completion_type,completion_type=0*/;
delimiter /*!*/;
# at 4#170524 17:16:37 server id 2 end_log_pos 120 crc32 0x4faba9ae start: binlog v 4, server v 5.6.31-log created 170524 17:16:37binlog 'du8lwq8caaaadaaaahgaaabaaaqans42ljmxlwxvzwaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
aaaaaaaaaaaaaaaaaaaaaaaaezgnaagaegaebaqeegaaxaaegggaaaaicagcaaaacgokgrkaaa6p
q08='/*!*/;# at 120#700101 8:00:00 server id 1 end_log_pos 0 crc32 0x74c6d70c rotate to mysql-bin.000001 pos: 120# at 167#170524 17:15:49 server id 1 end_log_pos 0 crc32 0xed2672eb start: binlog v 4, server v 5.6.31-log created 170524 17:15:49binlog 'ru8lwq8baaaadaaaaaaaaaaaaaqans42ljmxlwxvzwaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
aaaaaaaaaaaaaaaaaaaaaaaaezgnaagaegaebaqeegaaxaaegggaaaaicagcaaaacgokgrkaaety
ju0='/*!*/;# at 283#170524 17:17:20 server id 1 end_log_pos 238 crc32 0xdd48c118 query thread_id=2 exec_time=0 error_code=0set timestamp=1495617440/*!*/;
set @@session.pseudo_thread_id=2/*!*/;
set @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
set @@session.sql_mode=1075838976/*!*/;
set @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;/*!\c utf8 *//*!*/;
set @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
set @@session.lc_time_names=0/*!*/;
set @@session.collation_database=default/*!*/;
create table sbtest.b(id int,name varchar(10))/*!*/;
# at 401#170524 17:17:27 server id 1 end_log_pos 315 crc32 0xae393750 query thread_id=2 exec_time=0 error_code=0set timestamp=1495617447/*!*/;
begin/*!*/;
# at 478#170524 17:17:27 server id 1 end_log_pos 421 crc32 0x28a781ae query thread_id=2 exec_time=0 error_code=0set timestamp=1495617447/*!*/;
insert into sbtest.b values(1,'a')/*!*/;
# at 584#170524 17:17:27 server id 1 end_log_pos 452 crc32 0x680f1bfe xid = 29commit/*!*/;
# at 615#170524 17:17:33 server id 1 end_log_pos 529 crc32 0x6a1aae7e query thread_id=2 exec_time=0 error_code=0set timestamp=1495617453/*!*/;
begin/*!*/;
# at 692#170524 17:17:33 server id 1 end_log_pos 635 crc32 0x117786ca query thread_id=2 exec_time=0 error_code=0set timestamp=1495617453/*!*/;
insert into sbtest.b values(2,'b')/*!*/;
# at 798#170524 17:17:33 server id 1 end_log_pos 666 crc32 0xa8400ec6 xid = 30commit/*!*/;
# at 829#170524 17:17:38 server id 1 end_log_pos 743 crc32 0x24f9a1d2 query thread_id=2 exec_time=0 error_code=0set timestamp=1495617458/*!*/;
begin/*!*/;
# at 906#170524 17:17:38 server id 1 end_log_pos 849 crc32 0x56fa9e89 query thread_id=2 exec_time=0 error_code=0set timestamp=1495617458/*!*/;
insert into sbtest.b values(3,'c')/*!*/;
# at 1012#170524 17:17:38 server id 1 end_log_pos 880 crc32 0x2ac656d4 xid = 31commit/*!*/;
# at 1043#170524 17:17:44 server id 1 end_log_pos 957 crc32 0x73a903bf query thread_id=2 exec_time=0 error_code=0set timestamp=1495617464/*!*/;
begin/*!*/;
# at 1120#170524 17:17:44 server id 1 end_log_pos 1063 crc32 0x171b9b27 query thread_id=2 exec_time=0 error_code=0set timestamp=1495617464/*!*/;
insert into sbtest.b values(4,'d')/*!*/;
# at 1226#170524 17:17:44 server id 1 end_log_pos 1094 crc32 0x47d6fe57 xid = 32commit/*!*/;
# at 1257#170524 17:17:49 server id 1 end_log_pos 1171 crc32 0x2d37da37 query thread_id=2 exec_time=0 error_code=0set timestamp=1495617469/*!*/;
begin/*!*/;
# at 1334#170524 17:17:49 server id 1 end_log_pos 1277 crc32 0xd2201fa2 query thread_id=2 exec_time=0 error_code=0set timestamp=1495617469/*!*/;
insert into sbtest.b values(5,'e')/*!*/;
# at 1440#170524 17:17:49 server id 1 end_log_pos 1308 crc32 0xac1b464e xid = 33commit/*!*/;
delimiter ;
# end of log filerollback /* added by mysqlbinlog */;/*!50003 set completion_type=@old_completion_type*/;/*!50530 set @@session.pseudo_slave_mode=0*/;
view code
mysql中binlog有个有意思的地方是，位置点其实是也是字节的大小。
譬如，上面这个relay log中，最后一个位点是# at 1440，算上最后一个commit操作需占用31个字节，所以整个文件的大小是1471，与实际大小吻合。
[root@node2 mysql]# ll mysqld-relay-bin.000002-rw-rw---- 1 mysql mysql 1471 may 24 17:17 mysqld-relay-bin.000002
3. 通过show slave status查看io thread和sql thread的位置信息
mysql> show slave status\g*************************** 1. row ***************************
slave_io_state: waiting for master to send event
master_host: 192.168.244.10
master_user: repl
master_port: 3306
connect_retry: 60
master_log_file: mysql-bin.000001
read_master_log_pos: 1308
relay_log_file: mysqld-relay-bin.000002
relay_log_pos: 1471
relay_master_log_file: mysql-bin.000001
slave_io_running: yes
slave_sql_running: yes
replicate_do_db:
replicate_ignore_db:
replicate_do_table:
replicate_ignore_table:
replicate_wild_do_table:
replicate_wild_ignore_table:
last_errno: 0
last_error:
skip_counter: 0
exec_master_log_pos: 1308
relay_log_space: 1645
until_condition: none
until_log_file:
until_log_pos: 0
master_ssl_allowed: no
master_ssl_ca_file:
master_ssl_ca_path:
master_ssl_cert:
master_ssl_cipher:
master_ssl_key:
seconds_behind_master: 0master_ssl_verify_server_cert: no
last_io_errno: 0
last_io_error:
last_sql_errno: 0
last_sql_error:
replicate_ignore_server_ids:
master_server_id: 1
master_uuid: 2a6365e0-1d05-11e7-956d-000c29c64704
master_info_file: /var/lib/mysql/master.info
sql_delay: 0
sql_remaining_delay: null
slave_sql_running_state: slave has read all relay log; waiting for the slave i/o thread to update it
master_retry_count: 86400
master_bind:
last_io_error_timestamp:
last_sql_error_timestamp:
master_ssl_crl:
master_ssl_crlpath:
retrieved_gtid_set:
executed_gtid_set:
auto_position: 01 row in set (0.00 sec)
待会儿需要修改上面master_log_file,read_master_log_pos,relay_log_file,relay_log_pos,relay_master_log_file,exec_master_log_pos的值。
虽然这几个参数的值与master.info和relay-log.info文件是相对应的，
但通过修改master.info和relay-log.info的值，并重启slave，并不会将上述几个参数值修改。
上述几个参数是保存到内存中的，唯一可行的方案是首先关闭slave实例，再修改master.info和relay-log.info文件，然后重新启动mysql实例。
4. 关闭candicate master实例，剪裁relay log，修改master.info和relay-log.info文件。
关闭实例
[root@node2 mysql]# service mysqld stop
剪裁relay log
这里，写了个python脚本实现该功能
#!/usr/bin/pythonf1 = open('mysqld-relay-bin.000002','r')
f2 = open('tmp_relay_bin','w+')
size1=f1.read(615)f2.write(size1)
f1.seek(1471)
size2=f1.read()
f2.write(size2)
f1.close()
f2.close()
在上述脚本size1中，615对应的是insert into sbtest.b values(1,'a')这条记录
[root@node2 mysql]# python 1.py
[root@node2 mysql]# mv tmp_relay_bin mysqld-relay-bin.000002
修改master.info的内容
主要是修改第三行
23mysql-bin.0000011308
修改为
23mysql-bin.000001452
修改relay-log.info的内容
原文件如下：
7./mysqld-relay-bin.0000021471mysql-bin.0000011308001
修改为：
7./mysqld-relay-bin.000002615mysql-bin.000001452001
启动slave，注意，配置文件中必须设置skip-slave-start，不然它自动开启主从复制。
[root@node2 mysql]# service mysqld start
5. 对于slave，同样如此处理，只不过relay log的位置点要靠后些
#!/usr/bin/pythonf1 = open('mysqld-relay-bin.000002','r')
f2 = open('tmp_relay_bin','w+')
size1=f1.read(1043)
f2.write(size1)
f1.seek(1471)
size2=f1.read()
f2.write(size2)
f1.close()
f2.close()
1043对应的是insert into sbtest.b values(3,'c')这条记录
修改master.info的内容
23mysql-bin.000001
880
修改relay-log.info的内容
7./mysqld-relay-bin.000002
1043mysql-bin.000001
8800
01
6. 开启mha监控
# nohup masterha_manager --conf=/etc/masterha/app1.cnf --remove_dead_master_conf --ignore_last_failover < /dev/null >
/masterha/app1/manager.log 2>&1 &
# masterha_check_status --conf=/etc/masterha/app1.cnf
app1 (pid:1615) is running(0:ping_ok), master:192.168.244.10
7. 关闭master实例
# service mysqld stop
8. 查看mha切换日志，了解整个切换过程。
该日志的时间点与上面relay log的时间点并不吻合，原因在于这个反复测试了很多次。
sun may 21 20:50:46 2017 - [warning] got error on mysql connect: 2013 (lost connection to mysql server at 'reading initial communication packet', system error: 111)
sun may 21 20:50:46 2017 - [warning] connection failed 1 time(s)..
sun may 21 20:50:46 2017 - [info] executing secondary network check script: /usr/local/bin/masterha_secondary_check -s 192.168.244.20 -s 192.168.244.30 --user=root --master_host=192.168.244.10 --master_ip=192.168.244.10 --master_port=3306 --user=root --master_host=192.168.244.10 --master_ip=192.168.244.10 --master_port=3306 --master_user=monitor --master_password=monitor123 --ping_type=select
sun may 21 20:50:46 2017 - [info] executing ssh check script: save_binary_logs --command=test --start_pos=4 --binlog_dir=/var/lib/mysql --output_file=/tmp/save_binary_logs_test --manager_version=0.56 --binlog_prefix=mysql-bin
monitoring server 192.168.244.20 is reachable, master is not reachable from 192.168.244.20. ok.
sun may 21 20:50:46 2017 - [info] healthcheck: ssh to 192.168.244.10 is reachable.
monitoring server 192.168.244.30 is reachable, master is not reachable from 192.168.244.30. ok.-- 当monitor检测到master mysqld不可用的时候，即根据masterha_secondary_check脚本从candicate master和slave上判断master mysqld的可用性，
根据上面的显示信息，通过192.168.244.20和192.168.244.30也判断到master mysqld不可用。
如果任意一个slave判断到master mysqld可用，则输出的信息如下：
# /usr/local/bin/masterha_secondary_check -s 192.168.244.20 -s 192.168.244.30 --user=root --master_host=192.168.244.10 --master_ip=192.168.244.10 --master_port=3306
master is reachable from 192.168.244.20!
sun may 21 20:50:46 2017 - [info] master is not reachable from all other monitoring servers. failover should start.
sun may 21 20:50:47 2017 - [warning] got error on mysql connect: 2013 (lost connection to mysql server at 'reading initial communication packet', system error: 111)
sun may 21 20:50:47 2017 - [warning] connection failed 2 time(s)..
sun may 21 20:50:48 2017 - [warning] got error on mysql connect: 2013 (lost connection to mysql server at 'reading initial communication packet', system error: 111)
sun may 21 20:50:48 2017 - [warning] connection failed 3 time(s)..
sun may 21 20:50:49 2017 - [warning] got error on mysql connect: 2013 (lost connection to mysql server at 'reading initial communication packet', system error: 111)
sun may 21 20:50:49 2017 - [warning] connection failed 4 time(s)..
sun may 21 20:50:49 2017 - [warning] master is not reachable from health checker!sun may 21 20:50:49 2017 - [warning] master 192.168.244.10(192.168.244.10:3306) is not reachable!sun may 21 20:50:49 2017 - [warning] ssh is reachable.-- 一共判断了4次，均判断master mysqld不可用，但是master主机通过ssh还是能登录上去。
如果这里显示的是ssh is not reachable，则代表master主机也已经宕机了，
刚开始还以为是通过ssh来判断主机是否宕机，但在之前的测试方案中（具体可见文末），master并没有宕机，这里却显示ssh is not reachable.
通过上面的输出才知道是通过save_binary_logs脚本来判断ssh可用性的。
sun may 21 20:50:49 2017 - [info] connecting to a master server failed. reading configuration file /etc/masterha_default.cnf and /etc/masterha/app1.cnf again, and trying to connect to all servers to check server status..
sun may 21 20:50:49 2017 - [warning] global configuration file /etc/masterha_default.cnf not found. skipping.
sun may 21 20:50:49 2017 - [info] reading application default configuration from /etc/masterha/app1.cnf..
sun may 21 20:50:49 2017 - [info] reading server configuration from /etc/masterha/app1.cnf..
sun may 21 20:50:50 2017 - [warning] sql thread is stopped(no error) on 192.168.244.20(192.168.244.20:3306)
sun may 21 20:50:50 2017 - [warning] sql thread is stopped(no error) on 192.168.244.30(192.168.244.30:3306)
sun may 21 20:50:50 2017 - [info] gtid failover mode = 0sun may 21 20:50:50 2017 - [info] dead servers:
sun may 21 20:50:50 2017 - [info] 192.168.244.10(192.168.244.10:3306)
sun may 21 20:50:50 2017 - [info] alive servers:
sun may 21 20:50:50 2017 - [info] 192.168.244.20(192.168.244.20:3306)
sun may 21 20:50:50 2017 - [info] 192.168.244.30(192.168.244.30:3306)
sun may 21 20:50:50 2017 - [info] alive slaves:
sun may 21 20:50:50 2017 - [info] 192.168.244.20(192.168.244.20:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 20:50:50 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 20:50:50 2017 - [info] primary candidate for the new master (candidate_master is set)
sun may 21 20:50:50 2017 - [info] 192.168.244.30(192.168.244.30:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 20:50:50 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 20:50:50 2017 - [info] checking slave configurations..
sun may 21 20:50:50 2017 - [info] checking replication filtering settings..
sun may 21 20:50:50 2017 - [info] replication filtering check ok.
sun may 21 20:50:50 2017 - [info] master is down!sun may 21 20:50:50 2017 - [info] terminating monitoring script.
sun may 21 20:50:50 2017 - [info] got exit code 20 (master dead).
sun may 21 20:50:50 2017 - [info] mha::masterfailover version 0.56.
sun may 21 20:50:50 2017 - [info] starting master failover.-- 读取mha的配置文件，检查slave的相关配置，比如read_only参数，是否设置了复制的过滤规则
从上面的输出中可以看出，sql thread正常停止了并不影响mha的切换。
sun may 21 20:50:50 2017 - [info]
sun may 21 20:50:50 2017 - [info] * phase 1: configuration check phase..
sun may 21 20:50:50 2017 - [info]
sun may 21 20:50:51 2017 - [warning] sql thread is stopped(no error) on 192.168.244.20(192.168.244.20:3306)
sun may 21 20:50:51 2017 - [warning] sql thread is stopped(no error) on 192.168.244.30(192.168.244.30:3306)
sun may 21 20:50:51 2017 - [info] gtid failover mode = 0sun may 21 20:50:51 2017 - [info] dead servers:
sun may 21 20:50:51 2017 - [info] 192.168.244.10(192.168.244.10:3306)
sun may 21 20:50:51 2017 - [info] checking master reachability via mysql(double check)...
sun may 21 20:50:51 2017 - [info] ok.
sun may 21 20:50:51 2017 - [info] alive servers:
sun may 21 20:50:51 2017 - [info] 192.168.244.20(192.168.244.20:3306)
sun may 21 20:50:51 2017 - [info] 192.168.244.30(192.168.244.30:3306)
sun may 21 20:50:51 2017 - [info] alive slaves:
sun may 21 20:50:51 2017 - [info] 192.168.244.20(192.168.244.20:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 20:50:51 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 20:50:51 2017 - [info] primary candidate for the new master (candidate_master is set)
sun may 21 20:50:51 2017 - [info] 192.168.244.30(192.168.244.30:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 20:50:51 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 20:50:51 2017 - [info] starting sql thread on 192.168.244.20(192.168.244.20:3306) ..
sun may 21 20:50:51 2017 - [info] done.
sun may 21 20:50:51 2017 - [info] starting sql thread on 192.168.244.30(192.168.244.30:3306) ..
sun may 21 20:50:51 2017 - [info] done.
sun may 21 20:50:51 2017 - [info] starting non-gtid based failover.
sun may 21 20:50:51 2017 - [info]
sun may 21 20:50:51 2017 - [info] ** phase 1: configuration check phase completed.-- 第一阶段，检查了mha的配置信息，并再次判断了master的可用性。
第二阶段，关闭dead master。
包括执行摘除master上的vip，同时执行shutdown_script脚本，因为该脚本在配置文件中没有定义，故跳过。
sun may 21 20:50:51 2017 - [info]
sun may 21 20:50:51 2017 - [info] * phase 2: dead master shutdown phase..
sun may 21 20:50:51 2017 - [info]
sun may 21 20:50:51 2017 - [info] forcing shutdown so that applications never connect to the current master..
sun may 21 20:50:51 2017 - [info] executing master ip deactivation script:
sun may 21 20:50:51 2017 - [info] /usr/local/bin/master_ip_failover --orig_master_host=192.168.244.10 --orig_master_ip=192.168.244.10 --orig_master_port=3306 --command=stopssh --ssh_user=root
disabling the vip an old master: 192.168.244.10 siocsifflags: cannot assign requested address
sun may 21 20:50:51 2017 - [info] done.
sun may 21 20:50:51 2017 - [warning] shutdown_script is not set. skipping explicit shutting down of the dead master.
sun may 21 20:50:51 2017 - [info] * phase 2: dead master shutdown phase completed.
sun may 21 20:50:51 2017 - [info]
-- 第三阶段 3.1 判断哪个slave的二进制日志是最新的。
通过下面的输出可以看出，所有的slave中，最新的二进制日志位置是mysql-bin.000001:880（通过show slave status中的master_log_file, read_master_log_pos得到）
最旧的二进制日志位置是mysql-bin.000001:452
sun may 21 20:50:51 2017 - [info] * phase 3: master recovery phase..
sun may 21 20:50:51 2017 - [info]
sun may 21 20:50:51 2017 - [info] * phase 3.1: getting latest slaves phase..
sun may 21 20:50:51 2017 - [info]
sun may 21 20:50:51 2017 - [info] the latest binary log file/position on all slaves is mysql-bin.000001:880sun may 21 20:50:51 2017 - [info] latest slaves (slaves that received relay log files to the latest):
sun may 21 20:50:51 2017 - [info] 192.168.244.30(192.168.244.30:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 20:50:51 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 20:50:51 2017 - [info] the oldest binary log file/position on all slaves is mysql-bin.000001:452sun may 21 20:50:51 2017 - [info] oldest slaves:
sun may 21 20:50:51 2017 - [info] 192.168.244.20(192.168.244.20:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 20:50:51 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 20:50:51 2017 - [info] primary candidate for the new master (candidate_master is set)
sun may 21 20:50:51 2017 - [info]
-- 3.2 保存master的binlog
注意，上面已经判断到slave中最新二进制日志是mysql-bin.000001:880，所以它把该位置后所有二进制日志都拼接起来，并scp到monitor的/masterha/app1目录下。
sun may 21 20:50:51 2017 - [info] * phase 3.2: saving dead master's binlog phase..sun may 21 20:50:51 2017 - [info]
sun may 21 20:50:52 2017 - [info] fetching dead master's binary logs..sun may 21 20:50:52 2017 - [info] executing command on the dead master 192.168.244.10(192.168.244.10:3306): save_binary_logs --command=save --start_file=mysql-bin.000001 --start_pos=880 --binlog_dir=/var/lib/mysql --output_file=/tmp/saved_master_binlog_from_192.168.244.10_3306_20170521205050.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.000001 pos 880 to mysql-bin.000001 eof into /tmp/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog ..
binlog checksum enabled
dumping binlog format description event, from position 0 to 120.. ok.
dumping effective binlog data from /var/lib/mysql/mysql-bin.000001 position 880 to tail(1308).. ok.
binlog checksum enabled
concat succeeded.
sun may 21 20:50:52 2017 - [info] scp from root@192.168.244.10:/tmp/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog to local:/masterha/app1/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog succeeded.
sun may 21 20:50:52 2017 - [info] healthcheck: ssh to 192.168.244.20 is reachable.
sun may 21 20:50:53 2017 - [info] healthcheck: ssh to 192.168.244.30 is reachable.
sun may 21 20:50:53 2017 - [info]
-- 3.3 选新主阶段
首先判断最新的slave中是否包括最旧的二进制日志（mysql-bin.000001:452）以后的relay log。
接着选新主，
因为192.168.244.20中设置了candidate_master设置了，所以192.168.244.20被指定为新主。
sun may 21 20:50:53 2017 - [info] * phase 3.3: determining new master phase..
sun may 21 20:50:53 2017 - [info]
sun may 21 20:50:53 2017 - [info] finding the latest slave that has all relay logs for recovering other slaves..
sun may 21 20:50:53 2017 - [info] checking whether 192.168.244.30 has relay logs from the oldest position..
sun may 21 20:50:53 2017 - [info] executing command: apply_diff_relay_logs --command=find --latest_mlf=mysql-bin.000001 --latest_rmlp=880 --target_mlf=mysql-bin.000001 --target_rmlp=452 --server_id=3 --workdir=/tmp --timestamp=20170521205050 --manager_version=0.56 --relay_log_info=/var/lib/mysql/relay-log.info --relay_dir=/var/lib/mysql/ :
opening /var/lib/mysql/relay-log.info ... ok.
relay log found at /var/lib/mysql, up to mysqld-relay-bin.000003
fast relay log position search failed. reading relay logs to find..
reading mysqld-relay-bin.000003
binlog checksum enabled
reading mysqld-relay-bin.000002
binlog checksum enabled
master version is 5.6.31-log
binlog checksum enabled
mysqld-relay-bin.000002 contains master mysql-bin.000001 from position 120target relay log found!sun may 21 20:50:53 2017 - [info] ok. 192.168.244.30 has all relay logs.
sun may 21 20:50:53 2017 - [info] searching new master from slaves..
sun may 21 20:50:53 2017 - [info] candidate masters from the configuration file:
sun may 21 20:50:53 2017 - [info] 192.168.244.20(192.168.244.20:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 20:50:53 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 20:50:53 2017 - [info] primary candidate for the new master (candidate_master is set)
sun may 21 20:50:53 2017 - [info] non-candidate masters:
sun may 21 20:50:53 2017 - [info] searching from candidate_master slaves which have received the latest relay log events..
sun may 21 20:50:53 2017 - [info] not found.
sun may 21 20:50:53 2017 - [info] searching from all candidate_master slaves..
sun may 21 20:50:53 2017 - [info] new master is 192.168.244.20(192.168.244.20:3306)
sun may 21 20:50:53 2017 - [info] starting master failover..
sun may 21 20:50:53 2017 - [info]
from:192.168.244.10(192.168.244.10:3306) (current master) +--192.168.244.20(192.168.244.20:3306) +--192.168.244.30(192.168.244.30:3306)
to:192.168.244.20(192.168.244.20:3306) (new master) +--192.168.244.30(192.168.244.30:3306)
sun may 21 20:50:53 2017 - [info]
-- 3.3 获取新主所需的差异二进制日志，包括两部分 1> 新主和最新的slave之间差异的relay log 2> 保存在mha manager上的最新的slave和原master之前差异的binlog
其中，差异的relay log通过如下方式获取：
ssh到192.168.244.30上，执行apply_diff_relay_logs获取差异的relay log。将差异的relay log scp到192.168.244.20。
sun may 21 20:50:53 2017 - [info] * phase 3.3: new master diff log generation phase..
sun may 21 20:50:53 2017 - [info]
sun may 21 20:50:53 2017 - [info] server 192.168.244.20 received relay logs up to: mysql-bin.000001:452sun may 21 20:50:53 2017 - [info] need to get diffs from the latest slave(192.168.244.30) up to: mysql-bin.000001:880 (using the latest slave's relay logs)sun may 21 20:50:53 2017 - [info] connecting to the latest slave host 192.168.244.30, generating diff relay log files..
sun may 21 20:50:53 2017 - [info] executing command: apply_diff_relay_logs --command=generate_and_send --scp_user=root --scp_host=192.168.244.20 --latest_mlf=mysql-bin.000001 --latest_rmlp=880 --target_mlf=mysql-bin.000001 --target_rmlp=452 --server_id=3 --diff_file_readtolatest=/tmp/relay_from_read_to_latest_192.168.244.20_3306_20170521205050.binlog --workdir=/tmp --timestamp=20170521205050 --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.56 --relay_log_info=/var/lib/mysql/relay-log.info --relay_dir=/var/lib/mysql/ sun may 21 20:50:54 2017 - [info]
opening /var/lib/mysql/relay-log.info ... ok.
relay log found at /var/lib/mysql, up to mysqld-relay-bin.000003
fast relay log position search failed. reading relay logs to find..
reading mysqld-relay-bin.000003
binlog checksum enabled
reading mysqld-relay-bin.000002
binlog checksum enabled
master version is 5.6.31-log
binlog checksum enabled
mysqld-relay-bin.000002 contains master mysql-bin.000001 from position 120
target relay log file/position found. start_file:mysqld-relay-bin.000002, start_pos:615.
concat binary/relay logs from mysqld-relay-bin.000002 pos 615 to mysqld-relay-bin.000003 eof into /tmp/relay_from_read_to_latest_192.168.244.20_3306_20170521205050.binlog ..
binlog checksum enabled
binlog checksum enabled
dumping binlog format description event, from position 0 to 283.. ok.
dumping effective binlog data from /var/lib/mysql/mysqld-relay-bin.000002 position 615 to tail(1066).. ok.
dumping binlog head events (rotate events), skipping format description events from /var/lib/mysql/mysqld-relay-bin.000003.. binlog checksum enabled
dumped up to pos 120. ok.
no need to dump effective binlog data from /var/lib/mysql/mysqld-relay-bin.000003 (pos starts 120, filesize 120). skipping.
binlog checksum enabled
binlog checksum enabled
concat succeeded.
generating diff relay log succeeded. saved at /tmp/relay_from_read_to_latest_192.168.244.20_3306_20170521205050.binlog . scp node3:/tmp/relay_from_read_to_latest_192.168.244.20_3306_20170521205050.binlog to root@192.168.244.20(22) succeeded.
sun may 21 20:50:54 2017 - [info] generating diff files succeeded.
sun may 21 20:50:54 2017 - [info] sending binlog..
sun may 21 20:50:54 2017 - [info] scp from local:/masterha/app1/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog to root@192.168.244.20:/tmp/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog succeeded.
sun may 21 20:50:54 2017 - [info]
-- 3.4 应用从master保存的二进制日志事件
首先，等原来的所有的relay log都应用完。
其次，再通过apply_diff_relay_logs应用差异的relay log，及差异的binlog。
应用完毕后，得到新的master binlog的文件和位置，其它slave可根据该文件和位置来建立主从复制关系。
第三，执行master_ip_failover脚本，执行如下操作 1> 将新主的read_only设置为0 2> 启动vip
sun may 21 20:50:54 2017 - [info] * phase 3.4: master log apply phase..
sun may 21 20:50:54 2017 - [info]
sun may 21 20:50:54 2017 - [info] *notice: if any error happens from this phase, manual recovery is needed.
sun may 21 20:50:54 2017 - [info] starting recovery on 192.168.244.20(192.168.244.20:3306)..
sun may 21 20:50:54 2017 - [info] generating diffs succeeded.
sun may 21 20:50:54 2017 - [info] waiting until all relay logs are applied.
sun may 21 20:50:54 2017 - [info] done.
sun may 21 20:50:54 2017 - [info] getting slave status..
sun may 21 20:50:54 2017 - [info] this slave(192.168.244.20)'s exec_master_log_pos equals to read_master_log_pos(mysql-bin.000001:452). no need to recover from exec_master_log_pos.sun may 21 20:50:54 2017 - [info] connecting to the target slave host 192.168.244.20, running recover script..
sun may 21 20:50:54 2017 - [info] executing command: apply_diff_relay_logs --command=apply --slave_user='monitor' --slave_host=192.168.244.20 --slave_ip=192.168.244.20 --slave_port=3306 --apply_files=/tmp/relay_from_read_to_latest_192.168.244.20_3306_20170521205050.binlog,/tmp/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog --workdir=/tmp --target_version=5.6.31-log --timestamp=20170521205050 --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.56 --slave_pass=xxx
sun may 21 20:50:55 2017 - [info]
concat all apply files to /tmp/total_binlog_for_192.168.244.20_3306.20170521205050.binlog ..
copying the first binlog file /tmp/relay_from_read_to_latest_192.168.244.20_3306_20170521205050.binlog to /tmp/total_binlog_for_192.168.244.20_3306.20170521205050.binlog.. ok.
dumping binlog head events (rotate events), skipping format description events from /tmp/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog.. binlog checksum enabled
dumped up to pos 120. ok. /tmp/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog has effective binlog events from pos 120.
dumping effective binlog data from /tmp/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog position 120 to tail(548).. ok.
concat succeeded.
all apply target binary logs are concatinated at /tmp/total_binlog_for_192.168.244.20_3306.20170521205050.binlog .
mysql client version is 5.6.31. using --binary-mode.
applying differential binary/relay log files /tmp/relay_from_read_to_latest_192.168.244.20_3306_20170521205050.binlog,/tmp/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog on 192.168.244.20:3306. this may take long time...
applying log files succeeded.
sun may 21 20:50:55 2017 - [info] all relay logs were successfully applied.
sun may 21 20:50:55 2017 - [info] getting new master's binlog name and position..sun may 21 20:50:55 2017 - [info] mysql-bin.000002:976sun may 21 20:50:55 2017 - [info] all other slaves should start replication from here. statement should be: change master to master_host='192.168.244.20', master_port=3306, master_log_file='mysql-bin.000002', master_log_pos=976, master_user='repl', master_password='xxx';
sun may 21 20:50:55 2017 - [info] executing master ip activate script:
sun may 21 20:50:55 2017 - [info] /usr/local/bin/master_ip_failover --command=start --ssh_user=root --orig_master_host=192.168.244.10 --orig_master_ip=192.168.244.10 --orig_master_port=3306 --new_master_host=192.168.244.20 --new_master_ip=192.168.244.20 --new_master_port=3306 --new_master_user='monitor' --new_master_password='monitor123' set read_only=0 on the new master.
enabling the vip 192.168.244.188 on the new master: 192.168.244.20 sun may 21 20:50:55 2017 - [info] ok.
sun may 21 20:50:55 2017 - [info] ** finished master recovery successfully.
sun may 21 20:50:55 2017 - [info] * phase 3: master recovery phase completed.-- 第四阶段 slave恢复阶段-- 4.1 因为192.168.244.30拥有最新的relay log，所以也没必要获取差异的relay log-- 4.2 开始slave的恢复阶段 1> 将monitor上保存的master上的差异的二进制日志scp到slave上。 2> 应用差异日志。 3> 清除原来的复制关系，并再次执行change master命令建立新的主从同步。
如果有多个slave，则该恢复过程是并行的。
sun may 21 20:50:55 2017 - [info]
sun may 21 20:50:55 2017 - [info] * phase 4: slaves recovery phase..
sun may 21 20:50:55 2017 - [info]
sun may 21 20:50:55 2017 - [info] * phase 4.1: starting parallel slave diff log generation phase..
sun may 21 20:50:55 2017 - [info]
sun may 21 20:50:55 2017 - [info] -- slave diff file generation on host 192.168.244.30(192.168.244.30:3306) started, pid: 4966. check tmp log /masterha/app1/192.168.244.30_3306_20170521205050.log if it takes time..
sun may 21 20:50:56 2017 - [info]
sun may 21 20:50:56 2017 - [info] log messages from 192.168.244.30 ...
sun may 21 20:50:56 2017 - [info]
sun may 21 20:50:55 2017 - [info] this server has all relay logs. no need to generate diff files from the latest slave.
sun may 21 20:50:56 2017 - [info] end of log messages from 192.168.244.30.
sun may 21 20:50:56 2017 - [info] -- 192.168.244.30(192.168.244.30:3306) has the latest relay log events.
sun may 21 20:50:56 2017 - [info] generating relay diff files from the latest slave succeeded.
sun may 21 20:50:56 2017 - [info]
sun may 21 20:50:56 2017 - [info] * phase 4.2: starting parallel slave log apply phase..
sun may 21 20:50:56 2017 - [info]
sun may 21 20:50:56 2017 - [info] -- slave recovery on host 192.168.244.30(192.168.244.30:3306) started, pid: 4968. check tmp log /masterha/app1/192.168.244.30_3306_20170521205050.log if it takes time..
sun may 21 20:50:58 2017 - [info]
sun may 21 20:50:58 2017 - [info] log messages from 192.168.244.30 ...
sun may 21 20:50:58 2017 - [info]
sun may 21 20:50:56 2017 - [info] sending binlog..
sun may 21 20:50:57 2017 - [info] scp from local:/masterha/app1/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog to root@192.168.244.30:/tmp/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog succeeded.
sun may 21 20:50:57 2017 - [info] starting recovery on 192.168.244.30(192.168.244.30:3306)..
sun may 21 20:50:57 2017 - [info] generating diffs succeeded.
sun may 21 20:50:57 2017 - [info] waiting until all relay logs are applied.
sun may 21 20:50:57 2017 - [info] done.
sun may 21 20:50:57 2017 - [info] getting slave status..
sun may 21 20:50:57 2017 - [info] this slave(192.168.244.30)'s exec_master_log_pos equals to read_master_log_pos(mysql-bin.000001:880). no need to recover from exec_master_log_pos.sun may 21 20:50:57 2017 - [info] connecting to the target slave host 192.168.244.30, running recover script..
sun may 21 20:50:57 2017 - [info] executing command: apply_diff_relay_logs --command=apply --slave_user='monitor' --slave_host=192.168.244.30 --slave_ip=192.168.244.30 --slave_port=3306 --apply_files=/tmp/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog --workdir=/tmp --target_version=5.6.31-log --timestamp=20170521205050 --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.56 --slave_pass=xxx
sun may 21 20:50:57 2017 - [info]
mysql client version is 5.6.31. using --binary-mode.
applying differential binary/relay log files /tmp/saved_master_binlog_from_192.168.244.10_3306_20170521205050.binlog on 192.168.244.30:3306. this may take long time...
applying log files succeeded.
sun may 21 20:50:57 2017 - [info] all relay logs were successfully applied.
sun may 21 20:50:57 2017 - [info] resetting slave 192.168.244.30(192.168.244.30:3306) and starting replication from the new master 192.168.244.20(192.168.244.20:3306)..
sun may 21 20:50:58 2017 - [info] executed change master.
sun may 21 20:50:58 2017 - [info] slave started.
sun may 21 20:50:58 2017 - [info] end of log messages from 192.168.244.30.
sun may 21 20:50:58 2017 - [info] -- slave recovery on host 192.168.244.30(192.168.244.30:3306) succeeded.
sun may 21 20:50:58 2017 - [info] all new slave servers recovered successfully.-- 第五阶段 清理阶段
从mha的配置文件中剔除server1的配置信息
sun may 21 20:50:58 2017 - [info]
sun may 21 20:50:58 2017 - [info] * phase 5: new master cleanup phase..
sun may 21 20:50:58 2017 - [info]
sun may 21 20:50:58 2017 - [info] resetting slave info on the new master..
sun may 21 20:50:58 2017 - [info] 192.168.244.20: resetting slave info succeeded.
sun may 21 20:50:58 2017 - [info] master failover to 192.168.244.20(192.168.244.20:3306) completed successfully.
sun may 21 20:50:58 2017 - [info] deleted server1 entry from /etc/masterha/app1.cnf .
sun may 21 20:50:58 2017 - [info]
-- 生成 failover 报告，发送告警邮件----- failover report -----app1: mysql master failover 192.168.244.10(192.168.244.10:3306) to 192.168.244.20(192.168.244.20:3306) succeeded
master 192.168.244.10(192.168.244.10:3306) is down!check mha manager logs at node4:/masterha/app1/manager.log for details.
started automated(non-interactive) failover.
invalidated master ip address on 192.168.244.10(192.168.244.10:3306)
the latest slave 192.168.244.30(192.168.244.30:3306) has all relay logs for recovery.
selected 192.168.244.20(192.168.244.20:3306) as a new master.192.168.244.20(192.168.244.20:3306): ok: applying all logs succeeded.192.168.244.20(192.168.244.20:3306): ok: activated master ip address.192.168.244.30(192.168.244.30:3306): this host has the latest relay log events.
generating relay diff files from the latest slave succeeded.192.168.244.30(192.168.244.30:3306): ok: applying all logs succeeded. slave started, replicating from 192.168.244.20(192.168.244.20:3306)192.168.244.20(192.168.244.20:3306): resetting slave info succeeded.
master failover to 192.168.244.20(192.168.244.20:3306) completed successfully.
sun may 21 20:50:58 2017 - [info] sending mail..
unknown option: conf
从上面的日志输出可以看出整个mha的切换过程
首先，mha manager检测到master不可用，则会通过另外两个slave检查master的可用性。一共检测4次。
同时判断mha manager到master的ssh可用性。
ssh可用性的判断结果影响后后续切换中的“phase 3.2: saving dead master's binlog phase”
phase 1: configuration check phase..
检查了mha的配置信息，并再次判断了master的可用性。
phase 2: dead master shutdown phase..
宕机的master处理阶段，包括摘除vip，执行shutdown_script中定义的脚本。
phase 3: master recovery phase..
phase 3.1: getting latest slaves phase..
判断哪个slave拥有最新的relay log（通过比较show slave status中的master_log_file, read_master_log_pos位置），
哪个slave拥有最旧的relay log
phase 3.2: saving dead master's binlog phase..
根据上面得到的slave的最新位置信息，将差异的二进制日志保存到mha manager的指定目录下。
如果在第一步骤中，判断了mha manager到master的ssh不可用，则会跳过这个阶段。
phase 3.3: determining new master phase..
选择新的master
phase 3.3: new master diff log generation phase..
将差异的relay log和master差异日志scp到新的master上。
phase 3.4: master log apply phase..
首先，等待slave上已有的relay log都应用完。
其次，通过apply_diff_relay_logs应用差异的relay log，及差异的binlog。
应用完毕后，得到新的master binlog的文件和位置，其它slave可根据该文件和位置来建立主从复制关系。
第三，执行master_ip_failover脚本，执行如下操作
1> 将新主的read_only设置为0
2> 启动vip
phase 4: slaves recovery phase
phase 4.1: starting parallel slave diff log generation phase
为slave获取差异的relay log
因为192.168.244.30拥有最新的relay log，所以也没必要获取差异的relay log
phase 4.2: starting parallel slave log apply phase
开始slave的恢复阶段
1> 将差异的relay log和master差异日志scp到slave上。
2> 应用差异日志。
3> 清除原来的复制关系，并再次执行change master命令建立新的主从同步。
如果有多个slave，则该恢复过程是并行的。
phase 5: new master cleanup phase
从mha的配置文件中剔除server1的配置信息
最后，生成failover report并发送告警邮件。
手动failover
与自动failover相对应的是手动failover，即当master发生故障时，通过手动执行脚本来进行故障切换。
命令如下：
# masterha_master_switch --master_state=dead --conf=/etc/masterha/app1.cnf --dead_master_host=192.168.244.10 --dead_master_port=3306 --new_master_host=192.168.244.30 --new_master_port=3306 --ignore_last_failover
输出日志信息如下：
--dead_master_ip=<dead_master_ip> is not set. using 192.168.244.10.
wed may 24 19:44:20 2017 - [warning] global configuration file /etc/masterha_default.cnf not found. skipping.
wed may 24 19:44:20 2017 - [info] reading application default configuration from /etc/masterha/app1.cnf..
wed may 24 19:44:20 2017 - [info] reading server configuration from /etc/masterha/app1.cnf..
wed may 24 19:44:20 2017 - [info] mha::masterfailover version 0.56.
wed may 24 19:44:20 2017 - [info] starting master failover.
wed may 24 19:44:20 2017 - [info]
wed may 24 19:44:20 2017 - [info] * phase 1: configuration check phase..
wed may 24 19:44:20 2017 - [info]
wed may 24 19:44:21 2017 - [info] gtid failover mode = 0wed may 24 19:44:21 2017 - [info] dead servers:
wed may 24 19:44:21 2017 - [info] 192.168.244.10(192.168.244.10:3306)
wed may 24 19:44:21 2017 - [info] checking master reachability via mysql(double check)...
wed may 24 19:44:21 2017 - [info] ok.
wed may 24 19:44:21 2017 - [info] alive servers:
wed may 24 19:44:21 2017 - [info] 192.168.244.20(192.168.244.20:3306)
wed may 24 19:44:21 2017 - [info] 192.168.244.30(192.168.244.30:3306)
wed may 24 19:44:21 2017 - [info] alive slaves:
wed may 24 19:44:21 2017 - [info] 192.168.244.20(192.168.244.20:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabledwed may 24 19:44:21 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
wed may 24 19:44:21 2017 - [info] primary candidate for the new master (candidate_master is set)
wed may 24 19:44:21 2017 - [info] 192.168.244.30(192.168.244.30:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabledwed may 24 19:44:21 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
master 192.168.244.10(192.168.244.10:3306) is dead. proceed? (yes/no): yes
wed may 24 19:44:23 2017 - [info] starting non-gtid based failover.
wed may 24 19:44:23 2017 - [info]
wed may 24 19:44:23 2017 - [info] ** phase 1: configuration check phase completed.
wed may 24 19:44:23 2017 - [info]
wed may 24 19:44:23 2017 - [info] * phase 2: dead master shutdown phase..
wed may 24 19:44:23 2017 - [info]
wed may 24 19:44:24 2017 - [info] healthcheck: ssh to 192.168.244.10 is reachable.
wed may 24 19:44:24 2017 - [info] forcing shutdown so that applications never connect to the current master..
wed may 24 19:44:24 2017 - [info] executing master ip deactivation script:
wed may 24 19:44:24 2017 - [info] /usr/local/bin/master_ip_failover --orig_master_host=192.168.244.10 --orig_master_ip=192.168.244.10 --orig_master_port=3306 --command=stopssh --ssh_user=root disabling the vip an old master: 192.168.244.10 siocsifflags: cannot assign requested address
wed may 24 19:44:24 2017 - [info] done.
wed may 24 19:44:24 2017 - [warning] shutdown_script is not set. skipping explicit shutting down of the dead master.
wed may 24 19:44:24 2017 - [info] * phase 2: dead master shutdown phase completed.
wed may 24 19:44:24 2017 - [info]
wed may 24 19:44:24 2017 - [info] * phase 3: master recovery phase..
wed may 24 19:44:24 2017 - [info]
wed may 24 19:44:24 2017 - [info] * phase 3.1: getting latest slaves phase..
wed may 24 19:44:24 2017 - [info]
wed may 24 19:44:24 2017 - [info] the latest binary log file/position on all slaves is mysql-bin.000002:120wed may 24 19:44:24 2017 - [info] latest slaves (slaves that received relay log files to the latest):
wed may 24 19:44:24 2017 - [info] 192.168.244.20(192.168.244.20:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabledwed may 24 19:44:24 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
wed may 24 19:44:24 2017 - [info] primary candidate for the new master (candidate_master is set)
wed may 24 19:44:24 2017 - [info] 192.168.244.30(192.168.244.30:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabledwed may 24 19:44:24 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
wed may 24 19:44:24 2017 - [info] the oldest binary log file/position on all slaves is mysql-bin.000002:120wed may 24 19:44:24 2017 - [info] oldest slaves:
wed may 24 19:44:24 2017 - [info] 192.168.244.20(192.168.244.20:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabledwed may 24 19:44:24 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
wed may 24 19:44:24 2017 - [info] primary candidate for the new master (candidate_master is set)
wed may 24 19:44:24 2017 - [info] 192.168.244.30(192.168.244.30:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabledwed may 24 19:44:24 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
wed may 24 19:44:24 2017 - [info]
wed may 24 19:44:24 2017 - [info] * phase 3.2: saving dead master's binlog phase..wed may 24 19:44:24 2017 - [info]
wed may 24 19:44:24 2017 - [info] fetching dead master's binary logs..wed may 24 19:44:24 2017 - [info] executing command on the dead master 192.168.244.10(192.168.244.10:3306): save_binary_logs --comman
d=save --start_file=mysql-bin.000002 --start_pos=120 --binlog_dir=/var/lib/mysql --output_file=/tmp/saved_master_binlog_from_192.168.244.10_3306_20170524194420.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.000002 pos 120 to mysql-bin.000002 eof into /tmp/saved_master_binlog_from_192.168.244.10_330
6_20170524194420.binlog .. binlog checksum enabled
dumping binlog format description event, from position 0 to 120.. ok.
dumping effective binlog data from /var/lib/mysql/mysql-bin.000002 position 120 to tail(143).. ok.
binlog checksum enabled
concat succeeded.
saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlog 100% 143 0.1kb/s 00:00 wed may 24 19:44:24 2017 - [info] scp from root@192.168.244.10:/tmp/saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlo
g to local:/masterha/app1/saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlog succeeded.wed may 24 19:44:25 2017 - [info] healthcheck: ssh to 192.168.244.20 is reachable.
wed may 24 19:44:25 2017 - [info] healthcheck: ssh to 192.168.244.30 is reachable.
wed may 24 19:44:25 2017 - [info]
wed may 24 19:44:25 2017 - [info] * phase 3.3: determining new master phase..
wed may 24 19:44:25 2017 - [info]
wed may 24 19:44:25 2017 - [info] finding the latest slave that has all relay logs for recovering other slaves..
wed may 24 19:44:25 2017 - [info] all slaves received relay logs to the same position. no need to resync each other.
wed may 24 19:44:25 2017 - [info] 192.168.244.30 can be new master.
wed may 24 19:44:25 2017 - [info] new master is 192.168.244.30(192.168.244.30:3306)
wed may 24 19:44:25 2017 - [info] starting master failover..
wed may 24 19:44:25 2017 - [info]
from:192.168.244.10(192.168.244.10:3306) (current master) +--192.168.244.20(192.168.244.20:3306) +--192.168.244.30(192.168.244.30:3306)
to:192.168.244.30(192.168.244.30:3306) (new master) +--192.168.244.20(192.168.244.20:3306)
starting master switch from 192.168.244.10(192.168.244.10:3306) to 192.168.244.30(192.168.244.30:3306)? (yes/no): yes
wed may 24 19:44:32 2017 - [info] new master decided manually is 192.168.244.30(192.168.244.30:3306)
wed may 24 19:44:32 2017 - [info]
wed may 24 19:44:32 2017 - [info] * phase 3.3: new master diff log generation phase..
wed may 24 19:44:32 2017 - [info]
wed may 24 19:44:32 2017 - [info] this server has all relay logs. no need to generate diff files from the latest slave.
wed may 24 19:44:32 2017 - [info] sending binlog..
saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlog 100% 143 0.1kb/s 00:00 wed may 24 19:44:33 2017 - [info] scp from local:/masterha/app1/saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlog to
root@192.168.244.30:/tmp/saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlog succeeded.wed may 24 19:44:33 2017 - [info]
wed may 24 19:44:33 2017 - [info] * phase 3.4: master log apply phase..
wed may 24 19:44:33 2017 - [info]
wed may 24 19:44:33 2017 - [info] *notice: if any error happens from this phase, manual recovery is needed.
wed may 24 19:44:33 2017 - [info] starting recovery on 192.168.244.30(192.168.244.30:3306)..
wed may 24 19:44:33 2017 - [info] generating diffs succeeded.
wed may 24 19:44:33 2017 - [info] waiting until all relay logs are applied.
wed may 24 19:44:33 2017 - [info] done.
wed may 24 19:44:33 2017 - [info] getting slave status..
wed may 24 19:44:33 2017 - [info] this slave(192.168.244.30)'s exec_master_log_pos equals to read_master_log_pos(mysql-bin.000002:120). no need to recover from exec_master_log_pos.wed may 24 19:44:33 2017 - [info] connecting to the target slave host 192.168.244.30, running recover script..
wed may 24 19:44:33 2017 - [info] executing command: apply_diff_relay_logs --command=apply --slave_user='monitor' --slave_host=192.168.244.30 --slave_ip=192.168.244.30 --slave_port=3306 --apply_files=/tmp/saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlog --workdir=/tmp --target_version=5.6.31-log --timestamp=20170524194420 --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.56 --slave_pass=xxxwed may 24 19:44:33 2017 - [info]
mysql client version is 5.6.31. using --binary-mode.
applying differential binary/relay log files /tmp/saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlog on 192.168.244.30:3306. this may take long time...applying log files succeeded.
wed may 24 19:44:33 2017 - [info] all relay logs were successfully applied.
wed may 24 19:44:33 2017 - [info] getting new master's binlog name and position..wed may 24 19:44:33 2017 - [info] mysql-bin.000001:1429wed may 24 19:44:33 2017 - [info] all other slaves should start replication from here. statement should be: change master to master_
host='192.168.244.30', master_port=3306, master_log_file='mysql-bin.000001', master_log_pos=1429, master_user='repl', master_password='xxx';wed may 24 19:44:33 2017 - [info] executing master ip activate script:
wed may 24 19:44:33 2017 - [info] /usr/local/bin/master_ip_failover --command=start --ssh_user=root --orig_master_host=192.168.244.10 --orig_master_ip=192.168.244.10 --orig_master_port=3306 --new_master_host=192.168.244.30 --new_master_ip=192.168.244.30 --new_master_port=3306 --new_master_user='monitor' --new_master_password='monitor123' set read_only=0 on the new master.
enabling the vip 192.168.244.188 on the new master: 192.168.244.30 wed may 24 19:44:33 2017 - [info] ok.
wed may 24 19:44:33 2017 - [info] ** finished master recovery successfully.
wed may 24 19:44:33 2017 - [info] * phase 3: master recovery phase completed.
wed may 24 19:44:33 2017 - [info]
wed may 24 19:44:33 2017 - [info] * phase 4: slaves recovery phase..
wed may 24 19:44:33 2017 - [info]
wed may 24 19:44:33 2017 - [info] * phase 4.1: starting parallel slave diff log generation phase..
wed may 24 19:44:33 2017 - [info]
wed may 24 19:44:33 2017 - [info] -- slave diff file generation on host 192.168.244.20(192.168.244.20:3306) started, pid: 1598. check
tmp log /masterha/app1/192.168.244.20_3306_20170524194420.log if it takes time..wed may 24 19:44:34 2017 - [info]
wed may 24 19:44:34 2017 - [info] log messages from 192.168.244.20 ...
wed may 24 19:44:34 2017 - [info]
wed may 24 19:44:33 2017 - [info] this server has all relay logs. no need to generate diff files from the latest slave.
wed may 24 19:44:34 2017 - [info] end of log messages from 192.168.244.20.
wed may 24 19:44:34 2017 - [info] -- 192.168.244.20(192.168.244.20:3306) has the latest relay log events.
wed may 24 19:44:34 2017 - [info] generating relay diff files from the latest slave succeeded.
wed may 24 19:44:34 2017 - [info]
wed may 24 19:44:34 2017 - [info] * phase 4.2: starting parallel slave log apply phase..
wed may 24 19:44:34 2017 - [info]
wed may 24 19:44:34 2017 - [info] -- slave recovery on host 192.168.244.20(192.168.244.20:3306) started, pid: 1600. check tmp log /ma
sterha/app1/192.168.244.20_3306_20170524194420.log if it takes time..saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlog 100% 143 0.1kb/s 00:00 wed may 24 19:44:35 2017 - [info]
wed may 24 19:44:35 2017 - [info] log messages from 192.168.244.20 ...
wed may 24 19:44:35 2017 - [info]
wed may 24 19:44:34 2017 - [info] sending binlog..
wed may 24 19:44:35 2017 - [info] scp from local:/masterha/app1/saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlog to
root@192.168.244.20:/tmp/saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlog succeeded.wed may 24 19:44:35 2017 - [info] starting recovery on 192.168.244.20(192.168.244.20:3306)..
wed may 24 19:44:35 2017 - [info] generating diffs succeeded.
wed may 24 19:44:35 2017 - [info] waiting until all relay logs are applied.
wed may 24 19:44:35 2017 - [info] done.
wed may 24 19:44:35 2017 - [info] getting slave status..
wed may 24 19:44:35 2017 - [info] this slave(192.168.244.20)'s exec_master_log_pos equals to read_master_log_pos(mysql-bin.000002:120). no need to recover from exec_master_log_pos.wed may 24 19:44:35 2017 - [info] connecting to the target slave host 192.168.244.20, running recover script..
wed may 24 19:44:35 2017 - [info] executing command: apply_diff_relay_logs --command=apply --slave_user='monitor' --slave_host=192.168.244.20 --slave_ip=192.168.244.20 --slave_port=3306 --apply_files=/tmp/saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlog --workdir=/tmp --target_version=5.6.31-log --timestamp=20170524194420 --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.56 --slave_pass=xxxwed may 24 19:44:35 2017 - [info]
mysql client version is 5.6.31. using --binary-mode.
applying differential binary/relay log files /tmp/saved_master_binlog_from_192.168.244.10_3306_20170524194420.binlog on 192.168.244.20:3306. this may take long time...applying log files succeeded.
wed may 24 19:44:35 2017 - [info] all relay logs were successfully applied.
wed may 24 19:44:35 2017 - [info] resetting slave 192.168.244.20(192.168.244.20:3306) and starting replication from the new master 192.168.244.30(192.168.244.30:3306)..wed may 24 19:44:35 2017 - [info] executed change master.
wed may 24 19:44:35 2017 - [info] slave started.
wed may 24 19:44:35 2017 - [info] end of log messages from 192.168.244.20.
wed may 24 19:44:35 2017 - [info] -- slave recovery on host 192.168.244.20(192.168.244.20:3306) succeeded.
wed may 24 19:44:35 2017 - [info] all new slave servers recovered successfully.
wed may 24 19:44:35 2017 - [info]
wed may 24 19:44:35 2017 - [info] * phase 5: new master cleanup phase..
wed may 24 19:44:35 2017 - [info]
wed may 24 19:44:35 2017 - [info] resetting slave info on the new master..
wed may 24 19:44:35 2017 - [info] 192.168.244.30: resetting slave info succeeded.
wed may 24 19:44:35 2017 - [info] master failover to 192.168.244.30(192.168.244.30:3306) completed successfully.
wed may 24 19:44:35 2017 - [info]
----- failover report -----app1: mysql master failover 192.168.244.10(192.168.244.10:3306) to 192.168.244.30(192.168.244.30:3306) succeeded
master 192.168.244.10(192.168.244.10:3306) is down!check mha manager logs at node4 for details.
started manual(interactive) failover.
invalidated master ip address on 192.168.244.10(192.168.244.10:3306)
the latest slave 192.168.244.20(192.168.244.20:3306) has all relay logs for recovery.
selected 192.168.244.30(192.168.244.30:3306) as a new master.192.168.244.30(192.168.244.30:3306): ok: applying all logs succeeded.192.168.244.30(192.168.244.30:3306): ok: activated master ip address.192.168.244.20(192.168.244.20:3306): this host has the latest relay log events.
generating relay diff files from the latest slave succeeded.192.168.244.20(192.168.244.20:3306): ok: applying all logs succeeded. slave started, replicating from 192.168.244.30(192.168.244.30:3306)192.168.244.30(192.168.244.30:3306): resetting slave info succeeded.
master failover to 192.168.244.30(192.168.244.30:3306) completed successfully.
wed may 24 19:44:35 2017 - [info] sending mail..
unknown option: conf
在切换的过程中，会有两次确认操作。
通过日志的输出，可以看出，手动failover的切换逻辑和自动failover的切换逻辑基本一致。
在上面的命令中，显示指定了--new_master_host参数，如果，没有显示指定该参数的话，则默认新主为192.168.244.20，因为在/etc/masterha/app1.cnf中将主机设置为candidate_master=1。
事实上，如果master alive的话，是不允许切换的。
wed may 24 19:26:24 2017 - [warning] global configuration file /etc/masterha_default.cnf not found. skipping.
wed may 24 19:26:24 2017 - [info] reading application default configuration from /etc/masterha/app1.cnf..
wed may 24 19:26:24 2017 - [info] reading server configuration from /etc/masterha/app1.cnf..
wed may 24 19:26:24 2017 - [info] mha::masterfailover version 0.56.
wed may 24 19:26:24 2017 - [info] starting master failover.
wed may 24 19:26:24 2017 - [info]
wed may 24 19:26:24 2017 - [info] * phase 1: configuration check phase..
wed may 24 19:26:24 2017 - [info]
wed may 24 19:26:26 2017 - [info] gtid failover mode = 0wed may 24 19:26:26 2017 - [info] dead servers:
wed may 24 19:26:26 2017 - [error][/usr/local/share/perl5/mha/masterfailover.pm, ln187] none of server is dead. stop failover.
wed may 24 19:26:26 2017 - [error][/usr/local/share/perl5/mha/managerutil.pm, ln177] got error: at /usr/local/bin/masterha_master_switch line 53.
view code
在默认情况下，如果mha检测到两次切换的时间小于8小时，则不允许进行failover，这个时候，需指定--ignore_last_failover参数
# masterha_master_switch --master_state=dead --conf=/etc/masterha/app1.cnf --dead_master_host=192.168.244.10 --dead_master_port=3306--dead_master_ip=<dead_master_ip> is not set. using 192.168.244.10.
wed may 24 19:26:24 2017 - [warning] global configuration file /etc/masterha_default.cnf not found. skipping.
wed may 24 19:26:24 2017 - [info] reading application default configuration from /etc/masterha/app1.cnf..
wed may 24 19:26:24 2017 - [info] reading server configuration from /etc/masterha/app1.cnf..
wed may 24 19:26:24 2017 - [info] mha::masterfailover version 0.56.
wed may 24 19:26:24 2017 - [info] starting master failover.
wed may 24 19:26:24 2017 - [info]
wed may 24 19:26:24 2017 - [info] * phase 1: configuration check phase..
wed may 24 19:26:24 2017 - [info]
wed may 24 19:26:26 2017 - [info] gtid failover mode = 0wed may 24 19:26:26 2017 - [info] dead servers:
wed may 24 19:26:26 2017 - [error][/usr/local/share/perl5/mha/masterfailover.pm, ln187] none of server is dead. stop failover.
wed may 24 19:26:26 2017 - [error][/usr/local/share/perl5/mha/managerutil.pm, ln177] got error: at /usr/local/bin/masterha_master_sw
itch line 53.[root@node4 ~]# masterha_master_switch --master_state=dead --conf=/etc/masterha/app1.cnf --dead_master_host=192.168.244.10 --dead_mas
ter_port=3306--dead_master_ip=<dead_master_ip> is not set. using 192.168.244.10.
wed may 24 19:29:23 2017 - [warning] global configuration file /etc/masterha_default.cnf not found. skipping.
wed may 24 19:29:23 2017 - [info] reading application default configuration from /etc/masterha/app1.cnf..
wed may 24 19:29:23 2017 - [info] reading server configuration from /etc/masterha/app1.cnf..
wed may 24 19:29:23 2017 - [info] mha::masterfailover version 0.56.
wed may 24 19:29:23 2017 - [info] starting master failover.
wed may 24 19:29:23 2017 - [info]
wed may 24 19:29:23 2017 - [info] * phase 1: configuration check phase..
wed may 24 19:29:23 2017 - [info]
wed may 24 19:29:24 2017 - [info] gtid failover mode = 0wed may 24 19:29:24 2017 - [info] dead servers:
wed may 24 19:29:24 2017 - [info] 192.168.244.10(192.168.244.10:3306)
wed may 24 19:29:24 2017 - [info] checking master reachability via mysql(double check)...
wed may 24 19:29:24 2017 - [info] ok.
wed may 24 19:29:24 2017 - [info] alive servers:
wed may 24 19:29:24 2017 - [info] 192.168.244.20(192.168.244.20:3306)
wed may 24 19:29:24 2017 - [info] 192.168.244.30(192.168.244.30:3306)
wed may 24 19:29:24 2017 - [info] alive slaves:
wed may 24 19:29:24 2017 - [info] 192.168.244.20(192.168.244.20:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabledwed may 24 19:29:24 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
wed may 24 19:29:24 2017 - [info] primary candidate for the new master (candidate_master is set)
wed may 24 19:29:24 2017 - [info] 192.168.244.30(192.168.244.30:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabledwed may 24 19:29:24 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
master 192.168.244.10(192.168.244.10:3306) is dead. proceed? (yes/no): yes
wed may 24 19:29:46 2017 - [error][/usr/local/share/perl5/mha/masterfailover.pm, ln309] last failover was done at 2017/05/24 16:04:54. current time is too early to do failover again. if you want to do failover, manually remove /masterha/app1/app1.failover.complete and run this script again.wed may 24 19:29:46 2017 - [error][/usr/local/share/perl5/mha/managerutil.pm, ln177] got error: at /usr/local/bin/masterha_master_sw
itch line 53.
view code
后面附上之前提到的测试结果不理想的两种方案
方案一：
模拟步骤如下：
1. master上创建测试表
mysql sbtest.t1(id ,col1 (),col2 (),col3 (),col4 (),col5 ),col6 (),col7 (),col8 (),col9 (),col10 ());
query ok, rows affected ( sec)
2. 关闭candicate master和slave的主从复制。
mysql> stop slave;
query ok, 0 rows affected (0.03 sec)
3. 在master上生成测试数据
创建存储过程
delimiter //create procedure p1()begin
declare v1 int default 0; while v1 <=700000 do insert into sbtest.t1 values(v1,'aaaaaaaaaa','bbbbbbbbbb','cccccccccc','dddddddddd','eeeeeeeeee','ffffffffff','gggggggggg','hhhhhhhhhh','iiiiiiiiii','jjjjjjjjjj'); set v1=v1+1; if v1 %1000 =0 then
commit; end if; end while;end//delimiter ;
执行存储过程
mysql> call p1;
共执行了两次，生成了500m左右的binlog
[root@node1 ~]# ll -h /var/lib/mysql/mysql-bin.000046 -rw-rw---- 1 mysql mysql 502m apr 24 15:18 /var/lib/mysql/mysql-bin.00004
5. 开启candicate master和slave的主从复制并kill掉master的mysqld进程，模拟主库发生故障，进行自动failover操作
在这里，我写了个脚本来实现开启slave复制并kill掉master mysqld进程的功能
# vim monitor_slave.py
= mysqldb.connect(host, , === slave_status_result[10], slave_status_result[11= [, == checkslavestatus(check_host[1 check_slave_status
= slave_status == [, 510 == subprocess.popen(command_line, stdout=subprocess.pipe, shell= ==
执行该脚本
6. 查看mha的切换日志
sun may 21 09:46:56 2017 - [warning] got error on mysql select ping: 2006 (mysql server has gone away)
sun may 21 09:46:56 2017 - [info] executing secondary network check script: /usr/local/bin/masterha_secondary_check -s 192.168.244.20 -s 192.168.244.30 --user=root --master_host=192.168.244.10 --master_ip=192.168.244.10 --master_port=3306 --user=root --master_host=192.168.244.10 --master_ip=192.168.244.10 --master_port=3306 --master_user=monitor --masteconnection timed out during banner exchange
sun may 21 09:47:08 2017 - [warning] global configuration file /etc/masterha_default.cnf not found. skipping.
sun may 21 09:47:08 2017 - [info] reading application default configuration from /etc/masterha/app1.cnf..
sun may 21 09:47:08 2017 - [info] reading server configuration from /etc/masterha/app1.cnf..
to mysql server at 'reading initial communication packet', system error: 111)
sun may 21 09:46:57 2017 - [warning] connection failed 2 time(s)..
sun may 21 09:46:58 2017 - [warning] got error on mysql connect: 2013 (lost connection to mysql server at 'reading initial communication packet', system error: 111)
sun may 21 09:46:58 2017 - [warning] connection failed 3 time(s)..
sun may 21 09:46:59 2017 - [warning] got error on mysql connect: 2013 (lost connection to mysql server at 'reading initial communication packet', system error: 111)
sun may 21 09:46:59 2017 - [warning] connection failed 4 time(s)..
monitoring server 192.168.244.20 is reachable, master is not reachable from 192.168.244.20. ok.
sun may 21 09:47:01 2017 - [warning] healthcheck: ssh to 192.168.244.10 is not reachable.
monitoring server 192.168.244.30 is reachable, master is not reachable from 192.168.244.30. ok.
sun may 21 09:47:07 2017 - [info] master is not reachable from all other monitoring servers. failover should start.
sun may 21 09:47:07 2017 - [warning] master is not reachable from health checker!sun may 21 09:47:07 2017 - [warning] master 192.168.244.10(192.168.244.10:3306) is not reachable!sun may 21 09:47:07 2017 - [warning] ssh is not reachable.
sun may 21 09:47:07 2017 - [info] connecting to a master server failed. reading configuration file /etc/masterha_default.cnf and /etc/masterha/app1.cnf again, and trying to connect to all servers to check server status..
sun may 21 09:47:07 2017 - [warning] global configuration file /etc/masterha_default.cnf not found. skipping.
sun may 21 09:47:07 2017 - [info] reading application default configuration from /etc/masterha/app1.cnf..
sun may 21 09:47:07 2017 - [info] reading server configuration from /etc/masterha/app1.cnf..
sun may 21 09:47:08 2017 - [info] gtid failover mode = 0sun may 21 09:47:08 2017 - [info] dead servers:
sun may 21 09:47:08 2017 - [info] 192.168.244.10(192.168.244.10:3306)
sun may 21 09:47:08 2017 - [info] alive servers:
sun may 21 09:47:08 2017 - [info] 192.168.244.20(192.168.244.20:3306)
sun may 21 09:47:08 2017 - [info] 192.168.244.30(192.168.244.30:3306)
sun may 21 09:47:08 2017 - [info] alive slaves:
sun may 21 09:47:08 2017 - [info] 192.168.244.20(192.168.244.20:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 09:47:08 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 09:47:08 2017 - [info] primary candidate for the new master (candidate_master is set)
sun may 21 09:47:08 2017 - [info] 192.168.244.30(192.168.244.30:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 09:47:08 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 09:47:08 2017 - [info] checking slave configurations..
sun may 21 09:47:08 2017 - [info] checking replication filtering settings..
sun may 21 09:47:08 2017 - [info] replication filtering check ok.
sun may 21 09:47:08 2017 - [info] master is down!sun may 21 09:47:08 2017 - [info] terminating monitoring script.
sun may 21 09:47:08 2017 - [info] got exit code 20 (master dead).
sun may 21 09:47:08 2017 - [info] mha::masterfailover version 0.56.
sun may 21 09:47:08 2017 - [info] starting master failover.
sun may 21 09:47:08 2017 - [info]
sun may 21 09:47:08 2017 - [info] * phase 1: configuration check phase..
sun may 21 09:47:08 2017 - [info]
sun may 21 09:47:09 2017 - [info] gtid failover mode = 0sun may 21 09:47:09 2017 - [info] dead servers:
sun may 21 09:47:09 2017 - [info] 192.168.244.10(192.168.244.10:3306)
sun may 21 09:47:09 2017 - [info] checking master reachability via mysql(double check)...
sun may 21 09:47:09 2017 - [info] ok.
sun may 21 09:47:09 2017 - [info] alive servers:
sun may 21 09:47:09 2017 - [info] 192.168.244.20(192.168.244.20:3306)
sun may 21 09:47:09 2017 - [info] 192.168.244.30(192.168.244.30:3306)
sun may 21 09:47:09 2017 - [info] alive slaves:
sun may 21 09:47:09 2017 - [info] 192.168.244.20(192.168.244.20:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 09:47:09 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 09:47:09 2017 - [info] primary candidate for the new master (candidate_master is set)
sun may 21 09:47:09 2017 - [info] 192.168.244.30(192.168.244.30:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 09:47:09 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 09:47:09 2017 - [info] starting non-gtid based failover.
sun may 21 09:47:09 2017 - [info]
sun may 21 09:47:09 2017 - [info] ** phase 1: configuration check phase completed.
sun may 21 09:47:09 2017 - [info]
sun may 21 09:47:09 2017 - [info] * phase 2: dead master shutdown phase..
sun may 21 09:47:09 2017 - [info]
sun may 21 09:47:09 2017 - [info] forcing shutdown so that applications never connect to the current master..
sun may 21 09:47:09 2017 - [info] executing master ip deactivation script:
sun may 21 09:47:09 2017 - [info] /usr/local/bin/master_ip_failover --orig_master_host=192.168.244.10 --orig_master_ip=192.168.244.10 --orig_master_port=3306 --command=stop
disabling the vip an old master: 192.168.244.10 sun may 21 09:47:09 2017 - [info] done.
sun may 21 09:47:09 2017 - [warning] shutdown_script is not set. skipping explicit shutting down of the dead master.
sun may 21 09:47:09 2017 - [info] * phase 2: dead master shutdown phase completed.
sun may 21 09:47:09 2017 - [info]
sun may 21 09:47:09 2017 - [info] * phase 3: master recovery phase..
sun may 21 09:47:09 2017 - [info]
sun may 21 09:47:09 2017 - [info] * phase 3.1: getting latest slaves phase..
sun may 21 09:47:09 2017 - [info]
sun may 21 09:47:09 2017 - [info] the latest binary log file/position on all slaves is mysql-bin.000001:37651149sun may 21 09:47:09 2017 - [info] latest slaves (slaves that received relay log files to the latest):
sun may 21 09:47:09 2017 - [info] 192.168.244.20(192.168.244.20:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 09:47:09 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 09:47:09 2017 - [info] primary candidate for the new master (candidate_master is set)
sun may 21 09:47:09 2017 - [info] the oldest binary log file/position on all slaves is mysql-bin.000001:35083093sun may 21 09:47:09 2017 - [info] oldest slaves:
sun may 21 09:47:09 2017 - [info] 192.168.244.30(192.168.244.30:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 09:47:09 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 09:47:09 2017 - [info]
sun may 21 09:47:09 2017 - [info] * phase 3.2: saving dead master's binlog phase..sun may 21 09:47:09 2017 - [info]
sun may 21 09:47:09 2017 - [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.
sun may 21 09:47:09 2017 - [info]
sun may 21 09:47:09 2017 - [info] * phase 3.3: determining new master phase..
sun may 21 09:47:09 2017 - [info]
sun may 21 09:47:09 2017 - [info] finding the latest slave that has all relay logs for recovering other slaves..
sun may 21 09:47:10 2017 - [info] healthcheck: ssh to 192.168.244.20 is reachable.
sun may 21 09:47:10 2017 - [info] checking whether 192.168.244.20 has relay logs from the oldest position..
sun may 21 09:47:10 2017 - [info] executing command: apply_diff_relay_logs --command=find --latest_mlf=mysql-bin.000001 --latest_rmlp=37651149 --target_mlf=mysql-bin.000001 --target_rmlp=35083093 --server_id=2 --workdir=/tmp --timestamp=20170521094708 --manager_version=0.56 --relay_log_info=/var/lib/mysql/relay-log.info --relay_dir=/var/lib/mysql/ :
opening /var/lib/mysql/relay-log.info ... ok.
relay log found at /var/lib/mysql, up to mysqld-relay-bin.000004
fast relay log position search succeeded.
target relay log file/position found. start_file:mysqld-relay-bin.000004, start_pos:35083256.
target relay log found!sun may 21 09:47:11 2017 - [info] ok. 192.168.244.20 has all relay logs.
sun may 21 09:47:11 2017 - [info] healthcheck: ssh to 192.168.244.30 is reachable.
sun may 21 09:47:13 2017 - [info] searching new master from slaves..
sun may 21 09:47:13 2017 - [info] candidate masters from the configuration file:
sun may 21 09:47:13 2017 - [info] 192.168.244.20(192.168.244.20:3306) version=5.6.31-log (oldest major version between slaves) log-bin:enabled
sun may 21 09:47:13 2017 - [info] replicating from 192.168.244.10(192.168.244.10:3306)
sun may 21 09:47:13 2017 - [info] primary candidate for the new master (candidate_master is set)
sun may 21 09:47:13 2017 - [info] non-candidate masters:
sun may 21 09:47:13 2017 - [info] searching from candidate_master slaves which have received the latest relay log events..
sun may 21 09:47:13 2017 - [info] new master is 192.168.244.20(192.168.244.20:3306)
sun may 21 09:47:13 2017 - [info] starting master failover..
sun may 21 09:47:13 2017 - [info]
from:192.168.244.10(192.168.244.10:3306) (current master) +--192.168.244.20(192.168.244.20:3306) +--192.168.244.30(192.168.244.30:3306)
to:192.168.244.20(192.168.244.20:3306) (new master) +--192.168.244.30(192.168.244.30:3306)
sun may 21 09:47:13 2017 - [info]
sun may 21 09:47:13 2017 - [info] * phase 3.3: new master diff log generation phase..
sun may 21 09:47:13 2017 - [info]
sun may 21 09:47:13 2017 - [info] this server has all relay logs. no need to generate diff files from the latest slave.
sun may 21 09:47:13 2017 - [info]
sun may 21 09:47:13 2017 - [info] * phase 3.4: master log apply phase..
sun may 21 09:47:13 2017 - [info]
sun may 21 09:47:13 2017 - [info] *notice: if any error happens from this phase, manual recovery is needed.
sun may 21 09:47:13 2017 - [info] starting recovery on 192.168.244.20(192.168.244.20:3306)..
sun may 21 09:47:13 2017 - [info] this server has all relay logs. waiting all logs to be applied..
sun may 21 09:47:56 2017 - [info] done.
sun may 21 09:47:56 2017 - [info] all relay logs were successfully applied.
sun may 21 09:47:56 2017 - [info] getting new master's binlog name and position..sun may 21 09:47:56 2017 - [info] mysql-bin.000010:166054508sun may 21 09:47:56 2017 - [info] all other slaves should start replication from here. statement should be: change master to master_host='192.168.244.20', master_port=3306, master_log_file='mysql-bin.000010', master_log_pos=166054508, master_user='repl', master_password='xxx';
sun may 21 09:47:56 2017 - [info] executing master ip activate script:
sun may 21 09:47:56 2017 - [info] /usr/local/bin/master_ip_failover --command=start --ssh_user=root --orig_master_host=192.168.244.10 --orig_master_ip=192.168.244.10 --orig_master_port=3306 --new_master_host=192.168.244.20 --new_master_ip=192.168.244.20 --new_master_port=3306 --new_master_user='monitor' --new_master_password='monitor123' set read_only=0 on the new master.
enabling the vip 192.168.244.188 on the new master: 192.168.244.20 sun may 21 09:47:59 2017 - [info] ok.
sun may 21 09:47:59 2017 - [info] ** finished master recovery successfully.
sun may 21 09:47:59 2017 - [info] * phase 3: master recovery phase completed.
sun may 21 09:47:59 2017 - [info]
sun may 21 09:47:59 2017 - [info] * phase 4: slaves recovery phase..
sun may 21 09:47:59 2017 - [info]
sun may 21 09:47:59 2017 - [info] * phase 4.1: starting parallel slave diff log generation phase..
sun may 21 09:47:59 2017 - [info]
sun may 21 09:47:59 2017 - [info] -- slave diff file generation on host 192.168.244.30(192.168.244.30:3306) started, pid: 3606. check tmp log /masterha/app1/192.168.244.30_3306_20170521094708.log if it takes time..
sun may 21 09:48:04 2017 - [info]
sun may 21 09:48:04 2017 - [info] log messages from 192.168.244.30 ...
sun may 21 09:48:04 2017 - [info]
sun may 21 09:47:59 2017 - [info] server 192.168.244.30 received relay logs up to: mysql-bin.000001:35083093sun may 21 09:47:59 2017 - [info] need to get diffs from the latest slave(192.168.244.20) up to: mysql-bin.000001:37651149 (using the latest slave's relay logs)sun may 21 09:47:59 2017 - [info] connecting to the latest slave host 192.168.244.20, generating diff relay log files..
sun may 21 09:47:59 2017 - [info] executing command: apply_diff_relay_logs --command=generate_and_send --scp_user=root --scp_host=192.168.244.30 --latest_mlf=mysql-bin.000001 --latest_rmlp=37651149 --target_mlf=mysql-bin.000001 --target_rmlp=35083093 --server_id=2 --diff_file_readtolatest=/tmp/relay_from_read_to_latest_192.168.244.30_3306_20170521094708.binlog --workdir=/tmp --timestamp=20170521094708 --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.56 --relay_log_info=/var/lib/mysql/relay-log.info --relay_dir=/var/lib/mysql/ sun may 21 09:48:04 2017 - [info]
opening /var/lib/mysql/relay-log.info ... ok.
relay log found at /var/lib/mysql, up to mysqld-relay-bin.000004
fast relay log position search succeeded.
target relay log file/position found. start_file:mysqld-relay-bin.000004, start_pos:35083256.
concat binary/relay logs from mysqld-relay-bin.000004 pos 35083256 to mysqld-relay-bin.000004 eof into /tmp/relay_from_read_to_latest_192.168.244.30_3306_20170521094708.binlog ..
binlog checksum enabled
binlog checksum enabled
dumping binlog format description event, from position 0 to 283.. ok.
dumping effective binlog data from /var/lib/mysql/mysqld-relay-bin.000004 position 35083256 to tail(37651312).. ok.
binlog checksum enabled
binlog checksum enabled
concat succeeded.
generating diff relay log succeeded. saved at /tmp/relay_from_read_to_latest_192.168.244.30_3306_20170521094708.binlog . scp node2:/tmp/relay_from_read_to_latest_192.168.244.30_3306_20170521094708.binlog to root@192.168.244.30(22) succeeded.
sun may 21 09:48:04 2017 - [info] generating diff files succeeded.
sun may 21 09:48:04 2017 - [info] end of log messages from 192.168.244.30.
sun may 21 09:48:04 2017 - [info] -- slave diff log generation on host 192.168.244.30(192.168.244.30:3306) succeeded.
sun may 21 09:48:04 2017 - [info] generating relay diff files from the latest slave succeeded.
sun may 21 09:48:04 2017 - [info]
sun may 21 09:48:04 2017 - [info] * phase 4.2: starting parallel slave log apply phase..
sun may 21 09:48:04 2017 - [info]
sun may 21 09:48:04 2017 - [info] -- slave recovery on host 192.168.244.30(192.168.244.30:3306) started, pid: 3613. check tmp log /masterha/app1/192.168.244.30_3306_20170521094708.log if it takes time..
sun may 21 09:48:12 2017 - [info]
sun may 21 09:48:12 2017 - [info] log messages from 192.168.244.30 ...
sun may 21 09:48:12 2017 - [info]
sun may 21 09:48:04 2017 - [info] starting recovery on 192.168.244.30(192.168.244.30:3306)..
sun may 21 09:48:04 2017 - [info] generating diffs succeeded.
sun may 21 09:48:04 2017 - [info] waiting until all relay logs are applied.
sun may 21 09:48:04 2017 - [info] done.
sun may 21 09:48:04 2017 - [info] getting slave status..
sun may 21 09:48:04 2017 - [info] this slave(192.168.244.30)'s exec_master_log_pos(mysql-bin.000001:35083010) does not equal to read_master_log_pos(mysql-bin.000001:35083093). it is likely that relay log was cut during transaction. need to recover from exec_master_log_pos.sun may 21 09:48:04 2017 - [info] saving local relay logs from exec pos to read pos on 192.168.244.30: from mysqld-relay-bin.000004:35083173 to the end of the relay log..
sun may 21 09:48:04 2017 - [info] executing command : save_binary_logs --command=save --start_file=mysqld-relay-bin.000004 --start_pos=35083173 --output_file=/tmp/relay_from_exec_to_read_192.168.244.30_3306_20170521094708.binlog --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.56 --relay_log_info=/var/lib/mysql/relay-log.info --binlog_dir=/var/lib/mysql/ sun may 21 09:48:05 2017 - [info]
creating /tmp if not exists.. ok.
concat binary/relay logs from mysqld-relay-bin.000004 pos 35083173 to mysqld-relay-bin.000004 eof into /tmp/relay_from_exec_to_read_192.168.244.30_3306_20170521094708.binlog ..
binlog checksum enabled
binlog checksum enabled
dumping binlog format description event, from position 0 to 283.. ok.
dumping effective binlog data from /var/lib/mysql/mysqld-relay-bin.000004 position 35083173 to tail(35083256).. ok.
binlog checksum enabled
binlog checksum enabled
concat succeeded.
sun may 21 09:48:05 2017 - [info] connecting to the target slave host 192.168.244.30, running recover script..
sun may 21 09:48:05 2017 - [info] executing command: apply_diff_relay_logs --command=apply --slave_user='monitor' --slave_host=192.168.244.30 --slave_ip=192.168.244.30 --slave_port=3306 --apply_files=/tmp/relay_from_exec_to_read_192.168.244.30_3306_20170521094708.binlog,/tmp/relay_from_read_to_latest_192.168.244.30_3306_20170521094708.binlog --workdir=/tmp --target_version=5.6.31-log --timestamp=20170521094708 --handle_raw_binlog=1 --disable_log_bin=0 --manager_version=0.56 --slave_pass=xxx
sun may 21 09:48:12 2017 - [info]
concat all apply files to /tmp/total_binlog_for_192.168.244.30_3306.20170521094708.binlog ..
copying the first binlog file /tmp/relay_from_exec_to_read_192.168.244.30_3306_20170521094708.binlog to /tmp/total_binlog_for_192.168.244.30_3306.20170521094708.binlog.. ok.
dumping binlog head events (rotate events), skipping format description events from /tmp/relay_from_read_to_latest_192.168.244.30_3306_20170521094708.binlog.. binlog checksum enabled
binlog checksum enabled
dumped up to pos 283. ok. /tmp/relay_from_read_to_latest_192.168.244.30_3306_20170521094708.binlog has effective binlog events from pos 283.
dumping effective binlog data from /tmp/relay_from_read_to_latest_192.168.244.30_3306_20170521094708.binlog position 283 to tail(2568339).. ok.
concat succeeded.
all apply target binary logs are concatinated at /tmp/total_binlog_for_192.168.244.30_3306.20170521094708.binlog .
mysql client version is 5.6.31. using --binary-mode.
applying differential binary/relay log files /tmp/relay_from_exec_to_read_192.168.244.30_3306_20170521094708.binlog,/tmp/relay_from_read_to_latest_192.168.244.30_3306_20170521094708.binlog on 192.168.244.30:3306. this may take long time...
applying log files succeeded.
sun may 21 09:48:12 2017 - [info] all relay logs were successfully applied.
sun may 21 09:48:12 2017 - [info] resetting slave 192.168.244.30(192.168.244.30:3306) and starting replication from the new master 192.168.244.20(192.168.244.20:3306)..
sun may 21 09:48:12 2017 - [info] executed change master.
sun may 21 09:48:12 2017 - [info] slave started.
sun may 21 09:48:12 2017 - [info] end of log messages from 192.168.244.30.
sun may 21 09:48:12 2017 - [info] -- slave recovery on host 192.168.244.30(192.168.244.30:3306) succeeded.
sun may 21 09:48:12 2017 - [info] all new slave servers recovered successfully.
sun may 21 09:48:12 2017 - [info]
sun may 21 09:48:12 2017 - [info] * phase 5: new master cleanup phase..
sun may 21 09:48:12 2017 - [info]
sun may 21 09:48:12 2017 - [info] resetting slave info on the new master..
sun may 21 09:48:12 2017 - [info] 192.168.244.20: resetting slave info succeeded.
sun may 21 09:48:12 2017 - [info] master failover to 192.168.244.20(192.168.244.20:3306) completed successfully.
sun may 21 09:48:12 2017 - [info] deleted server1 entry from /etc/masterha/app1.cnf .
sun may 21 09:48:12 2017 - [info]
----- failover report -----app1: mysql master failover 192.168.244.10(192.168.244.10:3306) to 192.168.244.20(192.168.244.20:3306) succeeded
master 192.168.244.10(192.168.244.10:3306) is down!check mha manager logs at node4:/masterha/app1/manager.log for details.
started automated(non-interactive) failover.
invalidated master ip address on 192.168.244.10(192.168.244.10:3306)
the latest slave 192.168.244.20(192.168.244.20:3306) has all relay logs for recovery.
selected 192.168.244.20(192.168.244.20:3306) as a new master.192.168.244.20(192.168.244.20:3306): ok: applying all logs succeeded.192.168.244.20(192.168.244.20:3306): ok: activated master ip address.192.168.244.30(192.168.244.30:3306): generating differential relay logs up to 192.168.244.20(192.168.244.20:3306)succeeded.
generating relay diff files from the latest slave succeeded.192.168.244.30(192.168.244.30:3306): ok: applying all logs succeeded. slave started, replicating from 192.168.244.20(192.168.244.20:3306)192.168.244.20(192.168.244.20:3306): resetting slave info succeeded.
master failover to 192.168.244.20(192.168.244.20:3306) completed successfully.
sun may 21 09:48:12 2017 - [info] sending mail..
unknown option: conf
view code
方案二
对candicate master上和slave上的网卡进行带宽限制
candicate master
[root@node2 ~]# /sbin/tc qdisc add dev eth0 root tbf rate 50kbit latency 50ms burst 15kb
slave
/sbin/tc qdisc add dev eth0 root tbf rate 80kbit latency 50ms burst 15kb
注意：candicate master的网卡限制在50kbit，slave的网卡限制在80kbit，
要确保candicate master的小于slave的，这样才能模拟出candicate master上relay log的位置小于slave上relay log的位置。
关于如何确认网卡的速率控制到多大合适，
可通过压测，测试master的吞吐量，
以及结合如下方法，测试主机之间的传输速率来确定网卡合适的速率。
[root@node1 ~]# dd if=/dev/zero of=hello.txt bs=100m count=1
[root@node1 ~]# time scp hello.txt 192.168.244.20:/tmp/
hello.txt 100% 100mb 2.6mb/s 00:39
参考
《深入浅出mysql》
以上就是mha自动failover与手动failover的切换原理的详细内容。