一、背景

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

二、源码分析

1、MySQL执行流程简介

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

执行流程:


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

注:kill+连接id默认是killconnection,代表断开连接,如果是killquery+连接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或者listensocketevent中时,通过connection2发送kill命令,中断connection1的执行流程。

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

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

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

frame1:0x000000010695961fmysqld`kill_one_thread(thd=0x00007fbed6bc9c00,id=2,only_kill_query=false)atsql_:6479:14frame3:0x000000010694e0famysqld`mysql_execute_command(thd=0x00007fbed6bc9c00,first_level=true)atsql_:4210:5frame5:0x0000000106942bf0mysqld`dispatch_command(thd=0x00007fbed6bc9c00,com_data=0x000070000de2fe78,command=COM_QUERY)atsql_:1491:5frame7:0x0000000106ad3976mysqld`::handle_connection(arg=0x00007fbee220b8d0)atconnection_handler_per_:313:13frame9:0x00007fff734b6109libsystem_`_pthread_start+148frame37780

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

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

(sql_,但是注意KILL_CONNECTION是不会重复进入awake的)

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

2)被kill线程响应kill命令

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

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

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

killed状态:

enumkilled_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/*meansneitherofthestates*/};

3)connection真正被kill掉

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

killed状态:

if(thd_prepare_connection(thd))handler_manager-inc_aborted_connects();else{while(thd_connection_alive(thd)){if(do_command(thd))break;}_connection(thd);}close_connection(thd,0,false,false);thd-get_stmt_da()-reset_diagnostics_area();thd-release_resources();//Cleanuperrorsnow,/*OPENSSL_VERSION_NUMBER0x10100000L*/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;}_connection(thd);}close_connection(thd,0,false,false);thd-get_stmt_da()-reset_diagnostics_area();thd-release_resources();//clean_up

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

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

select每行读取都会检查;

intrr_sequential(READ_RECORD*info){inttmp;while((tmp=info-table-file-ha_rnd_next(info-record))){/*ha_rnd_nextcanreturnRECORD_DELETEDforMyISAMwhenonethreadisreadingandanotherdeletingwithoutlocks.*/if(info-thd-killed||(tmp!=HA_ERR_RECORD_DELETED)){tmp=rr_handle_error(info,tmp);break;}}returntmp;}


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

*frame1:0x000000010686d901mysqld`row_search_mvcc(buf=",mode=PAGE_CUR_G,prebuilt=0x00007f826b81faa0,match_mode=0,direction=0):5245:6frame3:0x000000010663798cmysqld`ha_innobase::index_first(this=0x00007f825c8c1430,buf=")atha_:9186:14frame5:0x000000010563f7a5mysqld`handler::ha_rnd_next(this=0x00007f825c8c1430,buf="):2963:3frame7:0x0000000105e85c78mysqld`join_init_read_record(tab=0x00007f826780d1b8)atsql_:2504:10frame9:0x0000000105e7f299mysqld`do_select(join=0x00007f825e37a4d0)atsql_:957:12frame11:0x0000000105f5fe90mysqld`handle_query(thd=0x00007f825e35ec00,lex=0x00007f825e361058,result=0x00007f825e379cf8,added_options=0,removed_options=0)atsql_:191:21frame13:0x0000000105ef6527mysqld`mysql_execute_command(thd=0x00007f825e35ec00,first_level=true)atsql_:2826:12frame15:0x0000000105ef0bf0mysqld`dispatch_command(thd=0x00007f825e35ec00,com_data=0x00007000097d5e78,command=COM_QUERY)atsql_:1491:5frame17:0x0000000106081976mysqld`::handle_connection(arg=0x00007f82681d84f0)atconnection_handler_per_:313:13frame19:0x00007fff734b6109libsystem_`_pthread_start+148frame29,stopreason=*frame1:0x00000001060f8773mysqld`os_event::wait_low(this=0x00007fcce2b16598,reset_sig_count=1):366:3frame3:0x00000001060a9332mysqld`lock_wait_susp_thread(thr=0x00007fccd90936f0):315:2frame5:0x0000000106212fa6mysqld`row_search_mvcc(buf=",mode=PAGE_CUR_GE,prebuilt=0x00007fccd9092ea0,match_mode=1,direction=0):6292:6frame7:0x0000000104ff2c67mysqld`handler::index_read_map(this=0x00007fccd9091430,buf=",key="\x1e",keypart_map=1,find_flag=HA_READ_KEY_EXACT):2824:13frame9:0x0000000104feeb62mysqld`handler::read_range_first(this=0x00007fccd9091430,start_key=0x00007fccd9091518,_key=0x00007fccd9091538,eq_range_arg=true,sorted=true):7412:13frame11:0x0000000104fed4bamysqld`DsMrr_impl::dsmrr_next(this=0x00007fccd9091698,range_info=0x0000700009f3bc10):6869:24frame13:0x00000001056ec7c8mysqld`QUICK_RANGE_SELECT::get_next(this=0x00007fcce2b15fa0)atopt_:11247:21frame15:0x0000000105984e35mysqld`mysql_update(thd=0x00007fcce585f400,fields=0x00007fcce5863618,values=0x00007fcce58643d8,limit=709551615,handle_duplicates=DUP_ERROR,found_return=0x0000700009f3cb48,updated_return=0x0000700009f3cb40)atsql_:819:14frame17:0x000000010598d457mysqld`Sql_cmd_update::execute(this=0x00007fcce58643c8,thd=0x00007fcce585f400)atsql_:3058:7frame19:0x0000000105895d62mysqld`mysql_parse(thd=0x00007fcce585f400,parser_state=0x0000700009f40340)atsql_:5584:20frame21:0x0000000105894e70mysqld`do_command(thd=0x00007fcce585f400)atsql_:1032:17frame23:0x00000001063ee74cmysqld`::pfs_spawn_thread(arg=0x00007fcce2555f80):2197:3frame25:0x00007fff7102db8blibsystem_`thread_start+15

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


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

thread0:0x00000001060f910emysqld`os_event::set(this=0x00007fcce2b16598):93:2frame2:0x00000001060aa06emysqld`lock_wait_release_thread_if_susped(thr=0x00007fccd90936f0):411:3frame4:0x0000000106096679mysqld`lock_trx_handle_wait(trx=0x00007fcce1cc0ce0):6972:3frame6:0x0000000104fdcb96mysqld`kill_handlerton(thd=0x00007fcce585f400,plugin=0x0000700009f809d8,(null)=0x0000000000000000):1052:7frame8:0x00000001058d66a2mysqld`plugin_foreach_with_mask(thd=0x00007fcce585f400,func=(mysqld`kill_handlerton(THD*,st_plugin_int**,void*):1046),type=1,state_mask=8,arg=0x0000000000000000)(THD*,st_plugin_int**,void*),int,unsignedint,void*)atsql_:2539:10frame10:0x00000001057f8923mysqld`THD::awake(this=0x00007fcce585f400,state_to_set=KILL_CONNECTION)atsql_:2077:5frame12:0x0000000105896529mysqld`sql_kill(thd=0x00007fccd8b9ea00,id=3,only_kill_query=false)atsql_:6507:16frame14:0x0000000105895d62mysqld`mysql_parse(thd=0x00007fccd8b9ea00,parser_state=0x0000700009f84340)atsql_:5584:20frame16:0x0000000105894e70mysqld`do_command(thd=0x00007fccd8b9ea00)atsql_:1032:17frame18:0x00000001063ee74cmysqld`::pfs_spawn_thread(arg=0x00007fcce2405030):2197:3frame20:0x00007fff7102db8blibsystem_`thread_start+15


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

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

4)case4(mysql层唤醒)

开启connection0,lock一张表。

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

thread0:0x00007fff733f5882libsystem_`psynch_cvwait+10frame2:0x000000010ef6d495mysqld`native_cond_timedwait(cond=0x00007f96cb1a6538,mutex=0x00007f96cb1a64d8,abstime=0x000070000bc67e70)atthr_:136:10frame4:0x000000010ea69955mysqld`my_cond_timedwait(cond=0x00007f96cb1a6538,mp=0x00007f96cb1a6498,abstime=0x000070000bc67e70,file="/Users/zhaoxiaojie/CLionProjects//sql/",line=1868)atthr_:187:10frame6:0x000000010ea631f8mysqld`MDL_wait::timed_wait(this=0x00007f96cb1a6498,owner=0x00007f96cb1a6400,abs_timeout=0x000070000bc67e70,set_status_on_timeout=true,wait_state_name=0x00000001100b4b58):1867:18frame8:0x000000010eb8a090mysqld`open_table_get_mdl_lock(thd=0x00007f96cb1a6400,ot_ctx=0x000070000bc689a0,table_list=0x00007f96cb0e6e00,flags=0,mdl_ticket=0x000070000bc68318)atsql_:2914:35frame10:0x000000010eb8e77bmysqld`open_and_process_table(thd=0x00007f96cb1a6400,lex=0x00007f96cb1a8858,tables=0x00007f96cb0e6e00,counter=0x00007f96cb1a8918,flags=0,prelocking_strategy=0x000070000bc68ab8,has_prelocking_list=false,ot_ctx=0x000070000bc689a0)atsql_:5260:14frame12:0x000000010eb90c6dmysqld`open_tables_for_query(thd=0x00007f96cb1a6400,tables=0x00007f96cb0e6e00,flags=0)atsql_:6660:7frame14:0x000000010ed49457mysqld`Sql_cmd_update::execute(this=0x00007f96cb0e6dc8,thd=0x00007f96cb1a6400)atsql_:3058:7frame16:0x000000010ec51d62mysqld`mysql_parse(thd=0x00007f96cb1a6400,parser_state=0x000070000bc6c340)atsql_:5584:20frame18:0x000000010ec50e70mysqld`do_command(thd=0x00007f96cb1a6400)atsql_:1032:17frame20:0x000000010f7aa74cmysqld`::pfs_spawn_thread(arg=0x00007f96d5c1b300):2197:3frame22:0x00007fff734b1b8blibsystem_`thread_start+15

开启connection2,去killconnection1,执行到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线程之前先关闭连接,客户端就是这个时候报lostconnection的错误。这样大量客户端在线程还未被kill结束时已经开始了重连(sdk连接池),这样造成了问题加剧。

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

_conc_enter_innodb_with_atomics


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

2)复现

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

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

*frame1:0x000000010c6d9498mysqld`innobase_srv_conc_enter_innodb(prebuilt=0x00007f7fb1065ca0)atha_:1534:4frame3:0x000000010c6dd98cmysqld`ha_innobase::index_first(this=0x00007f7fb10a3630,buf=")atha_:9186:14frame5:0x000000010b6e57a5mysqld`handler::ha_rnd_next(this=0x00007f7fb10a3630,buf="):2963:3frame7:0x000000010bf2bc78mysqld`join_init_read_record(tab=0x00007f7fb0c1dd40)atsql_:2504:10frame9:0x000000010bf25299mysqld`do_select(join=0x00007f7fb206fc48)atsql_:957:12frame11:0x000000010c005e90mysqld`handle_query(thd=0x00007f7fb2065a00,lex=0x00007f7fb2067e58,result=0x00007f7fb206f2f8,added_options=0,removed_options=0)atsql_:191:21frame13:0x000000010bf9c527mysqld`mysql_execute_command(thd=0x00007f7fb2065a00,first_level=true)atsql_:2826:12frame15:0x000000010bf96bf0mysqld`dispatch_command(thd=0x00007f7fb2065a00,com_data=0x0000700007205e78,command=COM_QUERY)atsql_:1491:5frame17:0x000000010c127976mysqld`::handle_connection(arg=0x00007f7fbcb5e650)atconnection_handler_per_:313:13frame19:0x00007fff71032109libsystem_`_pthread_start+148frame#20:0x00007fff7102db8blibsystem_`thread_start+15


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

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


直到connection1退出innodb。



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



此时showprocesslist显示:




好了。讲到这里..