MySQL例項crash的案例詳細分析
【問題描述】
我們生產環境有一組叢集的多臺MySQL伺服器(MySQL 5.6.21)，不定期的會crash，但error log中只記錄了重啟資訊，未記錄crash時的堆疊：
mysqld_safe Number of processes running now: 0 mysqld_safe mysqld restarted
接下來首先排查系統日誌/var/log/message檔案，crash時沒有其他異常資訊，也不是OOM導致的。
【排查思路】
由於日誌中未記錄有價值的資訊。為定位crash的原因，首先開啟mysql core dump的功能。
下面是開啟core dump的步驟：
1、 在my.cnf檔案中增加2個配置項
[mysqld] core_file [mysqld_safe] core-file-size=unlimited
2、修改系統引數，配置suid_dumpable
echo 1 >/proc/sys/fs/suid_dumpable
3、重啟mysql服務，配置生效
【問題分析】
開啟core dump後，伺服器再次crash時生成了core file。
用gdb分析生成的core file，可以看到crash時的堆疊資訊如下：
從函式table_esms_by_digest::delete_all_rows可以看出觸發crash的是truncate table events_statements_summary_by_digest操作。
我們內部有個DML的分析工具，用來統計資料庫每分鐘增刪改查的訪問量。該工具的資料來源是events_statements_summary_by_digest表，採集程式會每一分鐘採集一次這張表的資料，採集完成後執行truncate操作。
暫停這組叢集上DML採集程式後MySQL沒有再發生crash。
進一步分析多個core file，發現最終函式的呼叫都發生在_lf_pinbox_real_free函式上。
結合現場環境，有兩處地方值得分析：
1、 記憶體的不正常值。當列印該變數時，此處變數的地址偏低，不太正常：
(gdb) p pins->pinbox $2 = (LF_PINBOX *) 0x1367208
2、紅字部分為pfs逐條釋放digest記錄的操作，正在釋放某行資料時出現錯誤：
void reset_esms_by_digest()
{
uint index;
if (statements_digest_stat_array == NULL)
return;
PFS_thread *thread= PFS_thread::get_current_thread();
if (unlikely(thread == NULL))
return;
for (index= 0; index < digest_max; index++)
{
statements_digest_stat_array[index].reset_index(thread);
statements_digest_stat_array[index].reset_data();
}
digest_index= 1;
}
猜測有兩種可能導致錯誤：
1、高併發下，對記憶體訪問出現衝突；
2、某個特殊SQL導致，在處理hash時。
在網上搜索類似的問題，有了進一步的進展，基本確定了這個問題是bug導致
如下Mysql的bug report中講述了類似問題
https://bugs.mysql.com/bug.php?id=73979
更詳細的環境描述如下連線中
https://bugs.launchpad.net/percona-server/+bug/1351148
查到5.6.35上的bug fix的修復內容，和我們碰到的情況非常類似。
對比_lf_pinbox_real_free的修改，該部分確實進行很大的調整。
下面是MySQL 5.6.35函式_lf_pinbox_real_free的程式碼片段：
static void _lf_pinbox_real_free(LF_PINS pins)
{
LF_PINBOX pinbox= pins->pinbox;
struct st_match_and_save_arg arg = {pins,pinbox,pins->purgatory};
pins->purgatory= NULL;
pins->purgatory_count= 0;
lf_dynarray_iterate(&pinbox->pinarray,(lf_dynarray_func)match_and_save,&arg);
if (arg.old_purgatory)
{
void *last= arg.old_purgatory;
while (pnext_node(pinbox,last))
last= pnext_node(pinbox,last);
pinbox->free_func(arg.old_purgatory,last,pinbox->free_func_arg);
}
}
下面是MySQL 5.6.21函式的_lf_pinbox_real_free的程式碼片段
static void _lf_pinbox_real_free(LF_PINS pins)
{
int npins;
void list;
void **addr= NULL;
void first= NULL,last= NULL;
LF_PINBOX pinbox= pins->pinbox;
npins= pinbox->pins_in_array+1;
if (pins->stack_ends_here != NULL)
{
int alloca_size= sizeof(void )LF_PINBOX_PINSnpins;
if (available_stack_size(&pinbox,*pins->stack_ends_here) > alloca_size)
{
struct st_harvester hv;
addr= (void **) alloca(alloca_size);
hv.granary= addr;
hv.npins= npins;
_lf_dynarray_iterate(&pinbox->pinarray,(lf_dynarray_func)harvest_pins,&hv);
npins= hv.granary-addr;
if (npins)
qsort(addr,npins,sizeof(void *),(qsort_cmp)ptr_cmp);
}
}
同時觀察到出問題的叢集有指標異常，QPS不到6000，Threads_connected將近8000。（對比其他高併發的叢集，QPS在20000以上，Threads_connected也只有300左右）。
排查應用端的連線方式，瞭解到其中一個應用有近百臺應用伺服器，可能同時發起請求，卻沒有合理的複用連線，維持大量的連線執行緒增大了bug觸發的概率。
Bugs Fixed的描述如下：
Miscalculation of memory requirements for qsort operations could result in stack overflow errors in situations with a large number of concurrent server connections. (Bug #73979,Bug #19678930,Bug #23224078)
【解決思路】
我們通過分析crash時的core file檔案，找到crash時的觸發條件，暫停DML採集程式（truncate table events_statements_summary_by_digest操作）後恢復。
後面瞭解到這是MySQL的一個bug，在MySQL 5.6.35版本後已修復。這個bug在應用端與資料庫建立大量的連線時，更容易觸發。
總結
以上就是這篇文章的全部內容了，希望本文的內容對大家的學習或者工作具有一定的參考學習價值，如果有疑問大家可以留言交流，謝謝大家對我們的支援。