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 线程获取