技术分享 | event_ scheduler导致复制中断的故障分析

原创：洪斌

问题背景

在5.6.29和5.7.11版本之前，当binlog格式设置成mixed时，创建event事件中包含sysdate函数时，会导致复制中断。

与此bug相关：

场景重现

测试版本：重现方法：分别设置statement、mixed、row格式执行以下语句，mixed格式时会导致复制中断，其他两种格式不会造成复制中断。

DELIMITER$DROPEVENTIFEXISTS`MIS_CUMULATIVE_REV_EVENT`$CREATEEVENTIFNOTEXISTS`MIS_CUMULATIVE_REV_EVENT`ONSCHEDULEEVERY3secondSTARTSsysdate()ONCOMPLETIONPRESERVEDOBEGINDECLAREEXITHANDLERFORSQLEXCEPTIONSELECTCONCAT('SQLEXCEPTION-TERMINATINGEVENTFORSTOREDPROCEDURECALL');END$

statement模式

setglobalbinlog_format=statement;

设置5s延迟观察下starts字段时间，复制正常，主从有差异

slave2[localhost]{msandbox}(test)changemastertoMASTER_DELAY=5;

Row模式

setglobalbinlog_format=row;

复制正常，主从有差异

start字段同样有差异，因为sysdate函数是sql实际执行时间；如果是now函数，start字段时间会是一样的。

mixed模式

setglobalbinlog_format=mixed;

关闭延迟

mixed模式下产生的binlog日志

正常的statement和row模式

从这些截图可知，在mixed模式下创建event时，在同一个事务内即产生了DDLstatement，也产生了额外写入表的row事件。

对于DDL语句在任何binlog格式下，都会以statement格式记录。

mixed模式下遇到非复制安全函数会转换成row模式。例如：sysdate()返回实际执行时间而非调用时间与now函数有差异。

mysqlSELECTNOW(),SLEEP(2),NOW();+---------------------+----------+---------------------+|NOW()|SLEEP(2)|NOW()|+---------------------+----------+---------------------+|2006-04-1213:47:36|0|2006-04-1213:47:36|+---------------------+----------+---------------------+mysqlSELECTSYSDATE(),SLEEP(2),SYSDATE();+---------------------+----------+---------------------+|SYSDATE()|SLEEP(2)|SYSDATE()|+---------------------+----------+---------------------+|2006-04-1213:47:44|0|2006-04-1213:47:46|+---------------------+----------+---------------------+

问题分析

利用systemtap观察下，createevent时函数调用，定位为何产生了row事件。查看源码中有哪些create_event函数

[root@10-186-21-66~]addr2line-e/usr/local/mysql/bin/mysqld0x8e6556/export/home/pb2/build/sb_0-14249461-1422537824.58//sql/sql_:3669

sql_

inlinevoidset_current_stmt_binlog_format_row_if_mixed(){DBUG_ENTER("set_current_stmt_binlog_format_row_if_mixed");/*Thisshouldonlybecalledfromdecide_logging_format.@todoOncewehaveensuredthis,uncommentthefollowingstatement,removethebigcommentbelowthat,andremovethein_sub_stmt==0conditionfromthefollowing'if'.*//*DBUG_ASSERT(in_sub_stmt==0);*//*Ifinastored/functiontrigger,_sub_stmttopreventintroducingbugswherepeoplewouldn'tensurethat,andwouldswitchtorow-basedmodeinthemiddleofexecutingastoredfunction/trigger(whichistoolate,seealsoreset_current_stmt_binlog_format_row());thisconditionwillmaketheirtestsfailandsoforcethemtopropagatethelex-binlog_row_based_if_mixedupwardstothecaller.*/if((_format==BINLOG_FORMAT_MIXED)(in_sub_stmt==0))set_current_stmt_binlog_format_row();DBUG_VOID_RETURN;}省略部分代码inlinevoidset_current_stmt_binlog_format_row(){DBUG_ENTER("set_current_stmt_binlog_format_row");current_stmt_binlog_format=BINLOG_FORMAT_ROW;DBUG_VOID_RETURN;}

从上述代码可以看出，此函数判断binlog格式是mixed时则调用set_current_stmt_binlog_format_row，

修复补丁中，在create_event和update_event函数中，在调用Event_db_repository::create_event前设置binlog格式为statement，再执行Event_db_repository::create_event时就不会产生row事件了。

@@-308,6+308,7@@Events::create_event(THD*thd,Event_parse_data*parse_data,{boolret;boolsave_binlog_row_based,event_already_exists;+ulongsave_binlog_format=_format;DBUG_ENTER("Events::create_event");if(check_if_system_tables_error())@@-341,10+342,15@@Events::create_event(THD*thd,Event_parse_data*parse_data,*/if((save_binlog_row_based=thd-is_current_stmt_binlog_format_row()))thd-clear_current_stmt_binlog_format_row();+_format=BINLOG_FORMAT_STMT;+if(lock_object_name(thd,MDL_key::EVENT,parse_,parse_))-DBUG_RETURN(TRUE);+{+ret=true;+gotoerr;+}/*Onerrorconditionsmy_error()iscalledsononeedtohandlehere*/if(!(ret=db_repository-create_event(thd,parse_data,if_not_exists,@@-399,10+405,12@@Events::create_event(THD*thd,Event_parse_data*parse_data,}}}+err:/*Restorethestateofbinlogformat*/DBUG_ASSERT(!thd-is_current_stmt_binlog_format_row());if(save_binlog_row_based)thd-set_current_stmt_binlog_format_row();+_format=save_binlog_format;

完整补丁见：gitlog-p112899f406d2f1f838a180669781a8973ef3e343

结论

1.升级到5.6.29版本或改用row模式

2.如果event的dml语句中出现类似sysdate()，在mixed模式下并不会造成数据不一致，会自动转成row模式

3.在主从环境下创建event_scheduler，slave默认是禁用状态SLAVESIDE_DISABLED。应考虑主从切换后，原主从的event_scheduler状态，避免产生意外行为，比如newslave写入数据。