deadlock导致MySQLHang分析(转)

问题现象：

成都创新互联公司自成立以来，一直致力于为企业提供从网站策划、网站设计、成都做网站、成都网站制作、电子商务、网站推广、网站优化到为企业提供个性化软件开发等基于互联网的全面整合营销服务。公司拥有丰富的网站建设和互联网应用系统开发管理经验、成熟的应用系统解决方案、优秀的网站开发工程师团队及专业的网站设计师团队。

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