deadlock導致MySQL Hang分析(轉)

問題現象：

MySQL 實例Hang 住，鏈接不斷累積然后達到連接數上限，所有涉及事務的操作及連接的操作都被卡住，CPU 及負載較低；

問題處理：

MySQL 主庫Hang 住不可用，臨時解決方法只能重啟實例或者切換到備庫，以保持業務持續可用；

問題原因：

錯誤監控線程（srv_error_monitor_thread）中調用 log_get_lsn 中的方法存在問題，不能解決 memory barrier 在mutex_exit 退出時可能導致的問題；

問題解決方法：

升級版本至 5.6.29 及以后，可以解決此問題，官方修復信息如下圖：

問題分析過程：

對現場信息使用 pt-pmp 進行歸類，詳情見文檔cti.pt_pmp ，簡單說明如下：

1456 __lll_lock_wait(libpthread.so.0),_L_lock_975(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),inline_mysql_mutex_lock(mysql_thread.h:690),THD::release_resources(sql_class.cc:1559),one_thread_per_connection_end(mysqld.cc:2751),do_handle_one_connection(sql_connect.cc:989),handle_one_connection(sql_connect.cc:898),pfs_spawn_thread(pfs.cc:1860),start_thread(libpthread.so.0),clone(libc.so.6)

1456 個線程在獲取  Lock_status 時被阻塞

16 __lll_lock_wait(libpthread.so.0),_L_lock_975(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),inline_mysql_mutex_lock(mysql_thread.h:690),fill_status(mysql_thread.h:690),do_fill_table(sql_show.cc:7416),get_schema_tables_result(sql_show.cc:7416),JOIN::prepare_result(sql_select.cc:823),JOIN::exec(sql_executor.cc:116),mysql_execute_select(sql_select.cc:1100),mysql_select(sql_select.cc:1100),handle_select(sql_select.cc:110),execute_sqlcom_select(sql_parse.cc:5134),mysql_execute_command(sql_parse.cc:2612),mysql_parse(sql_parse.cc:6386),dispatch_command(sql_parse.cc:1340),do_command(sql_parse.cc:1037),do_handle_one_connection(sql_connect.cc:982),handle_one_connection(sql_connect.cc:898),pfs_spawn_thread(pfs.cc:1860),start_thread(libpthread.so.0),clone(libc.so.6)

16 個線程在獲取  Lock_status 時被阻塞

 1 pthread_cond_wait,os_cond_wait(os0sync.cc:214),os_event_wait_low(os0sync.cc:214),sync_array_wait_event(sync0arr.cc:424),mutex_spin_wait(sync0sync.cc:580),mutex_enter_func(sync0sync.ic:218),pfs_mutex_enter_func(sync0sync.ic:218),srv_export_innodb_status(sync0sync.ic:218),innodb_export_status(ha_innodb.cc:12442),show_innodb_vars(ha_innodb.cc:12442),show_status_array(sql_show.cc:2597),fill_status(sql_show.cc:6749),do_fill_table(sql_show.cc:7416),get_schema_tables_result(sql_show.cc:7416),JOIN::prepare_result(sql_select.cc:823),JOIN::exec(sql_executor.cc:116),mysql_execute_select(sql_select.cc:1100),mysql_select(sql_select.cc:1100),handle_select(sql_select.cc:110),execute_sqlcom_select(sql_parse.cc:5134),mysql_execute_command(sql_parse.cc:2612),mysql_parse(sql_parse.cc:6386),dispatch_command(sql_parse.cc:1340),do_command(sql_parse.cc:1037),do_handle_one_connection(sql_connect.cc:982),handle_one_connection(sql_connect.cc:898),pfs_spawn_thread(pfs.cc:1860),start_thread(libpthread.so.0),clone(libc.so.6)

這個線程獲取了 Lock_status, 但是在獲取 srv_innodb_monitor_mutex時被阻塞

1 pthread_cond_wait,os_cond_wait(os0sync.cc:214),os_event_wait_low(os0sync.cc:214),sync_array_wait_event(sync0arr.cc:424),mutex_spin_wait(sync0sync.cc:580),mutex_enter_func(sync0sync.ic:218),pfs_mutex_enter_func(sync0sync.ic:218),log_print(sync0sync.ic:218),srv_printf_innodb_monitor(srv0srv.cc:1233),innodb_show_status(ha_innodb.cc:12491),innobase_show_status(ha_innodb.cc:12491),ha_show_status(handler.cc:6980),mysql_execute_command(sql_parse.cc:2836),mysql_parse(sql_parse.cc:6386),dispatch_command(sql_parse.cc:1340),do_command(sql_parse.cc:1037),do_handle_one_connection(sql_connect.cc:982),handle_one_connection(sql_connect.cc:898),pfs_spawn_thread(pfs.cc:1860),start_thread(libpthread.so.0),clone(libc.so.6)

這個線程獲取了 srv_innodb_monitor_mutex，但是在獲取 log_sys->mutex時被阻塞

1 pthread_cond_wait,os_cond_wait(os0sync.cc:214),os_event_wait_low(os0sync.cc:214),sync_array_wait_event(sync0arr.cc:424),mutex_spin_wait(sync0sync.cc:580),mutex_enter_func(sync0sync.ic:218),pfs_mutex_enter_func(sync0sync.ic:218),mtr_add_dirtied_pages_to_flush_list(sync0sync.ic:218),mtr_log_reserve_and_write(mtr0mtr.cc:270),mtr_commit(mtr0mtr.cc:270),trx_purge_free_segment(trx0purge.cc:392),trx_purge_truncate_rseg_history(trx0purge.cc:392),trx_purge_truncate_history(trx0purge.cc:527),trx_purge_truncate(trx0purge.cc:527),trx_purge(trx0purge.cc:527),srv_do_purge(srv0srv.cc:2589),srv_purge_coordinator_thread(srv0srv.cc:2589),start_thread(libpthread.so.0),clone(libc.so.6)

這個線程獲取了 log_sys->mutex，但是在獲取 log_sys->log_flush_order_muex 時被阻塞，原因是 memory barrier 的問題，詳情可參考：http://dbaplus.cn/news-11-718-1.html

 1 pthread_cond_wait,os_cond_wait(os0sync.cc:214),os_event_wait_low(os0sync.cc:214),sync_array_wait_event(sync0arr.cc:424),mutex_spin_wait(sync0sync.cc:580),mutex_enter_func(sync0sync.ic:218),pfs_mutex_enter_func(sync0sync.ic:218),log_reserve_and_write_fast(sync0sync.ic:218),mtr_log_reserve_and_write(sync0sync.ic:218),mtr_commit(sync0sync.ic:218),trx_undo_report_row_operation(trx0rec.cc:1353),btr_cur_upd_lock_and_undo(btr0cur.cc:1706),btr_cur_update_in_place(btr0cur.cc:1706),btr_cur_optimistic_update(btr0cur.cc:2166),row_upd_clust_rec(row0upd.cc:2132),row_upd_clust_step(row0upd.cc:2435),row_upd(row0upd.cc:2521),row_upd_step(row0upd.cc:2521),row_update_for_mysql(row0mysql.cc:1779),ha_innobase::update_row(ha_innodb.cc:7091),handler::ha_update_row(handler.cc:7305),Rpl_info_table::do_flush_info(rpl_info_table.cc:207),flush_info(rpl_info_handler.h:92),Master_info::flush_info(rpl_info_handler.h:92),flush_master_info(rpl_slave.cc:871),handle_slave_io(rpl_slave.cc:4818),pfs_spawn_thread(pfs.cc:1860),start_thread(libpthread.so.0),clone(libc.so.6)

這個線程獲取了 lock_log & mi->data_lock，但是在獲取 log_sys->mutex 被阻塞住，導致了其它 show slave status\G 被阻塞住；

1 __lll_lock_wait(libpthread.so.0),_L_lock_791(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),inline_mysql_mutex_lock(mysql_thread.h:690),next_event(mysql_thread.h:690),exec_relay_log_event(mysql_thread.h:690),handle_slave_sql(mysql_thread.h:690),pfs_spawn_thread(pfs.cc:1860),start_thread(libpthread.so.0),clone(libc.so.6)

sql thread 在獲取 lock_log 被阻塞，原因是 lock_log 被 IO thread 線程獲取