pstack 看下相关线程的 backtrace,show slave status 线程的 backtrace 如下,非常明显是在等mutex,对应代码为 mysql_mutex_lock(&mi->rli->data_lock):
#0 __lll_lock_wait #1 _L_lock_974 #2 __GI___pthread_mutex_lock #3 inline_mysql_mutex_lock #4 show_slave_status #5 mysql_execute_command #6 mysql_parse #7 dispatch_command #8 do_command #9 do_handle_one_connection #10 handle_one_connection ...
SQL 线程的 backtrace 如下,在等 COMMIT 锁:
#0 pthread_cond_timedwait #1 inline_mysql_cond_timedwait #2 MDL_wait::timed_wait #3 MDL_context::acquire_lock #4 ha_commit_trans #5 trans_commit #6 Xid_log_event::do_commit #7 Xid_log_event::do_apply_event #8 Log_event::apply_event #9 apply_event_and_update_pos #10 exec_relay_log_event #11 handle_slave_sql ...
如果我们gdb进去,去调试SQL线程,在 MDL_context::acquire_lock中:
(gdb) p (MDL_key::enum_mdl_namespace)lock->key->m_ptr[0] $24 = MDL_key::COMMIT (gdb) p ((THD*)lock->m_granted.m_list.m_first->m_ctx->m_owner)->thread_id $25 = 1
可以看到 COMMIT 锁被线程 1 持有。
SQL线程在 Xid_log_event::do_commit 之前会持有 rli_ptr->data_lock。
所以现在就清楚了,是线程1(备份线程)和线程3(SQL线程)死锁了,还原下死锁过程:
1. 备份线程执行 FTWRL,拿到 COMMIT 锁;
2. SQL线程执行到Xid event,准备提交事务,请求 COMMIT 锁,被备份线程阻塞;
3. 备份线程为了获取 slave 执行位点,执行 show slave status,需要获取 rli->data_lock,被 SQL 线程阻塞。
就这样2个线程互相持有等待,形成死锁。
我们知道,MDL 是有死锁检测的,为什么这里没有检测到呢?因为rli->data_lock是一个mutex,不属于MDL系统的,在这个死锁场景中,MDL锁系统只能检测到对 COMMIT 锁的请求,是不存在死锁的。
之后的 show slave status 都被堵,是因为在执行 show slave status 前,会请求一个mutex:
mysql_mutex_lock(&LOCK_active_mi); res= show_slave_status(thd, active_mi);
mysql_mutex_unlock(&LOCK_active_mi);
之前死锁的 show slave status 没有退出,后面的 show slave status 自然堵在这个 mutex 上,并且因为无法检测 thd->killed,所以一直无法退出。
死锁的原因是SQL线程在提交的时候,持有 rli->data_lock 锁,其实这个是不需要的,MySQL 官方在这个 patch 中修复。
CASE 2
在上面的bug修复后,又出现了死锁,但死锁的情况却不一样,show processlist 结果如下:
mysql> show processlist;
+----+-------------+-----------------+------+---------+------+----------------------------------+-------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+-------------+-----------------+------+---------+------+----------------------------------+-------------------+
| 2 | system user | | NULL | Connect | 436 | Waiting for master to send event | NULL |
| 3 | system user | | NULL | Connect | 157 | Waiting for commit lock | NULL |
| 6 | root | 127.0.0.1:42787 | NULL | Query | 86 | init | show slave status |
| 7 | root | 127.0.0.1:42788 | NULL | Query | 96 | Killing slave | stop slave |
| 8 | root | 127.0.0.1:42789 | NULL | Query | 0 | init | show processlist |
+----+-------------+-----------------+------+---------+------+----------------------------------+-------------------+
依然是 SQL 线程在等待commit锁,然后 show slave status 被堵住没有返回,不同的是多了一个 stop slave; 我们来看下 stop slave 的backtrace:
#0 pthread_cond_timedwait #1 inline_mysql_cond_timedwait #2 terminate_slave_thread #3 terminate_slave_threads #4 stop_slave #5 mysql_execute_command #6 mysql_parse #7 dispatch_command #8 do_command #9 do_handle_one_connection #10 handle_one_connection ...
对应代码,可以发现 stop slave 正在等待 SQL 线程退出,而SQL线程此时正在等待备份线程(id=6)持有的 COMMIT 锁。整个死锁过程是这样的:
1. 备份线程执行 FTWRL,拿到 COMMIT 锁;
2. SQL线程执行到Xid event,准备提交事务,请求 COMMIT 锁,被备份线程阻塞;
3. 用户执行 stop slave,准备停掉备库复制线程,等待 SQL 线程退出;
4. 备份线程为了获取 slave 执行位点,执行 show slave status,需要获取 LOCK_active_mi 锁,被用户线程(stop slave)阻塞。
这次是备份线程、SQL 线程、用户线程3个线程互相持有等待,形成死锁。
这次并不是代码bug,算是一个用法问题,因此我们在运维过程中,如果发现 SQL 线程在 Waiting for commit lock,就不要 stop slave。
死锁解决
如果不可避免出现了死锁,该怎么解决呢?