给Apache顶级项目提Bug,我有点飘...

2020年12月7日 359点热度 0人点赞 0条评论

送 福 利 啦

图片

关注HarmonyOS技术社区,回复【鸿蒙】小米小爱音箱mini(数量不多,先到先得),还可以免费下载鸿蒙入门资料


?扫码立刻关注?

图片

专注开源技术,共建鸿蒙生态

这篇文章记录了给 Apache 顶级项目分库分表中间件 ShardingSphere 提交 Bug 的历程。


图片

图片来自 Pexels


说实话,这是一次比较曲折的 Bug 跟踪之旅。10 月 28 日,我们在 GitHub 上提交 issue,中途因为官方开发者的主观臆断被 Close 了两次,直到 11 月 20 日才被认定成 Bug 并发出修复版本,历时 20 多天。

本文将还原该 Bug 的分析过程,将有价值的经验和技术点进行提炼。通过本文,你将收获到:

  • 疑难问题的排查思路

  • 数据库中间件 Sharding Proxy 的原理

  • MySQL 预编译的流程和交互协议

  • Wireshark 抓包分析 MySQL 的奇淫技巧

问题描述

这个 Bug 来源于我的读者,他替公司预研 ShardingProxy(属于 ShardingSphere 的子产品,可用作分库分表,后文会详细介绍)。

他按照官方文档写了一个很简单的 demo,但是运行后无法查询出数据。

下面是他遇到问题后发给我的信息,希望我能帮忙一起定位下原因:

图片

截图中的 doc 详细记录了 ShardingProxy 的配置、调试分析日志、以及问题的具体现象。

为了方便大家理解,我重新描述下这个 Demo 的业务逻辑以及问题表象。

Demo 的业务逻辑说明

这个 Demo 很简单,主要为了跑通 ShardingProxy  的分库分表功能。程序用 SpringBoot+MyBatis 实现了一个单表的查询逻辑,然后用这张表的一个 long 类型字段作为分区键,并通过 ShardingProxy 进行了分表。

下面是那张数据表的详细定义,共 16 个字段,大家关注前两个字段即可,其他字段和本文提到的 Bug 无关。
图片

前两个字段的作用如下:

  • BIZ_DT:业务字段,date 类型,和 Bug 有关

  • ECIF_CUST_NO:bigint 类型,用做分区键

代码就是 Controller 调用 Service,Service 调用 Dao,Dao 通过 MyBatis 实现,这里就不粘贴了。

由于使用了 ShardingProxy 中间件,因此它跟直连数据库的配置会有所不同,在定义 dataSource 时,url 需要配置成这样:
jdbc:mysql://127.0.0.1:3307/sharding_db?useServerPrepStmts=true&cachePrepStmts=true&serverTimezone=UTC

可以看到,jdbc 连接的是 ShardingProxy 的逻辑数据源 sharding_db,端口使用的是 3307,并非真正的底层数据库以及 MySQL Server 的真实端口 3306,具体原理下文会介绍到。

其中,标蓝色的 useServerPrepStmts 和 cachePrepStmts 这两个参数,和本文说的 Bug 有关,这里先提一下,后面会具体分析。

另外,ShardingProxy 的分表策略是:用 long 类型的 ecif_cust_no 字段对 2 进行取模,分成了两张表。

具体配置如下:
shardingColumn: ecif_cust_no
algorithmExpression: pscst_prdt_cvr${ecif_cust_no % 2}

问题描述

再说下遇到的问题。首先,往数据表中预先插入一条 ECIF_CUST_NO 等于 10000 的数据:
图片
然后启动 demo 程序,使用 curl 发起 post 请求,查询 ecifCustNo 等于 10000 的那条记录,居然查询不出数据:

图片

至此,背景基本交代清楚了,为什么数据库中明明有数据,但是程序却查询不出来呢?问题到底出现在 ShardingProxy,还是应用程序本身?

ShardingProxy 原理简介

在开启这个问题的分析过程之前,我先快速普及下 ShardingProxy 的基本原理,以便大家能更好的理解我的分析思路。

开源的数据库中间件大家一定接触过,最流行的是 MyCat 和 ShardingSphere。

其中 MyCat 是阿里开源的;ShardingSphere 是由当当网开源,并在京东逐渐发展壮大,于 2020 年成为了 Apache 顶级项目。

ShardingSphere 的目标是一个生态圈,它由非常著名的 ShardingJDBC、ShardingProxy、ShardingSidecar 3 款独立的产品组成。本文重点普及下 ShardingProxy,另外两个就不展开了。

什么是 ShardingProxy?

ShardingProxy 属于和 MyCat 对标的产品,定位为透明化的数据库代理端,可以理解成:一个实现了 MySQL 协议的 Server(独立进程),可用于读写分离、分库分表、柔性事务等场景。

对于应用程序或者 DBA 来说,可以把 ShardingProxy 当做数据库代理,能用 MySQL 客户端工具(Navicat)或者命令行和它直接交互。

而 ShardingProxy 内部则通过 MySQL 原生协议与真实的 MySQL 服务器通信。
图片

图 1:ShardingProxy 的应用架构图

从架构图来看,ShardingProxy 就相当于 MySQL,它本身不存储数据,但是对外屏蔽了 Database 的存储细节。

你可以用连接 MySQL 的方式去连接 ShardingProxy(除了端口不同),用你熟悉的 ORMapping 框架使用它。

ShardingProxy 的内部架构

再来看下 ShardingProxy 的内部架构,后续源码分析时会涉及到此部分。
图片

图 2:ShardingProxy 的内部架构图

整个架构分为前端、核心组件和后端:

  • 前端(Frontend):负责与客户端进行网络通信,采用的是 NIO 框架,在通信的过程中完成对MySQL协议的编解码。

  • 核心组件(Core-module):得到解码的 MySQL 命令后,开始调用 Sharding-Core 对 SQL 进行解析、改写、路由、归并等核心功能。

  • 后端(Backend):与真实数据库交互,采用 Hikari 连接池,同样涉及到 MySQL 协议的编解码。

ShardingProxy 的预编译 SQL 功能

本文的 Bug 跟 ShardingProxy 的预编译 SQL 有关,这里单独介绍下此功能以及与之相关的 MySQL 协议,这个是本文的关键,请耐心看完。

熟悉数据库开发的同学一定了解:预编译 SQL(PreparedStatement),在数据库收到一条 SQL 到执行完毕。

一般分为以下 3 步:

  • 词法和语义解析

  • 优化 SQL,制定执行计划

  • 执行并返回结果

但是很多情况下,一条 SQL 语句可能会反复执行,只是执行时的参数值不同。

而预编译功能将这些值用占位符代替,最终达到一次编译、多次运行的效果,省去了解析优化等过程,能大大提高 SQL 的执行效率。

假设我们要执行下面这条 SQL 两次:
SELECT * FROM t_user WHERE user_id = 10;

那 JDBC 和 MySQL 之间的协议消息如下:

图片

通过上述流程可以看到:

  • 第 1 条消息是PreparedStatement,查询语句中的参数值用问号代替了,它告诉 MySQL 对这个SQL 进行预编译。

  • 第 2 条消息 MySQL 告诉 JDBC 准备成功了。

  • 第 3 条消息 JDBC 将参数设置为 1。

  • 第 4 条消息 MySQL 返回查询结果。

  • 第 5 条和第 6 条消息表示第二次执行同样的 SQL,已经无需再次预编译了。

再回到 ShardingProxy,如果需要支持预编译功能,交互流程肯定是需要变的,因为 Proxy 在收到 JDBC 的PreparedStatement 命令时,SQL 里的分片键是问号,它根本不知道该路由到哪个真实数据库。

因此,流程变成了下面这样:

图片

可以看到,Proxy在收到 PreparedStatement 命令后,并不会把这条消息转发给MySQL,只是缓存了这个 SQL,在收到 ExecuteStatement 命令后,才根据分片键和传过来的参数值确定真实的数据库,并与 MySQL 交互。

问题分析

上一章节基本把这个 Bug 相关的原理知识介绍清楚了,下面正式进入问题的分析过程。

最开始拿到这个问题,我也是比较头秃的,尤其看到读者下面这段信息。
图片

当然,我的功力是达不到盲猜水平的,说下我的完整思路。

第 1 步:复现问题

我让读者给我打包发了 Demo 的源代码、数据库脚本以及 ShardingProxy 配置,然后本地安装了 ShardingProxy 4.1.1 版本,再通过 Navicat 连接到 ShardingProxy 执行数据库脚本,环境基本就准备完毕了。

启动 Demo 程序后,通过 Postman 发送请求,问题稳定复现了,确实查不出数据。

第 2 步:确认应用程序是否有 Bug

因为整个代码很简单,代码层面唯一有可能存在问题的是 Mybatis 这一层。

为了确认这一点,我修改了 SpringBoot 的配置,将 MyBatis 的 debug 日志也打印了出来。

再次发起请求后,能从控制台中看到以下详细日志:
图片

日志中没发现异常,而且 PreparedStatement 以及 ExecuteStatement 的参数设置都是正确的,查询结果确实是空。

为了缩小排查范围,我把 dataSource 的 配置改回了直连真实数据库,这样能将 ShardingProxy 这个干扰因素排除在外。

改完后的 url 如下:
jdbc:mysql://127.0.0.1:3306/db1?useServerPrepStmts=true&cachePrepStmts=true&serverTimezone=UTC

其中,db1 是真实数据库,3306 也是MySQL 服务器的端口了。然后再次用 Postman 发送请求,可以看到:有正确数据返回了。
图片

通过这一步,我将怀疑对象再次转移到 ShardingProxy 上了,并将 dataSource 配置改回成原样,继续排查。

第 3 步:排查 ShardingProxy

首先,查看 ShardingProxy 的运行日志,没发现任何异常;其次,能看到日志中的 Actual SQL 是正确的,它已经根据分区键正确路由到了  pcsct_prdt_cvr0  这张表:
[INFO ] 17:25:48.804 [ShardingSphere-Command-15] 
ShardingSphere-SQL - Actual SQL: ds_0 ::: SELECT
BIZ_DT,ECIF_CUST_NO,DEP_FLG ...
FROM pscst_prdt_cvr0
WHERE ECIF_CUST_NO = ? ::: [10000]

因此可以推断:ShardingProxy 的分库分表配置应该是没有问题的。

我开始怀疑:是否跟 ShardingProxy 所使用的数据库驱动有关?因为这个 Jar 包是应用方选择版本,手动放到 ShardingProxy 安装目录中的。

因此,我将驱动版本从 5.1.47 版本改成了 8.0.13 (和 Demo 使用了相同的版本),但是问题仍然存在。

另外,还能想到的是:是否是 ShardingProxy 的这个最新版本引入了 Bug?然后,我又另外安装了它的上一个版本 4.1.0,重新测试了一遍,还是有问题。

这个时候,真感觉没有其他可疑点了,所有能想到的点都排查了一遍。我再次回到了 Demo 程序本身,它和 ShardingProxy 唯一的结合点就在 DataSource 的 url 上。
jdbc:mysql://127.0.0.1:3307/sharding_db?useServerPrepStmts=true&cachePrepStmts=true&serverTimezone=UTC

库名和端口号配置无误,唯一可疑的是另外三个参数:

  • useServerPrepStmts

  • cachePrepStmts

  • serverTimezone

其中,前两个参数和预编译 SQL 有关,是一个组合。因此,我将这两个参数从 url 中去掉,测试了一下。

这个时候奇迹出现了,居然返回了正确数据。至此,基本定位到了问题,但根本原因是什么呢?究竟是不是 ShardingProxy 的 Bug ?

第 4 步:Wireshark 抓包分析 MySQL 协议

找到这个问题的解决方案后,我同步给了读者。与此同时,他也在 ShardingProxy  的 GitHub 上提交了 issue,反馈了这个最新进展。

由于工作原因,这个问题我就暂时放一边了,准备抽空再接着排查。

大概过了一周我想起了这个问题,然后打开 issue 想了解下调查进度,让我非常惊讶的是:官方开发者居然在复现此问题后,主观臆断地认为是应用程序的问题,然后莫名奇妙的把这个 issue 关闭了。

他们的答复是这样的:
图片

意思就是:我们针对预编译 SQL 功能做了大量的测试,这个是不可能存在问题的,建议你们更换下应用程序的数据库连接池,抓包继续分析下。(这个说法真让人非常无语,完全不是程序员严谨的思维!)

第二天,我开始用 Wireshark 抓包分析 MySQL 的协议,想弄清楚根本原因到底是什么?同时联系上了官方,让他们 reopen 了这个问题。

Wireshark 如何抓取 MySQL 协议的数据包,这里就不展开了,大家可以网上查下资料。

注意将 Wireshark 的过滤条件设置成:
mysql || tcp.port==3307

其中:mysql 表示 ShardingProxy 和 MySQL Server 之间的数据包,tcp.port==3307 表示 Demo 程序和 ShardingProxy 之间的数据包。

启动 Wireshark 抓包后,再次用 Postman 发起请求,触发整个过程,然后就能顺利抓到下面截图的数据包了。
图片

大家关注底色为 深蓝色 的 8 个数据包即可。在本文第 2 章节的原理部分,我已经详细介绍过 ShardingProxy 的预编译功能以及该流程的 MySQL 协议消息,这里的 8 个数据包和原理介绍是完成吻合的。

那接下来如何进一步分析呢?结合 ShardingProxy 的架构图来思考下:Proxy 仅仅作为一个中间代理,介于应用程序和 MySQL Server 之间。

它完全实现了 MySQL 协议,以便对 MySQL 命令进行解码和编码,然后加上自己的分库分表逻辑。

如果 ShardingProxy 内部存在 Bug,那一定是某个数据包出现了问题。

顺着这个思路,很快就能发现:执行完 ExecuteStatement 后,MySQL Server 返回正确数据包给 Proxy 了,但是 Proxy 没有返回正确的数据包给应用程序。

下面截图的是倒数第 2 个 Response 数据包,由 MySQL Server 返回给 Proxy 的,Payload 中能看到那条记录的数据:
图片
下面截图的是最后 1 个 Response 数据包,由 Proxy 返回给应用程序的,Payload 中只能看到表字段的定义,那条记录已经不翼而飞了。
图片

通过这一步分析,就已经坐实了:ShardingProxy 是有 Bug 的。然后,我将这些依据发给了官方开发者,对方开始重视,并正式进入源码分析阶段。

根本原因定位

当天晚上,官方开发者就定位到了根本原因,发出了 Pull Request。我看了下代码改动,仅仅修改了一行代码。
图片

改动的这行代码,就是在 ShardingProxy 再次组装数据包返回给应用程序时抛出来的。

由于我们的数据表中存在一个 date 类型的字段,改动的这行代码却强制将 date 类型转换成了 Timestamp 类型,因此抛出了异常。还有几个疑点,我结合对源代码的理解逐一解答下。

①为什么代码抛异常了,但是 ShardingProxy 的控制台没打印呢?

图片

上面截图的是:抛出 ClassCastException 那个方法的整个调用链。由于 ShardingProxy 并没有捕获这个 RuntimeException 以及打印日志,最终这个异常被 netty 吞掉了。

②为什么 ShardingProxy 需要做 date 到 Timestamp 的类型转换呢?

可以从 ShardingProxy 的架构来理解,因为 Proxy 只有对 MySQL 协议进行编解码后,才能在中间插入它的分库分表逻辑。

针对 date 类型的字段,ShardingProxy 通过 JDBC 的 API 从查询结果中拿到的仍然是 Date 类型,之所以要转换成 Timestamp,这个又跟 MySQL 的协议有关了,下面是 MySQL 官方文档的说明:

图片

简单理解就是:ShardingProxy 在代码实现时,用了一个范围最大的 timestamp 存了三种可能的值 date,datetime 和 timestamp,然后再按照上面这个协议规范进行二进制的写入。

③这个 Bug 是只有在使用 SQL 预编译功能时才会被触发吗?

是的,只有在处理 ExecuteStatement 命令时,这个方法才会被调用到。那普通的 SQL 查询场景为什么用不到呢?

这个又跟 MySQL 协议有关了,普通的 SQL 查询场景,payload 不是二进制协议的,而是普通的文本协议。这种情况下,无需调用这个类进行转换。

至此,整个分析过程就结束了。

写在最后

本文详细复盘了这个 Bug 的分析过程,并对其中的原理知识和排查经验进行了总结。

对于 ShardingSphere 这种顶级开源项目来说,我个人觉得同样值得做一次深度复盘。

我不认同他们对于 issue 的处理方式,另外在核心功能的自动化测试上,也一定是存在 case 不完善的,不然不可能连续多个版本都没发现这个严重 Bug。

作者:骆俊武

简介:前亚马逊工程师,现 58 转转技术总监,持续分享个人的成长经历,希望为你的职场发展带来些新思路。

编辑:陶家龙

出处:转载自公众号IT人的职场进阶(ID:BestITer)

图片

精彩文章推荐:

CTO问我,为什么需要API网关?
老板:你写的接口有问题!赶紧起床瞧瞧
可笑,架构师也能写出这样的Bug

21820给Apache顶级项目提Bug,我有点飘...

root

这个人很懒,什么都没留下

文章评论