为了方便描述问题，先构造一个简单的 event，如下：

其中的 t1 表中，有 2 条记录。

同时打开 event_scheduer 和 slow_log，并把慢日志的时间设置为 1s。

待 event 执行段时间后，查询 slow_log 会看到如下的结果：

可以看到，slow_log 中的 和 select sleep(2) 相关记录是有问题的：

1. select * from t1 不应该被记为慢日志，同时其中的 lock_time(应该为0) 和 rows_sent(应该为2) 都是错的；

rows_sent 记错比较好确认，query_time 和 lock_time 记错我们可以从 start_time 和 thread_id 对照确认，另外select sleep(2) 是没有拿锁的，不应该有等锁的时间。

为了搞清楚这个问题，我们需要了解 slow_log 是怎么记的。

slow_log 是否记录判读的逻辑在 log_slow_applicable() 中：

a) 是否没有用到索引，并且 log_queries_not_using_indexes 打开（这种情况下还可能触发 throttle 导致不记录） b) 被标记为慢 SQL()

我们这里只关心 b) 这种 case。

在 SQL 执行结束时，会先调用 update_server_status() 来判断是否是慢 SQL，逻辑如下：

utime_after_lock 表示的是拿到锁的时间点，server 层通过 THD::set_time_after_lock() 设置，引擎层(目前只有 InnoDB 支持)如果有锁请求等待时间的话，会累加到这个变量上，通过 thd_storage_lock_wait() 函数。

select * from t1 语句执行结束，调用 update_server_status() 时，根据执行时间判断是不满足慢 SQL 的，但是因为 event 在执行前 server_status 没有重置，后面调用 log_slow_applicable() 时， 这个标志位还在，因此最终记到 slow_log 里了。

而其中时间记错的原因也是这样，每次执行语句前，start_utime 没有重置，而 utime_after_lock 会在执行 select * from t1 时拿锁被更新。

query_time 和 lock_time 的计算逻辑如下(LOGGER::slow_log_print())：

因此 event 中语句的 query_time 一直是增加的，lock_time 也不是 0。

需要注意的是，start_time 记录的并不是语句开始执行的时间，而是记入 slow_log 时的时间。

rows_sent 也是因为没有重置，一直都是累加的，而 rows_examined 会在 JOIN::exec() 中被重置，因此记的是对的。

出现这种问题的前提是:

1. 用了 MySQL 的 event_scheduler，并且 event 有多个 SQL 语句；

这个 bug 目前最新的 5.6.35/5.7.17 都受影响，官方已经确认，详见 bug#84450。

正常的用户 SQL 的执行逻辑就是这么干的，在 mysql_parse() 里会调用 THD::reset_for_next_command()，但是 event 执行过程中并没有调用这个函数。