原文: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版本过低,不具有本功能

复制监控脚本

参考原文修改。