0%

坑系列之canal的json解析bug

MySQL到其他异构数据库之间的同步,一般来说都是通过binlog + canal的方式,现在比较流行的说法称其为 change data capture (CDC),其实canal的诞生可以追溯到2014年,那会儿CDC的概念可能还没有,可见业界造词能力有越来越强的趋势。

遇到canal的这个问题说来也是诡异,异构数据库间同步的模块已经半年多没有变化。但是问题突然在一次upgrade后出现,所以一直在upgrade有关的模块排查,甚至一度想要rollback。

故障发生

运维在upgrade后告知线上数据同步不正常,排查后发现canal进程中断退出,错误日志停留在

这个错误其实提示还是比较明显的,就是数据解析失败,而且应该是一个越界异常。但到底是什么数据引发了就不得而知了。接下来兵分两路,一路排查跟升级有可能相关的代码,一路定位问题数据。

故障定位

定位问题数据的方式就是看canal在zookeeper中记录的binlog的position。但是由于canal处理binlog是批量处理,所以单用一个position无法准确定位到问题数据,所以我们尝试调整zookeeper中的position,大概找了三个点位后,发现了一个共性的问题,就是当出现某张表的一个json字段有更新时,就会出现canal数据解析失败的异常。

但是这里其实埋了一个大雷,由于binlog数据比较敏感,所以都是由运维在线上下载到远程机器上执行 mysqlbinlog -vv --base64-output=decode-rows mysql-bin.003705 类似的语句去进行解析,然后把解析后的文本发回。我们最终看到的是如下图显示的内容

可以看到箭头标识的地方没有正常的以 */ JSON 结尾,所以我们认为是阿里云的RDS出现了问题导致binlog的数据不完整。于是我急忙给RDS的售后人员提工单,当时已经差不多夜里12点了。

故障解决

临时方案

一方面在等阿里云售后的回复,一方面我们也需要及时恢复线上的数据同步, 否则等到第二天业务数据跑起来,客户发现分析系统完全没数据就有大问题了。当机立断,先抛弃有问题的问题,将其记录到log中,以后再恢复。于是紧急fork了一份canal的代码,定位到异常抛出的地方,一通try-catch的操作后。线上数据同步暂时恢复,canal遇到数据无法解析时只是记录log后跳过而不会直接退出。忙到这时差不多是凌晨3点。

最终解决

第二天主要精力就是在跟阿里云RDS的售后一起排查binlog的问题,事实证明是我们闹了乌龙,我将具体错误的binlog位点告知后,RDS的售后给出的解析结果是这样的

并没有格式的问题,之前没有正常的以 */ JSON 结尾,是由于运维工具的解码问题造成的,与binlog本身无关。也就是说binlog是好的,那么矛头又重新指向canal。

要想解决这种疑难杂症,最好的做法就是本地可以稳定复现。于是在一顿操作后,本地的canal可以开始消费出现问题的binlog文件。果然到固定的位点就出现异常。本地开启debug模式,一路追到 JsonConversion文件,发现是在解析一个叫做 JSON_TYPE_OPAQUE 类似的数据时出现了问题,这个 JSON_TYPE_OPAQUE 其实就是json中没有用引号的value,一般都是数值型。造成 limit excceed 也是由于对这个value的长度计算的不对,最终也只是改了计算长度的一行代码解决了,那么从本地模拟到这时候差不多也是花了整整一天。大功告成之际,准备给canal提一个PR,所以翻了下github上master的代码(我们使用的是最新的tag而不是mater分支),竟然发现有这个问题在2020年2月份就有人提过PR,并且已经被合并到了master。

此刻内心是崩溃的,这么严重的bug,canal的开源团队居然也不发一个hotfix,难不成都要让大家用master这个开发分支么。事实上canal这个项目也是很久没有维护了,可见一个活跃的开源团队对于开发者或者使用者来说是多么的重要。

番外

在本地模拟消费线上binlog的时候,无意发现canal的另一个问题,由于阿里云RDS的binlog会定时从mysql本地拉取到OSS中。所以对于一些旧的数据(视MySQL的磁盘容量而定,一般一天前的数据就会放到OSS),canal需要从OSS获取。在canal的开发文档中也是写着支持从OSS读取binlog,而且需要配置OSS的token和secret。

但是在我本地尝试拉取一天前的binlog时,一直抛错

1
sqlstate = HY000 errmsg = Could not find first log file name in binary log index file

可见并没有用OSS获取,还是尝试从MySQL的本地磁盘中获取,当然是获取不到的。

继续在github寻找答案,发现 这个issue,难不成用master就能好?果然还是too young,这一篇 说的更清楚。

希望对你有帮助,分享或是请我喝杯咖啡吧~