周一(2014-11-17)有个项目进行变更,而且是重大变更,DB测操作从早上持续到下午17点,QA同事到晚上10点测试后发现,slave上的数据与master上不一致。
忘介绍了,该项目的该模块有读请求以及delete逻辑在上面,被吓到没?
这个问题应该在情理之中但又在意料之外,其实DBA在下午DB变更时便遇到slave卡住:
Could not execute Delete_rows event on table codcpc_1004pc_0x3EC.mail; Can‘t find record in ‘mail ‘, Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event‘s master log binlog.010464, end_log_pos 82113, Error_code: 1032 141117 7:54:31 [Warning] Slave: Can‘t find record in ‘mail‘ Error_code: 1032
我当时的做法是直接跳过不存在的表,写了下面这个脚本:
mysqlconn="mysql -uADMIN -p4word" #while [ "1" = "1" ] for i in `seq 1 30` do status=`$mysqlconn -e "show slave status\G;" | grep -i "Last_SQL_Error" | grep -i "mail"` if [ -n "$status" ];then $mysqlconn -vvve "stop slave;set global sql_slave_skip_counter=1;start slave;" sleep 1 else $mysqlconn -vvve "show slave status\G" echo "error is OK!" exit 0 fi done
很奇怪的,本以为得写死循环跑,没想到在调试 3次以内就过了,当时没有深究,也因为没时间深究导致后面的熬夜排查问题。
始作俑者是一条SQL:delete from mail where recipientEntityID in (select userid from test.deltb);
今天出现卡住,主要还是因为Delete_rows发现键不存在,如果改为statement,这个问题就不会出现。因为那条罪魁祸首的sql,在slave上肯定能执行下去。
可关键是我们的binlog_format是MIXED模式,那么问题来了,在什么情况下,binlog_format=mixed时,生成的binlog会转换为row格式?关于这点我查了官方文档,看得不是很明白,留待之后更新。
而binlog_format是row模式的时候,skip是以事务级别来的。
下午的删除里边,在master上做的delete,实际上binlog会转换为很多binlog event,而这些event仅仅被几个begin commit包围着。
这也就解释了上面我的问题。
那么跳还是不跳?sql_slave_skip_counter=N在线上跳确实存在一定风险。
⑴ InnoDB时,N=1是跳过整个事务,而不只是一条SQL语句
⑵ 当RBR模式时,无论是InnoDB 或MyISAM,binlog event都是以begin;row group;commit来组织,当N=1时跳过的还是整个事务内容
更安全的做法是sql_exec_mode=IDEMPOTENT,只跳过有问题的SQL或者row,相对于sql_slave_skip_counter而言,slave_exec_mode的处理范围更小、更安全,不过其仅仅适合RBR模式 :(