问题现象
最近使用sysbench测试MySQL，由于测试时间较长，写了一个脚本按prepare->run->cleanup的顺序在后台跑着。跑完后察看日志发现一个问题，MySQL服务的错误日志中出现多条类似以下信息的报错：
[ERROR] InnoDB: Trying to do I/O to a tablespace which does not exist. I/O type: read, page: [page id: space=32, page number=57890], I/O length: 16384 bytes。
看起来是I/O出现了错误，但MySQL进程并未崩溃，sysbench客户端也没有报错。
发现问题过程
根据报错的时间记录以及脚本输出的各个阶段的时间点对比，确定了当时脚本正在执行的命令为：
sysbench --tables=100 --table-size=4000000 --threads=50 --mysql-db=sbtest --time=300 oltp_delete cleanup
重新手动执行一遍这个用例，却没有再出现同样的情况。但是用脚本执行却依然能够发现这个错误信息。初步怀疑是run和cleanup之间不能间隔太久才会触发这个问题。由于执行一遍100G数据量的时间较长，重现代价较大，先尝试缩减用例数据量。将—table-size=4000000修改为2000000，此时执行脚本，又不会触发这个问题了，最后将—table-size=3000000可以稳定触发又能减少部分重现时间。为了确认是否间隔太长会导致不能复现，修改脚本在run和cleanup两个阶段之间sleep 10秒，果然不会触发这个错误信息。修改为sleep 5秒则还能触发，不过报错条数已有所减少。
问题调查
察看对应版本mysql5.7.22的代码，发现这个报错只有一个位置：fil0fil.cc文件的第5578行fil_io()函数内。 直接使用gdb调试，在这个位置加上断点，并执行可复现的脚本，得到以下堆栈：
| (gdb) bt#0 fil_io (type=..., sync=sync@entry=false, page_id=..., page_size=..., byte_offset=byte_offset@entry=0, len=16384, buf=0x7f9ead544000, message=message@entry=0x7f9ea8ce9c78) at mysql-5.7.22/storage/innobase/fil/fil0fil.cc:5580#1 0x00000000010f99fa in buf_read_page_low (err=0x7f9ddaffc72c, sync=<optimized out>, type=0, mode=<optimized out>, page_id=..., page_size=..., unzip=true) at mysql-5.7.22/storage/innobase/buf/buf0rea.cc:195#2 0x00000000010fc5fa in buf_read_ibuf_merge_pages (sync=sync@entry=false, space_ids=space_ids@entry=0x7f9ddaffc7e0, page_nos=page_nos@entry=0x7f9ddaffc7a0, n_stored=2) at mysql-5.7.22/storage/innobase/buf/buf0rea.cc:834#3 0x0000000000f3a86c in ibuf_merge_pages (n_pages=n_pages@entry=0x7f9ddaffce30, sync=sync@entry=false) at mysql-5.7.22/storage/innobase/ibuf/ibuf0ibuf.cc:2552#4 0x0000000000f3a94a in ibuf_merge (sync=false, sync=false, n_pages=0x7f9ddaffce30) at mysql-5.7.22/storage/innobase/ibuf/ibuf0ibuf.cc:2656#5 ibuf_merge_in_background (full=full@entry=false) at mysql-5.7.22/storage/innobase/ibuf/ibuf0ibuf.cc:2721#6 0x000000000102bcf4 in srv_master_do_active_tasks () at mysql-5.7.22/storage/innobase/srv/srv0srv.cc:2132#7 srv_master_thread (arg=<optimized out>) at mysql-5.7.22/storage/innobase/srv/srv0srv.cc:2383#8 0x00007fa003eeddc5 in start_thread () from /lib64/libpthread.so.0#9 0x00007fa002aab74d in clone () from /lib64/libc.so.6 |
