我给Apache顶级项目提了个Bug（二）

 03 问题分析 

 

上一章节基本把这个 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 的。然后，我将这些依据发给了官方开发者，对方开始重视，并正式进入源码分析阶段。

 

 04 根本原因定位 

 

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

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

 

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

1、为什么代码抛异常了，但是 ShardingProxy 的控制台没打印呢？

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

2、为什么 ShardingProxy 需要做 date 到 Timestamp 的类型转换呢？

 

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

 

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

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

 

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

 

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

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

 

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

 05 写在最后 

 

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

 

对于 ShardingSphere 这种顶级开源项目来说，我个人觉得同样值得做一次深度复盘。我不认同他们对于 issue 的处理方式，另外在核心功能的自动化测试上，也一定是存在 case 不完善的，不然不可能连续多个版本都没发现这个严重 Bug。

 

 

公众号：铭毅天下Elasticsearch