作者：雷文霆
愛可生華東交付服務部 DBA 成員，主要負責Mysql故障處理及相關技術支援。愛好看書，電影。座右銘，每一個不曾起舞的日子，都是對生命的辜負。
本文來源：原創投稿
*愛可生開源社群出品，原創內容未經授權不得隨意使用，轉載請聯絡小編並註明來源。
目錄
- 背景資訊
- 故障分析
- 問題復現
- 測試日誌
- 測試結論
- 參考連結
背景資訊
在 MySQL5.7.30 主從讀寫分離環境下，從庫在某天出現了 MySQL crash.
系統側: 監控顯示該從庫主機的記憶體和CPU資源使用率在故障前後均正常，磁碟IO有2%的iowait（讀寫200M/s），說明故障前磁碟存在壓力。
服務側：slow-log 中記錄了服務重啟前，存在使用了臨時表和檔案排序的慢 SQL 語句。
Error-log 中記錄了服務呼叫到 btr0btr.cc 檔案 的 L2165 行，出現了 err == DB_SUCCESS 報錯。
0x7f2dd49d0700 InnoDB: Assertion failure in thread 139834817316608 in file btr0btr.cc line 2165
InnoDB: Failing assertion: err == DB_SUCCESS
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.故障分析
在系統側排除了磁碟空間不足和記憶體不足的因素，服務側懷疑是慢查詢和BUG的原因，之後通過" btr0btr.cc"關鍵字查詢到了一個類似的 BUG 。連結如下:
https://bugs.mysql.com/bug.ph...
報告的意思是，MySQL 在執行 btr_insert_on_non_leaf_level_func()函式時，寫入臨時表會導致帶有斷言的服務崩潰。
通過檢視 btr0btr.cc 檔案開頭的註釋瞭解到的原因是：
此檔案的呼叫機制是：對b樹行操作或記錄所做的所有更改。
L2165 行操作內容是：在處理插入到非葉級別的內容時，會檢查每個級別的可用空間(需保留2倍索引數高度的頁空間)，如果在操作之前，葉分裂已經開始，就很難撤銷，只能通過崩潰進行前滾。該 BUG 只會在 MySQL5.7 出現
程式碼查詢：https://github.com/mysql/mysq... (通過 Tags 標籤選擇對應版本)
程式碼內容：https://github.com/mysql/mysq...
nserts a data tuple to a tree on a non-leaf level. It is assumed
that mtr holds an x-latch on the tree. */
void
btr_insert_on_non_leaf_level_func()
---
ut_a(err == DB_SUCCESS);
---
其中ut_a()
https://dev.mysql.com/doc/dev/mysql-server/latest/ut0dbg_8h.html#ae7aed983dfe98ac872b5a9915fa778fa:
檢查資料庫關於臨時表的引數：
innodb_temp_data_file_path ibtmp1:12M:autoextend:max:20G
tmp_table_size 64M 和 max_heap_table_size 64M
註釋：實際限制取二者中的較小者。會話級別的引數，對於 innodb_buffer_pool_size 不大且沒有用到臨時大資料量查詢的情況，不建議設定的過大，可能會導致記憶體溢位的情況。連線數800+，64M為推薦值
internal_tmp_disk_storage_engine InnoDB
註釋：用於定義磁碟臨時表的儲存引擎。超出 InnoDB 行或列限制的磁碟內部臨時表的查詢會返回 Row size too large 或 Too many columns 錯誤。解決方法是設定 internal_tmp_disk_storage_engine 為 MYISAM ，我們的 error-log 中無相關報錯。初步排查階段不建議修改
created_tmp_disk_tables 2987733
created_tmp_tables 11049848
註釋：當在記憶體或磁碟上建立內部臨時表時，伺服器會增加該 Created_tmp_tables值。在磁碟上建立內部臨時表時，伺服器會增加該 Created_tmp_disk_tables值。如果在磁碟上建立了太多內部臨時表，請考慮增加tmp_table_size和max_heap_table_size設定。從早上10點36分到17點產生較多臨時表，結合業務繁忙情況，屬於正常現象
小結: 通過上面的分析，結合應用架構(無法升級到 MySQL8.0 )。初步階段是建議先優化 SQL 語句，減少對臨時表的使用，降低再次發生的概率。
問題復現
上文提到的 BUG 報告中，有個使用 MySQL Test Run 簡稱MTR(MySQL官方的自動化測試框架) 的測試用例。
下文將引用此測試用例，進行復現測試。
引數解釋：
innodb_limit_optimistic_insert_debug引數可以限制每個B樹頁面的記錄數，在 MySQL 執行過程中動態設定此引數可以導致頁分裂。
innodb_limit_optimistic_insert_debug
限制每個 B 樹頁面的記錄數。預設值 0 表示不施加限制。僅當使用 CMake選項編譯除錯支援時，需開啟DEBUG選項。
# 依賴
yum install -y gcc gcc-c++ cmake ncurses ncurses-devel bison openssl openssl-devel
tar -xvf mysql-boost-5.7.30.tar.gz
--編譯安裝MySQL，因為需要設定innodb_limit_optimistic_insert_debug引數-------
tar -xvf mysql-boost-5.7.30.tar.gz
# 非BOOST版本的Mysql原始碼包，需要指定-DDOWNLOAD_BOOST=1 -DWITH_BOOST=/usr/local/boost
cd mysql-5.7.30
cmake . -DCMAKE_INSTALL_PREFIX=/tools/mysql-test5.7.30 -DMYSQL_DATADIR=/tools/mysql-test5.7.30/data -DMYSQL_UNIX_ADDR=/tools/mysql-test5.7.30/mysql5.7.30.sock -DDEFAULT_CHARSET=utf8mb4 -DDEFAULT_COLLATION=utf8mb4_general_ci -DEXTRA_CHARSETS=all -DENABLED_LOCAL_INFILE=1 -DWITH_SSL=system -DWITH_BOOST=boost -DWITH_DEBUG=1
make
make install
# Cmake 編譯之後會在DCMAKE_INSTALL_PREFIX目錄中生成mysql-test測試框架目錄
/tools/mysql-test5.7.30/mysql-test/t
vim my0420.test
cat my0420.test
--source include/have_innodb.inc
--let $restart_parameters = "restart: --innodb_temp_data_file_path=ibtmp1:12M:autoextend:max:1G --big-tables=1"
--source include/restart_mysqld.inc
SELECT @@innodb_temp_data_file_path;
drop function if exists func1;
delimiter |;
create function func1(x int) returns int deterministic
begin
declare z1, z2 int;
set z1 = x;
set z2 = z1 + 2;
return z2;
end|
delimiter ;|
create table t1 (a int, b varchar(20));
insert into t1 values(1, 'a'), (2, 'b'), (3, 'c'), (3, 'c'), (4, 'c');
SET GLOBAL innodb_limit_optimistic_insert_debug=4;
--let $i=1
while ($i <= 15) {
INSERT INTO t1 SELECT * FROM t1;
--inc $i
}
SELECT COUNT(*) FROM t1;
SET GLOBAL innodb_limit_optimistic_insert_debug=2;
select * from t1 order by func1(a);
進行測試,
/tools/mysql-test5.7.30/mysql-test
./mtr my0420.test
其中 select * from t1 order by func1(a); 會使用Using temporary; Using filesort 和 業務SQL的執行計劃一致將 my0420.test 第二行新增--internal_tmp_disk_storage_engine=MYISAM引數後，服務不崩潰。
--let $restart_parameters = "restart: --innodb_temp_data_file_path=ibtmp1:12M:autoextend:max:1G --internal_tmp_disk_storage_engine=MYISAM --big-tables=1"
將 my0420.test 第二行增大為---innodb_temp_data_file_path=ibtmp1:12M:autoextend:max:6G引數後，服務不崩潰。
--let $restart_parameters = "restart: --innodb_temp_data_file_path=ibtmp1:12M:autoextend:max:6G --big-tables=1"
big_tables如果啟用，伺服器將所有臨時表儲存在磁碟上而不是記憶體中。這可以防止需要大型臨時表的操作的大多數錯誤，但也會減慢記憶體表就足夠的查詢。most The table *tbl_name* is full errors forSELECToperations，如果error-log中出現此報錯，說明select 操作使用了大的磁碟臨時表，不推薦啟用。
(小提示，客戶環境中時常會收到某張臨時表 #sql_tbl_name is full的告警郵件，需要考慮是否可以優化SQL了)
測試日誌
MTR 的執行邏輯為啟動一個臨時 MySQL 服務，並執行t目錄中 my0420.test 檔案的內容，執行結果預設會和r目錄中的 result 同名檔案(也叫標準執行結果檔案，一般會在正確的版本中生成)進行對比，用於判斷測試檔案是否正確。
在mysql-test目錄下：
./mtr my0420.test
--執行到以下語句時報錯--
SET GLOBAL innodb_limit_optimistic_insert_debug=2;
[100%] main.my0420 [ fail ]
Test ended at 2022-04-20 20:05:39
CURRENT_TEST: main.my0420
mysqltest: At line 32: query 'select * from t1 order by func1(a)' failed: 2013: Lost connection to MySQL server during query
safe_process[7080]: Child process: 7081, exit: 1
Server [mysqld.1 - pid: 7089, winpid: 7089, exit: 256] failed during test run
Server log from this test:Lost connection ，MySQL 服務已停止。之後列印了 error 資訊。錯誤同樣出現在 btr0btr.cc line 2165
Server log from this test:
----------SERVER LOG START-----------
2022-04-20T12:02:42.082135Z 0 [Note] /tools/mysql-test5.7.30/bin/mysqld (mysqld 5.7.30-debug-log) starting as process 7049 ...
2022-04-20T12:02:43.698812Z 0 [Note] /tools/mysql-test5.7.30/bin/mysqld: Shutdown complete
2022-04-20T12:02:45.051667Z 0 [Note] /tools/mysql-test5.7.30/bin/mysqld (mysqld 5.7.30-debug-log) starting as process 7090 ...
2022-04-20T12:02:45.262573Z 0 [Note] /tools/mysql-test5.7.30/bin/mysqld: ready for connections.
Version: '5.7.30-debug-log' socket: '/tools/mysql-test5.7.30/mysql-test/var/tmp/mysqld.1.sock' port: 13000 Source distribution
2022-04-20 15:05:37 0x7fc298bc4700 InnoDB: Assertion failure in thread 140473762858752 in file btr0btr.cc line 2165
InnoDB: Failing assertion: err == DB_SUCCESS
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
12:05:37 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 61093 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7fc234005890): select * from t1 order by func1(a)
Connection ID (thread ID): 2
Status: NOT_KILLED和客戶環境的區別之處:
生產中的報錯為 Query(7f3be00479d0) is an invalid pointer. 無效指標，類似磁碟空間不足的報錯.
測試中的報錯為 Query (7fc234005890): select * from t1 order by func1(a).
測試環境的堆疊資訊:
https://github.com/mysql/mysq...
（上圖中文是翻譯的程式碼註釋，可能會有些偏差錯誤）
檢查測試日誌檔案 error-log，預設會在當前目錄生成var目錄，其中包含 my.cnf 檔案
/tools/mysql-test5.7.30/mysql-test/var/log/mysqld.1.err
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7fc234005890): select * from t1 order by func1(a)
Connection ID (thread ID): 2
Status: NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file
safe_process[7089]: Child process: 7090, killed by signal: 6關於編譯安裝 MySQL 的補充：
Cmake 編譯之後會在 DCMAKE_INSTALL_PREFIX 目錄中生成 mysql-test 測試框架目錄，
不需要以下步驟（以下步驟在不需要 DEBUG 除錯時使用）
1.此包是mysql-test-5.7.30-linux-glibc2.12-x86_64.tar.gz
mv mysql-5.7.30-linux-glibc2.12-x86_64/ /tools/mysql-test
2.將mysql安裝包目錄下的檔案與mtr目錄合併，mysql安裝包目錄下為basedir
cp -r /data/mysql/base/5.7.30 /tools/mysql-test
(插播生活日記，make命令大約需要執行1個小時，剛好18:27，又恰逢隔離，起身洗鍋炸廚房了嗷)
測試結論
此 BUG 可能會出現在 MySQL5.7 版本中
1.測試中驗證了資料庫引數 innodb_temp_data_file_path 增大max_file_size後不會發生服務崩潰，如果業務 SQL 無法進行優化時，可以增大此引數，可降低觸發崩潰的概率。
2.測試中驗證了資料庫引數 internal_tmp_disk_storage_engine=MYISAM 時不會發生服務崩潰，預設 INNODB
如果業務無法升級到 8.0 時，可以動態調整此引數。
我們建議的變更順序是:
優化 SQL 語句 -> 增大 innodb_temp_data_file_path 引數的 max_file_size 值 -> 升級到 MySQL 8.0（使用會話臨時表空間） -> 修改 internal_tmp_disk_storage_engine 引數。
其中 internal_tmp_disk_storage_engine 引數，個人不是很理解，是否真的要將預設值 INNODB 更改為 MYISAM 。之後請教同事瞭解到，"內部臨時表不會被複制，不會有併發訪問，是可以考慮使用 MYISAM 的"
再次感謝嗷。
參考連結
BUG報告:
https://bugs.mysql.com/bug.ph...
https://jira.percona.com/brow...編譯安裝及引數說明:
https://blog.csdn.net/iteye_6...
https://baijiahao.baidu.com/s...https://dev.mysql.com/doc/ref...
MTR 文件:
https://dev.mysql.com/doc/dev...
資料庫引數:
https://dev.mysql.com/doc/ref...
https://dev.mysql.com/doc/ref...
https://dev.mysql.com/doc/ref...
https://dev.mysql.com/doc/ref...