MySQL在刪除表時I/O錯誤緣由分析

歡迎你們前往騰訊雲+社區，獲取更多騰訊海量技術實踐乾貨哦~

本文由騰訊數據庫技術 發表於雲+社區專欄

問題現象

最近使用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
複製代碼

很明顯這是後臺線程在作insert buffer merge操做。此時發現space->stop_new_ops爲true，也就是要處理的頁面所屬的space正在被刪除。爲何會去操做正在被刪除的space呢？這須要調查下insert buffer功能、insert buffer merge的流程以及刪除表的流程。

insert buffer背景知識

insert buffer是一種特殊的數據結構（B+ tree），當輔助索引頁面不在緩衝池中時，它會將更改緩存起來，稍後在頁面被其餘讀取操做加載到緩衝池中時合併。MySQL最初引進這個功能的時候只能緩存insert操做，因此叫作insert buffer，如今這些操做能夠是 INSERT, UPDATE, or DELETE(DML)，因此改叫作change buffer了（本文依然以insert buffer描述），但源碼中依然以ibuf做爲標識。這個功能把若干對同一頁面的更新緩存起來，合併爲一次性更新操做，減小了IO，並轉化隨機IO爲順序IO,這樣能夠避免隨機IO帶來性能損耗，提升數據庫的寫性能。

相關insert buffer merge邏輯

當buffer page讀入buffer pool時，就會進行insert buffer merge。主要有幾個場景會出現merge過程：

1. 當頁面被讀入緩衝池時，讀取完成後先進行ibuf的merge，而後頁面纔可用；
2. merge操做做爲後臺任務執行。 innodb_io_capacity參數可設置InnoDB後臺任務每次merge過程的頁面數上限；
3. 在崩潰恢復期間，當索引頁被讀入緩衝池時，將執行對應頁的insert buffer merge；
4. insert buffer具備持久性，系統崩潰不會致使它失效。重啓後，insert buffer merge操做將恢復正常；
5. 服務器關閉時可以使用—innodb-fast-shutdown = 0強制進行ibuf的徹底合併。

咱們此次的問題很明顯屬於第二種狀況。innodb主線程(svr_master_thread）會每隔一秒主動進行一次insert buffer的merge操做。先判斷過去1s以內服務器是否發生過活動（插入元組到頁面、undo表上的行操做等），若是發生過，則merge的最大頁面數爲innodb_io_capacity設定的5%。若是沒有則merge的最大頁面數爲innodb_io_capacity設定的值。

innodb主線程(svr_master_thread）merge的主流程以下：

1. 主線程從ibuf樹的葉子節點讀取頁號和space號，並記錄到一個二元數組中（未加鎖）；
2. 主線程對二元組中space進行檢測是否在表空間緩存中，如不在，說明已經被刪除了，刪除對應ibuf的記錄；
3. 主線程判斷是否對一個正在刪除的space進行異步讀取操做，若是是，報錯，並刪除對應ibuf的記錄，轉到過程2繼續下一個數組元素的判斷；
4. 若是一切判斷正常，主線程發出async io請求，async讀取須要被merge的索引頁面；
5. I/O handler 線程，在接受到完成的async I/O以後，進行merge操做；
6. 進行merge的時候調用fil_space_acquire對space->n_pending_ops進行自增。避免刪除操做併發；
7. 執行完畢後調用fil_space_release對space->n_pending_ops進行自減。

相關刪除表的邏輯

1. 對fil_system->mutex加鎖，設置sp->stop_new_ops = true，標記space正在刪除，不容許對它進行新操做，而後對fil_system->mutex解鎖；
2. 對fil_system->mutex加鎖，檢測space->n_pending_ops，對fil_system->mutex解鎖。若是檢測到大於0，意味着還有依賴的操做未完成，睡眠20ms後重試；
3. 對fil_system->mutex加鎖，檢測space->n_pending_flushes和(*node)->n_pending ，對fil_system->mutex解鎖。若是檢測到大於0，意味着還有依賴的I/O未完成，睡眠20ms後重試；
4. 此時認爲已經沒有衝突的操做了，刷出全部髒頁面或刪除全部給定的表空間的頁面；
5. 從表空間緩存刪除指定space的記錄；
6. 刪除對應數據文件。

問題結論

狀況很明確了，主線程獲取ibuf的（space，page）的過程與刪除操做執行的過程並無鎖保證互斥，只有async I/O完成以後的merge操做與刪除操做纔有互斥。若是後臺線程開始ibuf merge並已經執行過了第2步的檢測，但尚未執行到第3步檢測，此時用戶線程開始作刪除表的操做，並設置好stop_new_ops標記但尚未執行到第5步刪除表空間緩存，就會出現這個錯誤信息。兩線程的交互以下圖所示：

不出意外的話，在打中斷點時必然有線程在執行對應表的刪除操做。果真咱們能夠發現以下堆棧：

Thread 118 (Thread 0x7f9de0111700 (LWP 5234)):
#0 0x00007fa003ef1e8e in pthread_cond_broadcast@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1 0x0000000000f82f41 in broadcast (this=0xd452ef8) at mysql-5.7.22/storage/innobase/os/os0event.cc:184
#2 set (this=0xd452ef8) at mysql-5.7.22/storage/innobase/os/os0event.cc:75
#3 os_event_set (event=0xd452ef8) at mysql-5.7.22/storage/innobase/os/os0event.cc:483
#4 0x00000000010ec8a4 in signal (this=<optimized out>) at mysql-5.7.22/storage/innobase/include/ut0mutex.ic:105
#5 exit (this=<optimized out>) at mysql-5.7.22/storage/innobase/include/ib0mutex.h:690
#6 exit (this=<optimized out>) at mysql-5.7.22/storage/innobase/include/ib0mutex.h:961
#7 buf_flush_yield (bpage=<optimized out>, buf_pool=<optimized out>) at mysql-5.7.22/storage/innobase/buf/buf0lru.cc:405
#8 buf_flush_try_yield (processed=<optimized out>, bpage=<optimized out>, buf_pool=<optimized out>) at mysql-5.7.22/storage/innobase/buf/buf0lru.cc:449
#9 buf_flush_or_remove_pages (trx=<optimized out>, flush=<optimized out>, observer=<optimized out>, id=<optimized out>, buf_pool=<optimized out>) at mysql-5.7.22/storage/innobase/buf/buf0lru.cc:632
#10 buf_flush_dirty_pages (buf_pool=<optimized out>, id=<optimized out>, observer=<optimized out>, flush=<optimized out>, trx=<optimized out>) at mysql-5.7.22/storage/innobase/buf/buf0lru.cc:693
#11 0x00000000010f6de7 in buf_LRU_remove_pages (trx=0x0, buf_remove=BUF_REMOVE_FLUSH_NO_WRITE, id=55, buf_pool=0x31e55e8) at mysql-5.7.22/storage/innobase/buf/buf0lru.cc:893
#12 buf_LRU_flush_or_remove_pages (id=id@entry=55, buf_remove=buf_remove@entry=BUF_REMOVE_FLUSH_NO_WRITE, trx=trx@entry=0x0) at mysql-5.7.22/storage/innobase/buf/buf0lru.cc:951
#13 0x000000000114e488 in fil_delete_tablespace (id=id@entry=55, buf_remove=buf_remove@entry=BUF_REMOVE_FLUSH_NO_WRITE) at mysql-5.7.22/storage/innobase/fil/fil0fil.cc:2800
#14 0x0000000000fe77bd in row_drop_single_table_tablespace (trx=0x0, is_encrypted=false, is_temp=false, filepath=0x7f9d7c209f38 "./sbtest/sbtest25.ibd", tablename=0x7f9d7c209dc8 "sbtest/sbtest25", space_id=55) at mysql-5.7.22/storage/innobase/row/row0mysql.cc:4189
#15 row_drop_table_for_mysql (name=name@entry=0x7f9de010e020 "sbtest/sbtest25", trx=trx@entry=0x7f9ff9515750, drop_db=<optimized out>, nonatomic=<optimized out>, nonatomic@entry=true, handler=handler@entry=0x0) at mysql-5.7.22/storage/innobase/row/row0mysql.cc:4741
#16 0x0000000000f092f3 in ha_innobase::delete_table (this=<optimized out>, name=0x7f9de010f5e0 "./sbtest/sbtest25") at mysql-5.7.22/storage/innobase/handler/ha_innodb.cc:12539
#17 0x0000000000801a30 in ha_delete_table (thd=thd@entry=0x7f9d7c1f6910, table_type=table_type@entry=0x2ebd100, path=path@entry=0x7f9de010f5e0 "./sbtest/sbtest25", db=db@entry=0x7f9d7c00e560 "sbtest", alias=0x7f9d7c00df98 "sbtest25", generate_warning=generate_warning@entry=true) at mysql-5.7.22/sql/handler.cc:2586
#18 0x0000000000d0a6af in mysql_rm_table_no_locks (thd=thd@entry=0x7f9d7c1f6910, tables=tables@entry=0x7f9d7c00dfe0, if_exists=true, drop_temporary=false, drop_view=drop_view@entry=false, dont_log_query=dont_log_query@entry=false) at mysql-5.7.22/sql/sql_table.cc:2546
#19 0x0000000000d0ba58 in mysql_rm_table (thd=thd@entry=0x7f9d7c1f6910, tables=tables@entry=0x7f9d7c00dfe0, if_exists=<optimized out>, drop_temporary=<optimized out>) at mysql-5.7.22/sql/sql_table.cc:2196
#20 0x0000000000c9d90b in mysql_execute_command (thd=thd@entry=0x7f9d7c1f6910, first_level=first_level@entry=true) at mysql-5.7.22/sql/sql_parse.cc:3589
#21 0x0000000000ca1edd in mysql_parse (thd=thd@entry=0x7f9d7c1f6910, parser_state=parser_state@entry=0x7f9de01107a0) at mysql-5.7.22/sql/sql_parse.cc:5582
#22 0x0000000000ca2a20 in dispatch_command (thd=thd@entry=0x7f9d7c1f6910, com_data=com_data@entry=0x7f9de0110e00, command=COM_QUERY) at mysql-5.7.22/sql/sql_parse.cc:1458
#23 0x0000000000ca4377 in do_command (thd=thd@entry=0x7f9d7c1f6910) at mysql-5.7.22/sql/sql_parse.cc:999
#24 0x0000000000d5ed00 in handle_connection (arg=arg@entry=0x10b8e910) at mysql-5.7.22/sql/conn_handler/connection_handler_per_thread.cc:300
#25 0x0000000001223d74 in pfs_spawn_thread (arg=0x10c48f40) at mysql-5.7.22/storage/perfschema/pfs.cc:2190
#26 0x00007fa003eeddc5 in start_thread () from /lib64/libpthread.so.0
#27 0x00007fa002aab74d in clone () from /lib64/libc.so.6
複製代碼

解決辦法

爲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參數。

具體代碼參考MariaDB commit：8edbb1117a9e1fd81fbd08b8f1d06c72efe38f44

影響版本

察看相關信息，這個問題是修改Bug#19710564時刪除表空間版本引入的。

• MySQL Community Server 5.7.6引入，版本5.7.22還沒有修復，版本8.0.0已修復。
• MariaDB Server 10.2受影響。MariaDB Server 10.2.9, 10.3.2已修復

優化建議

可優化一下性能：在buf_read_ibuf_merge_pages中記錄下出錯的space id，循環的時候判斷下一個page的space id，若是space id是相同的，直接刪除對應ibuf的記錄（當前分配的最大space id記錄在系統表空間，space id佔4個字節，低於0xFFFFFFF0UL，分配時讀取系統表空間保存的值，而後加一，具備惟一性）。

---

騰訊數據庫技術團隊對內支持微信紅包，彩票、數據銀行等集團內部業務，對外爲騰訊雲提供各類數據庫產品，如CDB、CTSDB、CKV、CMongo， 騰訊數據庫技術團隊專一於加強數據庫內核功能，提高數據庫性能，保證系統穩定性並解決用戶在生產過程當中遇到的問題，並對生產環境中遇到的問題及知識進行分享。

問答

更新MySQL主鍵

相關閱讀

如何在數據庫中高效實現訂座功能？

如何備份你的MySQL數據庫

MySQL 8.0 版本功能變動介紹

此文已由做者受權騰訊雲+社區發佈，原文連接：https://cloud.tencent.com/developer/article/1159291?fromSource=waitui

歡迎你們前往騰訊雲+社區或關注雲加社區微信公衆號（QcloudCommunity），第一時間獲取更多海量技術實踐乾貨哦~

海量技術實踐經驗，盡在雲加社區！