<b>问题描述</b>
在 MySQL 官方最新的版本 MySQL 5.6.36 版本上,我们遇到了一个非常有意思的bug,实例几乎每个小时crash一次,查看其产生的 core file,发现如下的backtrace:
从core来看,现象也比较明确:
InnoDB master thread 正在淘汰 InnoDB 表数据对象 dict_table_t
淘汰的 dict_table_t 对象 table->drop_abort= true,所以需要删除未完成的index
当在row_merge_drop_indexes() 函数中删除索引时, 发现 table->indexes= 0, 随后就crash了
由于是master thread 后台线程触发的crash,所以并不能知道用户现场做了什么操作,以及什么时候做了什么操作而对此产生了影响。
所以,只能根据当前 core 文件中的对象 dict_table_t 的属性进行排查,来查找线索。
<b>InnoDB背景</b>
1. Master Thread
InnoDB有一个常驻后台 master 线程,主要做以下工作:
前台用户线程lazy drop 的 table,master thread负责清理
merge insert buffer
淘汰dict table cache
flush log buffer
make checkpoint
其中,evict table cache 的过程,会根据 server 层的一个变量 table_definition_cache 来进行淘汰,
因为 server 层会根据这个变量的设置来缓存从FRM文件中得到的数据字典定义 即table_share 对象,所以引擎层缓存超过这个设置的意义也不大。
Master线程会根据 LRU 链表即 dict_sys->table_LRU 进行淘汰,但淘汰的过程,需要保证 dict_table_t 对象不能被 handler 引用,也就是当前没有 statement 语句在操作这个表,在 dict_table_t 中,使用 table->n_ref_count 来表示有多少个handler对象在引用。
<b>2. dict_table_t的生命周期</b>
1. 装载 当操纵这个表的时候,InnoDB 的 handler 对象需要引用这个 dict_table_t 对象,首先会在 dict_sys->table_hash 进行hash查找:
如果存在,说明已经存在 dictionary cache 中,
如果不存在,需要读取InnoDB的数据字典SYS_TABLES, SYS_INDEXES, SYS_COLUMNS等来装载dict_table_t对象
2. 引用 当 statement 执行的时候,会先创建 handler,然后 handler 会引用 dict_table_t 对象对象,即增加 table->n_ref_count++,因为增加了引用,会调整 dict_sys->table_LRU 的位置,保持热度。 当语句结束的时候,如果 handler close 的话,会解除 dict_table_t 对象的引用,即递减 table->n_ref_count--。
3. 缓存 因为 server 层存在 table open cache,受 table_open_cache 参数设置影响,所以,当 statement 结束的时候,并不会立即 close opened table,相应的 InnoDB 的 handler 也不会立即关闭,这样就保持了 table->n_ref_count 引用数。
4. 淘汰 Master thread 每一秒钟都会轮询 dict_sys->table_LRU, 当 table->n_ref_count == 0, 进行淘汰dict_table_t 对象, 保留的数量受参数table_definition_cache控制。
3. table->drop_aborted
按照 InnoDB online DDL 的定义,在 DDL 的过程中,如果任务失败,会把 table->drop_aborted 设置成 true,随后,会回滚掉当前的操作,因为是online操作,在中间时刻不阻塞 DML, 所以这里会产生两种情况:
如果当前没有 statement 操作这个表,那当前在回滚的时候,就把这个 DDL 给直接回滚掉了
如果当前有 statement 在操作这个表,那就会把 table->drop_aborted 设置成TRUE,进行 lazy drop 回滚。
根据代码的路径,lazy drop的会在以下场景发生:
dict_table_close() 也就是当最后一个 statement 引用 dict_table_t 使用完了之后,即 table->n_ref_count == 0 时,这个线程负责清理掉未完成的 DDL
下一个 DDL 也就是当下一个 DDL 操作的时候,如果发现 table->drop_aborted 为 true,那么也会负责清理这个未完成的 DDL
<b>复现过程</b>
从上面的 InnoDB 背景介绍来看,我们已经 cover 了这个 crash 相关的概念和内容,下面我们就来看复现过程:
1. 从core文件看 table->drop_aborted= true
所以我们断定一定存在失败的 DDL 语句,随后通过审计日志,我们发现:
2.回滚 因为用户操作的时候,没有回滚掉这个 online add unique key 操作,所以我们断定在 alter 操作的时候,同时有 DML 语句在。
根据这两点我们构思了如下的case:
环境准备:
Session 1:
Session 2:
Session 3:
为了复现这个case,我们添加了两个sleep函数在代码中,参考如下:
这样我们就复现出来这个 crash, 同样,我们在 MySQL 5.7.18,以及还没有 release 的8.0版本上发现了存在相同的问题。
<b>问题原因和修复方法</b>
1. 问题原因 从代码的设计上,table->drop_aborted设置成TRUE,会在两种场景下进行lazy drop,即上面提到的:
dict_table_close 即 dict_table_t 对象 n_ref_count 引用数降成0
下一个 DDL 的时候
而这个 lazy drop 却是在 master thread 要淘汰 dict_table_t 的时候。 因为淘汰的条件需要 n_ref_count == 0, 所以一定发生过dict_table_close() 了。
那问题的原因就明确了: 在 dict_table_close 把 n_ref_count 降成0的时候,没有完成 lazy drop 回滚。
2. 修复方法 知道了问题的原因,修复方法很简单,我们发现 dict_table_close() 函数存在一些逻辑错误,
我们将会在Aliyun RDS版本和我们的开源版本AliSQL上进行修复,敬请关注。
同时也可以关注,我们提交给官方和MariaDB的进度: https://bugs.mysql.com/bug.php?id=86607 https://jira.mariadb.org/browse/MDEV-13051