对MySQL报警的一次分析处理小结

　　这是学习笔记的第2334篇文章
　　最近有一个服务出现了报警，已经让我到了忍无可忍的地步，报警信息如下：
　　Metric：mysql。innodbrowlockwaitsTags：port4306，servicexxxxdiff（1）：996900
　　大概的意思是有一个数据库监控指标innodbrowlockwaits目前超出了阈值900
　　但是尴尬的是，每次报警后去环境中查看，得到的信息都很有限，慢日志，错误日志里面都没有充分的信息可以分析，一来二去之后，我开始静下心来分析这个问题的原因。
　　首先这个报警信息的时间点貌似是有些规律的，我拿着最近几天的报警时间做了比对，发现还是比较有规律的，那么在系统层面有哪些任务可能会触发呢，我查找比对了相关的任务配置，发现有一个定时任务每1分钟会执行一次，但是到了这里疑问就来了，如果每1分钟执行1次，为什么在特定的时间会产生差异较大的处理结果？当然这个现象的解释是个起始。
　　其实要证明这一点还是蛮容易的，今天我就采取了守株待兔的模式，我在临近报警的时间前后打开了通用日志，从日志输出来看，操作的频率还是相对有限的。
　　很快得到了规律性的报警，于是我开始抓取相关的通用日志记录，比如11：18分，我们可以采用如下的模式得到相关的日志，首先得到一个临时的通用日志文件，把各种DML和执行操作都网罗进来。
　　catgeneral。loggrepEinsertdeleteupdateselectexecgeneraltmp。log
　　我们以11：18分为例，可以在前后1两分钟做比对，结果如下：
　　lessgeneraltmp。loggrep11：18wcl
　　400hrlessgeneraltmp。loggrep11：17wcl
　　666hrlessgeneraltmp。loggrep11：16wcl
　　15hr发现在报警的那1分钟前后，数量是能够对得上的。
　　这个表的数据量有200多万，表结构如下：CREATETABLEtaskqueue（AccIDbigint（20）NOTAUTOINCREMENTCOMMENT自增ID，TaskStepIDbigint（20）DEFAULTCOMMENT任务步骤IDtaskstepconf，QOrderint（11）DEFAULTCOMMENT队列排序taskstepconfi。StepID，QStatetinyintDEFAULT1COMMENT队列状态1：待执行2：执行中3：执行成功4：执行失败，QExcCountint（11）DEFAULT1COMMENT执行次数，CrtTimedatetimeDEFAULTCOMMENT创建时间，ModTimedatetimeDEFAULTCOMMENT修改时间，PRIMARYKEY（AccID），KEYidxtaskstepid（TaskStepID），KEYidxqstate（QState））ENGINEInnoDBAUTOINCREMENT3398341DEFAULTCHARSETutf8
　　在日志中根据分析和比对，基本能够锁定SQL是在一类Update操作上面，SQL的执行计划如下：explainupdatetaskqueuesetQState1，QExcCountQExcCount1，modtimenowwhereQState0andtaskstepid411G1。rowid：selecttype：UPDATEtable：taskqueuepartitions：type：indexmergepossiblekeys：idxtaskstepid，idxqstatekey：idxqstate，idxtaskstepidkeylen：2，9ref：rows：11filtered：100。00Extra：Usingintersect（idxqstate，idxtaskstepid）；UUsingtemporary
　　这个执行结果中keylen是2，9，是和以往的kenlen计算法则不一样的。其中Extra列已经给出了明确的提示，这是一个intersect处理，特别的是它是基于二级索引级别的处理，在优化器层面是有一个相关的参数indexmergeintersection。
　　我们知道在MySQL中主键是一等公民，而二级索引最后都会映射到主键层面处理，而索引级别的intersect其实有点我们的左右手，左手对应一些数据结果映射到一批主键id，右手对应一些数据结果映射到另外一批主键id，把两者的主键id值进行intersect交集计算，所以在当前的场景中，索引级别的intersect到底好不好呢？
　　在此我设想了3个对比场景进行分析，首先这是一个update语句，我们为了保证后续测试的可重复性，可以转换为一个select语句。
　　selectfromtaskqueuewhereQState0andtaskstepid411；
　　所以我们的对比测试基于查询语句进行比对分析。
　　场景1：优化器保持默认indexmergeintersection开启，基于profile提取执行明细信息explainselectfromtaskqueuewhereQState0andtaskstepid411G1。rowid：selecttype：SIMPLEtable：taskqueuepartitions：type：indexmergepossiblekeys：idxqstate，idxtaskstepidkey：idxqstate，idxtaskstepidkeylen：2，9ref：rows：11filtered：100。00Extra：Usingintersect（idxqstate，idxtaskstepid）；Usingwhererowinset，1warning（0。00sec）
　　profile信息为：
　　场景2：优化器关闭indexmergeintersection，基于profile进行对比
　　explainselectfromtaskqueuewhereQState0andtaskstepid411G1。rowid：selecttype：SIMPLEtable：taskqueuepartitions：type：refpossiblekeys：idxqstate，idxtaskstepidkey：idxqstatekeylen：ref：constrows：1451filtered：0。82Extra：Usingwhererowinset，1warning（0。00sec）
　　profile信息为：
　　场景3：重构索引，进行比对分析
　　根据业务逻辑，如果创建一个复合索引，是能够大大减少结果集的量级的，同时依然保留idxqstate索引，使得一些业务依然能够正常使用。altertabletaskqueueaddkeyidxtaskstepid（TaskStepID，QState）；explainselectfromtaskqueuewhereQState0andtaskstepid411G1。rowid：selecttype：SIMPLEtable：taskqueuepartitions：type：refpossiblekeys：idxqstate，idxtaskstepidkey：idxtaskstepidkeylen：11ref：const，constrows：filtered：100。00Extra：rowinset，1warning（0。00sec）
　　profile信息为：
　　可以明显看到通过索引重构，Sendingdata的部分少了两个数量级
　　所以接下里的事情就是进一步进行分析和验证，有理有据，等待的过程也不再彷徨，一天过去了，再没有收到1条报警，再次说明在工作中不要小看这些报警。
　　各大平台都可以找到我
　　微信公众号：杨建荣的学习笔记
　　Github：jeanron100
　　CSDN：jeanron100
　　知乎：jeanron100
　　头条号：杨建荣的学习笔记
　　网易号：杨建荣的数据库笔记
　　大鱼号：杨建荣的数据库笔记
　　腾讯云社区：杨建荣的学习笔记