原文：http://hcymysql.blog.51cto.com/5223301/888007

线上MYSQL同步报错故障处理总结

贺春旸 2012-06-05

前言

在发生故障切换后，经常遇到的问题就是同步报错，数据库很小的时候，dump完再导入很简单就处理好了，但线上的数据库都150G-200G，如果用单纯的这种方法，成本太高，故经过一段时间的摸索，总结了几种处理方法。

生产环境架构图

目前现网的架构，保存着两份数据，通过异步复制做的高可用集群，两台机器提供对外服务。在发生故障时，切换到slave上，并将其变成master，坏掉的机器反向同步新的master，在处理故障时，遇到最多的就是主从报错。下面是我收录下来的报错信息。

常见错误

最常见的3种情况

这3种情况是在HA切换时，由于是异步复制，且sync_binlog=0，会造成一小部分binlog没接收完导致同步报错。

异步半同步区别

简单的说就是master把binlog发送过去，不管slave是否接收完，也不管是否执行完，这一动作就结束了.

简单的说就是master把binlog发送过去，slave确认接收完，但不管它是否执行完，给master一个信号我这边收到了，这一动作就结束了。（谷歌写的代码，5.5上正式应用。）

当master上写操作繁忙时，当前POS点例如是10，而slave上IO_THREAD线程接收过来的是3，此时master宕机，会造成相差7个点未传送到slave上而数据丢失。

特殊的情况

这种情况SLAVE在宕机，或者非法关机，例如电源故障、主板烧了等，造成中继日志损坏，同步停掉。

这种情况同步会一直延时，永远也同步不完，error错误日志里一直出现上面两行信息。解决方法就是把server-id改成不一致即可。 

Slave: received end packet from server, apparent master shutdown:
Slave I/O thread: Failed reading log event, reconnecting to retry, log 'mysql-bin.000012' at postion 106

问题处理

删除失败

在master上删除一条记录，而slave上找不到。 

Last_SQL_Error: Could not execute Delete_rows event on table hcy.t1; 
Can't find record in 't1',
Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; 
the event's master log mysql-bin.000006, end_log_pos 254

解决方法：

由于master要删除一条记录，而slave上找不到故报错，这种情况主上都将其删除了，那么从机可以直接跳过。可用命令： 

stop slave;
set global sql_slave_skip_counter=1;
start slave;

如果这种情况很多，可用我写的一个脚本skip_error_replcation.sh，默认跳过10个错误（只针对这种情况才跳，其他情况输出错误结果，等待处理），这个脚本是参考maakit工具包的mk-slave-restart原理用shell写的，功能上定义了一些自己的东西，不是无论什么错误都一律跳过。）

主键重复

在slave已经有该记录，又在master上插入了同一条记录。 

Last_SQL_Error: Could not execute Write_rows event on table hcy.t1; 
Duplicate entry '2' for key 'PRIMARY', 
Error_code: 1062; 
handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000006, end_log_pos 924

解决方法：

在slave上用desc hcy.t1; 先看下表结构： 

mysql> desc hcy.t1;
+-------+---------+------+-----+---------+-------+
| Field | Type    | Null | Key | Default | Extra |
+-------+---------+------+-----+---------+-------+
| id    | int(11) | NO   | PRI | 0       |       | 
| name  | char(4) | YES  |     | NULL    |       | 
+-------+---------+------+-----+---------+-------+

删除重复的主键 

mysql> delete from t1 where id=2;
Query OK, 1 row affected (0.00 sec)

mysql> start slave;
Query OK, 0 rows affected (0.00 sec)

mysql> show slave status\G;
……
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
……
mysql> select * from t1 where id=2;

在master上和slave上再分别确认一下。

更新丢失

在master上更新一条记录，而slave上找不到，丢失了数据。 

Last_SQL_Error: Could not execute Update_rows event on table hcy.t1; 
Can't find record in 't1', 
Error_code: 1032; 
handler error HA_ERR_KEY_NOT_FOUND; 
the event's master log mysql-bin.000010, end_log_pos 794

解决方法：

在master上，用mysqlbinlog 分析下出错的binlog日志在干什么。 

/usr/local/mysql/bin/mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS mysql-bin.000010 | grep -A '10' 794

#120302 12:08:36 server id 22  end_log_pos 794  Update_rows: table id 33 flags: STMT_END_F
### UPDATE hcy.t1
### WHERE
###   @1=2 /* INT meta=0 nullable=0 is_null=0 */
###   @2='bbc' /* STRING(4) meta=65028 nullable=1 is_null=0 */
### SET
###   @1=2 /* INT meta=0 nullable=0 is_null=0 */
###   @2='BTV' /* STRING(4) meta=65028 nullable=1 is_null=0 */
# at 794
#120302 12:08:36 server id 22  end_log_pos 821  Xid = 60
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

在slave上，查找下更新后的那条记录，应该是不存在的。 

mysql> select * from t1 where id=2;
Empty set (0.00 sec)

然后再到master查看 

mysql> select * from t1 where id=2;
+----+------+
| id | name |
+----+------+
|  2 | BTV  | 
+----+------+
1 row in set (0.00 sec)

把丢失的数据在slave上填补，然后跳过报错即可。 

mysql> insert into t1 values (2,'BTV');
Query OK, 1 row affected (0.00 sec)

mysql> select * from t1 where id=2;    
+----+------+
| id | name |
+----+------+
|  2 | BTV  | 
+----+------+
1 row in set (0.00 sec)

mysql> stop slave ;set global sql_slave_skip_counter=1;start slave;
Query OK, 0 rows affected (0.01 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)

mysql> show slave status\G;
……
 Slave_IO_Running: Yes
 Slave_SQL_Running: Yes
……

中继日志损坏

slave的中继日志relay-bin损坏。 

Last_SQL_Error: Error initializing relay log position: I/O error reading the header from the binary log
Last_SQL_Error: Error initializing relay log position: Binlog has bad magic number;  
It's not a binary log file that can be used by  this version of MySQL

手工修复

解决方法：找到同步的binlog和POS点，然后重新做同步，这样就可以有新的中继日值了。

例子： 

mysql> show slave status\G;
*************************** 1. row ***************************
              Master_Log_File: mysql-bin.000010
          Read_Master_Log_Pos: 1191
               Relay_Log_File: vm02-relay-bin.000005
                Relay_Log_Pos: 253
        Relay_Master_Log_File: mysql-bin.000010
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
              Replicate_Do_DB: 
          Replicate_Ignore_DB: 
           Replicate_Do_Table: 
       Replicate_Ignore_Table: 
      Replicate_Wild_Do_Table: 
  Replicate_Wild_Ignore_Table: 
                   Last_Errno: 1593
                   Last_Error: Error initializing relay log position: I/O error reading the header from the binary log
                 Skip_Counter: 1
          Exec_Master_Log_Pos: 821

Slave_IO_Running ：接收master的binlog信息
                   Master_Log_File
                   Read_Master_Log_Pos

Slave_SQL_Running：执行写操作
                   Relay_Master_Log_File
                   Exec_Master_Log_Pos

以执行写的binlog和POS点为准。 

Relay_Master_Log_File: mysql-bin.000010
Exec_Master_Log_Pos: 821

mysql> stop slave;
Query OK, 0 rows affected (0.01 sec)

mysql> CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000010',MASTER_LOG_POS=821;
Query OK, 0 rows affected (0.01 sec)

mysql> start slave;
Query OK, 0 rows affected (0.00 sec)


mysql> show slave status\G;
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.8.22
                  Master_User: repl
                  Master_Port: 3306
                Connect_Retry: 10
              Master_Log_File: mysql-bin.000010
          Read_Master_Log_Pos: 1191
               Relay_Log_File: vm02-relay-bin.000002
                Relay_Log_Pos: 623
        Relay_Master_Log_File: mysql-bin.000010
             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: 1191
              Relay_Log_Space: 778
              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:

Ibbackup

各种大招都用上了，无奈slave数据丢失过多，ibbackup（需要银子）该你登场了。

Ibbackup热备份工具，是付费的。xtrabackup是免费的，功能上一样。

Ibbackup备份期间不锁表，备份时开启一个事务（相当于做一个快照），然后会记录一个点，之后数据的更改保存在ibbackup_logfile文件里，恢复时把ibbackup_logfile 变化的数据再写入到ibdata里。

Ibbackup 只备份数据（ ibdata、.ibd ），表结构.frm不备份。

下面一个演示例子：

备份：ibbackup /bak/etc/my_local.cnf /bak/etc/my_bak.cnf

恢复：ibbackup --apply-log /bak/etc/my_bak.cnf 

[root@vm01 etc]# more my_local.cnf 

datadir =/usr/local/mysql/data
innodb_data_home_dir = /usr/local/mysql/data
innodb_data_file_path = ibdata1:10M:autoextend
innodb_log_group_home_dir = /usr/local/mysql/data
innodb_buffer_pool_size = 100M
innodb_log_file_size = 5M
innodb_log_files_in_group=2



[root@vm01 etc]# ibbackup /bak/etc/my_local.cnf /bak/etc/my_bak.cnf 

InnoDB Hot Backup version 3.0.0; Copyright 2002-2005 Innobase Oy
License A21488 is granted to vm01 (chunyang_he@126.com)
(--apply-log works in any computer regardless of the hostname)
Licensed for use in a computer whose hostname is 'vm01'
Expires 2012-5-1 (year-month-day) at 00:00
See http://www.innodb.com for further information
Type ibbackup --license for detailed license terms, --help for help

Contents of /bak/etc/my_local.cnf:
innodb_data_home_dir got value /usr/local/mysql/data
innodb_data_file_path got value ibdata1:10M:autoextend
datadir got value /usr/local/mysql/data
innodb_log_group_home_dir got value /usr/local/mysql/data
innodb_log_files_in_group got value 2
innodb_log_file_size got value 5242880

Contents of /bak/etc/my_bak.cnf:
innodb_data_home_dir got value /bak/data
innodb_data_file_path got value ibdata1:10M:autoextend

datadir got value /bak/data
innodb_log_group_home_dir got value /bak/data
innodb_log_files_in_group got value 2
innodb_log_file_size got value 5242880

ibbackup: Found checkpoint at lsn 0 1636898
ibbackup: Starting log scan from lsn 0 1636864
120302 16:47:43  ibbackup: Copying log...
120302 16:47:43  ibbackup: Log copied, lsn 0 1636898
ibbackup: We wait 1 second before starting copying the data files...
120302 16:47:44  ibbackup: Copying /usr/local/mysql/data/ibdata1
ibbackup: A copied database page was modified at 0 1636898
ibbackup: Scanned log up to lsn 0 1636898
ibbackup: Was able to parse the log up to lsn 0 1636898
ibbackup: Maximum page number for a log record 0
120302 16:47:46  ibbackup: Full backup completed!
[root@vm01 etc]#
[root@vm01 etc]# cd /bak/data/
[root@vm01 data]# ls
ibbackup_logfile  ibdata1




[root@vm01 data]# ibbackup --apply-log /bak/etc/my_bak.cnf 

InnoDB Hot Backup version 3.0.0; Copyright 2002-2005 Innobase Oy
License A21488 is granted to vm01 (chunyang_he@126.com)
(--apply-log works in any computer regardless of the hostname)
Licensed for use in a computer whose hostname is 'vm01'
Expires 2012-5-1 (year-month-day) at 00:00
See http://www.innodb.com for further information
Type ibbackup --license for detailed license terms, --help for help

Contents of /bak/etc/my_bak.cnf:
innodb_data_home_dir got value /bak/data
innodb_data_file_path got value ibdata1:10M:autoextend
datadir got value /bak/data
innodb_log_group_home_dir got value /bak/data
innodb_log_files_in_group got value 2
innodb_log_file_size got value 5242880

120302 16:48:38  ibbackup: ibbackup_logfile's creation parameters:
ibbackup: start lsn 0 1636864, end lsn 0 1636898,
ibbackup: start checkpoint 0 1636898


ibbackup: start checkpoint 0 1636898
InnoDB: Doing recovery: scanned up to log sequence number 0 1636898
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 .....99
Setting log file size to 0 5242880
ibbackup: We were able to parse ibbackup_logfile up to
ibbackup: lsn 0 1636898
ibbackup: Last MySQL binlog file position 0 1191, file name ./mysql-bin.000010
ibbackup: The first data file is '/bak/data/ibdata1'
ibbackup: and the new created log files are at '/bak/data/'
120302 16:48:38  ibbackup: Full backup prepared for recovery successfully!

[root@vm01 data]# ls
ibbackup_logfile  ibdata1  ib_logfile0  ib_logfile1

把ibdata1 ib_logfile0 ib_logfile1拷贝到从，把.frm也拷贝过去，启动MYSQL后，做同步，那个点就是上面输出的： 

ibbackup: Last MySQL binlog file position 0 1191, file name ./mysql-bin.000010

CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000010',MASTER_LOG_POS=1191;

Maatkit工具包

http://www.maatkit.org/

maatkit是一个开源的工具包，为mysql日常管理提供了帮助。目前，已被Percona公司收购并维护。其中：

mk-table-checksum是用来检测master和slave上的表结构和数据是否一致。

mk-table-sync是发生主从数据不一致时，来修复的。

这两个工具包，没有在现网实际操作的经验，这里仅仅是新技术探讨和学术交流，下面展示下如何使用。

http://www.actionsky.com/products/mysql-others/maatkit.jsp 

[root@vm02]# mk-table-checksum h=vm01,u=admin,p=123456 h=vm02,u=admin,p=123456 -d hcy -t t1
Cannot connect to MySQL because the Perl DBI module is not installed or not found.  
Run 'perl -MDBI' to see the directories that Perl searches for DBI.
If DBI is not installed, try:
  Debian/Ubuntu  apt-get install libdbi-perl
  RHEL/CentOS    yum install perl-DBI
  OpenSolaris    pgk install pkg:/SUNWpmdbi

提示缺少perl-DBI模块，那么直接 yum install perl-DBI。 

[root@vm02 bin]# mk-table-checksum h=vm01,u=admin,p=123456 h=vm02,u=admin,p=123456 -d hcy -t t1
DATABASE TABLE CHUNK HOST ENGINE      COUNT         CHECKSUM TIME WAIT STAT  LAG
hcy      t1        0 vm02 InnoDB       NULL       1957752020    0    0 NULL NULL
hcy      t1        0 vm01 InnoDB       NULL       1957752020    0    0 NULL NULL

如果表数据不一致，CHECKSUM的值是不相等的。

解释下输出的意思： 

DATABASE：数据库名
TABLE：表名
CHUNK：checksum时的近似数值
HOST：MYSQL的地址
ENGINE：表引擎
COUNT：表的行数
CHECKSUM：校验值
TIME：所用时间
WAIT：等待时间
STAT：MASTER_POS_WAIT()返回值
LAG：slave的延时时间

如果你想过滤出不相等的都有哪些表，可以用mk-checksum-filter这个工具，只要在后面加个管道符就行了。 

[root@vm02 ~]# mk-table-checksum h=vm01,u=admin,p=123456 h=vm02,u=admin,p=123456 -d hcy | mk-checksum-filter       
hcy      t2        0 vm01 InnoDB       NULL       1957752020    0    0 NULL NULL
hcy      t2        0 vm02 InnoDB       NULL       1068689114    0    0 NULL NULL

知道有哪些表不一致，可以用mk-table-sync这个工具来处理。

注：在执行mk-table-checksum时会锁表，表的大小取决于执行的快慢。 

MASTER上的t2表数据：                      SLAVE上的t2表数据：
mysql> select * from t2;                  mysql> select * from t2;    
+----+------+                             +----+------+
| id | name |                             | id | name |
+----+------+                             +----+------+
|  1 | a    |                             |  1 | a    | 
|  2 | b    |                             |  2 | b    | 
|  3 | ss   |                             |  3 | ss   | 
|  4 | asd  |                             |  4 | asd  |  
|  5 | ss   |                             +----+------+
+----+------+                             4 rows in set (0.00 sec)
5 rows in set (0.00 sec) 
                                          mysql> \! hostname; 
mysql> \! hostname;                       vm02       
vm01 

[root@vm02 ~]# mk-table-sync --execute --print --no-check-slave --transaction --databases hcy h=vm01,u=admin,p=123456 h=vm02,u=admin,p=123456 
INSERT INTO `hcy`.`t2`(`id`, `name`) VALUES ('5', 'ss') /*maatkit src_db:hcy src_tbl:t2 src_dsn:h=vm01,p=...,u=admin dst_db:hcy dst_tbl:t2 
dst_dsn:h=vm02,p=...,u=admin lock:0 transaction:1 changing_src:0 replicate:0 bidirectional:0 pid:3246 user:root host:vm02*/;

它的工作原理是：先一行一行检查主从库的表是否一样，如果哪里不一样，就执行删除，更新，插入等操作，使其达到一致。表的大小决定着执行的快慢。 

If C<--transaction> is specified, C<LOCK TABLES> is not used.  Instead, lock
and unlock are implemented by beginning and committing transactions.
The exception is if L<"--lock"> is 3.
If C<--no-transaction> is specified, then C<LOCK TABLES> is used for any
value of L<"--lock">. See L<"--[no]transaction">.
When enabled, either explicitly or implicitly, the transaction isolation level
is set C<REPEATABLE READ> and transactions are started C<WITH CONSISTENT
SNAPSHOT>

MySQL复制监控

MySQL常见错误类型

1005：创建表失败
1006：创建数据库失败
1007：数据库已存在，创建数据库失败
1008：数据库不存在，删除数据库失败
1009：不能删除数据库文件导致删除数据库失败
1010：不能删除数据目录导致删除数据库失败
1011：删除数据库文件失败
1012：不能读取系统表中的记录
1020：记录已被其他用户修改
1021：硬盘剩余空间不足，请加大硬盘可用空间
1022：关键字重复，更改记录失败
1023：关闭时发生错误
1024：读文件错误
1025：更改名字时发生错误
1026：写文件错误
1032：记录不存在
1036：数据表是只读的，不能对它进行修改
1037：系统内存不足，请重启数据库或重启服务器
1038：用于排序的内存不足，请增大排序缓冲区
1040：已到达数据库的最大连接数，请加大数据库可用连接数
1041：系统内存不足
1042：无效的主机名
1043：无效连接
1044：当前用户没有访问数据库的权限
1045：不能连接数据库，用户名或密码错误
1048：字段不能为空
1049：数据库不存在
1050：数据表已存在
1051：数据表不存在
1054：字段不存在
1065：无效的SQL语句，SQL语句为空
1081：不能建立Socket连接
1114：数据表已满，不能容纳任何记录
1116：打开的数据表太多
1129：数据库出现异常，请重启数据库
1130：连接数据库失败，没有连接数据库的权限
1133：数据库用户不存在
1141：当前用户无权访问数据库
1142：当前用户无权访问数据表
1143：当前用户无权访问数据表中的字段
1146：数据表不存在
1147：未定义用户对数据表的访问权限
1149：SQL语句语法错误
1158：网络错误，出现读错误，请检查网络连接状况
1159：网络错误，读超时，请检查网络连接状况
1160：网络错误，出现写错误，请检查网络连接状况
1161：网络错误，写超时，请检查网络连接状况
1062：字段值重复，入库失败
1169：字段值重复，更新记录失败
1177：打开数据表失败
1180：提交事务失败
1181：回滚事务失败
1203：当前用户和数据库建立的连接已到达数据库的最大连接数，请增大可用的数据库连接数或重启数据库
1205：加锁超时
1211：当前用户没有创建用户的权限
1216：外键约束检查失败，更新子表记录失败
1217：外键约束检查失败，删除或修改主表记录失败
1226：当前用户使用的资源已超过所允许的资源，请重启数据库或重启服务器
1227：权限不足，您无权进行此操作
1235：MySQL版本过低，不具有本功能

复制监控脚本

参考原文修改。