自拍偷在线精品自拍偷,亚洲欧美中文日韩v在线观看不卡

MySQL在刪除表時I/O錯誤原因分析

作者：騰訊云加社區(qū)
數(shù)據(jù)庫 MySQL
最近使用sysbench測試MySQL，由于測試時間較長，寫了一個腳本按prepare->run->cleanup的順序在后臺跑著。跑完后察看日志發(fā)現(xiàn)一個問題，MySQL服務(wù)的錯誤日志中出現(xiàn)多條類似以下信息的報錯......看起來是I/O出現(xiàn)了錯誤，但MySQL進(jìn)程并未崩潰，sysbench客戶端也沒有報錯。

問題現(xiàn)象

最近使用sysbench測試MySQL，由于測試時間較長，寫了一個腳本按prepare->run->cleanup的順序在后臺跑著。跑完后察看日志發(fā)現(xiàn)一個問題，MySQL服務(wù)的錯誤日志中出現(xiàn)多條類似以下信息的報錯：

 

  1. [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出現(xiàn)了錯誤，但MySQL進(jìn)程并未崩潰，sysbench客戶端也沒有報錯。

發(fā)現(xiàn)問題過程

根據(jù)報錯的時間記錄以及腳本輸出的各個階段的時間點對比，確定了當(dāng)時腳本正在執(zhí)行的命令為：

 

  1. sysbench --tables=100 --table-size=4000000 --threads=50 --mysql-db=sbtest --time=300 oltp_delete cleanup 

重新手動執(zhí)行一遍這個用例，卻沒有再出現(xiàn)同樣的情況。但是用腳本執(zhí)行卻依然能夠發(fā)現(xiàn)這個錯誤信息。初步懷疑是run和cleanup之間不能間隔太久才會觸發(fā)這個問題。由于執(zhí)行一遍100G數(shù)據(jù)量的時間較長，重現(xiàn)代價較大，先嘗試縮減用例數(shù)據(jù)量。將—table-size=4000000修改為2000000，此時執(zhí)行腳本，又不會觸發(fā)這個問題了，***將—table-size=3000000可以穩(wěn)定觸發(fā)又能減少部分重現(xiàn)時間。為了確認(rèn)是否間隔太長會導(dǎo)致不能復(fù)現(xiàn)，修改腳本在run和cleanup兩個階段之間sleep 10秒，果然不會觸發(fā)這個錯誤信息。修改為sleep 5秒則還能觸發(fā)，不過報錯條數(shù)已有所減少。

問題調(diào)查

察看對應(yīng)版本mysql5.7.22的代碼，發(fā)現(xiàn)這個報錯只有一個位置：fil0fil.cc文件的第5578行fil_io()函數(shù)內(nèi)。 直接使用gdb調(diào)試，在這個位置加上斷點，并執(zhí)行可復(fù)現(xiàn)的腳本，得到以下堆棧：

 

  1. (gdb) bt  
  2. #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 
  3. #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 
  4. #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 
  5. #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 
  6. #4  0x0000000000f3a94a in ibuf_merge (sync=false, sync=false, n_pages=0x7f9ddaffce30) at mysql-5.7.22/storage/innobase/ibuf/ibuf0ibuf.cc:2656 
  7. #5  ibuf_merge_in_background (full=full@entry=false) at mysql-5.7.22/storage/innobase/ibuf/ibuf0ibuf.cc:2721 
  8. #6  0x000000000102bcf4 in srv_master_do_active_tasks () at mysql-5.7.22/storage/innobase/srv/srv0srv.cc:2132 
  9. #7  srv_master_thread (arg=<optimized out>) at mysql-5.7.22/storage/innobase/srv/srv0srv.cc:2383 
  10. #8  0x00007fa003eeddc5 in start_thread () from /lib64/libpthread.so.0 
  11. #9  0x00007fa002aab74d in clone () from /lib64/libc.so.6 

 

很明顯這是后臺線程在做insert buffer merge操作。此時發(fā)現(xiàn)space->stop_new_ops為true，也就是要處理的頁面所屬的space正在被刪除。為什么會去操作正在被刪除的space呢？這需要調(diào)查下insert buffer功能、insert buffer merge的流程以及刪除表的流程。

insert buffer背景知識

insert buffer是一種特殊的數(shù)據(jù)結(jié)構(gòu)（B+ tree），當(dāng)輔助索引頁面不在緩沖池中時，它會將更改緩存起來，稍后在頁面被其他讀取操作加載到緩沖池中時合并。MySQL最初引進(jìn)這個功能的時候只能緩存insert操作，所以叫做insert buffer，現(xiàn)在這些操作可以是 INSERT, UPDATE, or DELETE(DML)，所以改叫做change buffer了（本文依然以insert buffer描述），但源碼中依然以ibuf作為標(biāo)識。這個功能把若干對同一頁面的更新緩存起來，合并為一次性更新操作，減少了IO，并轉(zhuǎn)化隨機(jī)IO為順序IO,這樣可以避免隨機(jī)IO帶來性能損耗，提高數(shù)據(jù)庫的寫性能。

相關(guān)insert buffer merge邏輯

當(dāng)buffer page讀入buffer pool時，就會進(jìn)行insert buffer merge。主要有幾個場景會出現(xiàn)merge過程：

  1. 當(dāng)頁面被讀入緩沖池時，讀取完成后先進(jìn)行ibuf的merge，然后頁面才可用；
  2. merge操作作為后臺任務(wù)執(zhí)行。 innodb_io_capacity參數(shù)可設(shè)置InnoDB后臺任務(wù)每次merge過程的頁面數(shù)上限；
  3. 在崩潰恢復(fù)期間，當(dāng)索引頁被讀入緩沖池時，將執(zhí)行對應(yīng)頁的insert buffer merge；
  4. insert buffer具有持久性，系統(tǒng)崩潰不會導(dǎo)致它失效。重啟后，insert buffer merge操作將恢復(fù)正常；
  5. 服務(wù)器關(guān)閉時可使用—innodb-fast-shutdown = 0強(qiáng)制進(jìn)行ibuf的完全合并。

我們這次的問題很明顯屬于第二種情況。innodb主線程(svr_master_thread）會每隔一秒主動進(jìn)行一次insert buffer的merge操作。先判斷過去1s之內(nèi)服務(wù)器是否發(fā)生過活動（插入元組到頁面、undo表上的行操作等），如果發(fā)生過，則merge的***頁面數(shù)為innodb_io_capacity設(shè)定的5%。如果沒有則merge的***頁面數(shù)為innodb_io_capacity設(shè)定的值。

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

  1. 主線程從ibuf樹的葉子節(jié)點讀取頁號和space號，并記錄到一個二元數(shù)組中（未加鎖）；
  2. 主線程對二元組中space進(jìn)行檢測是否在表空間緩存中，如不在，說明已經(jīng)被刪除了，刪除對應(yīng)ibuf的記錄；
  3. 主線程判斷是否對一個正在刪除的space進(jìn)行異步讀取操作，如果是，報錯，并刪除對應(yīng)ibuf的記錄，轉(zhuǎn)到過程2繼續(xù)下一個數(shù)組元素的判斷；
  4. 如果一切判斷正常，主線程發(fā)出async io請求，async讀取需要被merge的索引頁面；
  5. I/O handler 線程，在接受到完成的async I/O之后，進(jìn)行merge操作；
  6. 進(jìn)行merge的時候調(diào)用fil_space_acquire對space->n_pending_ops進(jìn)行自增。避免刪除操作并發(fā)；
  7. 執(zhí)行完畢后調(diào)用fil_space_release對space->n_pending_ops進(jìn)行自減。

相關(guān)刪除表的邏輯

  1. 對fil_system->mutex加鎖，設(shè)置sp->stop_new_ops = true，標(biāo)記space正在刪除，不允許對它進(jìn)行新操作，然后對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. 此時認(rèn)為已經(jīng)沒有沖突的操作了，刷出所有臟頁面或刪除所有給定的表空間的頁面；
  5. 從表空間緩存刪除指定space的記錄；
  6. 刪除對應(yīng)數(shù)據(jù)文件。

問題結(jié)論

情況很明確了，主線程獲取ibuf的（space，page）的過程與刪除操作執(zhí)行的過程并沒有鎖保證互斥，只有async I/O完成之后的merge操作與刪除操作才有互斥。如果后臺線程開始ibuf merge并已經(jīng)執(zhí)行過了第2步的檢測，但還沒有執(zhí)行到第3步檢測，此時用戶線程開始做刪除表的操作，并設(shè)置好stop_new_ops標(biāo)記但還沒有執(zhí)行到第5步刪除表空間緩存，就會出現(xiàn)這個錯誤信息。兩線程的交互如下圖所示：

MySQL在刪除表時I/O錯誤原因分析

不出意外的話，在打中斷點時必然有線程在執(zhí)行對應(yīng)表的刪除操作。果然我們可以發(fā)現(xiàn)如下堆棧：

 

  1. Thread 118 (Thread 0x7f9de0111700 (LWP 5234)):  
  2. #0  0x00007fa003ef1e8e in pthread_cond_broadcast@@GLIBC_2.3.2 () from /lib64/libpthread.so.0  
  3. #1  0x0000000000f82f41 in broadcast (this=0xd452ef8) at mysql-5.7.22/storage/innobase/os/os0event.cc:184  
  4. #2  set (this=0xd452ef8) at mysql-5.7.22/storage/innobase/os/os0event.cc:75  
  5. #3  os_event_set (event=0xd452ef8) at mysql-5.7.22/storage/innobase/os/os0event.cc:483  
  6. #4  0x00000000010ec8a4 in signal (this=<optimized out>) at mysql-5.7.22/storage/innobase/include/ut0mutex.ic:105  
  7. #5  exit (this=<optimized out>) at mysql-5.7.22/storage/innobase/include/ib0mutex.h:690  
  8. #6  exit (this=<optimized out>) at mysql-5.7.22/storage/innobase/include/ib0mutex.h:961  
  9. #7  buf_flush_yield (bpage=<optimized out>, buf_pool=<optimized out>) at mysql-5.7.22/storage/innobase/buf/buf0lru.cc:405  
  10. #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  
  11. #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  
  12. #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  
  13. #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  
  14. #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  
  15. #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  
  16. #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 
  17. #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 
  18. #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 
  19. #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 
  20. #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 
  21. #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 
  22. #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 
  23. #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 
  24. #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 
  25. #23 0x0000000000ca4377 in do_command (thd=thd@entry=0x7f9d7c1f6910) at mysql-5.7.22/sql/sql_parse.cc:999 
  26. #24 0x0000000000d5ed00 in handle_connection (arg=arg@entry=0x10b8e910) at mysql-5.7.22/sql/conn_handler/connection_handler_per_thread.cc:300 
  27. #25 0x0000000001223d74 in pfs_spawn_thread (arg=0x10c48f40) at mysql-5.7.22/storage/perfschema/pfs.cc:2190 
  28. #26 0x00007fa003eeddc5 in start_thread () from /lib64/libpthread.so.0 
  29. #27 0x00007fa002aab74d in clone () from /lib64/libc.so.6 

 

解決辦法

為buf_read_ibuf_merge_pages、buf_read_page_low、fil_io新增一個參數(shù)ignore_missing_space。表示忽略正在刪除的space，默認(rèn)為false，當(dāng)ibuf_merge_pages調(diào)用的時候置為true。在fil_io報錯處額外判斷該參數(shù)是否為true，是則不報錯，繼續(xù)其他流程。

或者直接在buf_read_ibuf_merge_pages調(diào)用buf_read_page_low時傳入IORequest::IGNORE_MISSING參數(shù)。

具體代碼參考MariaDB commit：8edbb1117a9e1fd81fbd08b8f1d06c72efe38f44

影響版本

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

  • MySQL Community Server 5.7.6引入，版本5.7.22尚未修復(fù)，版本8.0.0已修復(fù)。
  • MariaDB Server 10.2受影響。MariaDB Server 10.2.9, 10.3.2已修復(fù)

優(yōu)化建議

 

可優(yōu)化一下性能：在buf_read_ibuf_merge_pages中記錄下出錯的space id，循環(huán)的時候判斷下一個page的space id，如果space id是相同的，直接刪除對應(yīng)ibuf的記錄（當(dāng)前分配的***space id記錄在系統(tǒng)表空間，space id占4個字節(jié)，低于0xFFFFFFF0UL，分配時讀取系統(tǒng)表空間保存的值，然后加一，具有唯一性）。 

責(zé)任編輯：龐桂玉 來源： segmentfault
數(shù)據(jù)庫MySQLi-o
相關(guān)推薦

2013-09-17 15:13:28

IO

2014-06-30 10:12:02

移動安全密碼Google

2011-04-11 11:32:29

Oracle分區(qū)表磁盤IO沖突

2018-11-05 11:20:54

緩沖IO

2013-05-28 10:08:41

IO輸出

2012-08-28 09:35:15

存儲虛擬化

2012-11-14 11:18:29

Mysql

2011-01-14 09:25:28

LinuxIO機(jī)制

2020-12-11 11:04:07

NettyIO

2020-06-03 17:30:42

LinuxIO

2015-05-08 11:23:41

谷歌IO大會

2019-05-05 15:20:32

Linuxiotop磁盤

2021-02-10 08:09:48

Netty網(wǎng)絡(luò)多路復(fù)用

2017-01-19 19:14:20

Linux重定向命令

2021-10-13 06:49:15

網(wǎng)絡(luò) IO

2015-08-10 14:39:46

Java 操作建議

2013-09-16 16:07:38

Java基礎(chǔ)IO

2020-06-10 08:28:51

Kata容器I

2019-09-12 08:58:26

LinuxUNIX操作系統(tǒng)

2015-05-11 17:21:33

Google IO2015
點贊
收藏

51CTO技術(shù)棧公眾號