剧本杀：《若不是SkyWalking，MySQL的这个锅都没人背了》-Chapter

剧情需要剧本。该脚本显示您负责技术部门的链接跟踪系统和数据库中间件。剧情是你日常工作中的排错体验……刚刚看了这么多，导演大喊：“男主，请就位……准备！行动！你：哇，我要开始行动了现在？”1.问题开始记得那是一个阳光明媚的下午...突然把你拉进了一个临时工作组，窗口里飞快的跳出一条信息：@老张binlog字段更新，读db时却不能阅读。记得你作为男主，在剧本的这一章里叫老张。看到这条消息后，你的大脑开始对这些关键词进行拆解：应用A将MySQL中x记录中的y字段更新为canal（canal是什么？下面介绍）监听DB中的订单记录变更事件，发送到MQ应用B消费这个MQ，收到这个消息后，从MySQL中查询这条x记录但是！！！没有读到y字段的更新值同时，你大脑的另一个区域也勾勒出如下数据流图：当你对这个问题有了初步的了解后，脑子里就冒出一连串的问题条件反射，赶紧在群里发出来：对业务有严重影响吗？系统最近有变化吗？这是个人创纪录的现象吗？以前发生过吗？什么是traceId？我得到的答复是：问题并不严重。最近没有变化。这是个人创纪录的现象。好像没遇到过。我没有连接过SkyWalking（什么是SkyWalking，下面会介绍），现有的日志也没有什么猫腻。看完前4个答案，你松了一口气，没有什么大的影响，紧张的情绪也有所缓解；但同时你也意识到没有直观的链接跟踪数据，想弄清楚这个问题有点麻烦。1.1Canal知识补充：官方介绍：canal[k?'n?l]，译为水路/管道/沟渠，主要用于提供基于MySQL数据库增量日志解析的增量数据订阅和消费。早期由于杭州和美国双机房的部署，有跨机房同步的业务需求。实现方式主要是基于业务触发器获取增量变化。从2010年开始，业务逐渐尝试解析数据库日志获取增量变化进行同步，并由此衍生出大量的增量数据库订阅消费业务。canal官网icon.pnggithub地址：https://github.com/alibaba/canal1.2SkyWalking知识补充：SkyWalking是一个可观察性平台（ObservabilityAnalysisPlatform(OAP)andapplicationperformancemanagement(APM)）。提供分布式链路跟踪、ServiceMesh遥测分析、Metric聚合和可视化的一体化解决方案。下图是其linktracking的展示效果。通过它可以直观的看到一个请求的完整执行轨迹，经过了哪些应用，访问了哪些中间件，请求的关键信息是什么，每个环节的执行时间是多少，是否异常，etc.github地址：https://skywalking.apache.org/2.查询调查2.1整理数据流由于应用没有接入SkyWalking，缺乏直观完整的trace信息的帮助，只能通过低效的整理和人工查询。哪些应用，什么类型的DB，数据流向，经过一番沟通，了解到情况如下：，并从binlog中感知到x记录变化信息后，发送给MQ应用B来消费这个MQ。收到这条消息后，会在处理流程中请求应用A的Dubbo接口查询一些信息。应用A收到Dubbo请求后，也会从MySQL中查询这条x订单记录，但是！！！读出的status字段还是cccDB，读写分离。MySQL主从同步采用的异步同步方式2.2锁定可疑链接可以看出读取数据有3种方式：6.1读取缓存6.2读取从库6.3读取主库想了想，你推测是6.1或6.2这两种方式很可能读取到旧值，所以你开始检查。2.3排查Mybatis缓存问题根据经验可以猜到6.1读取新数据失败的可能性最大。缓存通常包括进程内缓存、Redis缓存、Mybatis缓存。经过进一步沟通，确认应用A没有使用内存缓存和Redis缓存。同事甚至怀疑数据库中间件是否有缓存。这个怀疑被你直接排除了（数据库中间件没有缓存），然后Mybatis缓存就可疑了，于是你赶紧从大脑的知识库中找出Mybatis二级缓存的机制原理。2.3.1排除一级缓存的嫌疑。默认启用一级缓存。是不是一级缓存的问题？你继续分析：按照现有的mapper用法，一个request中的所有CRUD操作都在同一个sqlSession中，一个sqlSession中的所有查询操作都会保存在这个sqlSession中的缓存中，即每个请求都有一个专门的一级缓存对每个请求都是隔离的，互不干扰。在x记录更新之前，应用A的查询请求中的一级缓存数据不会被x记录更新后的应用A的查询请求访问到。.经过这样的梳理分析，你已经排除了Mybatis一级缓存可能导致这个问题的可能性。2.3.2排除二级缓存的嫌疑那你继续查看是不是二级缓存导致的。你的知识库显示，二级缓存在sqlSession之外，由sqlSession共享，即多个请求可以共享同一个二级缓存，一级缓存和二级缓存的配合机制如下：缓存的数据通过sqlSession首先放入一级缓存，当sqlSession会话提交或关闭时，一级缓存数据会同步到二级缓存。去二级缓存里找，找不到就去一级缓存里搜索，读取二级缓存.png好像时间差匹配的话，疑似二级缓存很高。是不是二级缓存的问题？这时候一个知识点正狠狠地敲你的脑子【需要手动开启二级缓存】，于是你连忙问应用A是否开启了二级缓存，同事却想不通暂时不知道这个开关的知识，所以大家把如何开启二级缓存的说明发出来：打开单个mapper在需要开启二级缓存的XXXmapper.xml文件中添加如下配置所有mapper都开启在mybatis.xml中添加如下配置套用A的比较结论，Mybatis的二级缓存没有开启。经过这样的梳理和分析，你已经排除了Mybatis二级缓存可能导致这个问题的可能性。2.4binlog同步问题排查您按照上图继续排查。这时候你怀疑自己到了6.2从图书馆读的链接。向DBA查询后得知，MySQL主从同步采用的是异步同步方案；此刻，你的知识库表示尴尬：MySQL异步同步机制我不熟悉，于是找到隔壁老王（运河，MQ专家）请教。老王解释：在异步同步机制中，master-DB写入binlog后执行提交，并不等待slave-DB的同步状态；由于canalbinlog数据和slave-DB都是在读取binlog数据后进行处理，没有时序控制，所以有可能应用A从slave-DB读取x条记录时，slave-DB还没有完成同步x条记录，如下图：Synchronizationdelay.png同时，老王还补充说刚才检查了canal和MQ的工作状态，DBA也看到了DB的监控信息。这些系统的指标非常稳定，没有抖动。问题不应该只是这个记录。掌握了这些信息之后，你基本上假设应用A读取slave-DB，因为你的数据库中间件，在读写分离的场景下，读取请求默认会自动路由到slave-DB，除非...，突然你向应用程序A查询这个读取请求是否指定读取master-DB...应用程序A的响应与你的预期大相径庭。在这个请求中，他指定读取master-DB。为什么读master-DB，还能读到旧数据，是不是数据库中间件的路由机制有漏洞？导演让你马上配合上图的表情……OHMYGOD！！！2.5新困境过了一会儿，你平静了下来。凭着你强大的灵魂，你确定这不是数据库中间件路由机制的漏洞。这个时候DBA并不认为master-DB有问题，applicationA也不认为他指定读取master-DB的代码有问题，老王也不认为有问题用他的运河读取二进制日志。对视许久，众人默契的看向导演。作为主角，你自然要问导演接下来要做什么。3.SkyWalking的接入导演焦急的吼道：“那谁，都完了，剧本还没写好？”只见编剧不紧不慢地走进来，将剧本递给导演，导演跟着剧本仔细阅读：“缺乏有效的可观察痕迹数据，也没有办法快速复现，可能只有天知道是哪个环节错了。”你为什么不问上帝？”。就在这时，突然有人站了出来：“老天爷，我们把SkyWalking和AppA、AppB连接起来，下次再出现的时候，大家可以根据连接信息快速揭开问题的真相。”于是你在群里发出了访问SkyWalking的文件。两点很简单：在应用配置中心查看SkyWalking日志配置文件的访问权限，调整添加traceId占位符。自己的猜疑，期待接入SkyWalking后的见面，根据准确的信息定位。4.终章剧透下一章（终章）剧本中，你是主角老王；上面的尴尬情况激活了你更认真的能量，之后你查阅了很多资料进一步研究MySQL的同步机制讲解。问题复现后，给出MySQL同步机制缺陷的根本原因。……敬请期待最终章。关键情节如下：应用A和应用B连接到SkyWalking两周后，这个问题又出现了。SkyWalking中的跟踪信息表明应用程序A确实读取了master-DB。老王通过进一步的收集和研究发现，这是MySQL工作机制的天然缺陷。大家一致同意后续改进和标准调整来应对这个缺陷。转载本文请联系【结构染】公众号作者。