原文鏈接:http://click.aliyun.com/m/42521/ 摘要: 本文主要通過一個bug來記錄一下如何分析一個MySQL bug的崩潰信息。 版本:Percona 5.7.17-11 一、資料庫重啟日誌分析 terminate called after throwing an in ...
原文鏈接:http://click.aliyun.com/m/42521/
摘要: 本文主要通過一個bug來記錄一下如何分析一個MySQL bug的崩潰信息。 版本:Percona 5.7.17-11 一、資料庫重啟日誌分析 terminate called after throwing an instance of 'std::out_of_range' what(): ...
本文主要通過一個bug來記錄一下如何分析一個MySQL bug的崩潰信息。
版本:Percona 5.7.17-11
一、資料庫重啟日誌分析
terminate called after throwing an instance of 'std::out_of_range' what(): vector::_M_range_check 04:10:09 UTC - mysqld got signal 6 ; mysqld got signal 6 ; ...... Thread pointer: 0x0 Attempting backtrace. You can use the following information to find out where mysqld died. If you see nomessages after this, something went terribly wrong... stack_bottom = 0 thread_stack 0x40000/dbdata/mysql3306/bin/mysqld(my_print_stacktrace+0x35)[0xf3e175] /dbdata/mysql3306/bin/mysqld(handle_fatal_signal+0x4b4)[0x7c3b94] /lib64/libpthread.so.0(+0xf7e0)[0x7f79f28e87e0] /lib64/libc.so.6(gsignal+0x35)[0x7f79f137d495] /lib64/libc.so.6(abort+0x175)[0x7f79f137ec75] /usr/lib64/libstdc++.so.6(_ZN9__gnu_cxx27__verbose_terminate_handlerEv+0x12d)[0x7f79f1c37a8d] /usr/lib64/libstdc++.so.6(+0xbcbe6)[0x7f79f1c35be6] /usr/lib64/libstdc++.so.6(+0xbcc13)[0x7f79f1c35c13] /usr/lib64/libstdc++.so.6(+0xbcd32)[0x7f79f1c35d32] /usr/lib64/libstdc++.so.6(_ZSt20__throw_out_of_rangePKc+0x67)[0x7f79f1bdadb7] /dbdata/mysql3306/bin/mysqld[0x11d8f15] /dbdata/mysql3306/bin/mysqld[0x11d99d5] /dbdata/mysql3306/bin/mysqld(_Z17dict_stats_updateP12dict_table_t23dict_stats_upd_option_t+0x9dc)[0x11de0cc] /dbdata/mysql3306/bin/mysqld(dict_stats_thread+0x4f2)[0x11e0512] /lib64/libpthread.so.0(+0x7aa1)[0x7f79f28e0aa1] /lib64/libc.so.6(clone+0x6d)[0x7f79f1433bcd] You may download the Percona Server operations manual by visitinghttp://www.percona.com/software/percona-server/. You may find information in the manual which will help you identify the cause of the crash.
這部分是資料庫崩潰的時候的棧幀,因為收到的是信號6 SIGABRT,只要捕獲信號後改變其行為即可。這部分在MySQL官方文檔中叫做Stack Trace,參考:
28.5.1.5 Using a Stack Trace
實際上在這裡我們已經可以看到大約是統計數據收集的問題,因為我們看到了dict_stats_thread,這是統計收集線程的回調函數。
二、生成更加可視化的Stack Trace
1、通過Stack Trace獲得記憶體地址
獲取如下:
[0xf3e175] [0x7c3b94] [0x7f79f28e87e0] [0x7f79f137d495] [0x7f79f137ec75] [0x7f79f1c37a8d] [0x7f79f1c35be6] [0x7f79f1c35c13] [0x7f79f1c35d32] [0x7f79f1bdadb7] [0x11d8f15] [0x11d99d5] [0x11de0cc] [0x11e0512] [0x7f79f28e0aa1] [0x7f79f1433bcd]
2、將這些地址放入一個文件
如:vi /tmp/err0222.log放入即可
3、通nm命令獲取庫文件鏈接文件
如:nm -D -n ./mysqld > /tmp/mysqld.sym
4、使用mysql工具resolve_stack_dump得到輸出
如下:
[root@dyzsdb2 bin]# ./resolve_stack_dump -s /tmp/mysqld.sym -n /tmp/err0222.log | c++filt 0xf3e175my_print_stacktrace + 53 0x7c3b94 handle_fatal_signal + 1204 0x7f79f28e87e0 _end + -2581151440x7f79f137d495 _end + -280574355 0x7f79f137ec75 _end + -280568243 0x7f79f1c37a8d _end + -2714223630x7f79f1c35be6 _end + -271430210 0x7f79f1c35c13 _end + -271430165 0x7f79f1c35d32 _end + -2714298780x7f79f1bdadb7 _end + -271802481 0x11d8f15 dict_stats_analyze_index_for_n_prefix(dict_index_t*, unsigned long, std::vector<<span class="hljs-keyword" style="box-sizing: border-box; color: rgb(249, 38, 114);">unsigned
long, ut_allocator<<span class="hljs-keyword" style="box-sizing: border-box; color: rgb(249, 38, 114);">unsigned long> > const*, n_diff_data_t*, mtr_t*) + 49490x11d99d5 dict_stats_analyze_index(dict_index_t*) + 2693 0x11de0ccdict_stats_update(dict_table_t*, dict_stats_upd_option_t) + 2524 0x11e0512 dict_stats_thread + 1266 0x7f79f28e0aa1 _end + -258147207 0x7f79f1433bcd _end + -279827035
實際上到這裡通過函數的調用我們可以發現是統計數據收集出現了問題。
三、通過官方網站查詢Bug
在報錯信息中提起比較代表性的信息在官方網站中進行搜索通過在percona中查看發現本bug由上游MySQL代碼造成BUG號:Bug #84940
並且發現在5.7.18中得到修複同時給出了內部BUG號如下:
[10 Feb 2017 8:12] Shane Bester Oli, Umesh, this would be same as internal: Bug 24585978 - INNODB: ASSERTION TOTAL_RECS > 0 FAILURE IN FILE DICT0STATS.CC
四、查詢Bug到底修改了什麼地方
這裡請教了阿裡的印風兄才知道怎麼查看,首先拿到了內部bug號:24585978
然後在git的commit log中搜索得到
git --no-pager log >/root/commitlog
vi /root/commitlog 找到commit號為:
29acdaaaeef9afe32b42785f1da3d79d56ed7e59
如下是這個bug的修複地方:
commit 29acdaaaeef9afe32b42785f1da3d79d56ed7e59 Author: Thirunarayanan Balathandayuthapani Date: Wed Feb 8 12:00:52 2017 +0530 Bug #24585978 INNODB: ASSERTION TOTAL_RECS > 0 FAILURE IN FILEDICT0STATS.CC Analysis: ======== There was missing bracket for IF conditon indict_stats_analyze_index_level() and it leads to wrong result. Fix: ==== Fix the IF condition indict_stats_analyze_index_level() so that it satisfied the if condtion only if level is zero. Reviewed-by : Jimmy Yang diff --git a/storage/innobase/dict/dict0stats.cc b/storage/innobase/dict/dict0stats.cc index 3494070..55a2626 100644 --- a/storage/innobase/dict/dict0stats.cc +++ b/storage/innobase/dict/dict0stats.cc @@ -1099,10+1099,10 @@ dict_stats_analyze_index_level( leaf-level delete marks because delete marks on non-leaf level do not make sense. */ - if (level == 0 && srv_stats_include_delete_marked? 0: + if(level == 0 && (srv_stats_include_delete_marked ? 0: rec_get_deleted_flag( rec, - page_is_comp(btr_pcur_get_page(&pcur)))) { + page_is_comp(btr_pcur_get_page(&pcur))))) { if(rec_is_last_on_page && !prev_rec_is_copied
五、為什麼這麼修改
這裡是我的淺顯的分析,不對的地方的還請見諒。
我們發現這裡實際上修改就是多了一個括弧而已,但是意義是相當重要的。
if (level == 0 && srv_stats_include_delete_marked ? 0: rec_get_deleted_flag( rec, page_is_comp(btr_pcur_get_page(&pcur)))) 修改為了 if (level == 0 && (srv_stats_include_delete_marked ? 0: rec_get_deleted_flag( rec, page_is_comp(btr_pcur_get_page(&pcur)))))
修改前:
如果level != 0 不管innodb_stats_include_delete_marked參數如何設置必然觸發判斷是否存在del_flag,然後通過設置偏移量的方式 跳過這行,但是隨後的(*total_recs)++; 將不會觸發,極端情況下可能為0。
而在上層代碼dict_stats_analyze_index中的found_level:地方實際上是需要非葉子結點行數不為0的如下:
ut_ad(total_recs > 0); ut_ad(n_diff_on_level[n_prefix - 1] > 0);
六、如何規避
在官網查看的時候有如下方式可以規避這個Bug
- 升級到5.7.18
- 設置參數
innodb-stats-persistent = 0 innodb-stats-transient-sample-pages = 20 innodb-stats-auto-recalc = 0
設置這些參數後實際上是使用的老的非固化的統計數據收集的方式,而不會通過線程dict_stats_thread收集下麵是邏輯片段位於row_update_statistics_if_needed中如下:
if (dict_stats_is_persistent_enabled(table)) { //參數innodb-stats-persistent 作用 if (counter > n_rows / 10 && dict_stats_auto_recalc_is_enabled(table)) {//參數innodb-stats-auto-recalc 作用dict_stats_recalc_pool_add(table); table->stat_modified_counter = 0; } return; } if (counter > 16+ n_rows / 16 ) { ut_ad(!mutex_own(&dict_sys->mutex)); dict_stats_update(table, DICT_STATS_RECALC_TRANSIENT); }
這樣做的話肯定不會調用到觸發bug的函數,有興趣的可以看看dict_stats_update(table, DICT_STATS_RECALC_TRANSIENT);的邏輯。實際上使用的是老的方式斷點可以打在btr_estimate_number_of_different_key_vals函數上。