麒麟v10 上部署 TiDB v5.1.2 生产环境优化实践
871
2023-04-22
剧本杀 :《若不是SkyWalking,MySQL的这个锅都没人背了》-终章
本篇尝试悬疑推理风剧本杀,剧情纯属虚构(若有雷同实属巧合):应用 A 更新了 MySQL 数据 -> canal 监听 binlog ,发给 MQ -> 应用 B 消费 MQ,并向 A 发起 Dubbo 请求 -> 应用 A 处理时却查到了更新前的数据。这个情况多数人都没遇到过,但提前了解并规避是必要的。
本剧本杀分上下两章:
首章:《若不是SkyWalking,MySQL的这个锅都没人背了-首章》
终章:《若不是SkyWalking,MySQL的这个锅都没人背了-终章》(本篇)
请按需回顾前情,方便你尽快融入角色(戏精上身)。
一、前情回顾
在首章剧情中你在技术部门负责链路追踪系统和数据库中间件等,在一次日常技术支持中,遇到了神奇的现象:
应用 A 将 MySQL 中 x 订单记录里的 y 字段从 ccc 变成了 ddd
canal 监听 DB 中的订单表,从 binlog 中感知到 x 记录变更信息后,发到 MQ
应用 B 消费这个 MQ,收到这条消息后,处理流程中会再调用应用 A 的 Dubbo 服务,查询一些信息
应用 A 响应 Dubbo 请求时,处理逻辑中还会从 MySQL 中查询这条 x 订单记录,但是!!!读出的状态字段居然还是老数据 ccc
DB 是 MySQL ,采用读写分离架构,主从采用异步同步
你梳理的数据流转图如下:
数据流转图
通过这个数据流转图可以看出读数据有如下 3 种途径:
6.1 读缓存6.2 读 slave-DB6.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 信息截图
非原截图
Key
value
描述解释
服务
serviceA
应用 A 的服务名称
服务实例
111.111.111.222
执行本次操作的实例 IP
端点
跨度类型
Exit
Exit 表示访问了外部资源,如此处的MySQL
组件
mysql-connector-java
表明此 trace 信息是 JDBC 插件提供的
Peer
serviceA-xxxx:3311
db 实例的域名\ip 信息
失败
false
false 表示本次操作没有异常
db.type
sql
表示本次操作的 DB 是 SQL 类型
db.instance
serviceA
表示应用 A 的 DB 实例
db.statement
xxx
sql 语句
五、铁证如山
你从 trace 信息中筛选出应用 A 将 x 订单记录里 y 字段从 ccc 变成了 ddd操作的关键信息是:
之后又快速从 SkyWalking 的 web 页中查看核实应用 A 查询数据的 trace 信息,没有读 Mybatis 缓存、没有读 slave-DB,真儿真儿的是从 master-DB 中查询数据。至此, trace 信息提供的信息有效证明了 应用 A 更新记录和查询记录都发生在 master-DB serviceA-xxxx 中。
剧本提醒,拥有主角光环的你,此时已淡定、娴熟的把两条 trace 信息中关键事项的时间节点 结合 mysql 和 canal 日志(canal 系统还未接 SkyWalking,只能看日志信息)整理了出来,情况如下:
剧本提醒:作为主角的你,绝对不能表现出惊讶,但其他群演看完你整理的信息后,必需配合表演出下图中的表情(导演强调,怎么夸张怎么演)。
六、揭开玄机
因两周前隔壁老张提出疑虑后,你就已经开始查阅资料学习 MySQL 8(今年是从 5.6 升级了)的同步机制,大脑知识库中的资料显示 MySQL 是分两阶段处理事物请求的,其中跟剧情密切相关的是第二阶段的 3 个核心步骤:
写 binlog
当写完 biblog 后,事务已经提交并持久化了,若发生崩溃,重启之后就能正确恢复
同步 binlog
各种同步机制有差异
写 engine
会处理释放锁,释放 mvcc 相关的 read view 等;注意只有写完 engine 之后,事务中的变更才能被查询到
综合上述的信息,你将整个流程整理成下图:
读写流程时序
并在图中指出,这两次异常的情况的发生,全是因为在读 x 记录的时候,master-DB 中写 engine 尚未完成,你之所以在上图中使用2.谜之操作的名称,是因为 MySQL 并不确定这个同步耗时是多长;而且在强同步、半同步的机制下实现逻辑更复杂,可能出现此问题的概率会比异步同步模式更高,因细节和剧情的关系不那么密切,本剧本里并没有过多的描述,只提供了下边这个更为细致的流程图:
来自网络
通过你给出的解释和资料,除了老张的表情看起来是还在纠结着什么,其他众人皆表示此瓜香甜可口、回味无穷,经过学习思考后对此情况基本达成共识,开始考虑如何应对这个小概率事件。
七、新的疑虑和答案
第二天下班后,老张又找到你探讨为什么应用 A 的服务逻辑并未变更,而是升级 8.x 之后这个问题才开始出现(虽然概率不高);据老张讲,昨夜他查阅了好多资料,其中有一个关键信息是写 engine 后更新才能被查到,但是 5.7 开始,写 engine 的时机被调整了:
5.6 版本中是先写 engine 再同步,由于写 engine 的时机较早,产生问题的概率就更低。
5.7 提供的默认逻辑是先同步,再写 engine,由于同步前置了就可能带来更多的具有不确定性的耗时
MySQL 5.7 默认同步机制的变化
八、建议
总结来看,无论是 5.6 还是 5.7 + ,从逻辑看只是概率不同,监听 binlog 的方案始终是无法避免这类问题的。因无法确认 MySQL 的最大延迟时间,你的 canal 也无法使用 MQ 定时延迟消息的机制,因为延迟时间设大设小都不合适,你给出可行的 2 个建议:
异常重试 :异常时借助 MQ 的 delay 重试机制多试几次。
采用新的实现架构:从根本上规避再去查询 DB。
版权声明:本文内容由网络用户投稿,版权归原作者所有,本站不拥有其著作权,亦不承担相应法律责任。如果您发现本站中有涉嫌抄袭或描述失实的内容,请联系我们jiasou666@gmail.com 处理,核实后本网站将在24小时内删除侵权内容。