4万字《腾讯云技术实践精选集 2021》发布,点击下载 了解详情
写点什么

MySQL 进阶垫脚石:线程长时间处于 killed 状态怎么破?

  • 2021 年 6 月 30 日
  • 本文字数:14426 字

    阅读完需:约 47 分钟

MySQL进阶垫脚石:线程长时间处于killed状态怎么破?

一、背景

MySQL 中使用 kill 命令去杀死连接时,如果使用 show processlist 会发现线程会处于 killed 状态一段时间,而不是立即杀掉。一些情况下,killed 状态可能会存在很久,甚至可能会一直存在直到发送第二次 kill 命令才能杀掉连接。下面从 MySQL 执行 kill 命令代码流程(基于 5.7 版本的 MySQL)简单分析下出现这种现象的原因。

二、源码分析

1、MySQL 执行流程简介

MySQL 的启动入口函数为 mysqld 中的 main 函数,主要流程会启动一个线程去 listen 端口,accept tcp 连接,并创建一个 connection 并与具体的线程绑定,去处理来自客户端的消息。

 

执行流程:


日常执行 kill 流程,一般是通过 mysql 命令行客户端新起一个连接,通过 show processlist 找到需要 kill 掉的连接的 conncetion_id,然后发送 kill 命令。


注:kill + 连接 id 默认是 kill connection,代表断开连接,如果是 kill query + 连接 id 则只是终止本次执行的语句,连接还会继续监听来自 client 的命令。(具体执行区别可以参考下面 KILL 工作流程 1 中(1)、(2)部分)

 

2、KILL 工作流程

概念:

  • connection: socket 连接,默认有一个 max_connection,实际上可以接受 max_connection + 1 个连接,最后一个连接是预留给 SUPER 用户的。

  • pthread: mysql 的工作线程,每个 connection 建立时都会分配一个 pthread,connection 断开后 pthread 仍旧可以被其他 connection 复用。

  • thd: 线程描述类,每个 connection 对应一个 thd,其中包含很多连接状态的描述,其中 thd->killed 字段标识线程是否需要被 kill。


为方便说明,假设有两个连接 connection1, connection2, 对应上述流程,则是 connection1 在 do_command 或者 listen socket event 中时,通过 connection2 发送 kill 命令,中断 connection1 的执行流程。

 

kill connection 之后,对应此连接的 pthread 可能会被新连接复用(具体后面会分析)。


1)执行 kill 命令的线程发起 kill

以 connection2 的执行流程来分析 kill 的执行过程,跟踪 do_command 之后的代码堆栈可以看到:



* frame #0: 0x00000001068a8853 mysqld`THD::awake(this=0x00007fbede88b400, state_to_set=KILL_CONNECTION) at sql_class.cc:2029:27frame #1: 0x000000010695961f mysqld`kill_one_thread(thd=0x00007fbed6bc9c00, id=2, only_kill_query=false) at sql_parse.cc:6479:14frame #2: 0x0000000106946529 mysqld`sql_kill(thd=0x00007fbed6bc9c00, id=2, only_kill_query=false) at sql_parse.cc:6507:16frame #3: 0x000000010694e0fa mysqld`mysql_execute_command(thd=0x00007fbed6bc9c00, first_level=true) at sql_parse.cc:4210:5frame #4: 0x0000000106945d62 mysqld`mysql_parse(thd=0x00007fbed6bc9c00, parser_state=0x000070000de2f340) at sql_parse.cc:5584:20frame #5: 0x0000000106942bf0 mysqld`dispatch_command(thd=0x00007fbed6bc9c00, com_data=0x000070000de2fe78, command=COM_QUERY) at sql_parse.cc:1491:5frame #6: 0x0000000106944e70 mysqld`do_command(thd=0x00007fbed6bc9c00) at sql_parse.cc:1032:17 frame #7: 0x0000000106ad3976 mysqld`::handle_connection(arg=0x00007fbee220b8d0) atconnection_handler_per_thread.cc:313:13frame #8: 0x000000010749e74c mysqld`::pfs_spawn_thread(arg=0x00007fbee15dcf90) at pfs.cc:2197:3 frame #9: 0x00007fff734b6109 libsystem_pthread.dylib`_pthread_start + 148frame #10: 0x00007fff734b1b8b libsystem_pthread.dylib`thread_start + 15
复制代码


核心代码为 awake 函数(为方便,分为 3 段分析):


 ① 设置线程 killed flag 状态



if (this->m_server_idle && state_to_set == KILL_QUERY) { /* nothing */ } else { killed= state_to_set; }
复制代码


如果当前线程处于 idle 状态(代表命令已执行完),而且 kill 级别只是终止查询,而不是 kill 整个连接,那么不会去设置 thd->killed 状态,防止影响下一次正常的请求。

 

(认为需要被 kill 的查询已经执行结束了,不需要再做操作了)


 ② 关闭 socket 连接 &中断引擎等待



if (state_to_set != THD::KILL_QUERY && state_to_set != THD::KILL_TIMEOUT) { if (this != current_thd) {
shutdown_active_vio(); }
/* Send an event to the scheduler that a thread should be killed. */ if (!slave_thread) MySQL_CALLBACK(Connection_handler_manager::event_functions, post_kill_notification, (this)); //post_kill }
if (state_to_set != THD::NOT_KILLED) ha_kill_connection(this);
复制代码


之后会首先关闭 socket 连接(注如果是 kill query,则不会关闭连接)不再接收新的命令。客户端报下面这个错就是在这步之后:



另外会执行 ha_close_connection,这里实际是将处于 innodb 层等待状态的线程唤醒,具体代码在 ha_innodb.cc 中 innobase_kill_connection 里会调用 lock_trx_handle_wait 方法。

 

trx: 一个 mysql 线程对应的 innodb 的事务描述类。


 ③ 通过信号量通知处于 wait 状态的线程



if (is_killable) { mysql_mutex_lock(&LOCK_current_cond); if (current_cond && current_mutex) { DBUG_EXECUTE_IF("before_dump_thread_acquires_current_mutex", { const char act[]= "now signal dump_thread_signal wait_for go_dump_thread"; DBUG_ASSERT(!debug_sync_set_action(current_thd, STRING_WITH_LEN(act))); };); mysql_mutex_lock(current_mutex); mysql_cond_broadcast(current_cond); mysql_mutex_unlock(current_mutex); } mysql_mutex_unlock(&LOCK_current_cond);
复制代码


这里看到除了设置 connection1 的 thd->killed 状态外,还会获取 current_mutex 锁,唤醒 wait 条件变量 current_cond 的线程(connection2)。注意上述②和③中唤醒的对象不同:


ha_close_connection 唤醒的是本次对应的 innodb 事务中的锁(trx->lock.wait_lock),对应的一般是在 innodb 层事务中等待的某个行锁。mysql_cond_broadcast(current_cond)则是唤醒 thd 中的锁,等待锁是通过 THD::enter_cond()进入(如 open table 时获取表锁,或者 sleep 等)

 

具体可参考下面本地 debug 复现部分的分析。


为什么在发送信号量之前先关闭 socket 连接?


不关闭 socket 连接,并发情况下有什么问题?代码中提及了一种 case,假设 connection1 运行已经过了主动检查 flag 的点,之后 connection2 调用 awake 设置 flag 及发送信号量唤醒,然后 connection1 进入到 socket read 中,那么相当于这次信号量会丢失,connection1 就会一直阻塞在 read 中,所以需要关闭 socket 连接中断 read。BUG#37780

 

相当于是通过 io 中断解决信号量丢失的情况。

 

所以如果 connection1 在其他阶段发生信号量丢失(如 connection2 先 broadcast,connection1 再 wait),就需要发送第二次 kill 命令才能唤醒。


(sql_class.cc 2090,但是注意 KILL_CONNECTION 是不会重复进入 awake 的)

 

注: 一般出现这种情况是,connection2 修改了 killed 状态,但是由于 cpu 缓存一致性等问题,connection1 看不到 killed 状态,然后通过了主动检查点,进入了 wait 状态。


2)被 kill 线程响应 kill 命令

被 kill 线程感知(响应)kill 命令主要有两种方式:


  • 主动检查:connection1 在一些代码处会去主动检查 killed 状态;

  • 被通过信号量唤醒:connection1 在执行某些命令时(如引擎层去做一些操作),会主动去 await 一个 condition,释放掉相应的锁,connection2 执行 kill 命令时,会通过锁和 condition 唤醒 connection1,执行终止操作;


killed 状态:



enum killed_state { NOT_KILLED=0, KILL_BAD_DATA=1, KILL_CONNECTION=ER_SERVER_SHUTDOWN, KILL_QUERY=ER_QUERY_INTERRUPTED, KILL_TIMEOUT=ER_QUERY_TIMEOUT, KILLED_NO_VALUE /* means neither of the states */ };
复制代码


3)connection 真正被 kill 掉


真正被 kill 指的是 show processlist 看不到这个线程的时机。mysql 在新建一个 connection 之后,会不断的去监听连接(do_command),前面提到 kill 时会主动把连接的 socket 关闭(shutdown_active_vio)。所以真正连接终止的逻辑是在此处,判断 thd_connection_alive 的状态是待杀死之后,会关闭 connection,并且 release_resources,此时再去 show processlist,则 killed 的线程才会消失。相应的 pthread 也会等待其他连接复用。


killed 状态:



if (thd_prepare_connection(thd)) handler_manager->inc_aborted_connects(); else { while (thd_connection_alive(thd)) { if (do_command(thd)) break; } end_connection(thd); } close_connection(thd, 0, false, false);
thd->get_stmt_da()->reset_diagnostics_area(); thd->release_resources();
// Clean up errors now, before possibly waiting for a new connection. #if OPENSSL_VERSION_NUMBER < 0x10100000L ERR_remove_thread_state(0);#endif /* OPENSSL_VERSION_NUMBER < 0x10100000L */
thd_manager->remove_thd(thd); Connection_handler_manager::dec_connection_count();
........channel_info= Per_thread_connection_handler::block_until_new_connection(); //等待新连接复用线程
复制代码

3、被 KILL 线程主动检查点和唤醒机制分析

由前面 kill 过程分析,大致可以分为两种情况,一种是 connection1 代码一直在执行中(占据 cpu),那么总会执行到某些地方可以检查 thd->killed 状态,另外一种是 connection1 线程 wait 状态,需要其他线程通过信号量唤醒 connection1 的线程,实现 kill 中断目的。具体地,这两类又可以分为下面 4 种情况:


1)第一类:主动检查断点

 ① connection2 发送 kill 命令时,connection1 已执行完命令 (主动检查)


此时 connection1 阻塞在 socket_read 上,由于前面提到 connection2 会去 shutdown_active_vio,connection1 很容易感知到,执行后续操作,如回滚等。



if (thd_prepare_connection(thd)) handler_manager->inc_aborted_connects(); else { while (thd_connection_alive(thd)) { if (do_command(thd)) break; } end_connection(thd); } close_connection(thd, 0, false, false);
thd->get_stmt_da()->reset_diagnostics_area(); thd->release_resources(); //clean_up
复制代码


②内部 innodb 引擎在获取记录时,也会去判断 thd->killed 状态,决定是否中断操作,进行返回。


这一类检查点很多。如下面两处:


  • select 每行读取都会检查;



int rr_sequential(READ_RECORD *info){ int tmp; while ((tmp=info->table->file->ha_rnd_next(info->record))) { /* ha_rnd_next can return RECORD_DELETED for MyISAM when one thread is reading and another deleting without locks. */ if (info->thd->killed || (tmp != HA_ERR_RECORD_DELETED)) { tmp= rr_handle_error(info, tmp); break; } } return tmp;}
复制代码



  • 内部 innodb 引擎在获取记录时,也会去判断 thd->killed 状态,决定是否中断操作,进行返回。



* frame #0: 0x0000000106629a7e mysqld`trx_is_interrupted(trx=0x00007f8266dbd8a0) at ha_innodb.cc:3234:9 frame #1: 0x000000010686d901 mysqld`row_search_mvcc(buf=", mode=PAGE_CUR_G, prebuilt=0x00007f826b81faa0,match_mode=0, direction=0) at row0sel.cc:5245:6frame #2: 0x0000000106636cda mysqld`ha_innobase::index_read(this=0x00007f825c8c1430, buf=", key_ptr=0x0000000000000000, key_len=0, find_flag=HA_READ_AFTER_KEY) at ha_innodb.cc:8768:10frame #3: 0x000000010663798c mysqld`ha_innobase::index_first(this=0x00007f825c8c1430, buf=") at ha_innodb. cc:9186:14frame #4: 0x0000000106637c2a mysqld`ha_innobase::rnd_next(this=0x00007f825c8c1430, buf=") at ha_innodb.cc: 9284:11frame #5: 0x000000010563f7a5 mysqld`handler::ha_rnd_next(this=0x00007f825c8c1430, buf=") at handler.cc:2963:3frame #6: 0x0000000105d954d4 mysqld`rr_sequential(info=0x00007f826780d208) at records.cc:517:34frame #7: 0x0000000105e85c78 mysqld`join_init_read_record(tab=0x00007f826780d1b8) at sql_executor.cc:2504:10 frame #8: 0x0000000105e82a1c mysqld`sub_select(join=0x00007f825e37a4d0, qep_tab=0x00007f826780d1b8,end_of_records=false) at sql_executor.cc:1284:14frame #9: 0x0000000105e7f299 mysqld`do_select(join=0x00007f825e37a4d0) at sql_executor.cc:957:12 frame #10: 0x0000000105e7ec26 mysqld`JOIN::exec(this=0x00007f825e37a4d0) at sql_executor.cc:206:10 frame #11: 0x0000000105f5fe90 mysqld`handle_query(thd=0x00007f825e35ec00, lex=0x00007f825e361058,result=0x00007f825e379cf8, added_options=0, removed_options=0) at sql_select.cc:191:21 frame #12: 0x0000000105f006f7 mysqld`execute_sqlcom_select(thd=0x00007f825e35ec00,all_tables=0x00007f825e3796b0) at sql_parse.cc:5155:12frame #13: 0x0000000105ef6527 mysqld`mysql_execute_command(thd=0x00007f825e35ec00, first_level=true) at sql_parse.cc:2826:12frame #14: 0x0000000105ef3d62 mysqld`mysql_parse(thd=0x00007f825e35ec00, parser_state=0x00007000097d5340) at sql_parse.cc:5584:20frame #15: 0x0000000105ef0bf0 mysqld`dispatch_command(thd=0x00007f825e35ec00, com_data=0x00007000097d5e78, command=COM_QUERY) at sql_parse.cc:1491:5frame #16: 0x0000000105ef2e70 mysqld`do_command(thd=0x00007f825e35ec00) at sql_parse.cc:1032:17 frame #17: 0x0000000106081976 mysqld`::handle_connection(arg=0x00007f82681d84f0) atconnection_handler_per_thread.cc:313:13frame #18: 0x0000000106a4c74c mysqld`::pfs_spawn_thread(arg=0x00007f8268012fc0) at pfs.cc:2197:3 frame #19: 0x00007fff734b6109 libsystem_pthread.dylib`_pthread_start + 148frame #20: 0x00007fff734b1b8b libsystem_pthread.dylib`thread_start + 15
复制代码



2)第二类:需要其他线程通过信号量唤醒

 ① connection2 发送 kill 命令时,connection1 处于 innodb 层 wait 行锁状态


主要通过 awake 中的下面这行触发唤醒 (也可能由系统的后台线程 lock_wait_timeout_thread 唤醒)



/* Interrupt target waiting inside a storage engine. */ if (state_to_set != THD::NOT_KILLED) ha_kill_connection(this);
复制代码


参 考 下 面 debug 分 析 的 case3 。


 ② connection2 发送 kill 命令时,connection1 处于 msyql 层 wait 状态(由 connection2 唤醒)  


主要通过下面的方法实现唤醒:



/* Broadcast a condition to kick the target if it is waiting on it. */ if (is_killable) { mysql_mutex_lock(&LOCK_current_cond); if (current_cond && current_mutex) { DBUG_EXECUTE_IF("before_dump_thread_acquires_current_mutex", { const char act[]= "now signal dump_thread_signal wait_for go_dump_thread"; DBUG_ASSERT(!debug_sync_set_action(current_thd, STRING_WITH_LEN(act))); };); mysql_mutex_lock(current_mutex); mysql_cond_broadcast(current_cond); mysql_mutex_unlock(current_mutex); } mysql_mutex_unlock(&LOCK_current_cond);
复制代码


参考下面 debug 分析的 case4。

三、原因总结

通过上面代码分析可以得知,kill 之后会进行回滚操作(大事务)或清理临时表(比如较慢的 ddl),都有可能导致长时间处于 killed 状态。

 

具体回滚是上面提到的 handle_connection 中的 thd->release_resources()中执行 clean_up 进行回滚或者在 sql_parse 中 trans_rollback_stmt 中。  



除开回滚操作的影响,如果本身 mysql 机器负载较高,一样会导致主动检查 thd->killed 会有延迟或者影响线程的唤醒调度。

四、案例复现

1、本地 debug 复现

1)case 1

connection1 已执行完命令,connection2 去 kill 连接 1

 

(较为简单,略)


2)case2

connection1 正在执行(如 parse 阶段,还没有真正到 innodb 层),connection2 去 kill 连接 1

 

(较为简单,略)


3)case3(innodb 层唤醒)

新起一个 session 作为 connection0 开启事务,update 某一行 row1

 

再起一个 session 作为 connection1 update 同一行 row1



* thread #29, stop reason = breakpoint 127.1* frame #0: 0x00000001060f87cb mysqld`os_event::wait(this=0x00007fcce2b16598) at os0event.cc:180:4 frame #1: 0x00000001060f8773 mysqld`os_event::wait_low(this=0x00007fcce2b16598, reset_sig_count=1) atos0event.cc:366:3frame #2: 0x00000001060f91ed mysqld`os_event_wait_low(event=0x00007fcce2b16598, reset_sig_count=0) at os0event.cc:611:9frame #3: 0x00000001060a9332 mysqld`lock_wait_suspend_thread(thr=0x00007fccd90936f0) at lock0wait.cc:315:2 frame #4: 0x00000001061b4f77 mysqld`row_mysql_handle_errors(new_err=0x0000700009f3af6c,trx=0x00007fcce1cc0ce0, thr=0x00007fccd90936f0, savept=0x0000000000000000) at row0mysql.cc:783:3frame #5: 0x0000000106212fa6 mysqld`row_search_mvcc(buf=", mode=PAGE_CUR_GE, prebuilt=0x00007fccd9092ea0, match_mode=1, direction=0) at row0sel.cc:6292:6frame #6: 0x0000000105fd8cda mysqld`ha_innobase::index_read(this=0x00007fccd9091430, buf=", key_ptr="\x1e", key_len=514, find_flag=HA_READ_KEY_EXACT) at ha_innodb.cc:8768:10frame #7: 0x0000000104ff2c67 mysqld`handler::index_read_map(this=0x00007fccd9091430, buf=", key="\x1e", keypart_map=1, find_flag=HA_READ_KEY_EXACT) at handler.h:2824:13frame #8: 0x0000000104fe1f14 mysqld`handler::ha_index_read_map(this=0x00007fccd9091430, buf=", key="\x1e", keypart_map=1, find_flag=HA_READ_KEY_EXACT) at handler.cc:3047:3frame #9: 0x0000000104feeb62 mysqld`handler::read_range_first(this=0x00007fccd9091430, start_key=0x00007fccd9091518, end_key=0x00007fccd9091538, eq_range_arg=true, sorted=true) at handler.cc:7412:13frame #10: 0x0000000104fec01b mysqld`handler::multi_range_read_next(this=0x00007fccd9091430, range_info=0x0000700009f3bc10) at handler.cc:6477:15frame #11: 0x0000000104fed4ba mysqld`DsMrr_impl::dsmrr_next(this=0x00007fccd9091698, range_info=0x0000700009f3bc10) at handler.cc:6869:24frame #12: 0x0000000105fee7f6 mysqld`ha_innobase::multi_range_read_next(this=0x00007fccd9091430, range_info=0x0000700009f3bc10) at ha_innodb.cc:20585:18frame #13: 0x00000001056ec7c8 mysqld`QUICK_RANGE_SELECT::get_next(this=0x00007fcce2b15fa0) at opt_range.cc: 11247:21frame #14: 0x00000001057371ad mysqld`rr_quick(info=0x0000700009f3c320) at records.cc:405:29frame #15: 0x0000000105984e35 mysqld`mysql_update(thd=0x00007fcce585f400, fields=0x00007fcce5863618, values=0x00007fcce58643d8, limit=18446744073709551615, handle_duplicates=DUP_ERROR, found_return=0x0000700009f3cb48, updated_return=0x0000700009f3cb40) at sql_update.cc:819:14frame #16: 0x000000010598cc87 mysqld`Sql_cmd_update::try_single_table_update(this=0x00007fcce58643c8, thd=0x00007fcce585f400, switch_to_multitable=0x0000700009f3cc07) at sql_update.cc:2927:21frame #17: 0x000000010598d457 mysqld`Sql_cmd_update::execute(this=0x00007fcce58643c8, thd=0x00007fcce585f400) at sql_update.cc:3058:7frame #18: 0x000000010589b475 mysqld`mysql_execute_command(thd=0x00007fcce585f400, first_level=true) at sql_parse.cc:3616:26frame #19: 0x0000000105895d62 mysqld`mysql_parse(thd=0x00007fcce585f400, parser_state=0x0000700009f40340) at sql_parse.cc:5584:20frame #20: 0x0000000105892bf0 mysqld`dispatch_command(thd=0x00007fcce585f400, com_data=0x0000700009f40e78, command=COM_QUERY) at sql_parse.cc:1491:5frame #21: 0x0000000105894e70 mysqld`do_command(thd=0x00007fcce585f400) at sql_parse.cc:1032:17 frame #22: 0x0000000105a23976 mysqld`::handle_connection(arg=0x00007fcce2555370) atconnection_handler_per_thread.cc:313:13frame #23: 0x00000001063ee74c mysqld`::pfs_spawn_thread(arg=0x00007fcce2555f80) at pfs.cc:2197:3 frame #24: 0x00007fff71032109 libsystem_pthread.dylib`_pthread_start + 148frame #25: 0x00007fff7102db8b libsystem_pthread.dylib`thread_start + 15
复制代码


可以看到 connection1 在等待 row1 的行锁



开启新的 session 作为 connection2 执行 kill connection1 的命令,走到前面代码中分析到的 ha_close_connection 时,会去中断 innodb 行锁的等待。堆栈为



thread #30frame #0: 0x00000001060f910e mysqld`os_event::set(this=0x00007fcce2b16598) at os0event.cc:93:2 frame #1: 0x00000001060f90b5 mysqld`os_event_set(event=0x00007fcce2b16598) at os0event.cc:560:9frame #2: 0x00000001060aa06e mysqld`lock_wait_release_thread_if_suspended(thr=0x00007fccd90936f0) at lock0wait.cc:411:3frame #3: 0x0000000106089a99 mysqld`lock_cancel_waiting_and_release(lock=0x00007fccd8866c18) at lock0lock. cc:6789:3frame #4: 0x0000000106096679 mysqld`lock_trx_handle_wait(trx=0x00007fcce1cc0ce0) at lock0lock.cc:6972:3 frame #5: 0x0000000105ff93a6 mysqld`innobase_kill_connection(hton=0x00007fccd7e094d0,thd=0x00007fcce585f400) at ha_innodb.cc:4868:3frame #6: 0x0000000104fdcb96 mysqld`kill_handlerton(thd=0x00007fcce585f400, plugin=0x0000700009f809d8, (null)=0x0000000000000000) at handler.cc:1052:7frame #7: 0x00000001058d659c mysqld`plugin_foreach_with_mask(thd=0x00007fcce585f400, funcs=0x0000700009f80a60, type=1, state_mask=4294967287, arg=0x0000000000000000)(THD*, st_plugin_int**, void*), int, unsigned int, void*) at sql_plugin.cc:2524:21frame #8: 0x00000001058d66a2 mysqld`plugin_foreach_with_mask(thd=0x00007fcce585f400, func= (mysqld`kill_handlerton(THD*, st_plugin_int**, void*) at handler.cc:1046), type=1, state_mask=8, arg=0x0000000000000000)(THD*, st_plugin_int**, void*), int, unsigned int, void*) at sql_plugin.cc:2539:10frame #9: 0x0000000104fdcb1b mysqld`ha_kill_connection(thd=0x00007fcce585f400) at handler.cc:1060:3frame #10: 0x00000001057f8923 mysqld`THD::awake(this=0x00007fcce585f400, state_to_set=KILL_CONNECTION) at sql_class.cc:2077:5frame #11: 0x00000001058a961f mysqld`kill_one_thread(thd=0x00007fccd8b9ea00, id=3, only_kill_query=false) at sql_parse.cc:6479:14frame #12: 0x0000000105896529 mysqld`sql_kill(thd=0x00007fccd8b9ea00, id=3, only_kill_query=false) at sql_parse.cc:6507:16frame #13: 0x000000010589e0fa mysqld`mysql_execute_command(thd=0x00007fccd8b9ea00, first_level=true) at sql_parse.cc:4210:5frame #14: 0x0000000105895d62 mysqld`mysql_parse(thd=0x00007fccd8b9ea00, parser_state=0x0000700009f84340) at sql_parse.cc:5584:20frame #15: 0x0000000105892bf0 mysqld`dispatch_command(thd=0x00007fccd8b9ea00, com_data=0x0000700009f84e78, command=COM_QUERY) at sql_parse.cc:1491:5frame #16: 0x0000000105894e70 mysqld`do_command(thd=0x00007fccd8b9ea00) at sql_parse.cc:1032:17 frame #17: 0x0000000105a23976 mysqld`::handle_connection(arg=0x00007fcce5307d10) atconnection_handler_per_thread.cc:313:13frame #18: 0x00000001063ee74c mysqld`::pfs_spawn_thread(arg=0x00007fcce2405030) at pfs.cc:2197:3 frame #19: 0x00007fff71032109 libsystem_pthread.dylib`_pthread_start + 148frame #20: 0x00007fff7102db8b libsystem_pthread.dylib`thread_start + 15
复制代码



注 :mysql 启动时也会启动一个线程检测锁是否超时(间隔 1s),也会去调用 lock_cancel_waiting_and_release 中断等待行锁的线程。


这里的超时机制也可以防止信号量丢失无法唤醒的问题。


4)case4 (mysql 层唤醒)


开启 connection0,lock 一张表。

 

然后开启 connection1, 去 update 这张表,可以看到线程会阻塞在 wait 表锁状态。



thread #29frame #0: 0x00007fff733f5882 libsystem_kernel.dylib` psynch_cvwait + 10frame #1: 0x00007fff734b6425 libsystem_pthread.dylib`_pthread_cond_wait + 698 frame #2: 0x000000010ef6d495 mysqld`native_cond_timedwait(cond=0x00007f96cb1a6538,mutex=0x00007f96cb1a64d8, abstime=0x000070000bc67e70) at thr_cond.h:136:10frame #3: 0x000000010ef6d37a mysqld`safe_cond_timedwait(cond=0x00007f96cb1a6538, mp=0x00007f96cb1a6498, abstime=0x000070000bc67e70, file="/Users/zhaoxiaojie/CLionProjects/mysql-5.7.33/sql/mdl.cc", line=1868) at thr_cond.c:100:10frame #4: 0x000000010ea69955 mysqld`my_cond_timedwait(cond=0x00007f96cb1a6538, mp=0x00007f96cb1a6498, abstime=0x000070000bc67e70, file="/Users/zhaoxiaojie/CLionProjects/mysql-5.7.33/sql/mdl.cc", line=1868) at thr_cond.h:187:10frame #5: 0x000000010ea63341 mysqld`inline_mysql_cond_timedwait(that=0x00007f96cb1a6538, mutex=0x00007f96cb1a6498, abstime=0x000070000bc67e70, src_file="/Users/zhaoxiaojie/CLionProjects/mysql-5.7.33/sql/mdl.cc", src_line=1868) at mysql_thread.h:1232:13frame #6: 0x000000010ea631f8 mysqld`MDL_wait::timed_wait(this=0x00007f96cb1a6498, owner=0x00007f96cb1a6400, abs_timeout=0x000070000bc67e70, set_status_on_timeout=true, wait_state_name=0x00000001100b4b58) at mdl.cc:1867: 18frame #7: 0x000000010ea660e5 mysqld`MDL_context::acquire_lock(this=0x00007f96cb1a6498, mdl_request=0x00007f96cb0e71a0, lock_wait_timeout=31536000) at mdl.cc:3699:25frame #8: 0x000000010eb8a090 mysqld`open_table_get_mdl_lock(thd=0x00007f96cb1a6400, ot_ctx=0x000070000bc689a0, table_list=0x00007f96cb0e6e00, flags=0, mdl_ticket=0x000070000bc68318) at sql_base. cc:2914:35frame #9: 0x000000010eb885ec mysqld`open_table(thd=0x00007f96cb1a6400, table_list=0x00007f96cb0e6e00, ot_ctx=0x000070000bc689a0) at sql_base.cc:3296:9frame #10: 0x000000010eb8e77b mysqld`open_and_process_table(thd=0x00007f96cb1a6400, lex=0x00007f96cb1a8858, tables=0x00007f96cb0e6e00, counter=0x00007f96cb1a8918, flags=0, prelocking_strategy=0x000070000bc68ab8, has_prelocking_list=false, ot_ctx=0x000070000bc689a0) at sql_base.cc:5260:14frame #11: 0x000000010eb8d8dc mysqld`open_tables(thd=0x00007f96cb1a6400, start=0x000070000bc68ac8, counter=0x00007f96cb1a8918, flags=0, prelocking_strategy=0x000070000bc68ab8) at sql_base.cc:5883:14frame #12: 0x000000010eb90c6d mysqld`open_tables_for_query(thd=0x00007f96cb1a6400, tables=0x00007f96cb0e6e00, flags=0) at sql_base.cc:6660:7frame #13: 0x000000010ed48b0c mysqld`Sql_cmd_update::try_single_table_update(this=0x00007f96cb0e6dc8, thd=0x00007f96cb1a6400, switch_to_multitable=0x000070000bc68c07) at sql_update.cc:2911:7frame #14: 0x000000010ed49457 mysqld`Sql_cmd_update::execute(this=0x00007f96cb0e6dc8, thd=0x00007f96cb1a6400) at sql_update.cc:3058:7frame #15: 0x000000010ec57475 mysqld`mysql_execute_command(thd=0x00007f96cb1a6400, first_level=true) at sql_parse.cc:3616:26frame #16: 0x000000010ec51d62 mysqld`mysql_parse(thd=0x00007f96cb1a6400, parser_state=0x000070000bc6c340) at sql_parse.cc:5584:20frame #17: 0x000000010ec4ebf0 mysqld`dispatch_command(thd=0x00007f96cb1a6400, com_data=0x000070000bc6ce78, command=COM_QUERY) at sql_parse.cc:1491:5frame #18: 0x000000010ec50e70 mysqld`do_command(thd=0x00007f96cb1a6400) at sql_parse.cc:1032:17 frame #19: 0x000000010eddf976 mysqld`::handle_connection(arg=0x00007f96cfe2e1b0) atconnection_handler_per_thread.cc:313:13frame #20: 0x000000010f7aa74c mysqld`::pfs_spawn_thread(arg=0x00007f96d5c1b300) at pfs.cc:2197:3 frame #21: 0x00007fff734b6109 libsystem_pthread.dylib`_pthread_start + 148frame #22: 0x00007fff734b1b8b libsystem_pthread.dylib`thread_start + 15
复制代码


开启 connection2,去 kill connection1,执行到 awake 时,可以看到要唤醒的条件变量和 connection1 在等待的是同一个对象。(0x00007f96cb1a6538)




connection2 执行完 broadcast 之后,connection1 线程即被唤醒



之后一层层返回错误,在 sql_parse 中会执行 trans_rollback_stmt 执行回滚操作。最后在 handle_connection 中检查到 connection 需要被关闭。

2、实际案例 1

之前在工作中实际碰到过一个执行 kill 命令后,连接数反而持续上涨的案例,现象简单概括就是:

 

异常流量导致数据库实例连接数过多后,dba 执行 kill 连接,连接数会短暂下降,之后连接数会继续上涨,继续 kill 之后,连接数还是会上涨。并且大量线程一直处于 killed 状态,看起来像是无法 kill 连接,只能重启解决。


1)问题 

连接数为什么反而会上涨?


前面 KILL 工作流程 1.(2)部分中提到,kill 线程会在唤醒被 kill 线程之前先关闭连接,客户端就是这个时候报 lost connection 的错误。这样大量客户端在线程还未被 kill 结束时已经开始了重连(sdk 连接池),这样造成了问题加剧。

 

另外 MySQL 中 innodb_thread_concurrency 会限制进入 innodb 的线程并发度。那么当进入 innodb 层的线程达到阈值后,后面重建的大量连接会在 mysql 层执行 for 循环判断是否可以进入 innodb。但是这个过程是没有检查 killed 状态的,导致这些线程一直无法被 kill(尽管 show processlist 显示为 Killed)。除非 innodb 里一个线程退出,使得某个线程可以进入 innodb,从而执行代码到主动检查处或被唤醒执行 kill 逻辑。

 

srv0conc.cc srv_conc_enter_innodb_with_atomics



注:实际 mysql 会有相关参数控制进入 innodb 时的最大等待时间,为简化描述问题,暂不展开。


2)复现

将 mysql  innodb_thread_concurrency 设置为 1(默认为 0 代表不限制)。connection1 执行 select 进入 innodb 后暂停住线程。     


connection2 也执行 select,那么会发现 connection2 会卡在检查是否可以进入 innodb。具体堆栈为:



* frame #0: 0x000000010c9772bd mysqld`srv_conc_enter_innodb(prebuilt=0x00007f7fb1065ca0) at srv0conc.cc:265:37 frame #1: 0x000000010c6d9498 mysqld`innobase_srv_conc_enter_innodb(prebuilt=0x00007f7fb1065ca0) at ha_innodb.cc: 1534:4frame #2: 0x000000010c6dcc19 mysqld`ha_innobase::index_read(this=0x00007f7fb10a3630, buf=", key_ptr=0x0000000000000000, key_len=0, find_flag=HA_READ_AFTER_KEY) at ha_innodb.cc:8753:3frame #3: 0x000000010c6dd98c mysqld`ha_innobase::index_first(this=0x00007f7fb10a3630, buf=") at ha_innodb.cc: 9186:14frame #4: 0x000000010c6ddc2a mysqld`ha_innobase::rnd_next(this=0x00007f7fb10a3630, buf=") at ha_innodb.cc:9284: 11frame #5: 0x000000010b6e57a5 mysqld`handler::ha_rnd_next(this=0x00007f7fb10a3630, buf=") at handler.cc:2963:3 frame #6: 0x000000010be3b4d4 mysqld`rr_sequential(info=0x00007f7fb0c1dd90) at records.cc:517:34frame #7: 0x000000010bf2bc78 mysqld`join_init_read_record(tab=0x00007f7fb0c1dd40) at sql_executor.cc:2504:10 frame #8: 0x000000010bf28a1c mysqld`sub_select(join=0x00007f7fb206fc48, qep_tab=0x00007f7fb0c1dd40, end_of_records=false) at sql_executor.cc:1284:14frame #9: 0x000000010bf25299 mysqld`do_select(join=0x00007f7fb206fc48) at sql_executor.cc:957:12 frame #10: 0x000000010bf24c26 mysqld`JOIN::exec(this=0x00007f7fb206fc48) at sql_executor.cc:206:10 frame #11: 0x000000010c005e90 mysqld`handle_query(thd=0x00007f7fb2065a00, lex=0x00007f7fb2067e58, result=0x00007f7fb206f2f8, added_options=0, removed_options=0) at sql_select.cc:191:21frame #12: 0x000000010bfa66f7 mysqld`execute_sqlcom_select(thd=0x00007f7fb2065a00, all_tables=0x00007f7fb206ecb0) at sql_parse.cc:5155:12frame #13: 0x000000010bf9c527 mysqld`mysql_execute_command(thd=0x00007f7fb2065a00, first_level=true) at sql_parse.cc:2826:12frame #14: 0x000000010bf99d62 mysqld`mysql_parse(thd=0x00007f7fb2065a00, parser_state=0x0000700007205340) at sql_parse.cc:5584:20frame #15: 0x000000010bf96bf0 mysqld`dispatch_command(thd=0x00007f7fb2065a00, com_data=0x0000700007205e78, command=COM_QUERY) at sql_parse.cc:1491:5frame #16: 0x000000010bf98e70 mysqld`do_command(thd=0x00007f7fb2065a00) at sql_parse.cc:1032:17 frame #17: 0x000000010c127976 mysqld`::handle_connection(arg=0x00007f7fbcb5e650) at connection_handler_per_thread.cc:313:13frame #18: 0x000000010caf274c mysqld`::pfs_spawn_thread(arg=0x00007f7fbcb6a5e0) at pfs.cc:2197:3 frame #19: 0x00007fff71032109 libsystem_pthread.dylib`_pthread_start + 148frame #20: 0x00007fff7102db8b libsystem_pthread.dylib`thread_start + 15
复制代码



再开启一个 connection3, 去 kill connection2,可以发现 connection2 会一直处于 killed 状态(客户端会断开连接)

 

即使 connection3 完成了前面提到的 ha_close_connection 和 broadcast 信号量,connection2 的堆栈还是一直在上面 for 循环中。



直到 connection1 退出 innodb 。




connection2 进入 innodb 之后通过主动检查的方式执行 kill 逻辑。




此时 show processlist 显示:




作者介绍

猿辅导数据库平台团队,承载猿辅导在线教育全公司的数据库产品研发、运维及服务需求。团队始终致力于新技术的探索实践,结合业务场景不断打磨并提升高可用、可扩展、高可靠的基础设施能力,作为核心基础设施建设者,支持业务快速发展。(猿辅导技术公众号 ID:gh_cb5c83bb3ee0)


赵晓杰,猿辅导数据库平台团队成员,主要从事数据库存储、中间件等方向研发工作。


本文转载自:dbaplus 社群(ID:dbaplus)

原文链接:MySQL进阶垫脚石:线程长时间处于killed状态怎么破?

2021 年 6 月 30 日 14:001079

评论 1 条评论

发布
暂无评论
发现更多内容

终于有腾讯云大神把困扰我多年的Redis(分布式锁、延时队列、位图、布隆过滤器、漏斗限流)全部讲清楚了

Java 程序员 架构 面试

hive交互的几种方式

五分钟学大数据

大数据 hive 5月日更

架构训练营模块 4 作业 - 江哲

江哲

BOE(京东方)亮相世界智能大会 创新科技强势发力智慧物联新赛道

DT极客

【签约计划】试用期规则

InfoQ写作平台官方

活动专区 签约计划

Flutter 混合开发基础

网易云信

flutter

比特币披萨节由来:11年前BTC首次在现实世界使用

meio

比特币

数字货币与加密货币、虚拟货币的区别

meio

比特币 数字货币 加密货币 虚拟货币

NetCore配置文件使用全过程

happlyfox

520单身福利

作为骨灰级MEME项目,Grin接下来会走向何方?

猫Buboo

一篇文章带你搞懂Python中的类

格致君的planB

从外包跳槽到大厂,我用了55天成功逆袭。

Java 程序员 架构 面试

全面隔绝虚拟货币暴涨暴跌风险

CECBC

并发王者课 - 青铜 2:峡谷笔记 - 简单认识Java中的线程

MetaThoughts

Java 后端 多线程 并发 王者并发课

花重金购买的“Java面试知识点”真香,知彼知己,百战不殆

Java架构师迁哥

浅谈 Serverless 开发和应用

网易云信

Serverless

2021年4月券商App行情刷新及交易体验评测报告

博睿数据

Matlab制作视频并转换成gif动态图的方法

格致君的planB

指挥中心可视化研判分析系统搭建解决方案

13823153121

一款优秀数据库中间件的不完全解析

Coder的技术之路

源码阅读 源码刨析 数据库中间件

博睿数据多点开花,数据链DNA加速走进金融、医疗、政企行业

博睿数据

数据链DNA

马斯克会在熊市周期里瞄准下一个百倍币么?

猫Buboo

区块链 狗狗币

4月热搜:揭秘金融级人脸实名认证解决方案背后的技术硬货

百度大脑

百度

打破固有思维(十四)

Changing Lin

IPFS与 Filecoin的区别是什么?

meio

IPFS Filecoin

5分钟速读之Rust权威指南(六)

码生笔谈

rust

医疗数字化:区块链或成最强辅助

CECBC

医疗

2021年10年后端开发程序员最新《C/C++Linux 服务器开发》学习路线总结,建议收藏

奔着腾讯去

学习 服务器集群 Linux服务器开发 C++后台开发

【建议收藏】B站上有哪些值得反复观看的Java视频教程?

格致君的planB

指挥中心可视化研判分析系统搭建解决方案

13823153121

HarmonyOS 的分布式技术,让小朋友爱上涂鸦

科技汇

MySQL进阶垫脚石:线程长时间处于killed状态怎么破?-InfoQ