MySQL-event机制详解及官方bug剖析
提示：公众号展示代码会自动折行，建议横屏阅读
近期，有线上5.6版本event用户反映了两个问题:
(1) 部分event莫名其妙的延迟执行 (2) 慢日志不记录event中的更新及插入语句 经过一系列的分析及验证，我们确认这两个问题是mysql原生代码的bug，并向官方report。下面就介绍一下相关代码及这两个bug的具体原因及修复方案。
1 mysql event的代码类图
mysql从5.1版本开始引入event机制，这里介绍的代码主要基于5.6/5.7/8.0。5.7/8.0版本除了在priority_queue的实现数据结构上略有变化外，其他的几乎没变。下面以5.6版本为例介绍相关的代码。
各个类的主要功能如下：
Events
event的入口模块，主要负责系统中events的加载卸载以及event的创建、删除、更改等操作。相关文件为events.h/events.cc。Event_parse_data
sql解析后的event内部结构体。相关文件为event_parse_data.h/event_parse_data.ccEvent_scheduler
event的调度模块。相关文件为event_scheduler.h/event_scheduler.ccEvent_queue
Event任务的内存管理结构，内部实现为一个小顶堆，队头的event为最近需要执行的任务。Event scheduler会循环获取队头的event并执行。相关文件为event_queue.h/event_queue.cc。Event_db_repository
mysql.event表的操作集合。相关文件为event_db_repository.h/event_db_repository.cc。Event_queue_element
event queue element元素相关操作。相关文件为event_data_objects.h/event_data_objects.cc。QUEUE
大/小顶堆。除了event模块以外，其他的如partition/file_sort/unique/fts等模块或流程也在使用。在event中用于实现event任务的存放及排序。在5.6中相关文件为queues.h/queues.c，在5.7/8.0中相关的文件为priority_queue.h。
2 mysql event的运行机制
对上图补充说明如下：
event metadata 如上图所示，event的元数据信息主要包括两部分：(1)内存中的event queue，管理所有的event任务及对其按照任务执行时间排序 (2)mysql库中的event表，负责持久化event的相关信息。
event scheduler
event scheduler线程循环获取event queue队列头的event，并等待任务到时启动event执行线程。event实际是按照存储过程的方式执行的。event执行完成后会更新event的元数据信息。
3 主要流程
3.1 event创建流程
handle_one_connection
-->do_handle_one_connection
---->do_command
------>dispatch_command
-------->mysql_parse
---------->mysql_execute_command
------------>Events::create_event
-------------->lock_object_name
-------------->db_repository->create_event
-------------->db_repository->load_named_event
-------------->event_queue->create_event
-------------->thd->add_to_binlog_accessed_dbs
-------------->write_bin_log
3.2 event删除流程
handle_one_connection
-->do_handle_one_connection
---->do_command
------>dispatch_command
-------->mysql_parse
---------->mysql_execute_command
------------>Events::drop_event
-------------->check_access
-------------->lock_object_name
-------------->Event_db_repository::drop_event
-------------->Event_queue::drop_event
-------------->thd->add_to_binlog_accessed_dbs
-------------->write_bin_log
3.3 event更改流程
handle_one_connection
-->do_handle_one_connection
---->do_command
------>dispatch_command
-------->mysql_parse
---------->mysql_execute_command
------------>Events::update_event
-------------->check_access
-------------->lock_object_name
-------------->Event_db_repository::update_event
-------------->Event_queue::update_event
-------------->thd->add_to_binlog_accessed_dbs
-------------->write_bin_log
3.4 event schduler启动及调度执行
Event调度器会在两种情况下启动: (1)mysqld进程启动时检测到event_scheduler打开时 (2)mysqld运行过程中检测到event_scheduler从关闭切换到打开时
mysqld进程启动时event scheduler启动流程：
mysqld_main
-->Events::init
---->Event_queue::init_queue
---->Events::load_events_from_db
---->Event_scheduler::start
------>mysql_thread_create(event_scheduler_thread)
mysqld运行过程中event_scheduler从关闭切换到打开时，启动流程：
event_scheduler_update
-->Event_scheduler::start
---->mysql_thread_create(event_scheduler_thread)
event_scheduler_thread线程执行流程:
-->Event_scheduler::run
---->Event_queue::get_top_for_execution_if_time
---->Event_scheduler::execute_top
------>mysql_thread_create(event_worker_thread)
event_worker_thread线程执行流程:
-->Event_worker_thread::run
---->Event_db_repository::load_named_event
---->Event_job_data::execute
------>check_access
------>Event_job_data::construct_sp_sql
------>parse_sql
------>sp_head::execute_procedure
4 event小顶堆插入算法
4.1 插入算法代码
/*功能:向queue队列中插入元素element*/
void queue_insert(register QUEUE *queue, uchar *element)
{
......
/* 哨兵节点，自下向上搜索时，搜索到element 0则停止 */
queue->root[0]= element;
/*队列中新增一个元素*/
idx= ++queue->elements;
/*
从最后一个元素的父节点开始，比较其和element的大小；
如果比element大，则将其移到子节点，并搜索父节点的父节点，以此类推……
直到搜索到的节点的值比element小或者相等
*/
while((queue->compare(queue->first_cmp_arg,
element + queue->offset_to_key,
queue->root[(next= idx >> 1)] +
queue->offset_to_key) * queue->max_at_top) < 0)
{
queue->root[idx]= queue->root[next];
idx= next;
}
/* 将当前节点的子节点赋值为element，插入完成*/
queue->root[idx]= element;
}
4.2 插入算法示例
在小顶堆1、2、7、3、5、9、10、6中插入0。step1:将0插入到最后一个节点，并和其父节点3进行比较
step2: 将最后一个节点及其父节点进行交换，并继续比较0和其父节点2的大小
step3: 将0和2进行交换，并继续比较0和其父节点1的大小
step4: 将0和1进行交换，已经到根节点，插入结束
5 event小顶堆删除算法
5.1 删除算法代码
/* 功能：删除queue中的第idx个元素 */
uchar *queue_remove(register QUEUE *queue, uint idx)
{
uchar *element;
/* 用最后一个元素的值覆盖当前位置的值，并删除最后一个元素 */
element= queue->root[++idx]; /* Intern index starts from 1 */
queue->root[idx]= queue->root[queue->elements--];
/* 当前位置的元素发生了变化，从当前位置开始，向下调整小顶堆 */
_downheap(queue, idx);
return element;
}
/* 功能：从第idx个元素开始，向下调整小顶堆 */
void _downheap(register QUEUE *queue, uint idx)
{
uchar *element;
uint elements,half_queue,offset_to_key, next_index;
my_bool first= TRUE;
uint start_idx= idx;
offset_to_key=queue->offset_to_key;
element=queue->root[idx];
half_queue=(elements=queue->elements) >> 1;
/* 从idx开始，将其子节点中值较小的节点向其父节点挪，直到最后一个索引节点。
目的是将idx子树节点重构成一个小顶堆
*/
while(idx <= half_queue)
{
next_index=idx+idx;
if(next_index < elements &&
(queue->compare(queue->first_cmp_arg,
queue->root[next_index]+offset_to_key,
queue->root[next_index+1]+offset_to_key) *
queue->max_at_top) > 0)
next_index++;
if(first &&
(((queue->compare(queue->first_cmp_arg,
queue->root[next_index]+offset_to_key,
element+offset_to_key) * queue->max_at_top) >= 0)))
{
queue->root[idx]= element;
return;
}
queue->root[idx]=queue->root[next_index];
idx=next_index;
first= FALSE;
}
next_index= idx >> 1;
/* 查找element这个元素应该在的节点：从next_idx开始，如果其值比element小则将其移动到子节点，并继续比较其父节点和element的值，
直到找到一个不小于element值的节点，即为element这个值应该在的节点 */
while(next_index > start_idx)
{
if((queue->compare(queue->first_cmp_arg,
queue->root[next_index]+offset_to_key,
element+offset_to_key) *
queue->max_at_top) < 0)
break;
queue->root[idx]=queue->root[next_index];
idx=next_index;
next_index= idx >> 1;
}
/* 将element赋值给搜索到的节点 */
queue->root[idx]=element;
}
5.2 删除算法示例
比如在第四节所述的小顶堆0、1、7、2、5、9、10、6、3中删除元素7，步骤如下：step1: 用最后一个元素3替换7，并删除最后一个元素
step2: 从3开始向下调整小顶
5.3 mysql中小顶堆中删除代码的bug
在上述例子中删除的是7，如果删除的是10，按照当前的算法用3替换10，然后从3开始向下调整，由于3没有子节点，则最终生成的树形状如下
很明显，这棵树已经不是小顶堆了，由于小顶堆每次都只取根节点，则3就会比7更晚被访问到，造成event延迟。
bug原因： mysql的小顶堆删除算法中用最后一个元素替换被删除位置的元素后，只做向下的堆调整，但是向下调整仅适合最后一个元素比被删除位置元素值大的情况，如果最后一个元素比被删除位置元素值小，则需要向上做堆的调整。具体案例请参考第7节。
6 慢更新请求不记录slow log(官方bug1)
bug1 链接： https://bugs.mysql.com/bug.php?id=96722
6.1 现象描述
(1) 在event中执行的慢select语句会被记录到慢日志 (2) 如果在在event中insert/update之前有慢select语句，那么后续的insert/update/delete语句无论快慢都会被记录到慢日志
6.2 现象1原因分析
6.2.1 慢日志的记录条件分析
慢日志的记录条件有两个，参见log_slow_applicable函数。具体条件如下：
(1)请求执行线程被设置了SERVER_QUERY_WAS_SLOW标志并且请求执行过程中检查的行数不小于min_examined_row_limit系统变量的值；
(2)设置了log_throttle_queries_not_using_indexes及log_queries_not_using_indexes标志并且当前记录未使用index的请求速度未达到流控阈值。
从现场看，第二条不满足，因为log_throttle_queries_not_using_indexes及log_queries_not_using_indexes都没有设置，只能是因为第一个原因。同时min_examined_row_limit的值是0，因此只能是因为SERVER_QUERY_WAS_SLOW未被设置才导致没有记录慢日志。
6.2.2 慢insert/update/delete未被设置SERVERQUERYWASSLOW标志的原因
在event执行过程中，SERVER_QUERY_WAS_SLOW的记录是在spinstrstmt::execute函数中，event命令被执行完成后检测更新的，代码如下：
if(thd->get_stmt_da()->is_eof())
{
/* 更新SERVER_QUERY_WAS_SLOW标记 */
thd->update_server_status();
thd->protocol->end_statement();
}
update_server_status函数负责更新请求的慢查询状态(SERVER_QUERY_WAS_SLOW)，这个函数很简单，直接比较请求执行时间和慢请求定义时间的大小，并设置慢查询状态。这个函数很简单，请求的起始时间也是在event开始之前就记录了，不可能出错。因此只可能是thd->getstmtda()->iseof()这个条件不满足。
继续跟踪代码，发现DA_EOF和DA_OK分别适用于不同的请求类型，DA_OK适用于不返回结果集的请求类型(增删改),DA_EOF适用于返回结果集的请求(查询)。这在代码中有注释说明，相关代码如下：
/**
Set OK status -- ends commands that do not return a
result set, e.g. INSERT/UPDATE/DELETE.
*/
voidDiagnostics_area::set_ok_status(ulonglong affected_rows, ulonglong last_insert_id, constchar*message)
6.2.3 现象1原因总结
存储过程执行完成后根据Diagnostics_area的状态是否为DA_EOF标记判断是否需要更新慢请求状态，但是更新操作未设置DA_EOF标记。
6.3 现象2原因分析
通过上面的分析，我们就明白了为什么慢增删改在event中不记录慢日志的原因。但是为什么如果增删改之前有慢查询，增删改就会记录慢日志呢？
从上面的分析中，我们可以猜测假如有慢查询，那么肯定会设置SERVER_QUERY_WAS_SLOW 标记，但是由于慢增删改不会设置这个标记，那么如果执行完慢查询之后，THD的慢查询状态没有被重置的话，那么后续的请求无论快慢就都会被记录在慢日志。实际跟踪代码，确实如此。
6.4 建议解决方案
(1) 在spinstrstmt::execute函数中如果是my_ok状态则也检测更新慢请求状态。
(2) 在event中每一个指令执行完成之后，重置慢请求状态。由于mysql官网上并没有对event中的慢请求的判断标准进行定义，因此上述两点只是建议的方案，需要官方确认后才能修复。
7.drop event后部分event被延迟执行(官方bug2)
bug2 链接： https://bugs.mysql.com/bug.php?id=96849
7.1 现象描述
部分event被延迟执行，有些延迟几个小时，有些延迟几天，有些甚至不执行。客户反馈说drop掉一个event后重建新的event就很容易复现，出现延迟后删除重新创建event就可以正常执行。最近一次出现的被延迟的event名称为event_delayed.
7.2 原因分析
7.2.1 怀疑点
结合相关代码，可能的原因有以下几种：
(1) event调度线程或者执行线程由于cpu负载较高，出现了延迟，导致event执行延迟；
(2) event被调度了但是执行过程中出错；
(3) event的执行时间计算错误；
(4) event队列的小顶堆排序出错；上面四种原因中第一个可以通过在测试环境通过加大cpu负载来复现验证；后面三个可以通过给线上加打印复现验证。
7.2.2 原因一验证
验证方法：在一个8核的实例上，启动sysbench测试线程至cpu基本满负载，然后创建80个event(线上实际只有40个)同时启动，观察event延迟情况。测试现象：实际观察，这80个event几乎同一时间执行，最多延迟一秒。没有出现延迟几个小时或者更长时间的情况。验证结论：cpu负载不可能造成event长时间延迟的原因。
7.2.3 原因二三验证
验证方法：在event执行的启动执行及结束流程添加相关流程打印及过程中event队列的数据打印，通过日志信息确定是哪种原因。测试现象及分析：(1) 相关的日志中没有event执行错误的打印,原因二被排除。(2) 通过对过程中打印的event队列的任务执行时间进行人工计算，发觉event队列中的任务执行时间全部正确，原因三被排除。(3) 通过上面两个排查，说明很可能是原因四。这个排查就比较繁琐，因为从出错的event被创建到延迟被发现这个过程进行了50多次event队列的更新，需要对这50多次打印的event队列信息进行逐一排查。
7.2.4 原因四排查分析
(1) 对这50个任务队列进行解析并检查每个队列是否满足小顶堆的特性。分析发现部分队列不满足小顶堆的特性，而且出错的节点就是用户发现的被延迟的event eventdelayed，如图：
由于每次取任务时只取根节点，而且后续的堆调整也是假设当前堆满足小顶堆条件的前提下进行， 所以当出现这种错误节点后，后续的调度就会出现很多不符合预期的情况，造成不可预期的延迟。
(2) 分析这个错误队列的造成原因通过对event event_delayed创建后的队列进行逐一排查，确定event队列的小顶堆被破坏的过程如下：
从上面的分析可以看出，小顶堆被破坏原因是:queue_remove函数在做堆调整时只做了向下调整，而没有根据实际被删除位置值的变化分别向下或者向上调整。
(3) 在5.6上复现
复现方法：在mysqs/queues.c的main函数中构造和线上删除event_dropped前一样的队列，删除event_dropped，观察删除后的堆是否满足小顶堆性质。
复现结论：由于queue_remove中堆调整算法不正确，导致删除event_dropped后的堆，小顶堆性质被破坏；
7.3 解决方案
(1) 解决方案：修改queue_remove函数，将down_heap替换为queue_fix。
(2)方案验证：修改queue_remove后，按照上述问题复现方法同样的操作后，小顶堆特性继续保持。如图所示：
经验证，该bug在5.7/8.0上都存在，修复思路和在5.6上一样。
8.总结
mysql的event机制从现在还不是特别完善，如果用户的业务对任务的执行时间要求很精确或者任务之间存在强依赖关系，最好不要强依赖event机制。同时我们作为云服务提供商也会及时发现并解决运行过程中存在的问题，努力让mysql运行的越来越稳定。
腾讯数据库技术团队对内支持QQ空间、微信红包、腾讯广告、腾讯音乐、腾讯新闻等公司自研业务，对外在腾讯云上支持TencentDB相关产品，如CynosDB、CDB、CTSDB、CMongo等。腾讯数据库技术团队专注于持续优化数据库内核和架构能力，提升数据库性能和稳定性，为腾讯自研业务和腾讯云客户提供“省心、放心”的数据库服务。此公众号和广大数据库技术爱好者一起，推广和分享数据库领域专业知识，希望对大家有所帮助。