• 1. 线上MYSQL同步报错故障处理总结 贺春旸
  • 2. 在发生故障切换后,经常遇到的问题就是同步报错,数据库很小的时候,dump完再导入很简单就处理好了,但线上的数据库都150G-200G,如果用单纯的这种方法,成本太高,故经过一段时间的摸索,总结了几种处理方法。 前言
  • 3. 生产环境架构图 目前现网的架构,保存着两份数据,通过异步复制做的高可用集群,两台机器提供对外服务。在发生故障时,切换到slave上,并将其变成master,坏掉的机器反向同步新的master,在处理故障时,遇到最多的就是主从报错。下面是我收录下来的报错信息。VIP
  • 4. 最常见的3种情况第一种:在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
  • 5. 最常见的3种情况第二种:主键重复。在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
  • 6. 最常见的3种情况这3种情况是在HA切换时,由于是异步复制, 且sync_binlog=0,会造成一小部分binlog没接收完导致 同步报错。第三种:在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 263
  • 7. 异步复制:简单的说就是master把binlog发送过去,不管slave是否接收完,也不管是否执行完,这一动作就结束了. 半同步复制:简单的说就是master把binlog发送过去,slave确认接收完,但不管它是否执行完,给master一个信号我这边收到了,这一动作就结束了。(谷歌写的代码,5.5上正式应用。) 异步的劣势:当master上写操作繁忙时,当前POS点例如是10,而slave上IO_THREAD线程接收过来的是3,此时master宕机,会造成相差7个点未传送到slave上而数据丢失。区别
  • 8. 特殊的情况出现频率低这种情况SLAVE在宕机,或者非法关机,例如电源故障、 主板烧了等,造成中继日志损坏,同步停掉。第四种: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
  • 9. 人为失误需谨慎这种情况同步会一直延时,永远也同步不完,error错误日 志里一直出现上面两行信息。解决方法就是把server-id改 成不一致即可。第五种:多台slave存在重复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
  • 10. 开始处理……
  • 11. 1、在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写的,功能上定义了一些自己的东西,不是无论什么错误都一律跳过。)故障处理
  • 12. 2、主键重复。在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; 先看下表结构, 故障处理
  • 13. mysql> desc hcy.t1; +-------+---------+------+-----+---------+-------+ | Field | Type | Null | Key | Default | Extra | +-------+---------+------+-----+---------+-------+ | id | int(11) | NO | PRI | 0 | | | name | char(4) | YES | | NULL | | +-------+---------+------+-----+---------+-------+ 2 rows in set (0.03 sec) 删除重复的主键 mysql> delete from t1 where id=2; Query OK, 1 row affected (0.00 sec)故障处理
  • 14. 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上再分别确认一下。故障处理
  • 15. 在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日志在干什么。 [root@vm01 data]# /usr/local/mysql/bin/mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS mysql-bin.000010 | grep -A '10' 794 故障处理
  • 16. [root@vm01 data]# /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*/; [root@vm01 data]# 故障处理
  • 17. 在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) 故障处理
  • 18. 把丢失的数据在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)故障处理
  • 19. 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 ……故障处理
  • 20. 第四种: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点,然后重新做同步,这样就可以有新的中继日值了。 例子:故障处理
  • 21. 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故障处理
  • 22. 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故障处理
  • 23. 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)故障处理
  • 24. 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: 故障处理
  • 25. 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: 故障处理
  • 26. 故障处理各种大招都用上了,无奈slave数据丢失过多,ibbackup(需要银子)该你登场了。
  • 27. Ibbackup热备份工具,是付费的。xtrabackup是免费的,功能上一样。 Ibbackup备份期间不锁表,备份时开启一个事务(相当于做一个快照),然后会记录一个点,之后数据的更改保存在ibbackup_logfile文件里,恢复时把ibbackup_logfile 变化的数据再写入到ibdata里。 Ibbackup 只备份数据( ibdata、.ibd ),表结构.frm不备份。 下面一个演示例子:故障处理
  • 28. 备份: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]#故障处理
  • 29. [root@vm01 etc]# more my_bak.cnf datadir =/bak/data innodb_data_home_dir = /bak/data innodb_data_file_path = ibdata1:10M:autoextend innodb_log_group_home_dir = /bak/data innodb_buffer_pool_size = 100M innodb_log_file_size = 5M innodb_log_files_in_group=2 [root@vm01 etc]#故障处理
  • 30. [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故障处理
  • 31. 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故障处理
  • 32. [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故障处理
  • 33. 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 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 Setting log file size to 0 5242880 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后,做同步,那个点就是给出的红色字。 CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000010',MASTER_LOG_POS=1191;故障处理
  • 34. http://www.maatkit.org/ 简介:maatkit是一个开源的工具包 包,为mysql日常管理提供了帮助。 目前,已被Percona公司收购并维护。 。其中mk-table-checksum是用来检测 master和slave上的表结构和数据是 否一致。mk-table-sync是发生主从数据不一致时,来修复的。 这两个工具包,没有在现网实际操作的经验,这里仅仅是新技术探讨和学术交流,下面展示下如何使用。 http://www.actionsky.com/products/mysql-others/maatkit.jsp Maatkit工具包
  • 35. [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 [root@vm02]# 提示缺少perl-DBI模块,那么直接 yum install perl-DBI。Maatkit工具包
  • 36. [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 [root@vm02 bin]# 如果表数据不一致,CHECKSUM的值是不相等的。Maatkit工具包
  • 37. 解释下输出的意思: DATABASE:数据库名 TABLE:表名 CHUNK:checksum时的近似数值 HOST:MYSQL的地址 ENGINE:表引擎 COUNT:表的行数 CHECKSUM:校验值 TIME:所用时间 WAIT:等待时间 STAT:MASTER_POS_WAIT()返回值 LAG:slave的延时时间 Maatkit工具包
  • 38. 如果你想过滤出不相等的都有哪些表,可以用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时会锁表,表的大小取决于执行的快慢。Maatkit工具包
  • 39. 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 mysql> mysql>Maatkit工具包
  • 40. [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 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 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 and transactions are started C Maatkit工具包
  • 41. 结束!