問題現象
最近使用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 |
