这篇文章记录了给 Apache 顶级项目 - 分库分表中间件 ShardingSphere 提交 Bug 的历程。前端
说实话,这是一次比较曲折的 Bug 跟踪之旅。10月28日,咱们在 GitHub 上提交 issue,中途由于官方开发者的主观臆断被 Close 了两次,直到 11 月 20 日才被认定成 Bug 并发出修复版本,历时 20 多天。mysql
本文将还原该 Bug 的分析过程,将有价值的经验和技术点进行提炼。经过本文,你将收获到:sql
一、疑难问题的排查思路数据库
二、数据库中间件 Sharding Proxy 的原理后端
三、MySQL 预编译的流程和交互协议缓存
四、Wireshark 抓包分析 MySQL 的奇淫技巧服务器
这个 Bug 来源于个人公号读者,他替公司预研 ShardingProxy(属于 ShardingSphere 的子产品,可用做分库分表,后文会详细介绍)。他按照官方文档写了一个很简单的 demo,可是运行后没法查询出数据。网络
下面是他遇到问题后发给个人信息,但愿我能帮忙一块儿定位下缘由。
架构
截图中的 doc 详细记录了 ShardingProxy 的配置、调试分析日志、以及问题的具体现象。并发
为了方便你们理解,我从新描述下这个 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 的基本原理,以便你们能更好的理解个人分析思路。
开源的数据库中间件你们必定接触过,最流行的是 MyCat 和 ShardingSphere。其中 MyCat 是阿里开源的;ShardingSphere 是由当当网开源,并在京东逐渐发展壮大,于 2020 年成为了 Apache 顶级项目。
ShardingSphere 的目标是一个生态圈,它由很是著名的 ShardingJDBC、ShardingProxy、ShardingSidecar 3 款独立的产品组成。本文重点普及下 ShardingProxy,另外两个就不展开了。
ShardingProxy 属于和 MyCat 对标的产品,定位为透明化的数据库代理端,能够理解成:一个实现了 MySQL 协议的 Server(独立进程),可用于读写分离、分库分表、柔性事务等场景。
对于应用程序或者 DBA 来讲,能够把 ShardingProxy 当作数据库代理,能用 MySQL 客户端工具(Navicat)或者命令行和它直接交互,而 ShardingProxy 内部则经过 MySQL 原生协议与真实的 MySQL 服务器通讯。
从架构图来看,ShardingProxy 就至关于 MySQL,它自己不存储数据,可是对外屏蔽了 Database 的存储细节,你能够用链接 MySQL 的方式去链接 ShardingProxy(除了端口不一样),用你熟悉的 ORMapping 框架使用它。
再来看下 ShardingProxy 的内部架构,后续源码分析时会涉及到此部分。
整个架构分为前端、核心组件和后端:
前端(Frontend)负责与客户端进行网络通讯,采用的是 NIO 框架,在通讯的过程当中完成对MySQL协议的编解码。
核心组件(Core-module)获得解码的 MySQL 命令后,开始调用 Sharding-Core 对 SQL 进行解析、改写、路由、归并等核心功能。
后端(Backend)与真实数据库交互,采用 Hikari 链接池,一样涉及到 MySQL 协议的编解码。
本文的 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 相关的原理知识介绍清楚了,下面正式进入问题的分析过程。
最开始拿到这个问题,我也是比较头秃的,尤为看到读者下面这段信息。
固然,个人功力是达不到盲猜水平的,说下个人完整思路。
我让读者给我打包发了 Demo 的源代码、数据库脚本以及 ShardingProxy 配置,而后本地安装了 ShardingProxy 4.1.1 版本,再经过 Navicat 链接到 ShardingProxy 执行数据库脚本,环境基本就准备完毕了。
启动 Demo 程序后,经过 Postman 发送请求,问题稳定复现了,确实查不出数据。
由于整个代码很简单,代码层面惟一有可能存在问题的是 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 配置改回成原样,继续排查。
首先,查看 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 ?
找到这个问题的解决方案后,我同步给了读者。与此同时,他也在 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。
若是你有任何疑问,欢迎评论区留言讨论。
做者简介:985硕士,前亚马逊工程师,现58转转技术总监
欢迎扫描下方的二维码,关注个人我的公众号:IT人的职场进阶