1、故障描述

某次，使用者MySQL資料庫出現異常當機，MySQL錯誤日誌中出現斷言失敗，例項崩潰並且不斷嘗試重啟恢復，發現業務異常後，緊急進行主從切換，先恢復業務。對於MySQL而言，如果例項出現奔潰，一般來講，問題已經非常嚴重，雖然做了容災切換，但是如果是資料庫本身的問題，可能在未來很短的時間內復現，因此需要高度關注，並做根因排查。

MySQL錯誤日誌的斷言輸出，如下：

2022-10-29T09:14:08.044233+08:00 458807751 [ERROR] [MY-013183] [InnoDB] Assertion failure: btr0cur.cc:3660:rec thread 140137891268352
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to 
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/8.0/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
01:14:08 UTC - mysqld got signal 6 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
Thread pointer: 0x7f745407b860
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f74653a7bf0 thread_stack 0x100000
/usr/sbin/mysqld(my_print_stacktrace(unsigned char const*, unsigned long)+0x3d) [0x200097d]
/usr/sbin/mysqld(print_fatal_signal(int)+0x2df) [0xf16eaf]
/usr/sbin/mysqld(my_server_abort()+0x7e) [0xf16ffe]
/usr/sbin/mysqld(my_abort()+0xa) [0x1ffacaa]
/usr/sbin/mysqld(ut_dbg_assertion_failed(char const*, char const*, unsigned long)+0x31f) [0x22b508f]
/usr/sbin/mysqld(btr_cur_optimistic_update(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, upd_t const*, unsigned long, que_thr_t*, unsigned long, mtr_t*)+0x932) [0x22f0be2]
/usr/sbin/mysqld() [0x2464ebd]
/usr/sbin/mysqld() [0x2465390]
/usr/sbin/mysqld(row_undo_mod(undo_node_t*, que_thr_t*)+0xadf) [0x246766f]
/usr/sbin/mysqld(row_undo_step(que_thr_t*)+0x65) [0x2246d75]
/usr/sbin/mysqld(que_run_threads(que_thr_t*)+0x46c) [0x21f37ec]
/usr/sbin/mysqld() [0x229775a]
/usr/sbin/mysqld() [0x2298299]
/usr/sbin/mysqld(trx_rollback_for_mysql(trx_t*)+0xf1) [0x2299da1]
/usr/sbin/mysqld() [0x20fcb34]
/usr/sbin/mysqld(ha_rollback_low(THD*, bool)+0x127) [0x1021737]
/usr/sbin/mysqld(trx_coordinator::rollback_in_engines(THD*, bool)+0x25) [0xec8b65]
/usr/sbin/mysqld(MYSQL_BIN_LOG::rollback(THD*, bool)+0xcf) [0x1c3f8bf]
/usr/sbin/mysqld(ha_rollback_trans(THD*, bool)+0x79) [0x1021919]
/usr/sbin/mysqld(trans_rollback(THD*)+0x4e) [0xecbd1e]
/usr/sbin/mysqld(mysql_execute_command(THD*, bool)+0x225e) [0xdae21e]
/usr/sbin/mysqld(dispatch_sql_command(THD*, Parser_state*)+0x41a) [0xdb069a]
/usr/sbin/mysqld(dispatch_command(THD*, COM_DATA const*, enum_server_command)+0xd3e) [0xdb193e]
/usr/sbin/mysqld(do_command(THD*)+0x207) [0xdb3b37]
/usr/sbin/mysqld() [0xf07610]
/usr/sbin/mysqld() [0x2511155]
/lib64/libpthread.so.0(+0x7ea5) [0x7f7cc0770ea5]
/lib64/libc.so.6(clone+0x6d) [0x7f7cbeb2c8dd]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f6eac049e70): rollback
Connection ID (thread ID): 458807751
Status: NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains

2、根因分析

如上，首先檢查MySQL錯誤日誌發生崩潰時，報錯前後是否有有用資訊。根據錯誤日誌資訊可知，MySQL崩潰之前並未有任何記錄，可以判斷在報錯前資料庫並未出現損壞。

然後又去檢視了作業系統日誌，瞭解MySQL崩潰時作業系統有無異常情況。根據message日誌資訊可知，MySQL程式突然退出，作業系統並未記錄到異常。

Oct 29 09:14:01 rmssdb systemd: Started Session 779337 of user root.
Oct 29 09:14:01 rmssdb systemd: Started Session 779336 of user root.
Oct 29 09:14:14 rmssdb systemd: mysqld.service: main process exited, code=exited, status=2/INVALIDARGUMENT
Oct 29 09:14:14 rmssdb systemd: Unit mysqld.service entered failed state.
Oct 29 09:14:14 rmssdb systemd: mysqld.service failed.
Oct 29 09:14:14 rmssdb systemd: mysqld.service holdoff time over, scheduling restart.
Oct 29 09:14:14 rmssdb systemd: Stopped MySQL Server.
Oct 29 09:14:14 rmssdb systemd: Starting MySQL Server...
Oct 29 09:14:25 rmssdb systemd: mysqld.service: main process exited, code=exited, status=2/INVALIDARGUMENT
Oct 29 09:14:25 rmssdb systemd: Failed to start MySQL Server.

既然如此，那就需要對錯誤資訊進行分析。截至目前，其實可以大致猜測，MySQL可能是因為bug導致崩潰。根據錯誤資訊作為關鍵詞，可以到MySQL的Bug網站和Oracle內部網站MOS中查詢是否有相關的記錄。

2022-10-29T09:14:08.044233+08:00 458807751 [ERROR] [MY-013183] [InnoDB] Assertion failure: btr0cur.cc:3660:rec thread 140137891268352

果然，在MOS中，匹配到了類似的故障描述。詳細可參考文件Instant DDL Causes Assertion Failure After Mysql Upgrade (Doc ID 2903537.1)。

 

根據文件的說明，當8.0.28版本以下的MySQL升級至8.0.30，執行DDL更改就有可能會導致資料損壞，引起該BUG。描述與實際故障情況符合。

 

3、解決方案

1、此BUG僅影響 8.0.29 和 8.0.30 版本，可下載8.0.31，根據標準流程對資料庫執行升級，如果可能，請在測試環境中重新測試問題。

2、MySQL在升級前建議評估好版本的穩定性以及對系統的影響，生產系統不建議隨便頻繁升級。

3 、由於MySQL 8.0 系列版本，未經過市場充分的驗證，可能存在很多未知的 BUG ，適當情況下，可以將版本回退至該系列更低的穩定版本。