持续创作,加速成长!这是我参与「掘金日新计划 · 6 月更文挑战」的第12天,点击查看活动详情
问题现象
最近使用sysbench测试MySQL,由于测试时间较长,写了一个脚本按prepare->run->cleanup的顺序在后台跑着。跑完后察看日志发现一个问题,MySQL服务的错误日志中出现多条类似以下信息的报错
看起来是I/O出现了错误,但MySQL进程并未崩溃,sysbench客户端也没有报错。
发现问题过程
根据报错的时间记录以及脚本输出的各个阶段的时间点对比,确定了当时脚本正在执行的命令为:
重新手动执行一遍这个用例,却没有再出现同样的情况。但是用脚本执行却依然能够发现这个错误信息。初步怀疑是run和cleanup之间不能间隔太久才会触发这个问题。由于执行一遍100G数据量的时间较长,重现代价较大,先尝试缩减用例数据量。将—table-size=4000000修改为2000000,此时执行脚本,又不会触发这个问题了,最后将—table-size=3000000可以稳定触发又能减少部分重现时间。为了确认是否间隔太长会导致不能复现,修改脚本在run和cleanup两个阶段之间sleep 10秒,果然不会触发这个错误信息。修改为sleep 5秒则还能触发,不过报错条数已有所减少。
innodb主线程(svr_master_thread)merge的主流程如下:
主线程从ibuf树的叶子节点读取页号和space号,并记录到一个二元数组中(未加锁);
主线程对二元组中space进行检测是否在表空间缓存中,如不在,说明已经被删除了,删除对应ibuf的记录;
主线程判断是否对一个正在删除的space进行异步读取操作,如果是,报错,并删除对应ibuf的记录,转到过程2继续下一个数组元素的判断;
如果一切判断正常,主线程发出async io请求,async读取需要被merge的索引页面;
I/O handler 线程,在接受到完成的async I/O之后,进行merge操作;
进行merge的时候调用fil_space_acquire对space->n_pending_ops进行自增。避免删除操作并发;
执行完毕后调用fil_space_release对space->n_pending_ops进行自减。
相关删除表的逻辑
对fil_system->mutex加锁,设置sp->stop_new_ops = true,标记space正在删除,不允许对它进行新操作,然后对fil_system->mutex解锁;
对fil_system->mutex加锁,检测space->n_pending_ops,对fil_system->mutex解锁。如果检测到大于0,意味着还有依赖的操作未完成,睡眠20ms后重试;
对fil_system->mutex加锁,检测space->n_pending_flushes和(*node)->n_pending ,对fil_system->mutex解锁。如果检测到大于0,意味着还有依赖的I/O未完成,睡眠20ms后重试;
此时认为已经没有冲突的操作了,刷出所有脏页面或删除所有给定的表空间的页面;
从表空间缓存删除指定space的记录;
删除对应数据文件。
问题结论
情况很明确了,主线程获取ibuf的(space,page)的过程与删除操作执行的过程并没有锁保证互斥,只有async I/O完成之后的merge操作与删除操作才有互斥。如果后台线程开始ibuf merge并已经执行过了第2步的检测,但还没有执行到第3步检测,此时用户线程开始做删除表的操作,并设置好stop_new_ops标记但还没有执行到第5步删除表空间缓存,就会出现这个错误信息。两线程的交互如下图所示:
不出意外的话,在打中断点时必然有线程在执行对应表的删除操作。果然我们可以发现如下堆栈:
解决办法
为buf_read_ibuf_merge_pages、buf_read_page_low、fil_io新增一个参数ignore_missing_space。表示忽略正在删除的space,默认为false,当ibuf_merge_pages调用的时候置为true。在fil_io报错处额外判断该参数是否为true,是则不报错,继续其他流程。
或者直接在buf_read_ibuf_merge_pages调用buf_read_page_low时传入IORequest::IGNORE_MISSING参数。