2017-03-29

深入理解mysql的主从复制

摘要：mysql主从复制原理学习笔记

主从复制的架构

主从复制的过程

当主库上发生事务提交动作时，会记录到主库的binlog中，然后由主库的dump线程发送日志到从库。从库的IO线程负责接收主库的binlog日志并记录到自己的relay log日志。SQL线程负责读取relay log并将数据写入从库。
主库的dump线程：

dump线程时刻的等待binlog的变化，一旦变化就将日志发送给从库。
从库的IO线程和SQL线程：

从库的IO线程在时刻等待主库的事件发送过来，如果有的话就接受并写入本地的relay log中。
从库的SQL线程在时刻等待relay log的变化，一旦有变化就读取并写入数据库。

在主库上看一个事务：

mysql> show master status \G;
*************************** 1. row ***************************
             File: mysql-bin.000952
         Position: 567035014
     Binlog_Do_DB: 
 Binlog_Ignore_DB: 
Executed_Gtid_Set: 8ac65959-4cb3-11e5-81af-005056a311e0:1-345390234,
9bc86bd5-a8a0-11e5-991c-005056a3bf07:4-233053957:233053959-572579981
1 row in set (0.00 sec)
ERROR: 
No query specified
mysql> show binlog events in 'mysql-bin.000952';
| mysql-bin.000952 |    236240 | Query          |       706 |      236317 | BEGIN
| mysql-bin.000952 |    236317 | Rows_query     |       706 |      236630 | # insert into t_table (task_set_id, user_id, task_set_date,task_terminal,
      task_set_status, day_tast_id, week_task_id, 
      month_task_id)
    values ('9edd6ca5ff98443f8981a01dc5eae397', '37728258', '2017-03-29', 
      0,2, '1ecf32416e7711e5ad54005056a3bad5', '',
      '')                                          
| mysql-bin.000952 |    236630 | Table_map      |       706 |      236712 | table_id: 82476 (t_db.t_table)  
| mysql-bin.000952 |    236712 | Write_rows     |       706 |      236839 | table_id: 82476 flags: STMT_END_F              
| mysql-bin.000952 |    236839 | Xid            |       706 |      236870 | COMMIT /* xid=146158662 */          
| mysql-bin.000952 |    236870 | Gtid           |       706 |      236918 | SET @@SESSION.GTID_NEXT= '9bc86bd5-a8a0-11e5-991c-005056a3bf07:572102075'

注意该事务COMMIT操作后面的/* xid=146158662 */ ：这是innodb的内部事务号，用于commit的二阶段提交！
单实例mysql（内部XA,需设置innodb_support_xa=on）的commit操作要写2个日志：一个是innodb的redo日志（也就是ib_logfile）是没有归档的，因此会被覆盖掉。另一个是mysql的binlog日志，binlog是不会被覆盖的。
开始提交阶段：binlog不提交，redo提交
正式提交阶段：binlog提交，如果提交成功，则redo完成！如果提交失败，则redo回滚！

主从复制相关参数

1、server-id：主从要设置不一样
2、read_only：主库设为off，从库设为on
3、sql_log_bin：主从都开启
4、log_slave_updates：如果要做级联复制(M-S-S)就要开启
5、binlog_format：row
6、binlog_cache_size：
7、max_binlog_size：
8、expire_logs_days：binlog保存时间
9、binlog-do-db：
10、binlog-ignore-db：

半同步复制

半同步复制的作用：可以保证主库将日志先传输到备库，然后再返回给应用事务提交成功。这个功能对网络要求较高，如果要使用的话建议把网络优化好一点，比如机器配置千M网卡且将同一组主从服务器位于同一交换机下。
查看源码包中是否支持半同步：

使用方法：主库安装semisync_master.so，从库安装semisync_slave.so然后开启rpl_semi_sync_master_enabled=on即可
主库安装：

[root@mongohost2 semisync]# /opt/mysql/bin/mysql
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 243535
Server version: 5.6.35-log Source distribution
Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.
Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
mysql> show variables like '%rpl_semi%';
Empty set (0.00 sec)
mysql> install plugin rpl_semi_sync_master soname 'semisync_master.so';
Query OK, 0 rows affected (0.04 sec)
mysql> show variables like '%rpl_semi%';
+------------------------------------+-------+
| Variable_name                      | Value |
+------------------------------------+-------+
| rpl_semi_sync_master_enabled       | OFF   |
| rpl_semi_sync_master_timeout       | 10000 |  #默认是10秒，可以自己调整
| rpl_semi_sync_master_trace_level   | 32    |
| rpl_semi_sync_master_wait_no_slave | ON    |
+------------------------------------+-------+
4 rows in set (0.00 sec)
mysql> set global rpl_semi_sync_master_enabled=on;
Query OK, 0 rows affected (0.00 sec)
从库：
mysql> install plugin rpl_semi_sync_slave soname 'semisync_slave.so';
Query OK, 0 rows affected (0.04 sec)

主从复制常见问题

主库挂了，如何判断从库是否同步完成？

从库执行：show slave status \G;
查看IO线程读取到主库的binlog日志文件及位置：
Master_Log_File: mysql-bin.000952
Read_Master_Log_Pos: 637762421
查看SQL线程执行的文件及位置：
Relay_Master_Log_File: mysql-bin.000952
Exec_Master_Log_Pos: 637762421
比较以上两者是否相等。如果都相等说明同步完成，否则没有完成同步！
还可以参考：
Seconds_Behind_Master: 0

如果主库重启了。可以通过show master status查看binlog和位置与从库的binlog文件和位置比较是否一致。

mysql主从库同步错误

错误号：1062

主键冲突

错误号：1060

主从DDL不一致

错误号：1032

Last_Errno: 1032
Last_Error: Could not execute Update_rows event on table testdb.table; Can't find record in 'table', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000252, end_log_pos 441796235

原因：主从数据不一致
解决办法：

mysql> set sql_slave_skip_counter=1;
如果就个别事务可以先跳过事务再手动同步数据。如果数据量大则只能重做备库！

错误号：1756

Last_Errno: 1756
Last_Error: ... The slave coordinator and worker threads are stopped, possibly leaving data in inconsistent state. A restart should restore consistency automatically, although using non-transactional storage for data or info tables or DDL queries could lead to problems. In such cases you have to examine your data (see documentation for details).

alert日志报错：

2017-05-02 09:19:38 21850 [Warning] Slave SQL: Worker 7 failed executing transaction '7d7ebcb4-4cb3-11e5-81ae-005056a35f06:374729743' at master log 
mysql-bin.000382, end_log_pos 693272629; Could not execute Delete_rows event on table testdb.q_answer; Deadlock found when trying to get lock; try 
restarting transaction, Error_code: 1213; handler error HA_ERR_LOCK_DEADLOCK; the event's master log mysql-bin.000382, end_log_pos 693272629, Error_
code: 1213
2017-05-02 09:19:38 21850 [ERROR] Slave SQL: ... The slave coordinator and worker threads are stopped, possibly leaving data in inconsistent state. 
A restart should restore consistency automatically, although using non-transactional storage for data or info tables or DDL queries could lead to pr
oblems. In such cases you have to examine your data (see documentation for details). Error_code: 1756
2017-05-02 09:19:38 21850 [Note] Error reading relay log event: slave SQL thread was killed

原因：死锁导致。
疑问：这个报错会不会导致slave上q_answer表的数据不一致？通过确认slave的relaylog和binlog都有记录这个DELETE语句,可能终止slave进程是为了保证这个事务可以重启并正常执行。
解决办法：

mysql> stop slave;start slave;

错误号：1837

Last_Errno: 1837
Last_Error: Worker 7 failed executing transaction '' at master log mysql-bin.000189, end_log_pos 398170585; Error 'When @@SESSION.GTID_NEXT is set to a GTID, you must explicitly set it to a different value after a COMMIT or ROLLBACK. Please check GTID_NEXT variable manual page for detailed explanation. Current @@SESSION.GTID_NEXT is '7d7ebcb4-4cb3-11e5-81ae-005056a35f72:198818971'.' on query. Default database: 'testdb'. Query: 'INSERT INTO table(unit_id, unit_name, unit_type, book_id, sort) VALUES ('130003002653462007003', '动：综合表演（火车来了）', 2, '130003002653462', '130003002653462007003')'

原因：不明，可能是BUG，偶尔遇到。
解决办法：

mysql> stop slave;start slave;
如果还不行的话就要重启Mysql实例：service mysqld restart

错误号：1236

Last_IO_Errno: 1236
Last_IO_Error: Got fatal error 1236 from master when reading data from binary log: 'Client requested master to start replication from position > file size; the first event 'mysql-bin.000159' at 647052798, the last event read from '/data/log/mysql/mysql-bin.000159' at 4, the last byte read from '/data/log/mysql/mysql-bin.000159' at 4.'

解决办法：重新指定开始复制的日志位置

错误号：1594

Last_Errno: 1594
Last_Error: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.

错误号：1118

Last_Errno: 1118
Last_Error: Error 'Row size too large (> 8126). Changing some columns to TEXT or BLOB or using ROW_FORMAT=DYNAMIC or ROW_FORMAT=COMPRESSED may help. In current row format, BLOB prefix of 768 bytes is stored inline.' on query. Default database: 'testdb'. Query: 'update table set content = '<span> </span> \n<p>\n      <span style="font-family:宋体;font-size:16px;"><span>一、创设情境、激发兴趣</span></span> \n</p>\n<span> </span><span style="font-family:宋体;"><span style="font-size:16px;">1、结合具体生活情境，回顾认识质量单位千克、克、吨，进一步感受</span><span style="font-size:16px;">1</span><span style="font-size:16px;">千克、</span><span style="font-size:16px;">1</span><span style="font-size:16px;">克、</span><span style="font-size:16px;">1</span><span style="font-size:16px;">吨的实际质量。</span></span> \n<p style="color:#000000;font-family:&quot;Times New Roman&quot;,serif;font-size:10.5pt;font-style:normal;font-weight:normal;">\n   <sp

错误号：1755

Last_Errno: 1755
Last_Error: Cannot execute the current event group in the parallel mode. Encountered event Update_rows, relay-log name /data/mysql2/log/mysqld-relay-bin.000125, position 354 which prevents execution of this event group in parallel mode. Reason: the event is a part of a group that is unsupported in the parallel execution mode.

原因：5.6版本开启GTID后，MSS架构级联复制的时候会遇到这个BUG（备机salve线程执行SQL,主键冲突的话会导致自己的binlog异常，此时如果有其他备机以这台备机作为主机，会出现复制异常。）
解决办法：slave库注释掉：#slave-parallel-workers=64然后重启mysql

错误号：1205

Last_Errno: 1205
Last_Error: Slave SQL thread retried transaction 10 time(s) in vain, giving up. Consider raising the value of the slave_transaction_retries variable.

原因：slave上的操作被lock阻塞
解决：重启slave

错误号：1864

Last_Errno: 1864
Last_Error: Cannot schedule event Rows_query, relay-log name /log/mysql/mysqld-relay-bin.000819, position 165048918 to Worker thread because its size 16777219 exceeds 16777216 of slave_pending_jobs_size_max.

原因：由于event大小已经超过了等待任务大小的上限（配置slave-pending-jobs-size-max )
解决：调大slave_pending_jobs_size_max

mysql> show variables like 'slave_pending_jobs_size_max';
+-----------------------------+----------+
| Variable_name               | Value    |
+-----------------------------+----------+
| slave_pending_jobs_size_max | 16777216 |
+-----------------------------+----------+
1 row in set (0.00 sec)
mysql> stop slave;
Query OK, 0 rows affected (1.42 sec)
mysql> set global slave_pending_jobs_size_max=20000000; 
Query OK, 0 rows affected, 1 warning (0.00 sec)
mysql> start slave;
Query OK, 0 rows affected, 1 warning (0.68 sec)

主从复制异常处理一则

监控显示一个主从复制异常，报错如下：

Last_Errno: 1032
Last_Error: Worker 7 failed executing transaction '7d7ebcb4-4cb3-11e5-81ae-005056a35f10:821249741' at master log mysql-bin.000895, end_log_pos 544715794; Could not execute Delete_rows event on table riverdb.t_message; Can't find record in 't_message', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000895, end_log_pos 544715794

紧急处理：先跳过错误，使主从复制恢复正常。

mysql> stop slave;
Query OK, 0 rows affected (6.58 sec)
mysql> set gtid_next='7d7ebcb4-4cb3-11e5-81ae-005056a35f10:821249741';
Query OK, 0 rows affected (0.00 sec)
mysql> begin;commit;
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
mysql> set gtid_next="AUTOMATIC";
Query OK, 0 rows affected (0.00 sec)
mysql> start slave;
Query OK, 0 rows affected, 1 warning (3.34 sec)
mysql> show slave status \G;
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.8.210
                  Master_User: repluser
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000895
          Read_Master_Log_Pos: 911006213
               Relay_Log_File: mysqld-relay-bin.002527
                Relay_Log_Pos: 654533257
        Relay_Master_Log_File: mysql-bin.000895
             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: 654533119
              Relay_Log_Space: 911007051
              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: 26258
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: 1006
                  Master_UUID: 7d7ebcb4-4cb3-11e5-81ae-005056a35f10
             Master_Info_File: mysql.slave_master_info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: Waiting for Slave Workers to free pending events
           Master_Retry_Count: 86400
                  Master_Bind: 
      Last_IO_Error_Timestamp: 
     Last_SQL_Error_Timestamp: 
               Master_SSL_Crl: 
           Master_SSL_Crlpath: 
           Retrieved_Gtid_Set: 7d7ebcb4-4cb3-11e5-81ae-005056a35f10:3632632-821409185
            Executed_Gtid_Set: 7d7ebcb4-4cb3-11e5-81ae-005056a35f10:141-3587561:3632632-111743098:111743100-233849683:233849685-821249779:821249782-821249785,
7d7ebcb4-4cb3-11e5-81ae-005056a35f72:1-305858337,
7d7ebcb4-4cb3-11e5-81ae-005076a65f78:1-13002
                Auto_Position: 0
1 row in set (0.00 sec)
ERROR: 
No query specified
mysql>

修复不一致的数据

到主库上查看该事务的具体SQL（根据gtid搜索binlog），可以看到是一条delete语句，执行时间是#170710 2:02:06

SET @@SESSION.GTID_NEXT= '7d7ebcb4-4cb3-11e5-81ae-005056a35f10:821249741'/*!*/;
# at 542745604
#170710  2:02:06 server id 1006  end_log_pos 542745690 CRC32 0xb8a380e7         Query   thread_id=8803177       exec_time=0     error_code=0
SET TIMESTAMP=1499623326/*!*/;
BEGIN
/*!*/;
# at 542745690
#170710  2:02:06 server id 1006  end_log_pos 542745805 CRC32 0x92776dca         Rows_query
# delete from t_message
#     where send_time   <=   DATE_SUB(NOW() , INTERVAL 3 MONTH)

由于这个事务被跳过了，所以这个delete事务肯定没有完成。到从库上去查下这个时间点的数据：

mysql> select count(*) from riverdb.t_message where send_time   <=   DATE_SUB('2017-07-10 02:02:06' , INTERVAL 3 MONTH);
+----------+
| count(*) |
+----------+
|     4824 |
+----------+
1 row in set (0.01 sec)

到主库上查：

root@(none) 09:47:22>select count(*) from riverdb.t_message where send_time   <=   DATE_SUB('2017-07-10 02:02:06' , INTERVAL 3 MONTH);
+----------+
| count(*) |
+----------+
|        0 |
+----------+
1 row in set (0.00 sec)

这个事务异常的时间点数据相差4824,再看看数据总行数：
主库：
root@(none) 09:47:16>select count() from riverdb.t_message;
+———-+
| count() |
+———-+
| 353984 |
+———-+
1 row in set (0.06 sec)
从库：
mysql> select count() from riverdb.t_message;
+———-+
| count() |
+———-+
| 358808 |
+———-+
1 row in set (0.07 sec)
从库比主库数据多了：
mysql> select 358808-353984;
+—————+
| 358808-353984 |
+—————+
| 4824 |
+—————+
1 row in set (0.00 sec)
可以看到从库多出来的数据正好是被跳过事务的数据差，那么就把从库上这部分数据删掉即可保持主从库的数据一致。
如果业务繁忙的话是不好统计总数差的，直接根据where条件在从库删除掉这部分数据就行。

本文标题:深入理解mysql的主从复制

文章作者:一条大河

发布时间:2017-03-29, 13:11:37

最后更新:2017-09-25, 15:23:20

原始链接:http://riverdba.github.io/2017/03/29/Deep-comprehend-mysql-replication/

许可协议: "署名-非商用-相同方式共享 4.0" 转载请保留原文链接及作者。