刚更新的数据居然查不到，MySQL你到底在做什么妖-下

本文正在参加「技术专题19期 漫谈数据库技术」活动

你用忙碌送走白昼，笑迎安静的深夜

并非贪恋繁星的闪耀，而是钟爱默默地拼搏

欢迎关注【架构染色】交流学习

本篇尝试悬疑推理风剧本杀，剧情纯属虚构（若有雷同实属巧合)：应用 A 更新了 MySQL 数据 -> canal 监听 binlog ，发给 MQ -> 应用 B 消费 MQ，并向 A 发起 Dubbo 请求 -> 应用 A 处理时却查到了更新前的数据。这个情况多数人都没遇到过，但提前了解并规避是必要的。

本剧本杀分上下两章：

• 首章：《刚更新的数据居然查不到，MySQL你到底在做什么妖-上》
• 终章：《刚更新的数据居然查不到，MySQL你到底在做什么妖-下》（本篇）

请按需回顾前情，方便你尽快融入角色（戏精上身）。

一、前情回顾

在首章剧情中你在技术部门负责链路追踪系统和数据库中间件等，在一次日常技术支持中，遇到了神奇的现象：

1. 应用 A 将 MySQL 中 x 订单记录里的 y 字段从 ccc 变成了 ddd
2. canal 监听 DB 中的订单表，从 binlog 中感知到 x 记录变更信息后，发到 MQ
3. 应用 B 消费这个 MQ，收到这条消息后，处理流程中会再调用应用 A 的 Dubbo 服务，查询一些信息
4. 应用 A 响应 Dubbo 请求时，处理逻辑中还会从 MySQL 中查询这条 x 订单记录，但是！！！读出的状态字段居然还是老数据 ccc
5. DB 是 MySQL ，采用读写分离架构，主从采用异步同步

你梳理的数据流转图如下：

数据流转图.png

通过这个数据流转图可以看出读数据有如下 3 种途径：

• 6.1 读缓存
• 6.2 读 slave-DB
• 6.3 读 master-DB

你反复思索之后推测 6.1 或 6.2 这两种途径很可能会读取到旧值，但经梳理排查将各方信息整合后，似乎并没有执行 6.1 的读缓存，也没有执行 6.2 的读 slave-DB，你也认定不会是数据库中间件的路由机制有漏洞，而 DBA 也不认为 master-DB 有问题，应用 A 也不认为他指定读 master-DB 的代码有问题，老王也不认为他的 canal 读到的 binlog 有问题。但由于没有 trace 信息提供直接有效的证据，各方只能保留意见，不乱猜疑。

面面相觑好久，大家心照不宣地望向了导演，作为主角的你去问导演接下来怎么演。

导演也着急，把编剧叫来朝他怒吼：“那谁，这都演完了，你剧本还没写出来嘛？”

只见编剧不慌不忙的把剧本递给导演，导演定睛一看，剧本上写着"没有有效的观测数据，又没有办法复现，可能只有上帝视角知道是哪个环节有问题，要不问问上帝？”。

此时有人自称上帝的站出来说：”应用 A、应用 B、canal 都接入 SkyWalking，等下次复现时，根据链路信息来寻找线索“。

二、终章剧本

因剧情所需，这次你在技术部门负责 canal 和 MQ 等，情节延续上一次的排障经历...

突然，导演大喊：男主请就位... 预备 ! Action!

你：我去，咋的这就又开始演了？

三、心中的疑虑

当听完上帝让接 SkyWalking 后，你必须开始心中有疑虑，疑虑些什么呢？终章剧本要求作为主角的你，要好好想一想为什么接入 SkyWalking 后就能准确定位问题，帮助定位问题的信息 SkyWalking 是提供的？因为不擅长这个领域，你很头疼；倘若刚好你很熟悉 SkyWalking ，这里也需要假装不熟悉且头疼一下，导演要求就这么演。。。

头疼了一会儿，你突然想到隔壁老张，在首章中是主角，负责 SkyWalking ，于是你去咨询 SkyWalking 能提供哪些有效的信息，老张拿出之前梳理的图，指着其中几个关键环节：

• 应用 A 什么时候开始更新记录，什么时候结束更新记录
• 应用 B 什么时候消费 MQ，什么时候请求应用 A，应用 A 什么时候开始执行的查询，查询的是哪里？用缓存没？如果没用缓存，访问的又是哪个 DB？

这些关键信息 SkyWalking 的 trace 中都有记录，且在界面中清晰可见，

老张继续解释说，虽然当前的 MySQL 没有传递 traceId 信息，会导致链路断开成更新和查询这两条 trace，但是可以通过关键字从日志中检索出这两条 trace 的 traceId(下文用 TID) 。

听完老张的讲解，你了解并相信了 SkyWalking 的能力。原本你也推测查询的是 slave-DB 或缓存，所以当时下意识的决策就是等到复现后用 trace 信息来印证你的推测；不过老张在下班时又向你抛出一个疑虑：会不会真有当 canal 读到 binlog 时 MySQL 事务还未完成提交的可能呢？

从你以往的经验看是没有这个情况的，但被老张这么一问却不自信了。难道当前版本的 canal 同步 binlog 的机制有问题？“到底有没有问题呢，到底有没有呢？”这个声音一直在你耳边萦绕，莫名感让你觉得很不踏实，于是之后便在空闲时搜集学习 MySQL 同步机制的更多内幕。

四、问题再现

大约两周后，问题排查群突然出现@全员的消息，想到可能是问题再现，你赶紧点开查看；只见在群聊窗口中已经发出了把 x 记录的 y 字段从 ccc 更新成 ddd 这个过程的 TID 以及 trace 信息截图

非原截图.png

因为剧情所需，作为本章主角的你，此时已很熟悉 SkyWalking 了，当看到这个截图后，亲自在 SkyWalking 的 web 页中通过此 TID 查看 trace 信息，点击Mysql/JDBI/Connection/commit，看到 commit 的具体信息如下：

五、铁证如山

你从 trace 信息中筛选出应用 A 将 x 订单记录里 y 字段从 ccc 变成了 ddd操作的关键信息是：

1. 事务发生在 MySQL 实例 serviceA-xxxx 中（这是 master-DB）
2. 事务 commit 的开始是 09:58:54 的 第 72 毫秒（后边都只显示毫秒)
3. 事务 commit 的结束是在第 123 毫秒

之后又快速从 SkyWalking 的 web 页中查看核实应用 A 查询数据的 trace 信息，没有读 Mybatis 缓存、没有读 slave-DB，真儿真儿的是从 master-DB 中查询数据。至此， trace 信息提供的信息有效证明了 应用 A 更新记录和查询记录都发生在 master-DB serviceA-xxxx 中。

剧本提醒，拥有主角光环的你，此时已淡定、娴熟的把两条 trace 信息中关键事项的时间节点 结合 mysql 和 canal 日志（canal 系统还未接 SkyWalking，只能看日志信息）整理了出来，情况如下：

• 第 72 毫秒：应用 A 更新事务 commit 开始
• 第 73 毫秒：MySQL 服务端开始写 Binlog
• 第 77 毫秒：canal 同步到 Binlog 后发送到 MQ
• 第 78 毫秒：应用 B 拉取到 canal 消息后，向应用 A 发起 Dubbo 调用
• 第 88 毫秒：应用 A 查询 Mysql
• 第 123 毫秒：应用 A 的事务 commit 结束返回

剧本提醒：作为主角的你，绝对不能表现出惊讶，但其他群演看完你整理的信息后，必需配合表演出下图中的表情（导演强调，怎么夸张怎么演）。

六、揭开玄机

因两周前隔壁老张提出疑虑后，你就已经开始查阅资料学习 MySQL 8（今年是从 5.6 升级了）的同步机制，大脑知识库中的资料显示 MySQL 是分两阶段处理事物请求的，其中跟剧情密切相关的是第二阶段的 3 个核心步骤：

1. 写 binlog
   当写完 biblog 后，事务已经提交并持久化了，若发生崩溃，重启之后就能正确恢复
   
2. 同步 binlog
   各种同步机制有差异
   
3. 写 engine
   会处理释放锁，释放 mvcc 相关的 read view 等；注意只有写完 engine 之后，事务中的变更才能被查询到
   
4. 客户端 commit 请求返回
   

综合上述的信息，你将整个流程整理成下图:

读写流程时序.png

并在图中指出，这两次异常的情况的发生，全是因为在读 x 记录的时候，master-DB 中写 engine 尚未完成，你之所以在上图中使用2.谜之操作的名称，是因为 MySQL 并不确定这个同步耗时是多长；而且在强同步、半同步的机制下实现逻辑更复杂，可能出现此问题的概率会比异步同步模式更高，因细节和剧情的关系不那么密切，本剧本里并没有过多的描述，只提供了下边这个更为细致的流程图：

来自网络.png

通过你给出的解释和资料，除了老张的表情看起来是还在纠结着什么，其他众人皆表示此瓜香甜可口、回味无穷，经过学习思考后对此情况基本达成共识，开始考虑如何应对这个小概率事件。

七、新的疑虑和答案

第二天下班后，老张又找到你探讨为什么应用 A 的服务逻辑并未变更，而是升级 8.x 之后这个问题才开始出现（虽然概率不高）；据老张讲，昨夜他查阅了好多资料，其中有一个关键信息是写 engine 后更新才能被查到，但是 5.7 开始，写 engine 的时机被调整了：

• 5.6 版本中是先写 engine 再同步，由于写 engine 的时机较早，产生问题的概率就更低。
• 5.7 提供的默认逻辑是先同步，再写 engine，由于同步前置了就可能带来更多的具有不确定性的耗时

MySQL 5.7 默认同步机制的变化.png

八、建议

总结来看，无论是 5.6 还是 5.7 + ，从逻辑看只是概率不同，监听 binlog 的方案始终是无法避免这类问题的。因无法确认 MySQL 的最大延迟时间，你的 canal 也无法使用 MQ 定时延迟消息的机制，因为延迟时间设大设小都不合适，你给出可行的 2 个建议：

• 异常重试 ：异常时借助 MQ 的 delay 重试机制多试几次。
• 采用新的实现架构：从根本上规避再去查询 DB。

九、杀青

恭喜你，《若不是 SkyWalking，MySQL 的这个锅都没人背了》-终章 到这里杀青了，因为你卓越的才识和精湛的演技，剧组专门颁发给你一个【MySQL同步-技术达人】 的称号，请收藏好，再次感谢！

十、幕后

将日常工作经历编写成本剧本杀实属偶然，也很辛苦，因为995 的工作日常本就不轻松；前天深夜看到华哥的一条朋友圈消息感同身受，这里借花献佛，向如此境况的猿类兄弟姐妹致敬。

每次下班回家时已是深夜，欣慰的是，走到这儿时，眼前这家店的灯总还亮着，似乎是一直在路旁守护着，玻璃透出的淡淡光色让人感觉很治愈很温暖。

十一、最后说一句(请关注，莫错过)

如果这篇文章对您有帮助，或者有所启发的话，欢迎关注公众号【 架构染色 】进行交流和学习。您的支持是我坚持写作最大的动力。

求一键三连:关注、点赞、转发。

感谢

blog.51cto.com/u_13691477/…

blog.csdn.net/weixin_3450…

t.csdn.cn/zC9xO

www.cnblogs.com/juanmaofeif…

cloud.tencent.com/developer/a…

blog.csdn.net/wenqing_ruy…

blog.csdn.net/universsky2…

本文正在参加「技术专题19期 漫谈数据库技术」活动