MySQL高可用方案MHA自动Failover与手动Failover…
2018-06-17 23:46:37来源：未知 阅读 ()
集群信息
角色 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:37 BINLOG ' 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:49 BINLOG ' 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=0 SET 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=0 SET 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=0 SET 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 = 29 COMMIT/*!*/; # at 615 #170524 17:17:33 server id 1 end_log_pos 529 CRC32 0x6a1aae7e Query thread_id=2 exec_time=0 error_code=0 SET 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=0 SET 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 = 30 COMMIT/*!*/; # at 829 #170524 17:17:38 server id 1 end_log_pos 743 CRC32 0x24f9a1d2 Query thread_id=2 exec_time=0 error_code=0 SET 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=0 SET 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 = 31 COMMIT/*!*/; # at 1043 #170524 17:17:44 server id 1 end_log_pos 957 CRC32 0x73a903bf Query thread_id=2 exec_time=0 error_code=0 SET 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=0 SET 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 = 32 COMMIT/*!*/; # at 1257 #170524 17:17:49 server id 1 end_log_pos 1171 CRC32 0x2d37da37 Query thread_id=2 exec_time=0 error_code=0 SET 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=0 SET 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 = 33 COMMIT/*!*/; DELIMITER ; # End of log file ROLLBACK /* added by mysqlbinlog */; /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
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: 0 Master_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: 0 1 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/python f1 = 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的内容
主要是修改第三行
23 mysql-bin.000001 1308
修改为
23 mysql-bin.000001 452
修改relay-log.info的内容
原文件如下：
7 ./mysqld-relay-bin.000002 1471 mysql-bin.000001 1308 0 0 1
修改为：
7 ./mysqld-relay-bin.000002 615 mysql-bin.000001 452 0 0 1
启动slave，注意，配置文件中必须设置skip-slave-start，不然它自动开启主从复制。
[root@node2 mysql]# service mysqld start
5. 对于slave，同样如此处理，只不过relay log的位置点要靠后些
#!/usr/bin/python f1 = 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的内容
23
mysql-bin.000001
880
修改relay-log.info的内容
7 ./mysqld-relay-bin.000002 1043 mysql-bin.000001 880 0 0 1
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 = 0 Sun 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 = 0 Sun 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:880 Sun 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:452 Sun 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 120 Target 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:452 Sun 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:976 Sun 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 = 0 Wed 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:120 Wed 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:120 Wed 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.16 8.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.3 0: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:1429 Wed 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.16 8.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.2 0: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 1 92.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:3 306)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 = 0 Wed 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.
在默认情况下，如果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 = 0 Wed 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 = 0 Wed 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.
后面附上之前提到的测试结果不理想的两种方案
方案一：
模拟步骤如下：
1. master上创建测试表
mysql> use sbtest; Database changed mysql> create table sbtest.t1(id int primary key,col1 varchar(10),col2 varchar(10),col3 varchar(10),col4 varchar(10),col5 varchar(10),col6 varchar(10),col7 varchar(10),col8 varchar(10),col9 varchar(10),col10 varchar(10));
Query OK, 0 rows affected (0.33 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
#!/usr/bin/python # coding=utf-8 import MySQLdb import subprocess import time class CheckSlaveStatus: def __init__(self, host): self.conn = MySQLdb.connect(host, "monitor", "monitor123") self.cursor = self.conn.cursor() self.cursor.execute("start slave") def get_slave_status(self): self.cursor.execute("show slave status") slave_status_result = self.cursor.fetchone() slave_io_running, slave_sql_running = slave_status_result[10], slave_status_result[11] return [slave_io_running, slave_sql_running] def quit(self): try: self.conn.commit() self.conn.close() except Exception as e: print e def main(): check_host = ['192.168.244.30', '192.168.244.20'] check_slave_status_30 = CheckSlaveStatus(check_host[0]) check_slave_status_20 = CheckSlaveStatus(check_host[1]) for check_slave_status in [check_slave_status_30, check_slave_status_20]: print "Begin to check slave status" while True: slave_status = check_slave_status.get_slave_status() print slave_status if slave_status == ['Yes', 'Yes']: time.sleep(5) break time.sleep(10)
print "Begin to kill master mysqld" command_line="ps -ef |grep mysqld |grep -v grep |awk '{print $2}' |xargs kill -9" p = subprocess.Popen(command_line, stdout=subprocess.PIPE, shell=True) p.communicate() check_slave_status_30.quit() check_slave_status_20.quit() print "Finished" if __name__ == '__main__': main()
执行该脚本
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 = 0 Sun 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 = 0 Sun 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:37651149 Sun 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:35083093 Sun 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:166054508 Sun 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:35083093 Sun 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
方案二
对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》
标签：
版权申明：本站文章部分自网络，如有侵权，请联系：west999com@outlook.com
特别注意：本站所有转载文章言论不代表本站观点，本站所提供的摄影照片，插画，设计作品，如需使用，请与原作者联系，版权归原作者所有
相关文章
- MySQL replace函数怎么替换字符串语句 2020-03-09
- PHP访问MySQL查询超时怎么办 2020-03-09
- mysql登录时闪退 2020-02-27
- MySQL出现1067错误号 2020-02-27
- mysql7.x如何单独安装mysql 2020-02-27
IDC资讯： 主机资讯 注册资讯 托管资讯 vps资讯 网站建设
网站运营： 建站经验 策划盈利 搜索优化 网站推广 免费资源
网络编程： Asp.Net编程 Asp编程 Php编程 Xml编程 Access Mssql Mysql 其它
服务器技术： Web服务器 Ftp服务器 Mail服务器 Dns服务器 安全防护
软件技巧： 其它软件 Word Excel Powerpoint Ghost Vista QQ空间 QQ FlashGet 迅雷
网页制作： FrontPages Dreamweaver Javascript css photoshop fireworks Flash
热门词条
最新资讯
热门关注
热门标签